fetchmail Hangs on First and Only 1st Try
RE: fetchmail 5.3.3 ; InterMail vM.4.01.03.16 ; AT&T Worldnet
I have an odd problem fetching mail on the _first try_, and fetchmail
hanging at the sign-off stage of the process.
I have to ^C when it hangs (indefinitely, up to 90 minutes at least) and
from then on fetchmail gives no more further problems. I run it from a
cron job.
This set up had worked fine till 3/22. I haven't changed anything.
On that day, however, my ISP changed some offerings on its mail server.
It stopped ofering IMAP (albeit testing), and since then 'proto auto' in
my .fetchmailrc yields a 3 minute hang when fetchin mail. I mentioned my
observations and my problem to my provider, but they do not see any
correlation.
Doing, '$ fetchmail -vv' shows:
> fetchmail: SMTP< 250 OK id=14gJTW-00023x-00
> flushed
> fetchmail: POP3> DELE 118
> fetchmail: POP3< +OK
> fetchmail: POP3> QUIT
> fetchmail: POP3< +OK foo InterMail POP3 server signing off.
^^^^^^^^^^^^^^^^^^
At this stage it hangs indefinitely.
Using strace shows:
> [...]
> recv(5, "with a subject of \"unsubscribe\"."..., 8191, MSG_PEEK) = 84
> read(5, "with a subject of \"unsubscribe\"."..., 79) = 79
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
> write(7, "with a subject of \"unsubscribe\"."..., 79) = 79
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1500, 0}}, NULL) = 0
> recv(5, "\r\n.\r\n", 8191, MSG_PEEK) = 5
> read(5, "\r\n", 2) = 2
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
> write(7, "\r\n", 2) = 2
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1500, 0}}, NULL) = 0
> recv(5, ".\r\n", 8191, MSG_PEEK) = 3
> read(5, ".\r\n", 3) = 3
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
> write(7, ".\r\n", 3) = 3
> recv(7, "250 OK id=14kQom-00005S-01\r\n", 8190, MSG_PEEK) = 28
> read(7, "250 OK id=14kQom-00005S-01\r\n", 28) = 28
> time([986304357]) = 986304357
> getpid() = 336
> sigaction(SIGPIPE, {0x400eceec, [], 0x4000000}, {0x8053f40, [], SA_RESTART|0x4000000}, 0x40072868) = 0
> send(6, "<22>Apr 3 09:25:57 fetchmail[33"..., 46, 0) = 46
> sigaction(SIGPIPE, {0x8053f40, [], SA_RESTART|0x4000000}, NULL, 0x806d9f8) = 0
> write(5, "DELE 131\r\n", 10) = 10
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1500, 0}}, NULL) = 0
> recv(5, "+OK\r\n", 512, MSG_PEEK) = 5
> read(5, "+OK\r\n", 5) = 5
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
> write(5, "QUIT\r\n", 6) = 6
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1500, 0}}, NULL) = 0
> recv(5, "+OK foo InterMail POP3 server s"..., 512, MSG_PEEK) = 45
> read(5, "+OK foo InterMail POP3 server s"..., 45) = 45
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
> shutdown(5, 1 /* send */) = 0
> recv(5, 0xbfffb403, 1, MSG_PEEK) = ? ERESTARTSYS (To be restarted)
> --- SIGINT (Interrupt) ---
Here's where the problem seems to be. (Note my ^C)
> time([986306230]) = 986306230
> getpid() = 336
> sigaction(SIGPIPE, {0x400eceec, [], 0x4000000}, {0x8053f40, [], SA_RESTART|0x4000000}, 0x40072868) = 0
> send(6, "<22>Apr 3 09:57:10 fetchmail[33"..., 62, 0) = 62
> sigaction(SIGPIPE, {0x8053f40, [], SA_RESTART|0x4000000}, NULL, 0x806d9f8) = 0
> open("/home/john/.fetchids", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 8
> fstat(8, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
> old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40016000
> write(8, "aiax@mailandnews.com SMTP:3A58B6"..., 4096) = 4096
> write(8, "iax@mailandnews.com SMTP:3AA7561"..., 77) = 77
> close(8) = 0
> munmap(0x40016000, 4096) = 0
> unlink("/home/john/.fetchmail.pid") = 0
> munmap(0x40015000, 4096) = 0
> _exit(0) = ?
After I kill this *first* fetchmail process, all the ensuing fetches go
normally. Here's how that segment above looks like when things go
normal:
> [...]
> write(5, "QUIT\r\n", 6) = 6
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1500, 0}}, NULL) = 0
> recv(5, "+OK foo InterMail POP3 server s"..., 512, MSG_PEEK) = 45
> read(5, "+OK foo InterMail POP3 server s"..., 45) = 45
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
> shutdown(5, 1 /* send */) = 0
> recv(5, "", 1, MSG_PEEK) = 0
> close(5) = 0
> sigaction(SIGALRM, {0x805110c, [], SA_RESTART|0x4000000}, {0x8053f24, [], SA_RESTART|0x4000000}, 0x40072868) = 0
> sigaction(SIGPIPE, {0x805110c, [], SA_RESTART|0x4000000}, {0x8053f40, [], SA_RESTART|0x4000000}, 0x40072868) = 0
> write(7, "QUIT\r\n", 6) = 6
> recv(7, "221 dasher closing connection\r\n", 8190, MSG_PEEK) = 31
> read(7, "221 dasher closing connection\r\n", 31) = 31
> shutdown(7, 1 /* send */) = 0
> recv(7, "", 1, MSG_PEEK) = 0
> close(7) = 0
> open("/home/john/.fetchids", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 5
> fstat(5, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
> old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40016000
> write(5, "aiax@mailandnews.com SMTP:3A58B6"..., 4096) = 4096
> write(5, "iax@mailandnews.com SMTP:3AA7561"..., 77) = 77
> close(5) = 0
> munmap(0x40016000, 4096) = 0
> open("/home/john/.fetchids", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 5
> fstat(5, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
> old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40016000
> write(5, "aiax@mailandnews.com SMTP:3A58B6"..., 4096) = 4096
> write(5, "iax@mailandnews.com SMTP:3AA7561"..., 77) = 77
> close(5) = 0
> munmap(0x40016000, 4096) = 0
> unlink("/home/john/.fetchmail.pid") = 0
> munmap(0x40015000, 4096) = 0
> _exit(0) = ?
Here's my .fetchmailrc, without passwords, etc.
> set syslog
> set postmaster "postmaster"
> #set postmaster "john@dasher"
> set no bouncemail
> #poll postoffice.att.net proto auto timeout 1500 user foo password bar
> poll postoffice.att.net proto pop3 timeout 1500 user foo password bar
> #poll mailandnews.com proto pop3 timeout 1500 user aiax password baz
What is the problem?
John
--
John Bacalle
Reply to: