#1093711 fetchmail: stops downloading with socket error on malformed message

Package:
fetchmail
Source:
fetchmail
Description:
SSL enabled POP3, APOP, IMAP mail gatherer/forwarder
Submitter:
Francesco Potortì
Date:
2025-01-22 21:39:02 UTC
Severity:
normal
#1093711#5
Date:
2025-01-21 18:34:04 UTC
From:
To:
I have observed occasionally this bug starting one year ago (approximately) while downloading email from two different servers.  In all cases fetchmail stops downloading midway through a long message with a socket error and leaves the message on the server.  There is no way out: next time it polls, the same thing happens and no new mail is downloaded.  Only cure I found, login through webmail and delete the offending message, which is tyipically a big spam message.  Here is the lastest instance seen on the log:

fetchmail: reading message user@email.addr@provider.smtp.server:3 of 40 (3310505 octets) (log message incomplete)
fetchmail: socket error while fetching from user@email.addr@provider.smtp.server
fetchmail: Query status=2 (SOCKET)

Fetchmail stops on error and retries indefinitely, but gives no sign of this situation, so I am not alerted of it unless I notice that no mail is arriving.

Fetchmail should detect this situation and at least send an email signaling the problem.  At best, it could additionally mark the offending message and skip it.


Here is the same log as above with -v.  Info is obfuscated, but I will gladly send the onubfuscated log privately upon request.

+ provider.smtp.server at 2025-01-21 17:54:04+0100
fetchmail: Trying to connect to 79.98.45.16/110...connected.
fetchmail: POP3< +OK Dovecot ready. <b9304.2bb41.678fd12c.e+EVGzSmfuO/lTFNYllj4g==@provider.smtp.server>
fetchmail: POP3> APOP email.addr 21b30af8ca4ec117ca7cc8e50db7a11d
fetchmail: POP3< +OK Logged in.
fetchmail: POP3> STAT
fetchmail: POP3< +OK 112 15907273
fetchmail: POP3> UIDL
fetchmail: POP3< +OK
fetchmail: POP3< 1 UID6519-1416948771
fetchmail: POP3< 2 UID6520-1416948771
fetchmail: POP3< 3 UID6521-1416948771
fetchmail: POP3< 4 UID6522-1416948771
fetchmail: POP3< 5 UID6523-1416948771
fetchmail: POP3< 6 UID6524-1416948771
fetchmail: POP3< 7 UID6525-1416948771
fetchmail: POP3< 8 UID6526-1416948771
fetchmail: POP3< 9 UID6527-1416948771
fetchmail: POP3< 10 UID6528-1416948771
fetchmail: POP3< 11 UID6529-1416948771
fetchmail: POP3< 12 UID6530-1416948771
fetchmail: POP3< 13 UID6531-1416948771
fetchmail: POP3< 14 UID6532-1416948771
fetchmail: POP3< 15 UID6533-1416948771
fetchmail: POP3< 16 UID6534-1416948771
fetchmail: POP3< 17 UID6535-1416948771
fetchmail: POP3< 18 UID6536-1416948771
fetchmail: POP3< 19 UID6537-1416948771
fetchmail: POP3< 20 UID6538-1416948771
fetchmail: POP3< 21 UID6539-1416948771
fetchmail: POP3< 22 UID6540-1416948771
fetchmail: POP3< 23 UID6541-1416948771
fetchmail: POP3< 24 UID6542-1416948771
fetchmail: POP3< 25 UID6543-1416948771
fetchmail: POP3< 26 UID6544-1416948771
fetchmail: POP3< 27 UID6545-1416948771
fetchmail: POP3< 28 UID6546-1416948771
fetchmail: POP3< 29 UID6547-1416948771
fetchmail: POP3< 30 UID6548-1416948771
fetchmail: POP3< 31 UID6549-1416948771
fetchmail: POP3< 32 UID6550-1416948771
fetchmail: POP3< 33 UID6551-1416948771
fetchmail: POP3< 34 UID6552-1416948771
fetchmail: POP3< 35 UID6553-1416948771
fetchmail: POP3< 36 UID6554-1416948771
fetchmail: POP3< 37 UID6555-1416948771
fetchmail: POP3< 38 UID6556-1416948771
fetchmail: POP3< 39 UID6557-1416948771
fetchmail: POP3< 40 UID6558-1416948771
fetchmail: POP3< 41 UID6559-1416948771
fetchmail: POP3< 42 UID6560-1416948771
fetchmail: POP3< 43 UID6561-1416948771
fetchmail: POP3< 44 UID6562-1416948771
fetchmail: POP3< 45 UID6563-1416948771
fetchmail: POP3< 46 UID6564-1416948771
fetchmail: POP3< 47 UID6565-1416948771
fetchmail: POP3< 48 UID6566-1416948771
fetchmail: POP3< 49 UID6567-1416948771
fetchmail: POP3< 50 UID6568-1416948771
fetchmail: POP3< 51 UID6569-1416948771
fetchmail: POP3< 52 UID6570-1416948771
fetchmail: POP3< 53 UID6571-1416948771
fetchmail: POP3< 54 UID6572-1416948771
fetchmail: POP3< 55 UID6573-1416948771
fetchmail: POP3< 56 UID6574-1416948771
fetchmail: POP3< 57 UID6575-1416948771
fetchmail: POP3< 58 UID6576-1416948771
fetchmail: POP3< 59 UID6577-1416948771
fetchmail: POP3< 60 UID6578-1416948771
fetchmail: POP3< 61 UID6579-1416948771
fetchmail: POP3< 62 UID6580-1416948771
fetchmail: POP3< 63 UID6581-1416948771
fetchmail: POP3< 64 UID6582-1416948771
fetchmail: POP3< 65 UID6583-1416948771
fetchmail: POP3< 66 UID6584-1416948771
fetchmail: POP3< 67 UID6585-1416948771
fetchmail: POP3< 68 UID6586-1416948771
fetchmail: POP3< 69 UID6587-1416948771
fetchmail: POP3< 70 UID6588-1416948771
fetchmail: POP3< 71 UID6589-1416948771
fetchmail: POP3< 72 UID6590-1416948771
fetchmail: POP3< 73 UID6591-1416948771
fetchmail: POP3< 74 UID6592-1416948771
fetchmail: POP3< 75 UID6593-1416948771
fetchmail: POP3< 76 UID6594-1416948771
fetchmail: POP3< 77 UID6595-1416948771
fetchmail: POP3< 78 UID6596-1416948771
fetchmail: POP3< 79 UID6597-1416948771
fetchmail: POP3< 80 UID6598-1416948771
fetchmail: POP3< 81 UID6599-1416948771
fetchmail: POP3< 82 UID6600-1416948771
fetchmail: POP3< 83 UID6601-1416948771
fetchmail: POP3< 84 UID6602-1416948771
fetchmail: POP3< 85 UID6603-1416948771
fetchmail: POP3< 86 UID6604-1416948771
fetchmail: POP3< 87 UID6605-1416948771
fetchmail: POP3< 88 UID6606-1416948771
fetchmail: POP3< 89 UID6607-1416948771
fetchmail: POP3< 90 UID6608-1416948771
fetchmail: POP3< 91 UID6609-1416948771
fetchmail: POP3< 92 UID6610-1416948771
fetchmail: POP3< 93 UID6611-1416948771
fetchmail: POP3< 94 UID6612-1416948771
fetchmail: POP3< 95 UID6613-1416948771
fetchmail: POP3< 96 UID6614-1416948771
fetchmail: POP3< 97 UID6615-1416948771
fetchmail: POP3< 98 UID6616-1416948771
fetchmail: POP3< 99 UID6617-1416948771
fetchmail: POP3< 100 UID6618-1416948771
fetchmail: POP3< 101 UID6619-1416948771
fetchmail: POP3< 102 UID6620-1416948771
fetchmail: POP3< 103 UID6621-1416948771
fetchmail: POP3< 104 UID6622-1416948771
fetchmail: POP3< 105 UID6623-1416948771
fetchmail: POP3< 106 UID6624-1416948771
fetchmail: POP3< 107 UID6625-1416948771
fetchmail: POP3< 108 UID6626-1416948771
fetchmail: POP3< 109 UID6627-1416948771
fetchmail: POP3< 110 UID6628-1416948771
fetchmail: POP3< 111 UID6629-1416948771
fetchmail: POP3< 112 UID6630-1416948771
fetchmail: POP3< .
fetchmail: 112 messages for email.addr at provider.smtp.server (15907273 octets).
fetchmail: POP3> LIST 1
fetchmail: POP3< +OK 1 90798
fetchmail: POP3> RETR 1
fetchmail: POP3< +OK 90798 octets
fetchmail: reading message user@email.addr@provider.smtp.server:1 of 112 (90798 octets) flushed
fetchmail: POP3> DELE 1
fetchmail: POP3< +OK Marked to be deleted.
fetchmail: POP3> LIST 2
fetchmail: POP3< +OK 2 2357
fetchmail: POP3> RETR 2
fetchmail: POP3< +OK 2357 octets
fetchmail: reading message user@email.addr@provider.smtp.server:2 of 112 (2357 octets) flushed
fetchmail: POP3> DELE 2
fetchmail: POP3< +OK Marked to be deleted.
fetchmail: POP3> LIST 3
fetchmail: POP3< +OK 3 373082
fetchmail: POP3> RETR 3
fetchmail: POP3< +OK 373082 octets
fetchmail: reading message user@email.addr@provider.smtp.server:3 of 112 (373082 octets) (log message incomplete)
fetchmail: socket error while fetching from user@email.addr@provider.smtp.server
fetchmail: 6.4.39 querying provider.smtp.server (protocol APOP) at Tue Jan 21 17:54:04 2025: poll completed
fetchmail: Query status=2 (SOCKET)

#1093711#10
Date:
2025-01-21 20:55:43 UTC
From:
To:
Am 21.01.25 um 19:34 schrieb Francesco Potortì:

Hi Francesco,

thanks for taking the time to report this bug. It would seem this is an
upstream issue at first glance. Sorry it hurts.

Can you attach strace (you just add strace to fetchmail's command line)
and report the last few lines around where things start looking like
fetchmail running into timeouts (SIGALRM is one such sign) or socket
trouble (read errors), and/or also the last few lines of a tcpdump
running in parallel and filtering on traffic to 79.98.45.16/110?

Also, does it take a long time between starting to read the message 3
(see below) and before fetchmail fails?

I need to understand, from strace (or ltrace) and tcpdump, what are the
last few log lines around the connection getting reset and what the
software is doing.

If you feel that's too sensitive, feel free to e-mail me directly and
GnuPG encrypt. My key is available through key servers or from
https://docs.freebsd.org/en/articles/pgpkeys/#_matthias_andree_mandreefreebsd_org

Thanks again.

Regards,
Matthias

#1093711#15
Date:
2025-01-21 21:04:56 UTC
From:
To:
I made this an upstream feature request recorded at
https://gitlab.com/fetchmail/fetchmail/-/issues/65

#1093711#20
Date:
2025-01-21 21:04:56 UTC
From:
To:
I made this an upstream feature request recorded at
https://gitlab.com/fetchmail/fetchmail/-/issues/65

#1093711#25
Date:
2025-01-21 21:25:42 UTC
From:
To:
In practice this is very difficult: it would take a lot of time for me to try and do it.  Especially because that would have to be done while my personal email keeps arriving at my mailbox.  However, tomorrow I may try to do something.

Almost certainly less than one minute.

Ok, I'll see if I can manage to find the time and at least do an strace.

#1093711#30
Date:
2025-01-22 15:13:03 UTC
From:
To:
Unfortunately I canot reproduce it.  I had the message in the spam folder of the server, I moved it to inbox using the webmail interface and then started fetchmail in detached mode, but it managed to download the entire message without problems :(
#1093711#35
Date:
2025-01-22 15:16:43 UTC
From:
To:
In fact, when the problema appears, reading the message at the end of the list may not be enough, as when fetchmail meets it, it hangs, so no messages are in fact read (with POP, at least).  The only solution would be to skip that message entirely.

Or finding the bug, but it took me  awhile to setup debugging for the case of that message, but did not work.  I can think of a lot of other things to do, but that would require too much time :(

#1093711#40
Date:
2025-01-22 15:16:43 UTC
From:
To:
In fact, when the problema appears, reading the message at the end of the list may not be enough, as when fetchmail meets it, it hangs, so no messages are in fact read (with POP, at least).  The only solution would be to skip that message entirely.

Or finding the bug, but it took me  awhile to setup debugging for the case of that message, but did not work.  I can think of a lot of other things to do, but that would require too much time :(

#1093711#45
Date:
2025-01-22 21:35:32 UTC
From:
To:
Am 22.01.25 um 16:16 schrieb Francesco Potortì:
The actual thing is finding out the cause of this hang, and treating it
properly. A backtrace would be good, and we probably need to hack the
source code to deliberately set the timeout timer (setitimer), but avoid
trapping the related SIGALRM handler or letting it run through
sigsetjmp/siglongjmp -- because that unwinds the stack and we lose the
backtrace and where the issue happened. That's assuming a timeout causes
the socket error, and not something server side, not something in the
network, not some kernel or router bugs, and no genuine errors of
communication that would cause the socket error. That would be only for
debug use, not for "productive" use.  This can then be wrapped in a
debugger such as gdb or lldb and at least gdb can be told to pass
arguments to the executable to debug and auto-run it.

A somewhat more complete approach has been committed to Gitlab onto this
branch:
<https://gitlab.com/fetchmail/fetchmail/-/tree/fetchmail65-linux-backtrace-on-timeout?ref_type=heads>

It requires meson to build and is currently slightly past fetchmail
6.5.2, but I don't believe your log showed a timeout. At least fetchmail
6.5.2 would additionally report a timeout on the line before the socket
error, so this appears to be something else.

It might also be that the local mda you seem to be forwarding to acts up
and the socket error isn't from input but output. Dot-stuffed lines can
cause this. But we really need a way to reproduce this, including most
of your configuration (I don't need hostnames, passwords, usernames
currently), else we're poking in the dark.

#1093711#50
Date:
2025-01-22 21:35:32 UTC
From:
To:
Am 22.01.25 um 16:16 schrieb Francesco Potortì:
The actual thing is finding out the cause of this hang, and treating it
properly. A backtrace would be good, and we probably need to hack the
source code to deliberately set the timeout timer (setitimer), but avoid
trapping the related SIGALRM handler or letting it run through
sigsetjmp/siglongjmp -- because that unwinds the stack and we lose the
backtrace and where the issue happened. That's assuming a timeout causes
the socket error, and not something server side, not something in the
network, not some kernel or router bugs, and no genuine errors of
communication that would cause the socket error. That would be only for
debug use, not for "productive" use.  This can then be wrapped in a
debugger such as gdb or lldb and at least gdb can be told to pass
arguments to the executable to debug and auto-run it.

A somewhat more complete approach has been committed to Gitlab onto this
branch:
<https://gitlab.com/fetchmail/fetchmail/-/tree/fetchmail65-linux-backtrace-on-timeout?ref_type=heads>

It requires meson to build and is currently slightly past fetchmail
6.5.2, but I don't believe your log showed a timeout. At least fetchmail
6.5.2 would additionally report a timeout on the line before the socket
error, so this appears to be something else.

It might also be that the local mda you seem to be forwarding to acts up
and the socket error isn't from input but output. Dot-stuffed lines can
cause this. But we really need a way to reproduce this, including most
of your configuration (I don't need hostnames, passwords, usernames
currently), else we're poking in the dark.