Help → Intermittent password problem when using SSL

Intermittent password problem when using SSL

Ticket #82 was raised about an intermittent problem when using POPFile's SSL mode to retrieve mail from a paid-for Yahoo Mail-Plus account.

System configuration:
Windows XP SP3 (the problem also happened with XP SP2), POPFile 1.1.0 (RC2) with the extra SSL support files installed, system tray icon disabled, concurrent POP3 connections disabled.

The Pegasus email client is used to check accounts at three different ISPs, all of which require SSL connections.

Sometimes POPFile will work, sometimes it won't. When it fails there are no console messages from POPFile, there is no Dr Watson error report, and popfileb.exe does not terminate.

The only sign that something has gone wrong is that Pegasus complains about a timeout and POPFile's UI cannot be accessed.

It is hard to catch this error on demand. Sometimes POPFile will work ok all day, sometimes it fails immediately.

When POPFile's logger_level was set to 2 it was found that the problem happened when logging into the Yahoo mail server. Three out of six attempts at checking Yahoo mail all failed at the same point:

11:51:13 1172: pop3: 303: USER XXXXXX
11:51:30 1172: pop3: 643: Read slurp data +OK password required.[0d][0a]
11:51:30 1172: pop3: 303: +OK password required.[0d][0a]
11:52:07 1172: mq: 377: post CMPLT (1172)

(the other two similar log extracts ended with the "+OK password required" line)

Here is what happened when a successful login occurred:

12:27:15 1172: pop3: 303: USER XXXXXX
12:27:15 1172: pop3: 643: Read slurp data +OK password required.[0d][0a]
12:27:15 1172: pop3: 303: +OK password required.[0d][0a]
12:27:15 1172: pop3: 209: Command: --PASS XXXXXX--
12:27:15 1172: pop3: 303: PASS XXXXXX
12:27:16 1172: pop3: 643: Read slurp data +OK maildrop ready, 2 messages (10952 octets) (12109)[0d][0a]
12:27:16 1172: pop3: 303: +OK maildrop ready, 2 messages (10952 octets) (12109)[0d][0a]

All of the waiting messages were received by Pegasus.

These six attempts were not all handled by the same mail server:

attempt 1 : pop102.plus.mail.mud.yahoo.com (failed)
attempt 2 : pop105.plus.mail.re2.yahoo.com (OK)
attempt 3 : pop110.plus.mail.mud.yahoo.com (failed)
attempt 4 : pop108.plus.mail.mud.yahoo.com (OK)
attempt 5 : pop101.plus.mail.mud.yahoo.com (OK)
attempt 6 : pop110.plus.mail.mud.yahoo.com (failed, see attempt 3)

All six attempts at logging in to the other two ISPs via SSL all worked OK.

I don't know what to do next.

Brian

  • Message #427

    I've had an idea. By default POPFile's POP3 listen port is set to 110 which is the default port for POP3 traffic. Nowadays most anti-virus programs use a transparent proxy to scan incoming email and as a result they also listen on port 110.

    Unfortunately Windows does not seem to handle this sort of situation very well and this may be causing your intermittent problem, e.g. when POPFile gets the "+OK password required" response from the mail server it tries to pass this back to Pegasus but sometimes Pegasus never gets the message so you end up with POPFile waiting for Pegasus to supply the password while Pegasus is waiting for the "+OK password required" response from POPFile ... hence the intermittent timeout error you get from Pegasus.

    An easy way to solve this problem is to change POPFile's "POP3 Listen Port" to, say, 124 using the CONFIGURATION page in the UI (you'll need to shutdown POPFile and then restart it for this change to take effect) and also change the POP3 port Pegasus is using (for all the accounts handled by POPFile) to 124.

    Try this and see if it helps. (I have been using a non-standard POPFile POP3 listen report for over 5 years which is why it has taken me so long to think of this solution.)

    Of course there is still the problem that POPFile should not stop responding just because Pegasus has not supplied the expected password message... with forking disabled, the UI will not respond until the POP3 activity has finished so it looks like that part of POPFile needs to be looked at again.

    Brian

  • Message #428

    Hi Brian

    11:51:13 1172: pop3: 303: USER XXXXXX
    11:51:30 1172: pop3: 643: Read slurp data +OK password required.[0d][0a]

    There's strange delay (17 seconds!) before the mail server's response.
    Is there same delay in other logs?

    Pegasus Mail's connection timeout seems to be 30 seconds by default.
    Pegasus Mail may have given up waiting response from POPFile.

    But why the delay occurs?
    I remember we have had similar problem (delay on SSL) long ago.

    The delay seems to be from this line in Proxy/Proxy.pm :

        my ($ready) = $selector->can_read( (!$null_resp?$self->global_config_( 'timeout' ):.5) );
    

    http://getpopfile.org/browser/branches/b0_22_2/engine/Proxy/Proxy.pm#L399

    To check the internal buffer of OpenSSL may solve the problem again.

    Here's my old post:

    http://sourceforge.net/forum/message.php?msg_id=2776475

    I'll write a patch to do this.

    Naoki

    • Message #429

      There's strange delay (17 seconds!) before the mail server's response.

      Well spotted, Naoki! I'd not checked the timestamps for those entries.

      Is there same delay in other logs?

      The log shows no delays like this when checking the other ISPs. There was no new mail waiting for those accounts and the entire sequence only took 2 or 3 seconds (from the initial "+OK POP3 POPFile" entry to the "+OK goodbye" entry at the end).

      However the Yahoo servers did not respond so quickly in the 3 cases that failed.

      In the 3 cases that worked, the Yahoo server response was faster (e.g. the entire sequence to download 5 messages took only 5 seconds). Does this mean the problem is an intermittent Yahoo one?

      I've sent you the annotated log file which used to be attached to Ticket #82.

      Brian

      • Message #430

        In the 3 cases that worked, the Yahoo server response was faster (e.g. the entire sequence to download 5 messages took only 5 seconds). Does this mean the problem is an intermittent Yahoo one?

        Maybe.

        I've sent you the annotated log file which used to be attached to Ticket #82.

        Thanks. And I've found more strange delay in the log:

        2008/8/25 11:45:39 1172: mq: 386: LOGIN queue length now 0
        2008/8/25 11:50:50 1172: pop3: 514: Attempting to connect to SSL server at pop.mail.yahoo.com:995
        
        2008/8/30 13:41:30 2392: mq: 386: LOGIN queue length now 0
        2008/8/30 13:43:52 2392: pop3: 514: Attempting to connect to SSL server at pop.mail.yahoo.com:995
        
        2008/9/9 14:36:39 664: mq: 386: LOGIN queue length now 0
        2008/9/9 14:39:00 664: pop3: 514: Attempting to connect to SSL server at pop.mail.yahoo.com:995
        

        POPFile spent 2 or 5 minutes to connect the mail server.
        First, we need to figure out what is occurring.

        Naoki

        • Message #431

          POPFile spent 2 or 5 minutes to connect the mail server.
          First, we need to figure out what is occurring.

          Although I have not figured out the exact cause of the problem,
          I've written an experimental workaround patch and post it to the
          repository: [3351]

          The main topics are:

          1. Add Timeout to the connection options.
          2. Add MultiHomed? to the connection options. (I don't understand what this option does, but in this case yahoo's mail server seems to be multihomed.)
          3. Check the internal buffer of OpenSSL.

          I hope this change has good effect to the problem.

          Naoki

    • Message #432

      Hi Guys,

      Pegasus Mail's connection timeout seems to be 30 seconds by default.
      Pegasus Mail may have given up waiting response from POPFile.

      For reference, in an unsuccessful effort to correct the problem:

      Some months ago, I changed the POPFile connection timeout to 90 seconds.

      And some months ago I changed Pegasus Mail's POP3 receiving timeout to 120 seconds.

      Pegasus is waiting a long time before it returns with it's "8: Socket read timeout" message.

      Not sure if this helps to shed light.

      Thanks,

      Stefan

      • Message #433

        Pegasus Mail's connection timeout seems to be 30 seconds by default.
        Pegasus Mail may have given up waiting response from POPFile.


        For reference, in an unsuccessful effort to correct the problem:

        Some months ago, I changed the POPFile connection timeout to 90 seconds.

        And some months ago I changed Pegasus Mail's POP3 receiving timeout to 120 seconds.

        Thanks for the information.

        2008/8/25 11:45:39 1172: pop3: 209: Command: --USER XXXXXX--
        <snip>
        2008/8/25 11:51:30 1172: pop3: 303: +OK password required.[0d][0a]
        
        2008/8/30 13:41:30 2392: pop3: 209: Command: --USER XXXXXX--
        <snip>
        2008/8/30 13:43:57 2392: pop3: 303: +OK password required.[0d][0a]
        
        2008/9/9 14:36:39 664: pop3: 209: Command: --USER XXXXXX--
        <snip>
        2008/9/9 14:39:06 664: pop3: 303: +OK password required.[0d][0a]
        

        Here's snippets from your log file.
        The first line of each snippet means POPFile received USER command from your mail client.
        And the second line means POPFile sent the result of the command to your mail client.

        In the first case, your mail client have to have waited 351 seconds.
        The second and third: 147 seconds.

        As I mentioned in the other post, I've committed an experimental workaround code:

        http://getpopfile.org/browser/branches/b0_22_2/engine/Proxy/Proxy.pm?rev=3351

        If you can, please download the new code from the 'Original Format' link in the bottom of the page and replace the file in your POPFile installation folder with it.

        I hope this workaround has good effect for your problem.

        Naoki

        • Message #435

          Hi Naoki,

          Thank you for your revised module of Proxy.pm. I've downloaded it and put it into the POPFile installation here. We'll see how it goes. I won't know immediately because of the intermittent nature of the failure, but I'll let you know.

          Thanks,

          Stefan

        • Message #466

          Hi Naoki,

          Re: Follow up since installing your proxy.pm workaround

          POPFile operation is looking good. I've looked through the POPFile logs since installing your workaround:

          1. The password transactions on the yahoo account have been delivering the password a-ok.

          2. There have been none of the very long delays that you pointed out in earlier logs.

          Thanks again,

          Stefan

        • Message #470

          Hi Naoki,

          I'm running with POPFileb today and have encountered further weird-looking transaction failures. Here is a log sample. Not sure what to make of this.

          Thanks,

          Stefan

          2008/9/16 14:10:25 2552: pop3: 303: +OK POP3 POPFile (v1.1.0) server ready[0d][0a]
          2008/9/16 14:10:25 2552: pop3: 194: Regexps: ^USER XXXXXX
          2008/9/16 14:10:25 2552: pop3: 209: Command: --USER XXXXXX--
          2008/9/16 14:10:25 2552: mq: 377: post LOGIN ([YahooUserProfile])
          2008/9/16 14:10:25 2552: mq: 384: queuing post LOGIN ([YahooUserProfile])
          2008/9/16 14:10:25 2552: mq: 386: LOGIN queue length now 0
          2008/9/16 14:10:25 2552: pop3: 519: Attempting to connect to SSL server at pop.mail.yahoo.com:995
          
          
          Pegasus Mail waits 120 (or more?) seconds, times out and reports:
          
          [*] Connection established to 127.0.0.1
          >> 0040 +OK POP3 POPFile (v1.1.0) server ready
          << 0066 USER pop.mail.yahoo.com:995:[YahooUserProfile]:ssl
          8: Socket read timeout.
          
          Then Pegasus drops it's timeout error dialog and POPFile continues as if it 
          had connected ok?
           
          But the password transaction fails because Pegasus had earlier timed out?
          
          2008/9/16 14:15:17 2552: pop3: 545: Connected to pop.mail.yahoo.com:995 timeout 90
          2008/9/16 14:15:17 2552: pop3: 593: Connection returned: +OK hello from popgate 2.40 on pop110.plus.mail.mud.yahoo.com[0d][0a]
          2008/9/16 14:15:17 2552: pop3: 306: auth plaintext
          2008/9/16 14:15:17 2552: pop3: 303: USER XXXXXX
          2008/9/16 14:15:32 2552: pop3: 643: Read slurp data +OK password required.[0d][0a]
          2008/9/16 14:15:32 2552: pop3: 303: +OK password required.[0d][0a]
          2008/9/16 14:15:32 2552: mq: 377: post CMPLT (2552)
          2008/9/16 14:15:32 2552: mq: 388: dropping post CMPLT (2552)
          2008/9/16 14:15:32 2552: pop3: 667: POP3 proxy done
          2008/9/16 14:15:32 2552: mq: 128: Message LOGIN ([YahooUserProfile]) ready for delivery
          2008/9/16 14:15:32 2552: mq: 131: Delivering message LOGIN ([YahooUserProfile]) to html
          
          • Message #480

            Hi Stefan

            2008/9/16 14:10:25 2552: pop3: 519: Attempting to connect to SSL server at pop.mail.yahoo.com:995
            <snip> 
            2008/9/16 14:15:17 2552: pop3: 545: Connected to pop.mail.yahoo.com:995 timeout 90
            

            It seems that it took almost 5 minutes before POPFile connected to the mail server.
            That is strange. POPFile should time out in 90 seconds...

            Er..., ok.
            The older version of IO::Socket::SSL does not seem to support the Timeout option:

            http://search.cpan.org/src/SULLR/IO-Socket-SSL-1.15/Changes

            We have to use version 1.10 or later to use the Timeout option.
            The earlier version waits forever to connect to the server.
            The Windows version is using v1.08.

            Brian, can we update IO::Socket::SSL?

            Then Pegasus drops it's timeout error dialog and POPFile continues as if it
            had connected ok?

            But the password transaction fails because Pegasus had earlier timed out?

            I think you're right.

            Naoki

            • Message #485

              Brian, can we update IO::Socket::SSL?

              Yes. Will IO::Socket::SSL v1.13 be good enough?

              I've made a special version of the small SSL Support wizard (addssl_rc4.zip, 663 KB) to make it install this new version together with the rest of the usual SSL files from the University of Winnipeg.

              Or would you rather have an RC5 with your latest SVN changes?

              Brian

              • Message #488

                I've made a special version of the small SSL Support wizard

                Forgot to give the download link to the file: addssl_rc4.zip

                This wizard will install the SSL files into an existing POPFile installation and, unlike the current 1.1.0 RC4 installer, it will install a version of IO::Socket::SSL which supports the "timeout" option.

                Brian

              • Message #489

                Hi Brian

                Yes. Will IO::Socket::SSL v1.13 be good enough?

                I think it will.

                I've made a special version of the small SSL Support wizard (addssl_rc4.zip, 663 KB) to make it install this new version together with the rest of the usual SSL files from the University of Winnipeg.

                Thank you for your immediate work!

                Stefan, can you try the new SSL wizard?

                Or would you rather have an RC5 with your latest SVN changes?

                No. Let's go to RC5 if the new module solves the problem.

                Naoki

                • Message #497

                  Hi Naoki & Brian,

                  Thanks for the newest patches. To confirm that I've properly installed these for testing:

                  I installed the POPFile v1.10 RC4 setup-RC4.exe, and then applied the RC4 addssl.exe.

                  I double checked the timeouts: POPFile is set for a 90 second timeout; Pegasus is set for 120 sec timeouts. I expect that this is way larger than would normally be needed, but we're trying to give the somehwat temperamental Yahoo transaction plenty of time.

                  Anything else I should be doing to help the testing process?

                  Stefan

  • Message #500

    Hi Naoki & Brian,

    Revisiting the current status and errors:

    I have POPFile v1.10 RC4 installed with addssl.exe RC4 applied. I'm seeing the following two errors on an intermittent basis.

    1. The timeout miscoordination appears to not yet have been solved:

    2008/9/21 15:54:27 1252: pop3: 303: +OK POP3 POPFile (v1.1.0) server ready[0d][0a]
    2008/9/21 15:54:27 1252: pop3: 194: Regexps: ^USER XXXXXX
    2008/9/21 15:54:27 1252: pop3: 209: Command: --USER XXXXXX--
    2008/9/21 15:54:27 1252: mq: 377: post LOGIN ([YahooUserProfile])
    2008/9/21 15:54:27 1252: mq: 384: queuing post LOGIN ([YahooUserProfile])
    2008/9/21 15:54:27 1252: mq: 386: LOGIN queue length now 0
    2008/9/21 15:54:27 1252: pop3: 519: Attempting to connect to SSL server at pop.mail.yahoo.com:995
    
    
    Pegasus mail times out after 120 seconds with this message:
    
    [*] Connection established to 127.0.0.1
    >> 0040 +OK POP3 POPFile (v1.1.0) server ready
    << 0066 USER pop.mail.yahoo.com:995:[YahooUserProfile]:ssl
    8: Socket read timeout.
    
    
    After the Pegasus mail error message has cleared, there is further POPFile log delay
    and then POPFile continues as if it has connected ok:
    
    2008/9/21 15:59:58 1252: pop3: 545: Connected to pop.mail.yahoo.com:995 timeout 90
    2008/9/21 15:59:58 1252: pop3: 593: Connection returned: +OK hello from popgate 2.40 on pop110.plus.mail.mud.yahoo.com[0d][0a]
    2008/9/21 15:59:59 1252: pop3: 306: auth plaintext
    2008/9/21 15:59:59 1252: pop3: 303: USER XXXXXX
    
    
    And then another POPFile log delay before the log continues. 
    
    2008/9/21 16:01:16 1252: pop3: 643: Read slurp data +OK password required.[0d][0a]
    2008/9/21 16:01:16 1252: pop3: 303: +OK password required.[0d][0a]
    2008/9/21 16:01:16 1252: mq: 377: post CMPLT (1252)
    2008/9/21 16:01:16 1252: mq: 388: dropping post CMPLT (1252)
    2008/9/21 16:01:16 1252: pop3: 667: POP3 proxy done
    2008/9/21 16:01:16 1252: mq: 128: Message LOGIN ([YahooUserProfile]) ready for delivery
    2008/9/21 16:01:16 1252: mq: 131: Delivering message LOGIN ([YahooUserProfile]) to html
    

    2. I'm also seeing an -ERR can't connect to pop.mail.yahoo.com:995
    This could be a yahoo busy condition.

    However, I did not start seeing it until after we had put in the revised proxy.pm and after I had moved up to v1.10 RC3, so POPFile may also be playing a role in this error.

    2008/9/21 16:04:08 1252: pop3: 303: +OK POP3 POPFile (v1.1.0) server ready[0d][0a]
    2008/9/21 16:04:08 1252: pop3: 194: Regexps: ^USER XXXXXX
    2008/9/21 16:04:08 1252: pop3: 209: Command: --USER XXXXXX--
    2008/9/21 16:04:08 1252: mq: 377: post LOGIN ([YahooUserProfile])
    2008/9/21 16:04:08 1252: mq: 384: queuing post LOGIN ([YahooUserProfile])
    2008/9/21 16:04:08 1252: mq: 386: LOGIN queue length now 0
    2008/9/21 16:04:08 1252: pop3: 519: Attempting to connect to SSL server at pop.mail.yahoo.com:995
    2008/9/21 16:04:29 1252: pop3: 303: -ERR can't connect to pop.mail.yahoo.com:995[0d][0a]
    
    
    [*] Connection established to 127.0.0.1
    >> 0040 +OK POP3 POPFile (v1.1.0) server ready
    << 0066 USER pop.mail.yahoo.com:995:[YahooUserProfile]:ssl
    >> 0046 -ERR can't connect to pop.mail.yahoo.com:995
    
    
    2008/9/21 16:05:21 1252: pop3: 209: Command: --QUIT--
    2008/9/21 16:05:21 1252: pop3: 303: +OK goodbye[0d][0a]
    2008/9/21 16:05:21 1252: mq: 377: post CMPLT (1252)
    2008/9/21 16:05:21 1252: mq: 388: dropping post CMPLT (1252)
    2008/9/21 16:05:21 1252: pop3: 667: POP3 proxy done
    2008/9/21 16:05:22 1252: mq: 128: Message LOGIN ([YahooUserProfile]) ready for delivery
    2008/9/21 16:05:22 1252: mq: 131: Delivering message LOGIN ([YahooUserProfile]) to html
    

    What do you think? Brian has reviewed some of our recent conversation on trouble ticket #82 and suggested looking at stunnel as an alternative. I'll look into stunnel as I'm able.

    (I have a big bunch of doctor appointments and medical labs in the next couple of weeks. That will preempt my time, though I'll make every effort to be present for further troubleshooting.)

    Thanks for your dedication,

    Stefan

    • Message #501

      I'll look into stunnel as I'm able

      I've downloaded the Windows version of Stunnel-4.26 and managed to get it to connect to a POP3 mail server via SSL. Once the connection was made I could use telnet to talk to the mail server via Stunnel.

      The hardest part was getting it configured. I found lots of examples but could not get them to work at all ... until I stumbled across a page that discussed upgrading to stunnel4 and gave a link to the old version 3 man page.

      The home page at http://www.stunnel.org/ had warned about this problem ("Since the release of Stunnel-4.x, a major change to the architecture, these web pages have not all been updated to reflect the new changes.") but I'd not realised just how much had changed between the 3.x and 4.x versions (and to make things worse, the pages I had been looking at just referred to "stunnel" so I did not know I was looking at 3.x examples).

      Brian

    • Message #502

      Hi Stefan,

      1. The timeout miscoordination appears to not yet have been solved:

      Thank you for the report.

      It seems that the Timeout option does not work on Windows.
      I've written a test script which tries to connect Yahoo! mail server every 5 seconds and executed it on Windows and on Mac OS X.

      The test script:
      http://getpopfile.org/attachment/ticket/82/ssl_test.pl

      The results:
      http://getpopfile.org/attachment/ticket/82/test_v113_windows.log
      http://getpopfile.org/attachment/ticket/82/test_v113_macosx.log

      As you see, the script gave up to connect the mail server on Mac OS X after about 60 seconds passed:

      2008/9/23 15:20:39 49399: --- Try 12 ---
      2008/9/23 15:20:39 49399: Attempting to connect to SSL server at pop.mail.yahoo.com:995
      2008/9/23 15:21:50 49399: Cannot connect to pop.mail.yahoo.com:995
      2008/9/23 15:21:50 49399: --- failed in 71 second(s) ---
      

      But on Windows, the script kept trying to connect the server for over 4 minutes:

      2008/9/23 16:12:00 792: --- Try 30 ---
      2008/9/23 16:12:00 792: Attempting to connect to SSL server at pop.mail.yahoo.com:995
      2008/9/23 16:15:57 792: Connected to pop.mail.yahoo.com:995 timeout 60
      2008/9/23 16:15:57 792: Connection returned: +OK hello from popgate 2.40 on pop110.plus.mail.mud.yahoo.com[0d][0a]
      2008/9/23 16:15:57 792: --- succeeded in 237 second(s) ---
      

      The main problem is that the server 'pop110.plus.mail.mud.yahoo.com' is dead slow.
      In my test, it took every time about 4 or 5 minutes for connecting to that server:

      2008/9/23 16:12:00 792: --- Try 30 ---
      2008/9/23 16:12:00 792: Attempting to connect to SSL server at pop.mail.yahoo.com:995
      2008/9/23 16:15:57 792: Connected to pop.mail.yahoo.com:995 timeout 60
      2008/9/23 16:15:57 792: Connection returned: +OK hello from popgate 2.40 on pop110.plus.mail.mud.yahoo.com[0d][0a]
      2008/9/23 16:15:57 792: --- succeeded in 237 second(s) ---
      
      2008/9/23 16:20:42 792: --- Try 74 ---
      2008/9/23 16:20:42 792: Attempting to connect to SSL server at pop.mail.yahoo.com:995
      2008/9/23 16:24:42 792: Connected to pop.mail.yahoo.com:995 timeout 60
      2008/9/23 16:25:15 792: Connection returned: +OK hello from popgate 2.40 on pop110.plus.mail.mud.yahoo.com[0d][0a]
      2008/9/23 16:25:15 792: --- succeeded in 273 second(s) ---
      
      2008/9/23 16:27:52 792: --- Try 95 ---
      2008/9/23 16:27:52 792: Attempting to connect to SSL server at pop.mail.yahoo.com:995
      2008/9/23 16:32:18 792: Connected to pop.mail.yahoo.com:995 timeout 60
      2008/9/23 16:32:18 792: Connection returned: +OK hello from popgate 2.40 on pop110.plus.mail.mud.yahoo.com[0d][0a]
      2008/9/23 16:32:18 792: --- succeeded in 266 second(s) ---
      
      2008/9/23 16:33:02 792: --- Try 100 ---
      2008/9/23 16:33:02 792: Attempting to connect to SSL server at pop.mail.yahoo.com:995
      2008/9/23 16:37:26 792: Connected to pop.mail.yahoo.com:995 timeout 60
      2008/9/23 16:37:26 792: Connection returned: +OK hello from popgate 2.40 on pop110.plus.mail.mud.yahoo.com[0d][0a]
      2008/9/23 16:37:26 792: --- succeeded in 264 second(s) ---
      

      I'm wondering why just this specific server is so slow...

      BTW, I've tried to connect to the Yahoo! mail server several times using OpenSSL (openssl s_client command) and found it takes sometimes long time to connect to the server named 'pop110'.

      Brian, the new version of IO::Socket::SSL did not solve the problem.
      Do you think we should go back to the original (v1.08) version?

      Naoki

      • Message #503

        Brian, the new version of IO::Socket::SSL did not solve the problem.

        Do you think we should go back to the original (v1.08) version?

        V1.16.1 came out a few days ago. Why not try using one of the newer versions of IO::Socket::SSL from the "archive" link on the module's CPAN page?

        http://backpan.perl.org/authors/id/S/SU/SULLR/ includes

        IO-Socket-SSL-1.13.tar.gz 27-Jan-2008 22:44
        IO-Socket-SSL-1.13_2.tar.gz 22-Feb-2008 01:07
        IO-Socket-SSL-1.13_3.tar.gz 24-Feb-2008 01:42
        IO-Socket-SSL-1.13_4.tar.gz 25-Feb-2008 13:18
        IO-Socket-SSL-1.13_5.tar.gz 10-Mar-2008 01:46
        IO-Socket-SSL-1.14.tar.gz 16-Jul-2008 02:27
        IO-Socket-SSL-1.15.tar.gz 28-Aug-2008 13:03
        IO-Socket-SSL-1.16.tar.gz 18-Sep-2008 23:34
        IO-Socket-SSL-1.16_1.tar.gz 19-Sep-2008 09:54

        I checked the SSL.pm file from IO-Socket-SSL-1.13.tar.gz and it was identical to the version my modified addssl.exe wizard installs, so I guess the SSL.pm files from the more recent versions can be used with RC4's minimal Perl.

        I've not tried reading the ReadMe? files for these various releases (and I'm not sure I'd understand them)

        I think it would be worth trying these to see if any of them work better than v1.13.

        Brian

        • Message #504

          V1.16.1 came out a few days ago. Why not try using one of the newer versions of IO::Socket::SSL from the "archive" link on the module's CPAN page?

          V1.16.1 is developer release so I tried v1.16.
          Here's the result:

          http://getpopfile.org/attachment/ticket/82/test_v116_windows.log

          2008/9/23 23:20:59 1268: --- Try 35 ---
          2008/9/23 23:20:59 1268: Attempting to connect to SSL server at pop.mail.yahoo.com:995
          2008/9/23 23:26:23 1268: Connected to pop.mail.yahoo.com:995 timeout 60
          2008/9/23 23:26:23 1268: Connection returned: +OK hello from popgate 2.40 on pop110.plus.mail.mud.yahoo.com[0d][0a]
          2008/9/23 23:26:23 1268: --- succeeded in 324 second(s) ---
          
          2008/9/23 23:29:04 1268: --- Try 53 ---
          2008/9/23 23:29:04 1268: Attempting to connect to SSL server at pop.mail.yahoo.com:995
          2008/9/23 23:34:03 1268: Connected to pop.mail.yahoo.com:995 timeout 60
          2008/9/23 23:34:09 1268: Connection returned: +OK hello from popgate 2.40 on pop110.plus.mail.mud.yahoo.com[0d][0a]
          2008/9/23 23:34:09 1268: --- succeeded in 305 second(s) ---
          
          2008/9/23 23:35:29 1268: --- Try 61 ---
          2008/9/23 23:35:29 1268: Attempting to connect to SSL server at pop.mail.yahoo.com:995
          2008/9/23 23:40:06 1268: Connected to pop.mail.yahoo.com:995 timeout 60
          2008/9/23 23:40:33 1268: Connection returned: +OK hello from popgate 2.40 on pop110.plus.mail.mud.yahoo.com[0d][0a]
          2008/9/23 23:40:33 1268: --- succeeded in 304 second(s) ---
          

          Unfortunately the same result.

          And here's the IO::Socket::SSL debug log with my test log:

          2008/9/23 23:35:29 1268: --- Try 61 ---
          2008/9/23 23:35:29 1268: Attempting to connect to SSL server at pop.mail.yahoo.com:995
          DEBUG: .../IO/Socket/SSL.pm:202: CA file certs/my-ca.pem not found, using CA path instead.
          
          DEBUG: .../IO/Socket/SSL.pm:1387: new ctx 30752136
          DEBUG: .../IO/Socket/SSL.pm:269: socket not yet connected
          DEBUG: .../IO/Socket/SSL.pm:271: socket connected
          DEBUG: .../IO/Socket/SSL.pm:284: ssl handshake not started
          
          --- long delay ---
          
          DEBUG: .../IO/Socket/SSL.pm:327: Net::SSLeay::connect -> 1
          DEBUG: .../IO/Socket/SSL.pm:382: ssl handshake done
          2008/9/23 23:40:06 1268: Connected to pop.mail.yahoo.com:995 timeout 60
          2008/9/23 23:40:33 1268: Connection returned: +OK hello from popgate 2.40 on pop110.plus.mail.mud.yahoo.com[0d][0a]
          2008/9/23 23:40:33 1268: --- succeeded in 304 second(s) ---
          DEBUG: .../IO/Socket/SSL.pm:1422: free ctx 30752136 open=30752136
          DEBUG: .../IO/Socket/SSL.pm:1425: OK free ctx 30752136
          

          IO::Socket::SSL debug log on Mac OS X:

          2008/9/23 17:59:53 49562: --- Try 81 ---
          2008/9/23 17:59:53 49562: Attempting to connect to SSL server at pop.mail.yahoo.com:995
          DEBUG: .../IO/Socket/SSL.pm:202: CA file certs/my-ca.pem not found, using CA path instead.
          
          DEBUG: .../IO/Socket/SSL.pm:1387: new ctx 4775376
          DEBUG: .../IO/Socket/SSL.pm:269: socket not yet connected
          DEBUG: .../IO/Socket/SSL.pm:271: socket connected
          DEBUG: .../IO/Socket/SSL.pm:284: ssl handshake not started
          DEBUG: .../IO/Socket/SSL.pm:314: set socket to non-blocking to enforce timeout=60
          DEBUG: .../IO/Socket/SSL.pm:327: Net::SSLeay::connect -> -1
          DEBUG: .../IO/Socket/SSL.pm:337: ssl handshake in progress
          DEBUG: .../IO/Socket/SSL.pm:347: waiting for fd to become ready: SSL wants a read first
          DEBUG: .../IO/Socket/SSL.pm:357: handshake failed because socket did not became ready
          DEBUG: .../IO/Socket/SSL.pm:1135: IO::Socket::INET configuration failederror:00000000:lib(0):func(0):reason(0)
          
          DEBUG: .../IO/Socket/SSL.pm:1422: free ctx 4775376 open=4775376
          DEBUG: .../IO/Socket/SSL.pm:1425: OK free ctx 4775376
          2008/9/23 18:00:57 49562: Cannot connect to pop.mail.yahoo.com:995
          2008/9/23 18:00:57 49562: --- failed in 64 second(s) ---
          
          

          There are some differences in these logs.

          First, the line

          DEBUG: .../IO/Socket/SSL.pm:314: set socket to non-blocking to enforce timeout=60
          

          exists only in the Mac OS X log.

          This debug log is from here:

          	if ( defined($timeout) && $timeout>0 && $self->blocking(0) ) {
          		DEBUG(2, "set socket to non-blocking to enforce timeout=$timeout" );
          		# timeout was given and socket was blocking
          		# enforce timeout with now non-blocking socket
          	} else {
          		# timeout does not apply because invalid or socket non-blocking
          		$timeout = undef; 
          	}
          

          This means that the timeout option is ignored (undef-ed) on Windows.

          Second, on Windows Net::SSLeay::connect seems to block.
          On Mac OS X, Net::SSLeay::connect returns immediately.

          I don't know what is causing these differences.

          Naoki

          • Message #505

            This means that the timeout option is ignored (undef-ed) on Windows.

            Second, on Windows Net::SSLeay::connect seems to block.
            On Mac OS X, Net::SSLeay::connect returns immediately.

            I think the documentation for IO::Socket::SSL says the timeout will only be used if the underlying socket is not blocking - this seems to confirm your findings.

            It looks like we need to find a version of Net::SSLeay that does not block on Windows systems. I don't know if there is such a thing.

            Could the blocking be caused by something other than Net::SSLeay?

            Have you compared the versions of the Perl modules used on your Windows and Mac OS X systems - that might provide some clues?

            Brian

            • Message #506

              Could the blocking be caused by something other than Net::SSLeay?

              Your Mac OS X debug log mentions IO::Socket::INET which sounds like the underlying socket that IO::Socket::SSL uses:

              DEBUG: .../IO/Socket/SSL.pm:1135: IO::Socket::INET configuration failederror:00000000:lib(0):func(0):reason(0)
              

              Brian

            • Message #510

              It looks like we need to find a version of Net::SSLeay that does not block on Windows systems. I don't know if there is such a thing.

              Net::SSLeay::connect calls SSL_connect function of OpenSSL.
              Here's the document about SSL_connect:

              https://www.openssl.org/docs/ssl/SSL_connect.html

              The behaviour of SSL_connect() depends on the underlying BIO.

              If the underlying BIO is blocking, SSL_connect() will only return once the handshake has been finished or an error occurred.

              SSL_connect blocks when the underlying BIO is blocking.

              So we need to change the socket to non-blocking mode.

              To change the blocking mode, IO::Socket::SSL has 'blocking' function and
              it calls 'io_blocking' function of IO module:

              http://search.cpan.org/src/GBARR/IO-1.2301/IO.xs

              static int
              io_blocking(pTHX_ InputStream f, int block)
              {
              #if defined(HAS_FCNTL)
              <snip>
              #else
                  return -1;
              #endif
              }
              

              On Windows, HAS_FCNTL is not defined. So the function always returns -1.
              (In the Perl side, IO::Socet::SSL::blocking always returns undef)

              This means that we can't use the non-blocking mode if we normally use
              IO::Socket::SSL on Windows. We have to use ioctl function to change
              the blocking mode.

              For more information, please see:
              http://www.perlmonks.org/?node_id=529812

              Now we have two choices:

              1. Modify IO::Socket::SSL to support non-blocking mode
              2. Create a new module which inherits IO::Socket::SSL and override blocking function

              The former may be easy to implement but is not smart.
              The latter is smart but may be difficult to implement.

              Naoki

              • Message #511

                I found another approach.

                At first, connect to the server using IO::Socket::INET.
                Second, change the connection socket to the non-blocking mode.
                Third, upgrade the connection socket to SSL using IO::Socket::SSL->start_SSL.

                The changes: [3372]

                I tested the new code on Windows 2000 Pro SP4 with IO::Socket::SSL v1.03 and
                it seems to solve the problem.

                The new Proxy.pm can be downloaded at:
                http://getpopfile.org/browser/branches/b0_22_2/engine/Proxy/Proxy.pm?rev=3372

                Stefan, can you try this?

                Naoki

                • Message #512

                  Here's an example of the POPFile log file:

                  2008/9/26 00:05:22 1276: pop3: 522: Attempting to connect to SSL server at mail.mac.com:995
                  2008/9/26 00:05:23 1276: pop3: 541: Try to upgrade socket IO::Socket::INET=GLOB(0xdc5fa8) to SSL
                  2008/9/26 00:05:36 1276: pop3: 553: Got an error SSL wants a read first from start_SSL
                  2008/9/26 00:05:37 1276: pop3: 553: Got an error SSL wants a read first from start_SSL
                  2008/9/26 00:05:37 1276: pop3: 573: The socket IO::Socket::SSL=GLOB(0xdc5fa8) has successfully been upgraded
                  2008/9/26 00:05:37 1276: pop3: 602: Connected to mail.mac.com:995 timeout 60
                  
                • Message #513

                  Hi Naoki,

                  I've got your revised proxy.pm in place and running. Sample of a good connect looks like your example:

                  2008/9/25 12:42:40 3340: pop3: 522: Attempting to connect to SSL server at pop.mail.yahoo.com:995
                  2008/9/25 12:42:41 3340: pop3: 542: Trying to upgrade socket IO::Socket::INET=GLOB(0xfb19dc) to SSL
                  2008/9/25 12:42:41 3340: pop3: 555: Got an error SSL wants a read first from start_SSL
                  2008/9/25 12:42:41 3340: pop3: 555: Got an error SSL wants a read first from start_SSL
                  2008/9/25 12:42:41 3340: pop3: 575: The socket IO::Socket::SSL=GLOB(0xfb19dc) has successfully been upgraded
                  2008/9/25 12:42:41 3340: pop3: 604: Connected to pop.mail.yahoo.com:995 timeout 90
                  

                  Thanks,

                  Stefan

  • Message #514

    [Revisit encore of POPFile status and errors. This will be following message #513. I'm starting at a higher outline level because we're getting so squeezed to the right.]

    Hi Naoki & Brian,

    Running with POPFile RC4, addssl RC4, proxy.pm updated 2008-09-25

    Mail pickup from Yahoo has been failing all afternoon since the installation
    of the revised proxy.pm. I don't know if this is the software or further instability
    of the yahoo pool of POP3 servers. (I did receive a message through gmail.)

    POPFile sees that there are two messages for pickup, and then appears to
    immediately determine that there is no response from the server. Should
    POPFile be waiting a bit longer there for a server response?

    Here is a sample: There are two messages for pickup but they fail to get downloaded.

    I did log onto Yahoo webmail. There are indeed two messages waiting for POP3 download.

    2008/9/25 14:06:18 3340: pop3: 305: +OK POP3 POPFile (v1.1.0) server ready[0d][0a]
    2008/9/25 14:06:18 3340: pop3: 194: Regexps: ^USER XXXXXX
    2008/9/25 14:06:18 3340: pop3: 209: Command: --USER XXXXXX--
    2008/9/25 14:06:18 3340: mq: 377: post LOGIN ([YahooUserProfile])
    2008/9/25 14:06:18 3340: mq: 384: queuing post LOGIN ([YahooUserProfile])
    2008/9/25 14:06:18 3340: mq: 386: LOGIN queue length now 0
    2008/9/25 14:06:18 3340: pop3: 522: Attempting to connect to SSL server at pop.mail.yahoo.com:995
    2008/9/25 14:06:18 3340: pop3: 542: Trying to upgrade socket IO::Socket::INET=GLOB(0x17f4544) to SSL
    2008/9/25 14:06:18 3340: pop3: 555: Got an error SSL wants a read first from start_SSL
    2008/9/25 14:06:18 3340: pop3: 555: Got an error SSL wants a read first from start_SSL
    2008/9/25 14:06:18 3340: pop3: 575: The socket IO::Socket::SSL=GLOB(0x17f4544) has successfully been upgraded
    2008/9/25 14:06:18 3340: pop3: 604: Connected to pop.mail.yahoo.com:995 timeout 90
    2008/9/25 14:06:18 3340: pop3: 652: Connection returned: +OK hello from popgate 2.40 on pop108.plus.mail.mud.yahoo.com[0d][0a]
    2008/9/25 14:06:18 3340: pop3: 306: auth plaintext
    2008/9/25 14:06:18 3340: pop3: 305: USER XXXXXX
    2008/9/25 14:06:18 3340: pop3: 643: Read slurp data +OK password required.[0d][0a]
    2008/9/25 14:06:18 3340: pop3: 305: +OK password required.[0d][0a]
    2008/9/25 14:06:18 3340: pop3: 209: Command: --PASS XXXXXX--
    2008/9/25 14:06:18 3340: pop3: 305: PASS XXXXXX
    2008/9/25 14:06:19 3340: pop3: 643: Read slurp data +OK maildrop ready, 2 messages (11873 octets) (13231)[0d][0a]
    2008/9/25 14:06:19 3340: pop3: 305: +OK maildrop ready, 2 messages (11873 octets) (13231)[0d][0a]
    2008/9/25 14:06:19 3340: pop3: 209: Command: --STAT--
    2008/9/25 14:06:19 3340: pop3: 305: STAT[0d][0a]
    2008/9/25 14:06:19 3340: pop3: 643: Read slurp data +OK 2 11873[0d][0a]
    2008/9/25 14:06:19 3340: pop3: 305: +OK 2 11873[0d][0a]
    2008/9/25 14:06:19 3340: pop3: 209: Command: --LIST--
    2008/9/25 14:06:19 3340: pop3: 305: LIST[0d][0a]
    2008/9/25 14:06:19 3340: pop3: 643: Read slurp data +OK 2 messages (11873 octets)[0d][0a]1 8711[0d][0a]2 3162[0d][0a].[0d][0a]
    2008/9/25 14:06:19 3340: pop3: 305: -ERR no response from mail server[0d][0a]
    
    
    Pegasus Mail error dialog
    
    [*] Connection established to 127.0.0.1
    >> 0040 +OK POP3 POPFile (v1.1.0) server ready
    << 0066 USER pop.mail.yahoo.com:995:[YahooUserProfile]:ssl
    >> 0024 +OK password required.
    << 0035 PASS XXXXXXXXXXXXXXXXXXXXXXXXXXXX
    >> 0055 +OK maildrop ready, 2 messages (11873 octets) (13231)
    << 0006 STAT
    >> 0013 +OK 2 11873
    << 0006 LIST
    >> 0031 +OK 2 messages (11873 octets)
    << 0008 RETR 1
    >> 0035 -ERR no response from mail server
    
    
    2008/9/25 14:06:19 3340: mq: 377: post CMPLT (3340)
    2008/9/25 14:06:19 3340: mq: 388: dropping post CMPLT (3340)
    2008/9/25 14:06:19 3340: pop3: 667: POP3 proxy done
    2008/9/25 14:06:19 3340: mq: 128: Message LOGIN ([YahooUserProfile]) ready for delivery
    2008/9/25 14:06:19 3340: mq: 131: Delivering message LOGIN ([YahooUserProfile]) to html
    

    What do you think? Thanks,

    Stefan

    • Message #515

      Hi Stefan

      Mail pickup from Yahoo has been failing all afternoon since the installation
      of the revised proxy.pm. I don't know if this is the software or further instability
      of the yahoo pool of POP3 servers. (I did receive a message through gmail.)

      POPFile sees that there are two messages for pickup, and then appears to
      immediately determine that there is no response from the server. Should
      POPFile be waiting a bit longer there for a server response?

      I'm so sorry.
      The new problem may be caused by the side-effect of my latest change.
      I'll look into the problem.

      Please use the older version of Proxy.pm until I find out the cause of the problem.
      You can download the previous version from here:

      http://getpopfile.org/browser/branches/b0_22_2/engine/Proxy/Proxy.pm?rev=3370

      Naoki

      • Message #520

        I'll look into the problem.

        I think I could find the cause of the problem and build a new Proxy.pm:

        http://getpopfile.org/browser/branches/b0_22_2/engine/Proxy/Proxy.pm?rev=3376

        I hope the new code would solve the problem.

        Stefan, can you give it a try?

        BTW, the mail server named 'pop110' seems to respond in a few seconds today.
        Stefan, are you seeing the 'original' intermittent password problem these days?

        Naoki

        • Message #521

          Hi Naoki,

          I have your newly revised proxy.pm in place. Working ok. I'm able to pick up mail from yahoo.

          I also checked through the logs for the 'pop110' server for the last few days. It is showing good response time and not getting hung at the password transaction.

          Also, Brian had pointed me at stunnel as an alternative SSL wrapper. After some experimentation, I have what appears to be a good stunnel configuration talking to the three different hosts, gmail, sonic & yahoo, for comparative testing to the POPFile native SSL should we find that useful.

          Thanks,

          Stefan

          • Message #522

            Hi Stefan

            I have your newly revised proxy.pm in place. Working ok. I'm able to pick up mail from yahoo.

            Glad to hear that.
            We could finally solve the problem. Thank you for reporting!

            I also checked through the logs for the 'pop110' server for the last few days. It is showing good response time and not getting hung at the password transaction.

            I see. Yahoo! may have done some work on their server.

            Naoki

            • Message #524

              Hi Naoki,


              Glad to hear that. We could finally solve the problem. Thank you for reporting!

              Thank you for your dedicated troubleshooting and for assembling your yahoo POP3 server pool testing script.

              Your doc for POPFile 1.10 notes that the v1.10 system tray icon should be more stable. I'll switch over to the POPFileib.exe and see how that goes.

              Thanks a million,

              Stefan

              • Message #533

                Hi Stefan,

                Thank you for your dedicated troubleshooting and for assembling your yahoo POP3 server pool testing script.

                We've just released POPFile 1.1.0 RC5 and it includes all of the changes done since RC2.

                Your doc for POPFile 1.10 notes that the v1.10 system tray icon should be more stable. I'll switch over to the POPFileib.exe and see how that goes.

                Yes. The new tray icon will be very stable when you don't enable the concurrent POP3 connections.

                Naoki

                • Message #536

                  Hi Naoki,

                  We've just released POPFile 1.1.0 RC5 and it includes all of the changes > > done since RC2.

                  Thanks for your note. I've put RC5 into place.



                  Yes. The new tray icon will be very stable when you
                  don't enable the concurrent POP3 connections.

                  Ok. Just to confirm your meaning: with forking off, then tray icon is ok. With forking on, one should turn the tray icon off. Yes?

                  Thanks,

                  Stefan

                  • Message #542

                    Yes. The new tray icon will be very stable when you
                    don't enable the concurrent POP3 connections.


                    Ok. Just to confirm your meaning: with forking off, then tray icon is ok. With forking on, one should turn the tray icon off. Yes?

                    Currently yes.

                    We've been working to solve the problem which occurs when the tray icon and forking are both enabled.
                    The problem seems to have been solved, but I'm not sure yet.
                    For more information about the problem, please see:

                    http://getpopfile.org/discussion/1/100
                    http://getpopfile.org/ticket/80

                    Naoki

  • Message #545

    Hi Naoki,

    I'm still seeing some intermittent POPFile SSL errors under POPFile
    version 1.1.0 RC4 & RC5.

    I substituted Stunnel for the POPFile SSL front-end and have run
    for two days without such errors.

    This would seem to suggest that there is possibly still something not
    working as planned with the POPFile SSL?

    What do you think?

    I've contacted Yahoo to let them know about the delays we had
    been seeing in their POP3 server pool. Are the connection testing
    scripts you wrote showing problems?

    Thanks,

    Stefan

    Error condition 1:

    POPFile attempts to connect, but then in each case exactly 21 seconds later
    the connection fails with: "-ERR can't connect to plus.pop.mail.yahoo.com:995"

    The POPFile timeout is set to 90 seconds.

    Is this a case of POPFile giving up prematurely, or a case of the yahoo POP
    server saying "go away, I'm not here"?

    2008/10/5 11:49:46 948: pop3: 305: +OK POP3 POPFile (v1.1.0) server ready[0d][0a]
    2008/10/5 11:49:46 948: pop3: 194: Regexps: ^USER XXXXXX
    2008/10/5 11:49:46 948: pop3: 209: Command: --USER XXXXXX--
    2008/10/5 11:49:46 948: mq: 377: post LOGIN ([YahooUserProfile])
    2008/10/5 11:49:46 948: mq: 384: queuing post LOGIN ([YahooUserProfile])
    2008/10/5 11:49:46 948: mq: 386: LOGIN queue length now 0
    2008/10/5 11:49:46 948: pop3: 522: Attempting to connect to SSL server at plus.pop.mail.yahoo.com:995
    2008/10/5 11:50:07 948: pop3: 305: -ERR can't connect to plus.pop.mail.yahoo.com:995[0d][0a]
    
    The time from "Attempting" to "-ERR" is in each case 21 seconds.
    
    
    Pegasus mail error dialog
    
    [*] Connection established to 127.0.0.1
    >> 0040 +OK POP3 POPFile (v1.1.0) server ready
    << 0071 USER plus.pop.mail.yahoo.com:995:[YahooUserProfile]:ssl
    >> 0051 -ERR can't connect to plus.pop.mail.yahoo.com:995
    
    
    after clearing the Pegasus Mail error dialog, POPFile continues
    
    2008/10/5 11:51:39 948: pop3: 209: Command: --QUIT--
    2008/10/5 11:51:39 948: pop3: 305: +OK goodbye[0d][0a]
    2008/10/5 11:51:39 948: mq: 377: post CMPLT (948)
    2008/10/5 11:51:40 948: mq: 388: dropping post CMPLT (948)
    2008/10/5 11:51:40 948: pop3: 667: POP3 proxy done
    2008/10/5 11:51:40 948: mq: 128: Message LOGIN ([YahooUserProfile]) ready for delivery
    2008/10/5 11:51:40 948: mq: 131: Delivering message LOGIN ([YahooUserProfile]) to html
    

    Error condition 2: "Failed to upgrade the socket to SSL"

    2008/10/4 18:16:19 3316: pop3: 305: +OK POP3 POPFile (v1.1.0) server ready[0d][0a]
    2008/10/4 18:16:19 3316: pop3: 194: Regexps: ^USER XXXXXX
    2008/10/4 18:16:19 3316: pop3: 209: Command: --USER XXXXXX--
    2008/10/4 18:16:19 3316: mq: 377: post LOGIN ([YahooUserProfile])
    2008/10/4 18:16:19 3316: mq: 384: queuing post LOGIN ([YahooUserProfile])
    2008/10/4 18:16:19 3316: mq: 386: LOGIN queue length now 0
    2008/10/4 18:16:19 3316: pop3: 522: Attempting to connect to SSL server at plus.pop.mail.yahoo.com:995
    2008/10/4 18:16:19 3316: pop3: 542: Trying to upgrade socket IO::Socket::INET=GLOB(0x16d0b04) to SSL
    2008/10/4 18:16:19 3316: pop3: 555: Got an error SSL wants a read first from start_SSL
    2008/10/4 18:17:49 3316: pop3: 570: Failed to upgrade the socket to SSL
    2008/10/4 18:17:49 3316: pop3: 305: -ERR can't connect to plus.pop.mail.yahoo.com:995[0d][0a]
    
    In this case, it looks like POPFile waited the 90 second timeout trying to
    upgrade the socket to SSL.
    
    
    Pegasus mail error dialog
    
    [*] Connection established to 127.0.0.1
    >> 0040 +OK POP3 POPFile (v1.1.0) server ready
    << 0071 USER plus.pop.mail.yahoo.com:995:[YahooUserProfile]:ssl
    >> 0051 -ERR can't connect to plus.pop.mail.yahoo.com:995
    
    
    after clearing the Pegasus Mail error dialog, POPFile continues
    
    2008/10/4 18:20:03 3316: pop3: 209: Command: --QUIT--
    2008/10/4 18:20:03 3316: pop3: 305: +OK goodbye[0d][0a]
    2008/10/4 18:20:03 3316: mq: 377: post CMPLT (3316)
    2008/10/4 18:20:03 3316: mq: 388: dropping post CMPLT (3316)
    2008/10/4 18:20:03 3316: pop3: 667: POP3 proxy done
    2008/10/4 18:20:03 3316: mq: 128: Message LOGIN ([YahooUserProfile]) ready for delivery
    2008/10/4 18:20:03 3316: mq: 131: Delivering message LOGIN ([YahooUserProfile]) to html
    
    • Message #546

      Hi Stefan

      I'm still seeing some intermittent POPFile SSL errors under POPFile
      version 1.1.0 RC4 & RC5.

      I substituted Stunnel for the POPFile SSL front-end and have run
      for two days without such errors.

      This would seem to suggest that there is possibly still something not
      working as planned with the POPFile SSL?

      What do you think?

      Hmm... it seems that this is not the POPFile's problem.

      I've contacted Yahoo to let them know about the delays we had
      been seeing in their POP3 server pool. Are the connection testing
      scripts you wrote showing problems?

      Yesterday I've run the test script two times (this means that the
      script tried to connect to the Yahoo! mail server 200 times) and
      sometimes it failed to connect to the server.
      But today, the problem has disappeared.

      Error condition 1:
      <snip>
      Is this a case of POPFile giving up prematurely, or a case of the yahoo POP

      server saying "go away, I'm not here"?

      Yes. In this case POPFile failed to connect to the Yahoo! POP server.

      Error condition 2: "Failed to upgrade the socket to SSL"
      <snip>
      2008/10/4 18:16:19 3316: pop3: 555: Got an error SSL wants a read first from start_SSL
      2008/10/4 18:17:49 3316: pop3: 570: Failed to upgrade the socket to SSL
      2008/10/4 18:17:49 3316: pop3: 305: -ERR can't connect to plus.pop.mail.yahoo.com:995[0d][0a]

      In this case, it looks like POPFile waited the 90 second timeout trying to
      upgrade the socket to SSL.

      Yes. POPFile successfully connected to the POP server but could not
      read data from the connection in 90 seconds.

      Naoki

      • Message #547

        Hi Naoki,


        Hmm... it seems that this is not the POPFile's problem.

        Yesterday I've run the test script two times (this means that the
        script tried to connect to the Yahoo! mail server 200 times) and
        sometimes it failed to connect to the server.
        But today, the problem has disappeared.

        Error condition 1:
        <snip>


        Yes. In this case POPFile failed to connect to the Yahoo! POP server.

        Error condition 2: "Failed to upgrade the socket to SSL"
        <snip>


        Yes. POPFile successfully connected to the POP server but could not
        read data from the connection in 90 seconds.

        Thanks for looking at these issues and for running your test script on Yahoo. Sounds like they have some erratic instability on their POP3 server.

        Much obliged.

        Best,

        Stefan