237131 - popstate.dat cleared after unexpected response from server

Status: RESOLVED WORKSFORME

(MailNews Core :: Networking: POP, defect)

Description

[:aceman]

User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.7b) Gecko/20040305 Firefox/0.8.0+
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.7b) Gecko/20040305 Firefox/0.8.0+

My popstate.dat file is cleared after the following communication with the
server. See the attachments.
The account is set up to leave messages on the server and delete when deleted
locally.

Reproducible: Always
Steps to Reproduce:
I reproduced this at least 2 times in a row.
Actual Results:  
popstate.dat cleared.

Expected Results:  
popstate.dat shouldn't be touched because there were no changes in message
existence - deletions, new ones. At least Moz doesn't know about them, due to
bug 230294.

Is there any way (a utility) to recreate popstate.dat from the existing messages
in the mail folders? Just grepping X-uidl from the files should be enough.

Comment 1

[:aceman]

Moz 1.6 final. I am not sure the misunderstanding with the server is the
culprit, but all other accounts checked (on the same server) in the same run
went ok and their popstate files are correct.

Comment 2

[:aceman]

Attachment: The affected popstate.dat before its clearing.

Comment 3

[:aceman]

Attachment: The pop3 log of the server communication.

Comment 4

[David :Bienvenu]

Your server is not following the POP RFC. In particular, this paragraph:

After the POP3 server has opened the maildrop, it assigns a message-
   number to each message, and notes the size of each message in octets.
   The first message in the maildrop is assigned a message-number of
   "1", the second is assigned "2", and so on, so that the nth message
   in a maildrop is assigned a message-number of "n".  In POP3 commands
   and responses, all message-numbers and message sizes are expressed in
   base-10 (i.e., decimal).

The pop3 log you've attached shows the message numbers starting at 472. That
causes us grief. Bug 226669 describes a related problem where the server leaves
holes in the ranges. What kind of pop3 server is this, do you know? I think
we'll have to come up with a solution for both problems. It's unfortunate that
there are pop3 servers out there not following the RFC. It's not like it's a
complicated RFC :-)

Comment 5

[Christian Eyrich]

But David, you must admit it's Moz' failure. In another constellation the server
can leave holes in the list without violating the RFC.
Let's fix bug 226669.

Comment 6

[David :Bienvenu]

yes, as I said, let's fix bug 226669. Do you want to have a stab at it, or do
you want me to? I'm thinking adding the level of indirection is the way to go.

Comment 7

[:aceman]

(In reply to comment #4)
> Your server is not following the POP RFC. In particular, this paragraph:
> 
> After the POP3 server has opened the maildrop, it assigns a message-
>    number to each message, and notes the size of each message in octets.
>    The first message in the maildrop is assigned a message-number of
>    "1", the second is assigned "2", and so on, so that the nth message
>    in a maildrop is assigned a message-number of "n".  In POP3 commands
>    and responses, all message-numbers and message sizes are expressed in
>    base-10 (i.e., decimal).
> 
> The pop3 log you've attached shows the message numbers starting at 472. That
> causes us grief.
Yes, that is a mystery for me too. Because there are really 1073 messages on the
server as the STAT command says (I can look at them through a web interface). I
have no clue why does the server list only 1073-472 of them.

> Bug 226669 describes a related problem where the server leaves
> holes in the ranges.
I know, I have filed a recent dupe of it ;)

> What kind of pop3 server is this, do you know? I think
It may be Kerio MailServer 5.7.3 (from mail headers), try pop3.atlas.sk, but
there is some cluster of servers, so I am not sure.

> we'll have to come up with a solution for both problems. It's unfortunate that
> there are pop3 servers out there not following the RFC. It's not like it's a
> complicated RFC :-)

Anyway, do you also think that this may be the cause for the clearing of the
popstate.dat file? I don't know how it could, but this combination is the only 
think I suspect so far.
But that file should not be affected by any buggy servers.

Comment 8

[David :Bienvenu]

It certainly could be responsible for the crunching of popstate.dat, but I don't
know for sure. I'll have to look at the code and see what it would do with that
kind of server output.

Comment 9

[:aceman]

The messages on the server got fixed. The number of messages dropped down to
about 600 (which is those 1073-472). I don't understand that, because it deleted
messages I didn't want deleted.

I suspect bug 224711 comment 13.

Additionally I noticed bug 238365.

Anyway, I can no longer test this bug for a while, until the server screws it up
again.

Comment 10

[:aceman]

I came across a slightly less radical version of this.

I tried to download mail.
Moz said there are 15 new messages, then tried to download some message which
was not already there (bug 230294),
reported that it is marked for deletion and cannot continue. OK
I tried to download messages again. There were suddenly 50(!) new messages, but
Moz hanged on the same problem as above.
On the third try there were 80 new messages!
I gave up and waited about a week for the server to fix the deleted messages (It
always cleans up after a while, as reported in other bugs).
After the week I downloaded the messages again. There were about 150 new ones
but downloaded correctly.
Of course, only about 25 of them were really new, all others were duplicates of
messages already in the Inbox file.
Interesting is, there was a clean date boundary on which the messages started to
duplicate. All messages (except spam, which was already deleted from server)
after this date were downloaded a second time. This was with 1.5, there was no
aging of messages as implemented in 1.6 in play.
It looks like parts of popstate.dat (actually it's memory representation) were
cut off with each attempt to download messages.

I will see if the fix for 226669 helps this, but it will be a long time, because
if Moz handles that problem correctly (skipping deleted messages), there will be
no indication of it.

Comment 11

[:aceman]

I currently experience this with Moz 1.7.0. The first messages on the server are
deleted. The server lists messages with numbers e.g. 10 to 100. Moz tries to get
message 1 and gets the error that it is marked for deletion. Server disconnects
and popstate.dat is now empty. Without closing Mozilla.

This whould be fixed independently of bug 226669, because there may be other
cases of unexpected responses which are not covered by that bug.

Comment 12

[:aceman]

This still happens in seamonkey 1.0.5, e.g. when it is downloading an email (actually it is about to receive its data, just that the antivirus is still buffering and scanning it and just keeps mozilla happy with sporadic "X-x: TimeOut" messages -- so that you know in which state moz is, if it is useful), and the connection breaks down, e.g. modem hangup. popstate.dat is cleared and/or the next time a successive attempt to download messages, an error appears saying "error truncating mailbox file,... delete msf file..." for each message that is filtered (moved) to other folder(file). On an unreliable modem connection this renders seamonkey useless, because I have to repair the damage (manually truncating the file, restoring popstate.dat from backup (so that the same emails are not downloaded again), etc.), it is very annoing.
I hope it helps.

Comment 13

[David :Bienvenu]

aceman, is the last case you describe also one where we're trying to retrieve the first message? I recentl fixed the case where we get an error listing all the uidls, I think...

Comment 14

[:aceman]

What do you mean with first message? Numbered "1" in the list/uidl command? No. As popstate.dat is not empty, there are some messages on the server. The new ones, with high numbers are going to be downloaded. Mozilla says it is downloading messages 1 of 1, and while it is in progress, the internet connection breaks. The modem hangs up, so simply there is no network anymore and Mozilla chokes, stays done, but no message appears.

Comment 15

[David :Bienvenu]

I meant trying to retrieve the first message of the messages it's going to try to retrieve...as opposed to the last message, for example. Of course, 1 of 1 is going to be the first and last message. What's your check for new mail interval set to? If it's one minute, could it be that a second check comes along while the virus checker is still keeping us waiting for the message, or while we're waiting for the dead connection?

Comment 16

[David :Bienvenu]

Have you tried with a recent trunk build? I've tried to simulate various errors in the debugger, but I can't get it to lose my popstate.dat info anymore...

Comment 17

[:aceman]

(In reply to comment #15)
> I meant trying to retrieve the first message of the messages it's going to try
> to retrieve...as opposed to the last message, for example. Of course, 1 of 1 is
> going to be the first and last message.
That was only an example. It may be 5 of 10, anything.

> What's your check for new mail interval
> set to? If it's one minute, could it be that a second check comes along while
> the virus checker is still keeping us waiting for the message, or while we're
> waiting for the dead connection?
No interval, I have to manually check mail.

Comment 18

[:aceman]

(In reply to comment #16)
> Have you tried with a recent trunk build? I've tried to simulate various errors
> in the debugger, but I can't get it to lose my popstate.dat info anymore...
I use seamonkey 1.0.5, not trunk. This problems happen more ofter than in 1.7. The truncation problem never appeared before, it is new to seamonkey. I can't help you how to reproduce it. I use win98, modem. Sometimes it is not even necessary to break the connection, seamonkey simply stops downloading the email. It may be a problem together with the antivirus. I'll attach a log here. Unfortunatelly there are no timestamps, so it is not possible to check if maybe something timeout out...

Comment 19

[:aceman]

Attachment: Log of seamonkey communication with server

The communication is simply interrupted and subsequent message fetches have the problems described in previous comments.

Comment 20

[David :Bienvenu]

OK, that's a log of the virus checker keeping the connection alive, right? There's no actual error in the log. Do you then hit get new mail again while that connection is sitting spinning? Or do you eventually lose the connection, but we don't see that in the log?

Comment 21

[:aceman]

Good point. I don't know. There is no progress indicated anywhere (mozilla statusbar, modem RX/TX lights, etc.). Pressing Stop doesn't send a Quit command to the server (other bug), so the connection may be open, I don't know. The modem link is up. So I press 'get new mail'.

Comment 22

[:aceman]

I have new data. I modified the account settings to bypass the antivirus and connect to the real POP3 server. I downloaded a huge mail (3mb) and it got interrupted. It was downloading and suddenly stopped. Mozilla indicated no error, just that the email didn't appear in the Inbox. I didn't try anymore. On the next Mozilla start, all messages on that server were downloaded again. I think this means popstate.dat was cleared at the previous shutdown.

Comment 23

[:aceman]

(In reply to comment #16)
> Have you tried with a recent trunk build? I've tried to simulate various errors
> in the debugger, but I can't get it to lose my popstate.dat info anymore...
> 
Debugger? Could you maybe try to pull the cable out of your modem (or network card) while mozilla is downloading a large email? Maybe it is necessary to do it on Windows, not linux...

Comment 24

[David :Bienvenu]

processing stop does send a quit to the server, I believe. However, if we lose the connection, we don't send a QUIT, because we've lost the connection.

I've tried pulling out the cable when downloading a large message, on Windows. It didn't cause a problem, other than the server locking the mailbox because we weren't able to clean up the connection. Pressing stop on a large message download multiple times worked fine.

I know this bug is out there, because I've seen it happen, but I'm unable to reproduce it on demand at all.

Comment 25

[Larry Cook]

David, when I was working on the POP3 timeout bug I fixed, I used the test POP server included with the Mail::Box perl module.  In the 'tests/43pop3' directory is the perl script 'server' which I modified to not respond in certain situations so that I could test my timeout fix.  Maybe this 'server' script would be useful to you for reproducing various situations.
Homepage: http://perl.overmeer.net/mailbox/
Download: http://perl.overmeer.net/mailbox/source/source-current.tar.gz

Comment 26

[Jim Booth]

It just happened to me again with Seamonkey 1.0.7

I had clicked on GET MSGS, and the status line displayed:
  Connect: Host contacted, sending login information...
for a LONG TIME (around a minute).   I clicked the STOP button in the toolbar, and then clicked GET MSGS again.  It started redownloading 10000+ messages.  The popstate.dat file was wiped clean.

Comment 27

[:aceman]

Could you please tell us something about your network hardware setup? And OS? Thanks

Comment 28

[:aceman]

Still there on seamonkey 1.1.2, but less frequently as I could see. It hapens only sometimes, even under the seemingly same circumstances - download of a large email (4MB on my dialup) is interrupted. The connection is still up but seamonkey simply decides to stop downloading the email. All seems fine, but the email doesn't appear in the folder. Only after restarting seamonkey, the Inbox summary file is rebuilt and the email appears (partially truncated). Sometimes the popstate.dat is empty, sometimes not.

Comment 31

[Wayne Mery (:wsmwk)]

do you use the quarantine option?  Or don't you use AV software?   iirc option was created in bug 116443

Comment 32

[:aceman]

Yes, I am using an avtivirus, that is between seamonkey and the server. But the problem also happens when I bypass it...

Comment 35

[David :Bienvenu]

I fixed a few issues like this - does it still happen in SM 2.0 beta builds, or TB 3.0 b3?

Comment 36

[David Borhani]

I've not noticed the bug recently (last ~4 months, at least).

Comment 37

[David :Bienvenu]

ok, thx, marking WFM. Most of the work happened in bug 240049, I believe.

Comment 38

[:aceman]

I have radically changed my setup (to Linux, Thunderbird 2, fast machine, fast Adsl connection, the same pop3 server), and I have never experienced this problem on it (for 1 year). I agree with WFM. I can reopen if it happens again.

It only happened when my filesystem went full, popstate.dat was cleared and all messages on server redownloaded again. Is there a bug for this?

Comment 39

[Larry Cook]

(In reply to comment #38)
> It only happened when my filesystem went full, popstate.dat was cleared and all
> messages on server redownloaded again. Is there a bug for this?

There is bug 239455 which is very old and has status 'RESOLVED WORKSFORME'.

Comment 40

[:aceman]

Thanks, that's it.