SMTP time limit ($Timeout) fails if server is not responding at all

[BurninLeo]

I had a hard day with an SMTP issue... Although the PHPMailer::$Timeout was set to 30 (does not matter which value) SMTP::get_lines() hung for a very long time (30-60 minutes). I run on an up-to-date Linux system (Ubuntu VPS, nginx, php5-pfm).

A plausible explanation was that the SMTP server does not send anything, which can cause stream_set_timeout() to be effectless. Here's is a suggestion how to modify SMTP::get_lines() to solve the issue - at least on a Linux system.

Replace the following line:

            $str = @fgets($this->smtp_conn, 515);

by the following block:

            // Use non-blocking reading for first loop to avoid the timeout being ignored because not data is received
            if (($data === '') and ($this->Timeout > 0)) {
                stream_set_blocking($this->smtp_conn, false);
                $endtimeOut = time() + $this->Timeout;
                $str = '';
                while ((time() < $endtimeOut) and (strlen($str) < 515) and !feof($this->smtp_conn)) {
                    sleep(1);  // Note: This may require tuning
                    $str.= @fgets($this->smtp_conn, 515);
                }
                if (time() >= $endtimeOut) {
                    $this->edebug(
                            'SMTP -> get_lines(): timed-out (' . $this->Timeout . ' sec)',
                            self::DEBUG_LOWLEVEL
                            );
                    break;
                }
                stream_set_blocking($this->smtp_conn, true);
            } else {
                $str = @fgets($this->smtp_conn, 515);
            }

I'd like to state explicitly that I am an expert neither on SMTP nor on non-blocking file operations. This is a practitioners solution that seems to work quite well.

[Synchro]

Unfortunately that would result in a massive performance hit. That sleep means you can never send more than 1 message per second, whereas I'm used to seeing up to about 200. We are using stream_set_timeout so I don't know why fgets would not be timing out according to that, as the docs say it should.

[BurninLeo]

Hello,

We are using stream_set_timeout so I don't know why gets would not be timing out according to that, as the docs say it should.

it does. I spent a whole day on tracking it down to this point :) I do not exactly know the background, but under some circumstances (possibly, if no data is received at all) stream_set_timeout does not limit the blocking as expected.

I also was unhappy with the performance reduction... I tried with shorter usleeps() - starting with 0 and increasing, but the feof() did not work as expected then. Finally, I came up with a solution that requires no additional sleep and solves the issue.

Replace these lines...

        while (is_resource($this->smtp_conn) && !feof($this->smtp_conn)) {
            $str = @fgets($this->smtp_conn, 515);

With those ones:

        $selR = array($this->smtp_conn);
        $selW = null;
        while (is_resource($this->smtp_conn) && !feof($this->smtp_conn)) {
            if (!stream_select($selR, $selW, $selW, $this->Timelimit)) {
                $this->edebug(
                        'SMTP -> get_lines(): timed-out (' . $this->Timeout . ' sec)',
                        self::DEBUG_LOWLEVEL
                        );
                break;
            }
            $str = @fgets($this->smtp_conn, 515);

The stream_select() timeout works as stream_set_timeout() should (but does not). In my script, 300 sec. is a bit long and it may be sensible for SMTP::setTimeout() to also affect $Timelimit - but that is another issue :)

[BurninLeo]

By the way... here's the output (with the stream_select() modification, using 10 sec. $Timelimit) from the connection that originally caused my script to hang during SMTP. The underlying cause seems to be that a user did not set TLS in the SMTP settings, but tried to connect unencrypted.

2016-01-10 13:03:40 SERVER -> CLIENT:
2016-01-10 13:03:40 CLIENT -> SERVER: EHLO www.
2016-01-10 13:03:40 SERVER -> CLIENT: * BYE Fatal error: tls_start_servertls() failed
2016-01-10 13:03:40 SMTP ERROR: EHLO command failed: * BYE Fatal error: tls_start_servertls() failed
2016-01-10 13:03:40 SMTP NOTICE: EOF caught while checking if connected
2016-01-10 13:03:40 SMTP Error: Could not authenticate.
2016-01-10 13:03:40 SMTP connect() failed. https://github.com/PHPMailer/PHPMailer/wiki/Troubleshooting

[Synchro]

This seems a little strange overall. You can't even attempt to call STARTTLS until you have connected. Do you mean you're using a traditional SMTPS (Port = 465 and SMTPSecure = 'ssl')? In this case SMTPDebug = 4 should show that happening. Because the connection is opened by an earlier fsockopen, it seems strange that it would not have already issued a select for that stream. There is a comment in the docs saying that stream_select should not be used with blocking connections (which is what we're doing), though the underlying reason is not clear.

The 300 sec default timeout is an RFC requirement, and I frequently see Yahoo servers waiting over 2 minutes before saying responding. If you're submitting via SMTP during a page load, this obviously gets in the way, but unfortunately that's the nature of SMTP - it's just not much good for anything real-time, so you need to hand off the transaction to something async, like a cron job.

[BurninLeo]

As far as I can see, the connection is created (in the logfile you see that there's a BYE response that does not stem from the PHPMailer, if I interpret this correctly?), but while the server expects TLS, some plain data is sent (no SSL or TLS). I do not exactly understand why the server ceases communication, maybe it's just waiting for further input.

There is a comment in the docs saying that stream_select should not be used with blocking connections

Good point. I read through the note twice, and can follow the argument (I hope). It says that - when set to blocking (which it is) than the stream operation will be completed before anything else is done. As stream_select() is some kind of temporary blocking function (is returns as soon as something happens or the time is up), this seems useless on a blocking read. But: As I placed the stream_select() before the reading operation, there is no blocking operation before stream_select() - making it's use sensible. If I got it correct, it's not the stream that is blocking/non-blocking, but the operation. In PHP, one may change the blocking-behavior before every fgets().

Regarding the $Timelimit: There's nothing wrong with the RFC ... well except that SMTP is somewhat outdated. I just thought that, if there is a function SMTP::setTimeout() than it may be sensible that this function does not only change $Timeout, but $Timelimit as well. Just in case, the $Timeout is set to a smaller value than $Timelimit. But possibly, I just messed up the meaning of $Timeout and $Timelimit. You probably know better which it the correct variable to be used in stream_select(), should I be able to convince you of adding this line of code :)

Of course, one should not use SMTP when loading a page. In my case it was a cronjob - but if the cronjob is killed after 1 hour due to a failed SMTP-connection (leaving later stuff in the cronjob undone), this still is a problem. Here's my trial of convincing you: Currently, under special circumstances, the $Timeout in the SMTP module seems to fail. If stream_select() does not cause other trouble (maybe its worthwhile asking the commenter from the PHP manual), catching a possible "hang up" would add reliability to PHPMailer.

[Synchro]

I think this sounds like a PHP bug since I don't see anything to suggest that fgets should ever ignore the stream timeout. I found this old bug that might be what we're seeing. Also issue #517 had exactly the opposite problem!

Another workaround (and what I'd recommend anyway) is to submit to a local mail server. That way you should never have timeout issues and you don't need to worry about cron running into trouble either.

BTW Timeout is the max allowed duration for the initial connection to return something, so that's the issue here. It covers the time from the initial connection setup until the first response from the server. Timelimit is the maximum allowed time for an SMTP command to complete after it has been issued - for example if a server is doing spam filtering on end-of-DATA, it may take a while, but the timelimit does not include the upload time itself, it only starts when the '.' has been sent. Also note that PHPMailer doubles the timelimit value for DATA (i.e. 10 mins by default) - the limits set in the RFC are a bit variable and it's easier to make everything proportional to a base value than provide lots of separate timeout properties.

[BurninLeo]

Hi, I had the issue with PHP 5.5.9 (should be the latest stable). Possible, it's still the "old" bug ... the bug report's status is still "open". Why should anyone fix the bug: The original cause still is the counterpart server ... easy to fix, usually ;)

Another workaround (and what I'd recommend anyway) is to submit to a local mail server.

Unfortunately, this is not an option in our software. Different users may specify "their own" SMTP servers - and these are usually not local... I am aware that this is not the intended use :) Btw.: A local SMTP may also fail. Imagine an update of the mailserver that changes it's response behavior...

Even if it's only a PHP bug, I'd still argue that stream_select() has no obvious disadvantages, but increases reliability by avoiding running into a PHP issue.

Thanks for the explanations regarding $Timeout and $Timelimit. $Timeout would be the appropriate variable for stream_select() then.

[Synchro]

I've made this change in the 6.0 branch - thanks for all your input and testing.

[ghoshashish]

2019-05-30 19:34:44 SERVER -> CLIENT: 250 2.0.0 Ok: queued as CD341CC950
2019-05-30 19:34:44 CLIENT -> SERVER: RSET
2019-05-30 19:34:44 SERVER -> CLIENT: 250 2.0.0 Ok

Email works fine .. no issue but displaying the client server time is not according to Indian Standard Time (IST).

According to above code the time is different from IST . Actually below is the current time.
Indian time - 2019-05-30 01:10:44

How to Change the time to IST of client server in debugging...

[Synchro]

Debug times are all UTC. You can change that by injecting your own debug output handler, but I would suggest you don’t bother. When debugging SMTP you’re usually only looking at the seconds anyway.