I have seen this same condition arrise on our server since upgrading from Qpopper 3.x.x to 4.0.3.
It happens mainly with mail messages with attachments, and affects both our OS/2 PMMAIL and Windows Pegasus Mail clients. The Pegasus mail clients have their TCPIP timeout set to 120sec and it seems to help, but the OS/2 clients are not able to have a timeout set. If anyone has a suggestion, please let us know. - Chris Payne Ted Cabeen wrote: > > I've been running qpopper 4.0.3 for months now with little to no problems. > However, a couple of hours ago we started have significant problems with > POP sessions hanging during the middle of a download. When I look at the > log file, I see lots of error messages like the following: > > Mar 18 21:35:45 red /usr/local/libexec/qpopper[5913]: I/O error flushing output to >client USERNAME at IP.impulse.net [207.154.0.0]: Operation not permitted (1) > Mar 18 21:35:45 red /usr/local/libexec/qpopper[5913]: USERNAME at IP.dia.impulse.net >(207.154.0.0): -ERR SIGHUP or SIGPIPE flagged > Mar 18 21:35:45 red /usr/local/libexec/qpopper[5913]: I/O error flushing output to >client USERNAME at IP.dia.impulse.net [207.154.0.0]: Operation not permitted (1) > Mar 18 21:35:45 red /usr/local/libexec/qpopper[5913]: USERNAME at IP.dia.impulse.net >(207.154.0.0): -ERR POP hangup from red.impulse.net > Mar 18 21:35:45 red /usr/local/libexec/qpopper[5913]: I/O error flushing output to >client USERNAME at IP.dia.impulse.net [207.154.0.0]: Operation not permitted (1) > Mar 18 21:35:45 red /usr/local/libexec/qpopper[5913]: Stats: USERNAME 0 0 7 114185 >IP.dia.impulse.net 207.154.0.0 > Mar 18 21:35:45 red /usr/local/libexec/qpopper[5913]: I/O error flushing output to >client USERNAME at IP.dia.impulse.net [207.154.0.0]: Operation not permitted (1) > > Over the last week, we'd usually see ~20-30 of these messages each day. > However, we've seen over 200 of these errors today. I tried a trace on the > qpopper server running on an alternate port in with --enable-low-debug > compiled in and got the following messages (IPs and usernames have been > masked for privacy): > > Mar 18 20:41:39.320 2002 [75954] Opened trace file "/tmp/qpopper.debug" as 4 > Mar 18 20:41:39.320 2002 > Mar 18 20:41:39.320 2002 [75954] opened stream socket; sockfd = 6 > Mar 18 20:41:39.320 2002 > Mar 18 20:41:39.320 2002 [75954] set stream socket options; sockfd = 6 > Mar 18 20:41:39.320 2002 > Mar 18 20:41:39.320 2002 [75954] did bind on stream socket; sockfd = 6 > Mar 18 20:41:39.320 2002 > Mar 18 20:41:39.320 2002 [75954] popper: Server: listening on 0.0.0.0:8765 > > Mar 18 20:41:39.320 2002 > Mar 18 20:41:39.320 2002 [75954] listening using socket fd 6 > Mar 18 20:41:39.320 2002 > Mar 18 20:41:39.320 2002 [75954] set fd 6 non-blocking (0x6) > Mar 18 20:41:39.320 2002 > Mar 18 20:55:51.969 2002 [75954] accept=7; sockfd=6; clilen=16; >cli_addr=207.154.0.0:3010 > > Mar 18 20:55:51.969 2002 > Mar 18 20:55:51.986 2002 [75954] new connection; fd=7 > Mar 18 20:55:51.986 2002 > Mar 18 20:55:51.986 2002 [75954] newsockfd (7) flags: 0x6 > Mar 18 20:55:51.986 2002 > Mar 18 20:55:51.986 2002 [75954] set fd 7 blocking (0x2) > Mar 18 20:55:51.986 2002 > Mar 18 20:55:51.997 2002 [75954] Set downcase-user to true > Mar 18 20:55:51.997 2002 > Mar 18 20:55:51.997 2002 [75954] Set fast-update to true > Mar 18 20:55:51.997 2002 > Mar 18 20:55:51.997 2002 [75954] Set reverse-lookup to false > Mar 18 20:55:51.997 2002 > Mar 18 20:55:51.997 2002 [75954] Set mail-command to "/usr/sbin/sendmail" > Mar 18 20:55:51.997 2002 > Mar 18 20:55:51.998 2002 [75954] Set statistics to true > Mar 18 20:55:51.998 2002 > Mar 18 20:55:51.998 2002 [75954] Set user-options to true > Mar 18 20:55:51.998 2002 > Mar 18 20:55:52.420 2002 [75954] (v4.0.3_DEBUG) POP login by user "USERNAME" at (* >_DEBUG *) * _DEBUG * > Mar 18 20:55:52.420 2002 > Mar 18 20:55:52.721 2002 [75954] ...FillMangleInfo; commandline(10)= > ugar.cane > Mar 18 20:55:52.721 2002 > Mar 18 20:58:39.126 2002 [75954] I/O error flushing output to client USERNAME at * >_DEBUG * [* _DEBUG *]: Operation not permitted (1) > Mar 18 20:58:39.126 2002 > Mar 18 20:58:39.126 2002 [75954] USERNAME at localhost: -ERR SIGHUP or SIGPIPE >flagged > Mar 18 20:58:39.126 2002 > Mar 18 20:58:39.126 2002 [75954] I/O error flushing output to client USERNAME at * >_DEBUG * [* _DEBUG *]: Operation not permitted (1) > Mar 18 20:58:39.126 2002 > Mar 18 20:58:39.126 2002 [75954] USERNAME at localhost: -ERR POP hangup from DEBUG > Mar 18 20:58:39.126 2002 > Mar 18 20:58:39.126 2002 [75954] I/O error flushing output to client USERNAME at * >_DEBUG * [* _DEBUG *]: Operation not permitted (1) > Mar 18 20:58:39.126 2002 > Mar 18 20:58:39.126 2002 [75954] Stats: USERNAME 0 0 10 439419 * _DEBUG * * _DEBUG * > Mar 18 20:58:39.126 2002 > Mar 18 20:58:39.127 2002 [75954] I/O error flushing output to client USERNAME at * >_DEBUG * [* _DEBUG *]: Operation not permitted (1) > Mar 18 20:58:39.127 2002 > Mar 18 20:58:39.127 2002 [75954] exiting after Qpopper returned > Mar 18 20:58:39.127 2002 > > Any thoughts? The debug log seems rather empty. Did I miss a > command line argument? I used > ./qpopper -t -f <path to normal config file> > > If necessary, I can rerun the debugging run again, but not until > the morning, when I can get a holf of a user who knows enough to > change his POP port. > > I'd appreciate any input you all have. Thanks. > > --Ted Cabeen
