Subject: [Imap-uw] Problems with ipop3d/email deletion/outlook?

From: Ken Kleiner <[email-masked]>
Date: Thu, 19 May 2005 16:53:43 -0400

One of our users uses MS outlook from home system with DSL link.  From 
time to time, a logout/disconnect from outlook deletes messages!  This 
behavior occurred several nights ago, but as you can see, the process 
to open the mailbox with PID 8994 didn't close until 4+hours.  There 
were several attempts
to read the mail between the open/close, hence the error opening lines.

The problem is the ndele=2424 message - what would cause ipop to delete 
messages if user did not specify to?

May 16 21:25:01 server ipop3d[8994]: Login user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxxx..19.154.78] 
nmsgs=2424/2424
May 16 21:43:24 server ipop3d[9318]: Error opening or locking INBOX 
user=tom host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78]
May 16 21:43:24 server ipop3d[9318]: Login user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] no mailbox
May 16 21:43:24 server ipop3d[9318]: Logout user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] nmsgs=2424 
ndele=0
May 16 21:47:40 server ipop3d[9356]: Error opening or locking INBOX 
user=tom host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78]
May 16 21:47:40 server ipop3d[9356]: Login user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] no mailbox
May 16 21:47:40 server ipop3d[9356]: Logout user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] nmsgs=2424 
ndele=0
May 16 22:01:40 server ipop3d[9694]: Error opening or locking INBOX 
user=tom host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78]
May 16 22:01:40 server ipop3d[9694]: Login user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] no mailbox
May 16 22:01:40 server ipop3d[9694]: Logout user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] nmsgs=2425 
ndele=0
May 16 23:28:01 server ipop3d[11632]: Error opening or locking INBOX 
user=tom host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78]
May 16 23:28:01 server ipop3d[11632]: Login user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] no mailbox
May 16 23:28:01 server ipop3d[11632]: Logout user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] nmsgs=2426 
ndele=0

---MESSAGES DELETED HERE---
May 17 00:28:07 server ipop3d[8994]: Logout user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] nmsgs=6 
ndele=2424
-------------------------------------------

May 17 08:27:39 server ipop3d[21151]: Login user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] 
nmsgs=17/17
May 17 08:28:02 server ipop3d[21151]: Logout user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] nmsgs=17 
ndele=0

   Here is what normal pop activity should look like, where a logout 
immediately follows a login for the same PROCESS ID (the number in []):

May 15 09:38:50 server ipop3d[30729]: Login user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] 
nmsgs=2491/2491
May 15 09:39:04 server ipop3d[30729]: Logout user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] nmsgs=2491 
ndele=0
May 15 11:56:15 server ipop3d[316]: Login user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] 
nmsgs=2491/2491
May 15 11:56:18 server ipop3d[316]: Logout user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] nmsgs=2491 
ndele=0
May 15 11:56:25 server ipop3d[341]: Login user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] 
nmsgs=2491/2491
May 15 11:56:26 server ipop3d[341]: Logout user=user 
host=blah-xxx-19-154-78.bos.east.verizon.net [xxx.19.154.78] nmsgs=2491 
ndele=0

     Thanks!

<><  ><> <><  ><> <><  ><> <><  ><> <><  ><> <><

Ken Kleiner
System Manager
Computer Science Department
Umass Lowell

voice : 978 934 3645
fax : 978 934 3551

cell : 603 305 5800 (emergencies only, please)

[email-masked]

_______________________________________________
Imap-uw mailing list
[email-masked]
https://mailman1.u.washington.edu/mailman/listinfo/imap-uw

---

From: Mark Crispin <[email-masked]>
Date: Thu, 19 May 2005 18:36:03 -0700 (Pacific Daylight Time)

In the example you gave, the ipop3d server with process ID 8994 held and 
retained the lock from 21:25:01 until 00:28:07, at which point it deleted 
2424 messages.  This was a normal POP3 logout, not a logout as a result of 
a disconnection.

As distributed by UW, a POP3 server session that has been idle for 10 
minutes will automatically log itself out.  In addition, a POP3 server 
session which has been idle for at least 5 minutes will relenquish the 
lock to a new POP3 server session which is trying to acquire the lock.

I do not know if your copy of ipop3d came from unmodified UW sources or 
not.  If you have modified ipop3d, or if you obtained ipop3d from a third 
party, I can not speak for its behavior.

Assuming that your ipop3d is unmodified, or the modifications do not 
affect ipop3d's behavior in this regard, then the only explanation for the 
log messages which you report is the following:

A POP3 client connected at 21:35:01 and got the process id 8994 server.

That POP3 client kept the session non-idle throughout this period.  Other 
POP3 clients attempted to connect at 21:43:24, 21:47:40, 22:01:40, and 
23:28:01, but could not get the mailbox because the process id 8994 server 
had activity with the prior 5 minutes.  At no time was the server idle for 
as long as 10 minutes.

Sometime between 21:35:01 and 00:28:07, the client to the process 8994 
server sent 2424 POP3 DELE commands to request that messages be deleted 
when the client logs out with a QUIT command.  The client had the option 
of cancelling these DELE requests with a RSET command, but did not do so.

At 00:28:07, the client connected to the process id 8994 server logged 
out with a QUIT command.

The upshot is that the responsible party is the POP3 client which was 
connected to the process ID 8994 server.  I do not think that client was 
Microsoft Outlook; it does not normally behave that way.

This suggests, especially if the problem affects one particular user, that 
something is going on that you havne't been told.

One possibility is pilot error; sometimes users don't tell you everything 
until you ferret it out.  Another possibility is that the user is being 
hacked.

Good luck in the detective work.

-- Mark --

http://staff.washington.edu/mrc
Science does not emerge from voting, party politics, or public debate.
Si vis pacem, para bellum.
_______________________________________________
Imap-uw mailing list
[email-masked]
https://mailman1.u.washington.edu/mailman/listinfo/imap-uw