504291 - Improve error message when POP3 command fails

Status: UNCONFIRMED

(MailNews Core :: Networking: POP, defect)

Description

[Martin Mokrejs]

User-Agent:       Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.1.21) Gecko/20090513 SeaMonkey/1.1.16
Build Identifier: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.1.21) Gecko/20090513 SeaMonkey/1.1.16

The POP3 session opened by mailer can fail in many ways. For example mailer can ask for a message with non-existing UIDL, issue "RETR 1" albeit messages start from number 8. 

First, I propose that mailer keeps a log of the session internally regardless any user setting and if any POP3 command fails user should receive a window with the log of the current session. 



Second, the message I am getting now is:

The RETR command did not succeed. Error retrieving a message. Mail server 10.8.0.1 responded: unable to open that message.

I propose the message should include the UIDL of the message asked for and the failing POP3 command.

Reproducible: Sometimes

Steps to Reproduce:
It happens sometimes although I did not upgrade my Gentoo Linux server with Gentoo Linux mail-mta/netqmail-1.05-r8 for a while and happened several times with seamonkey 1.1.13 to 1.1.16 (my current client).
Actual Results:  
I have two POP3 accounts configured in my client. Both download and delete messages from the server immediately, not aven after I trash them from my Inbox. However, bot accounts are on the same server. In addition, gmail downloads a copy of the emails just in case I am not on POP3. In theory, gmail and seamonkey access at the same time both email boxes (maldir format being used on the server with procmail as LDA). I do not think there is a reason why some messages could be deleted by gmail POPO3 session and cause my seamonkey POP3 session to attempt to retrieve a not anymore existing message. I am attaching the only log I have from qmail-pop3d:

2009-07-15 11:04:15.266874500 tcpserver: status: 1/40
2009-07-15 11:04:15.266918500 tcpserver: pid 16043 from 209.85.221.205
2009-07-15 11:04:15.269596500 tcpserver: ok 16043 ribosome.natur.cuni.cz:195.113.57.20:110 mail-qy0-f205.google.com:209.85.221.205::43344
2009-07-15 11:04:16.100476500 tcpserver: end 16043 status 256
2009-07-15 11:04:16.100477500 tcpserver: status: 0/40
2009-07-15 11:07:02.050960500 tcpserver: status: 1/40
2009-07-15 11:07:02.051001500 tcpserver: pid 16066 from 10.8.0.6
2009-07-15 11:07:02.053514500 tcpserver: ok 16066 :10.8.0.1:110 :10.8.0.6::46724
2009-07-15 11:07:02.605991500 tcpserver: status: 2/40
2009-07-15 11:07:02.606032500 tcpserver: pid 16067 from 10.8.0.6
2009-07-15 11:07:02.608291500 tcpserver: ok 16067 :10.8.0.1:110 :10.8.0.6::46725
2009-07-15 11:07:15.464441500 tcpserver: end 16067 status 256
2009-07-15 11:07:15.464442500 tcpserver: status: 1/40
2009-07-15 11:07:43.227849500 tcpserver: status: 2/40
2009-07-15 11:07:43.227894500 tcpserver: pid 16073 from 209.85.221.205
2009-07-15 11:07:43.230920500 tcpserver: ok 16073 ribosome.natur.cuni.cz:195.113.57.20:110 mail-qy0-f205.google.com:209.85.221.205::62162
2009-07-15 11:07:44.257204500 tcpserver: end 16073 status 256
2009-07-15 11:07:44.257205500 tcpserver: status: 1/40
2009-07-15 11:07:54.736616500 tcpserver: status: 2/40
2009-07-15 11:07:54.736664500 tcpserver: pid 16080 from 10.8.0.6
2009-07-15 11:07:54.739236500 tcpserver: ok 16080 :10.8.0.1:110 :10.8.0.6::46726
2009-07-15 11:07:54.826383500 tcpserver: end 16080 status 256
2009-07-15 11:07:54.826384500 tcpserver: status: 1/40
2009-07-15 11:08:54.739631500 tcpserver: status: 2/40
2009-07-15 11:08:54.739680500 tcpserver: pid 16087 from 10.8.0.6
2009-07-15 11:08:54.742293500 tcpserver: ok 16087 :10.8.0.1:110 :10.8.0.6::51034
2009-07-15 11:08:54.832574500 tcpserver: end 16087 status 256
2009-07-15 11:08:54.832575500 tcpserver: status: 1/40
2009-07-15 11:09:15.736705500 tcpserver: end 16066 status 256
2009-07-15 11:09:15.736706500 tcpserver: status: 0/40
2009-07-15 11:09:54.742601500 tcpserver: status: 1/40
2009-07-15 11:09:54.742651500 tcpserver: pid 16096 from 10.8.0.6
2009-07-15 11:09:54.744812500 tcpserver: ok 16096 :10.8.0.1:110 :10.8.0.6::51035
2009-07-15 11:09:54.832370500 tcpserver: end 16096 status 256
2009-07-15 11:09:54.832371500 tcpserver: status: 0/40



Related bugs which will benefit from the improved error message and pop3 log: bug #246335, #146453, #227665, nice description of the popstate.dat file in #352998.

Comment 1

[Serge Gautherie (:sgautherie)]

Can you reproduce with SeaMonkey v2.0a3 / current v2.0b1pre?

Comment 2

[Martin Mokrejs]

BTW, the substring "unable to open that message" comes from qmail-pop3d. Will try to repeat with never build.

Comment 3

[Phoenix]

Is this still reproducible?

Comment 4

[Philip Chee]

IanN, I think this should be moved to MailNews Core::POP3 Networking.

Comment 5

[Wayne Mery (:wsmwk)]

Ping, Shall we close this one?

Comment 6

[Martin Mokrejs]

Why do you want to close this? Did anybody check if the error messages were improved? If the logs I proposed are existing? I wrote in the original report more words that anybody later added. Please, be fair and check what the program does now.

Comment 7

[Wayne Mery (:wsmwk)]

This is not an arbitrary request. Ping has recently worked heavily in the pop code, and so is likely to have an informed view of whether this is potentially resolved.

Comment 8

[Ping Chen [:rnons] (away)]

First, I propose that mailer keeps a log of the session internally regardless any user setting and if any POP3 command fails user should receive a window with the log of the current session.

We don't have such a mechanism yet, but I think it's a good suggestion. Currently each module has it own log prefs, for POP3, set mailnews.pop3.loglevel to All.

Second, the message I am getting now is:
The RETR command did not succeed. Error retrieving a message. Mail server 10.8.0.1 responded: unable to open that message.
I propose the message should include the UIDL of the message asked for and the failing POP3 command.

This can be done.