Bug 4423 - goes to lunch on POP3 retrieval of Yahoo msgs
Summary: goes to lunch on POP3 retrieval of Yahoo msgs
Status: RESOLVED WORKSFORME
Alias: None
Product: Claws Mail (GTK 2)
Classification: Unclassified
Component: POP3 (show other bugs)
Version: 3.17.3
Hardware: PC Linux
: P3 minor
Assignee: users
URL:
Depends on:
Blocks:
 
Reported: 2020-12-16 05:30 UTC by claws-mail-bugs
Modified: 2020-12-17 01:38 UTC (History)
0 users

See Also:


Attachments

Description claws-mail-bugs 2020-12-16 05:30:23 UTC
Claws Mail goes to lunch on an initial POP3 download of over 50,000 msgs.  On the 1st attempt, the count of fetched messages reached just 184 before the Claws Mail window went completely white.  Firefox was running at the same time with no issue.  The /top/ command showed claws-mail was using 0.0 cpu.  I let is sit for a couple hours like that, and the UI never recovered from the white window.  So I killed it.

The 2nd time I tried launching this way: ionice -c 2 -n 6 claws-mail

That didn't help.  It went to lunch after 88 msgs were fetched.  So I killed it and restarted this way: claws-mail --debug.  That time not a single msg was fetched.  It went to lunch at about this point:

------8<---------
* Account 'yahoo - POP3': Connecting to POP3 server: pop.mail.yahoo.com:995...
...
[14:58:43] POP3< +OK hello from jpop-0.1 
[14:58:43] POP3> USER XXXXX@yahoo.com
[14:58:44] POP3< +OK password required.
[14:58:44] POP3> PASS ********
[14:58:44] POP3< +OK maildrop ready, (JPOP server ready)
[14:58:44] POP3> STAT
[14:58:46] POP3< +OK 59093 3869756552
[14:58:46] POP3> UIDL
[14:58:47] POP3< +OK 59093 message(s) (3969756552 octets)
------8<---------

Normally the next step is to send the LIST command, but on this 3rd attempt it doesn't get that far.  I should also mention that this is over a normal WAN (not Tor since Yahoo won't let Tor users authenticate).

4th attempt: ran with --debug but minimized the GUI (to rule out a malfunctioning animation like the status bar - some apps do better in the background).  ATM it has passed RETR 1000, and it's still running.

This bug could be related:

https://www.thewildbeast.co.uk/claws-mail/bugzilla/show_bug.cgi?id=2629
Comment 1 claws-mail-bugs 2020-12-16 15:10:21 UTC
The 4th attempt went until the ESP pushed an error msg, about 10% into the session.  C-M did not go to lunch on the 4th attempt, so it's a random non-reproducable manifestation.
Comment 2 claws-mail-bugs 2020-12-16 15:42:51 UTC
5th attempt:

The retrievals picked up on the msg where they left off.  But after a few hundred msgs Claws Mail went to lunch again.  The debug output shows:

---8<------------------------------------------------------
###!!! [parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost.

###!!! [parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost.
---8<------------------------------------------------------

Then I fiddled with the white window a bit, moved it, and it rendered.  I minimized it and the debug output took off, as if it returned from lunch.  It stopped with procmsg.c "changing flags for message X... setting flags for message X".  Gave an error popup "Error occurred while processing mail".  After the error the app is functional, so it didn't really go to lunch in a significant show-stopping way this time.  I was able to initiate a 6th download attempt without restarting the app.
Comment 3 claws-mail-bugs 2020-12-16 16:16:51 UTC
The 6th attempt fetched less than 100 msgs before this output:

---8<------------------------------------------------------
###!!! [parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost.
---8<------------------------------------------------------

Despite the window being minimized, C-M still went to lunch.  Restoring the window reveals a blank white window, and fiddling with the geometry makes no difference.  Top shows consumption of 0.0% CPU and 2.0% of memory.  Note as well that clicking the "X" does not terminate Claws Mail.  The desktop manager gives dialog saying "The window '..Claws Mail 3.17.3' does not seem to be responding.  Do you want to force it to exit by sending the terminate signal?"

After clicking "end process", the debug output shows that Claws Mail does a forced cleanup (e.g. "writing to password store", "saving address books").  It's not so hosed that it needs a kill -9, but the normal kill signal is the only thing that it responds to.
Comment 4 Paul 2020-12-16 16:27:40 UTC
That error message is not coming from claws-mail.

Upgrade claws-mail to the latest release, and make sure your system is up to date also, and re-try.
Comment 5 claws-mail-bugs 2020-12-16 17:26:12 UTC
The 7th attempt had a long delay after a RETR is sent and the +OK reply doesn't come.  Instead, there is this again:

---8<------------------------------------------------------
###!!! [parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost.

###!!! [parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost.
---8<------------------------------------------------------

I suspect what's happening is Yahoo's server is becoming non-responsive (perhaps a deliberate defensive measure for large retrievals), and Claws Mail is waiting for a response without a timeout mechanism.
Comment 6 claws-mail-bugs 2020-12-16 17:28:09 UTC
Thanks Paul.  I'm running the latest version for Sparky Linux, but I suppose it'll be worthwhile to install the latest upstream version on the side.
Comment 7 Paul 2020-12-16 17:40:47 UTC
The latest Sparky Linux is based on Debian Bullseye (testing), Debian Bullseye has Claws Mail 3.17.8.
Comment 8 claws-mail-bugs 2020-12-16 18:49:48 UTC
I removed the debian pkg and unpacked the tarball for 3.17.8.  The configure script gives:

---8<--------------------------------
configure: error: in `/usr/local/src/claws-mail-3.17.8':
configure: error: The pkg-config script could not be found or is too old.  Make sure it
is in your PATH or set the PKG_CONFIG environment variable to the full
path to pkg-config.

Alternatively, you may set the environment variables GLIB_CFLAGS
and GLIB_LIBS to avoid the need to call pkg-config.
See the pkg-config man page for more details.

To get pkg-config, see <http://pkg-config.freedesktop.org/>.
See `config.log' for more details
---8<--------------------------------
Comment 9 claws-mail-bugs 2020-12-16 18:55:31 UTC
I'm running Sparky stable 5.13 Nibiru
Comment 10 claws-mail-bugs 2020-12-16 19:00:14 UTC
I tried configuring for buster backports but that didn't advance it past 3.17.3.
Comment 11 claws-mail-bugs 2020-12-16 20:31:08 UTC
Some msgs are getting lost as a result of this bug.  It's apparently not a permanent loss.  That is, the RETR IDs reached over 9000 at one point when Claws Mail went to lunch, and yet only 6000 or so msgs are in the MH mailbox.  When the download is restarted, the RETR number starts back in the 6000 range.  So msgs apparently need to be redownloaded if C-M gets in a bad state before the msgs are processed.  It doesn't seem to be able to recover the data in the cache.
Comment 12 claws-mail-bugs 2020-12-17 01:38:58 UTC
After many botched downloads, the MH folder inbox was showing ~6000 msgs.  I started a new download after M-C went to lunch (after ~8th time or so). I hit Message >> Receive >> "Cancel receiving" after just ~100 msgs were fetched.  Then it spent some time copying msgs and working on the cache.  Then the inbox jumped from ~6000 msgs to over ~12,000 msgs.  Skimming through the inbox shows 5 dupes of some messages, and 1 copy of others, and everything in between.

Consequently, this bug is causing untreated msgs to pile up in the cache.  I'm sure this design is for simplicity of code and overall speed, but when the POP3 server signals up front that there are 10s of thousands of msgs coming, C-M should perhaps opt to process the msgs every ten or so fetches.

Note You need to log in before you can comment on or make changes to this bug.