Closed Bug 387361 Opened 12 years ago Closed 9 years ago

msg copy action to imap on incoming pop3 mail fails with quarantining turned on for antivirus (quarantine option=on/mailnews.downloadToTempFile=true, COPY to any of IMAP folder and local mail folder)

Categories

(MailNews Core :: Filters, defect, major)

x86
Windows XP
defect
Not set
major

Tracking

(Not tracked)

RESOLVED FIXED
Thunderbird 3.3a1

People

(Reporter: Bienvenu, Assigned: rkent)

References

(Depends on 1 open bug, Blocks 1 open bug)

Details

Attachments

(4 files, 4 obsolete files)

1. Set up a filter to copy an incoming pop3 message to an other local folder.
2. Turn on message quaranting in tools | options |privacy | anti-virus
3. Send yourself a msg that triggers the filter.

The message won't be copied successfully. I tried this with the global inbox turned on, but I don't think that matters.
Product: Core → MailNews Core
David, can you reproduce?
WFM filtering on subject 
Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1b4pre) Gecko/20090423 Shredder/3.0b3pre
Summary: msg copy action on incoming pop3 mail fails with quarantining turned on → msg copy action on incoming pop3 mail fails with quarantining turned on for antivirus
Blocks: 507090
I agree to comment #1: WFM here on

Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1.2pre) Gecko/20090729 Lightning/1.0pre Shredder/3.0b4pre ID:20090729051958

I try:
1. with filter apply to account [A] (not in local folders) and sending a mail fom local folders account [B] and moving incoming mail to another account [C] (not in local folders)

2. with filter apply to account (in local folder) [A] and sending a mail from account [B] not in local folder and moving incoming mail to folder located in local folder.

Anyone can confirm that work?
Attached patch unit test, WFM but leaks (obsolete) — Splinter Review
Since I'm in the middle of creating unit tests involving local folders and filtered copies, it was real easy to adapt one as a test for this. Test passes with current trunk.

Might as well add it to the tree - but this test leaks as reported in bug 507285. I'm not sure what the policy is in adding leaking tests.
Attachment #391623 - Flags: review?(bienvenu)
Comment on attachment 391623 [details] [diff] [review]
unit test, WFM but leaks

thx for the test. Let's hold off landing this until the underlying leak is fixed.
Attachment #391623 - Flags: review?(bienvenu) → review+
Depends on: 507285
Blocks: 383425
Severity: normal → major
I'm changing the assign to myself, since this has morphed into a unit test that confirms that the bug should be WFM (and I had lost track of its existence.)
Assignee: bienvenu → kent
The underlying leak was fixed long ago in bug 507285. I just reran this test, it works, and does not seem to leak anymore.

Would there by any objections to me landing the already approved unit test patch, and closing this bug?
no, sounds good, thx.
I'm going to mark this bug "Resolved - Fixed" and change the summary slightly to indicate that the bug has been morphed into writing a test for a function. Feel free to complain if that doesn't work for you.
Status: NEW → RESOLVED
Closed: 10 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Summary: msg copy action on incoming pop3 mail fails with quarantining turned on for antivirus → test: msg copy action on incoming pop3 mail fails with quarantining turned on for antivirus
Target Milestone: --- → Thunderbird 3.1b1
Backed out due to test failures (hangs) across all trunk tinderboxes (c-c plus m-c):

http://hg.mozilla.org/comm-central/rev/624f41b4f599

c-c plus m-1.9.2 seemed fine, but I couldn't see anything that was branch dependent at a quick glance.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
I saw this in 3.0.2 beta1 ... reported in Bug 545082 (feel free to mark it as a dupe of this one).
(In reply to comment #11)
> I saw this in 3.0.2 beta1 ... reported in Bug 545082 (feel free to mark it as a
> dupe of this one).

Nils, this bug does not currently have any known ways to reproduce, and the test was supposed to show that it is not an issue. The bug as defined is local->local copies, while I think your issue was local->IMAP.

So this bug needs to be either broadened to include the local->IMAP case, or we need a new bug (or morph one of your other bugs.)
(In reply to comment #12)
> this bug does not currently have any known ways to reproduce, (snip)

Procedure of of comment #0 to reproduce this bug is still effective.

(Filter rules for pop.ops.dti.ne.jp)
> name="test-1-Add-TAG" enabled="yes" type="17"
>   action="AddTag" actionValue="test-1"
>   condition="AND (subject,begins with,test-1)"
> name="test-1-Copy-POP" enabled="yes" type="17"
>   action="Copy to folder"
>   actionValue="mailbox://muttley%40ops.dti.ne.jp@pop.ops.dti.ne.jp/Inbox/test-1"
>   condition="AND (subject,begins with,test-1)"
> name="test-1-Move-IMAP" enabled="yes" type="17"
>   action="Move to folder"
>   actionValue="imap://yatter.one@imap.gmail.com/INBOX/F1"
>   condition="AND (subject,begins with,test-1)"

(0) Send two mails to muttley @ ops.dti.ne.jp.
    mail-1=Subject: test-1-A, mail-2=Subject: test-1-B
(1) Get Msgs
  (Tb 3.0.1 on Ms Win-XP, Qurantine option=enabled)
  (Fetch header only=Off, no download mail size limitation)
  (Leave message on server=On, as the POP3 account is for my daily use by Sm2)
(2) Two mails appeared in Inbox(unread mail count=2)
(3) Only one mail appeared at thread pane of Inbox/test-1, Subject=test-1-B
    (.msf entry of only last mail is created at copy-target/local folder)
    View/Messages Source : Nothing was displayed.  
    tag-1 was added to the mail (bug 355537 doesn't occur)
(4) After a while, two mails disappeared from local Inbox.
    Two mails appeared at IMAP Inbox/F1 folder.
    tag-1 was added (bug 355537 doesn't occur).
    => Unable to reproduce Bug 545082 by above message filter rules.

Kent James, did you check copied mail data in copy target folder?
If single test mail only, "last mail only at copy target folder" can't be observed. Check with multiple test mails, please.

To Nils Lohner:
As I wrote above, I couldn't reproduce your Bug 545082. Can you add detailed "steps to reproduce" to Bug 545082 with appropriate bug summary for IMAP case?
Note:
In my test, "Global Search and Indexer" was disabled. I checked both Inbox/F1(offline use=on) and Inbox/F2(offline use=off), and no difference was observed.
WADA: no, I have not tried multiple emails. I'll try to give that a try. Do you know if one of the folders needs to be IMAP, or does it also fail if all of the folders are Local (easier to write the XPCSHELL test if I don't have to use IMAP).
(In reply to comment #15)

"move to IMAP folder" part is only to check Bug 545082. Only "copy to local folder" with qurantine opion=on is needed. "add tag" part is merely to see "mail is really filtered" easily. 
As I have two free Gmail accounts for IMAP testing, I'll check "copy to IMAP folder" case. (I recomend you to get free Gmail account for ease of test.)
Steps to reproduce are posted in https://bugzilla.mozilla.org/show_bug.cgi?id=545082#c33  

I would assume that it doesn't make a difference whether the destination is local folders or IMAP but let's test:

- filtering from the POP3 inbox to another (local) folder in that account works fine
- filtering from the POP3 inbox to a folder in Local Folders works fine
- filtering from the POP3 inbox to a folder in the IMAP server does not work and yields Bug 545082

OK, so much for my assumptions ;)

Let me know if you need anything else.
(In reply to comment #17)
> and yields Bug 545082

Bug 545082 is "move to IMAP folder" case(you said no "Copy to" action).
Nils Lohner, is your test result of "to local folder" in comment #17 for "Move to" case? Or "Copy to" case? (This bug is for "Copy to" case, never for "Move to" case.)
@WADA I have only MOVE TO actions in my filters, no copying at all, please see the filter that I pasted into the other bug at https://bugzilla.mozilla.org/show_bug.cgi?id=545082#c13
(In reply to comment #19)
> @WADA I have only MOVE TO actions in my filters, no copying at all, (snip)

Nils Lohner, if so, please don't add comments for "Move to" cases to this bug (this bug is only for "Copy to" case) any more, please. "Move to IMAP" && "Source Folder=POP3" && "Quarantine option=On" case is your Bug 545082. Let's analyze your "Move to IMAP" case in that bug, instead of this bug which is only for "Copy to" case.
(In reply to comment #20)
> Nils Lohner, if so, please don't add comments for "Move to" cases to this bug
> (this bug is only for "Copy to" case) any more, please. "Move to IMAP" &&
> "Source Folder=POP3" && "Quarantine option=On" case is your Bug 545082. Let's
> analyze your "Move to IMAP" case in that bug, instead of this bug which is only
> for "Copy to" case.

Sorry, you commented that the IMAP MOVE is a COPY then DELETE ... which is why I commented here as well.
(In reply to comment #16)
> (In reply to comment #15)
> 
> "move to IMAP folder" part is only to check Bug 545082. Only "copy to local
> folder" with qurantine opion=on is needed. "add tag" part is merely to see
> "mail is really filtered" easily. 
> As I have two free Gmail accounts for IMAP testing, I'll check "copy to IMAP
> folder" case. (I recomend you to get free Gmail account for ease of test.)

One thing to be aware of is that filter moves on incoming mail happen synchronously, which is why they work. It's the async operations like copy, or move to an imap folder that cause problems.
(In reply to comment #21)
> you commented that the IMAP MOVE is a COPY then DELETE ...

I didn't(can't) say "is"(wrote "looks equivallent to" instead), as I don't know design. According to comment #22, the "equivallence" I thought seems "asynchronous or synchronous".
a. Move to local folder/same POP3 account: Synchronous
b. Copy to local folder/same POP3 account: Asynchronous
c. Move to IMAP folder: "server connection and select if required, and append"
                        step is same as "copy from local to IMAP", and seems
                        asynchronous. (how about "delete from local" step?)
b. is simplest case and is this bug. c.(your bug) is complex case than b.
Attached patch test case that fails (obsolete) — Splinter Review
This is a variation of test_localToImapFilter.js, with quarantining enabled, that fails and presumably demonstrates this bug. That is good for debugging. Unfortunately the original bug was disabled due to intermittent failures.
Attachment #391623 - Attachment is obsolete: true
Summary: test: msg copy action on incoming pop3 mail fails with quarantining turned on for antivirus → msg copy action to imap on incoming pop3 mail fails with quarantining turned on for antivirus
Target Milestone: Thunderbird 3.1b1 → Thunderbird 3.1b2
I've spent a bit of time looking at this, and here's a summary.

The quarantining code, which copies the message to a temporary file, tries to avoid adding that message back into the main mbox prior to filtering. Instead it tries to trick the filters into using the temporary file as the "inbox" with tricks like setting the message key to 0 temporarily, and passing the temporary file as the folder location. But this trick does not survive all filter actions, and in particular is failing for the imap folder copy. The imap folder copy ultimately sees a string request to copy from the local inbox folder with message key of 0, which fails.

It seems to me the cleanest way to fix this would be to go ahead and remove this trickery, and just move the message from the temp file to the mbox prior to running message filters.

But I don't really know the motivation for the trickery in the first place. Is this just some sort of performance optimization, trying to eliminate one move of the message in the case where the filter is going to move it again? Or is there some other reason for it?
Status: REOPENED → ASSIGNED
Whiteboard: [needs comment on direction]
(In reply to comment #25)

> But I don't really know the motivation for the trickery in the first place. Is
> this just some sort of performance optimization, trying to eliminate one move
> of the message in the case where the filter is going to move it again? Or is
> there some other reason for it?

The performance optimization is part of it. The other motivation is that delaying the move back to the mbox gives the virus checker as much time as possible to decide the message has a virus and only destroy the temp file, not the mbox. Reasoning about virus checkers is not a fruitful exercise, however, and the trickery is massively painful, so I could get behind your idea for fixing it.
Attached patch Remove the trickery (obsolete) — Splinter Review
I updated the test to use the async and new IMAPpump frameworks.

The patch attempts to remove all of the trickery associated with trying to use the temp file in the filters. The effects of this on antivirus vendors is hard to determine, but there is enough of a risk of issues that this should probably not be considered for 3.0.x, even though it is a bug fix.
Attachment #435365 - Attachment is obsolete: true
Attachment #437957 - Flags: superreview?(bienvenu)
Attachment #437957 - Flags: review?(bienvenu)
Whiteboard: [needs comment on direction] → [needs r/sr bienvenu]
Summary: msg copy action to imap on incoming pop3 mail fails with quarantining turned on for antivirus → msg copy action to imap on incoming pop3 mail fails with quarantining turned on for antivirus (quarantine option=on/mailnews.downloadToTempFile=true, COPY to IMAP folder)
this makes the movemail code compile.
Attachment #437957 - Attachment is obsolete: true
Attachment #437957 - Flags: superreview?(bienvenu)
Attachment #437957 - Flags: review?(bienvenu)
Attachment #448424 - Flags: superreview?(bienvenu)
Attachment #448424 - Flags: review?(bienvenu)
I tried running this test on the mac - it hung with the attached log...
I should say - the test eventually succeeds but it takes a couple minutes, which seems wrong.
+        // we need to clone because nsLocalFileUnix caches its stat result,
+        // so it doesn't realize the file has changed size.

I know you just changed the indentation, but it's nsLocalFileWin that caches the stat result, not Unix, afaict. I'm happy with the patch, but I'd really like to know why the test takes two minutes.
I don't have any way currently to test this on a Mac to see this. Do you have any suggestions of how to move forward?
Downloaded mails in test.
1. A spam mail(remains in Inbox)
2. Subject=test-1-A, body=test-1-A[CRLF]
3. Subject=test-1-B, body=test-1-B[CRLF]test-1-B[CRLF]
4. Subject=test-1-C, body=test-1-C[CRLF]test-1-C[CRLF]test-1-C[CRLF]

Files.
(1) Process monitor log(CSV) for download.
    "Get Msgs" to "unread count=3 at folder pane". 
    Filter: If process name=thunderbird.exe, Include.
            No other rule, so all file I/O by Tb is logged. 
    Unread mail count=3 is shown at folder pane.
(2) test-1.msf after download. test-1-A.msf, size=4,515 bytes.
    file size of test-1=0.
(3) test-1.msf after folder open(click test-1). test-1-B.msf, size=3,440 bytes.
    file size of test-1 is still 0.
    Unread mail count=1 is shown at folder pane.
    Thread pane shows test-1-C only.

(Observation)
1. Mail data is not appended to test-1.
2. At step (2), three mails are seen in .msf.
   However, only one mail(test-1-C) is seen after folder open, step (3).
   Where have test-1A/test-1-B gone?

Filter copy tries to copy from Inbox at where mail data is not written yet instead of ...\Temp\newmsg?
Filter copy is scheduled too early?

By the way, read of each one byte of \msgFilterRules.dat is seen in Process Monitor log. By design?
Filter log never helps diagnosis. David, is enhancement like next possible?
1. Add timetamp.
2. Add UIDL if POP3, UID if IMAP.
3. Add offset data(POP3) or UID(IMAP) to log for Copy/Move.
4. If something wrong happens after current filter log write for copy/move,
   write the incident of the something wrong in filter log.
5. NSPR logging or optional Error Console message for message filter activity.
Summary: msg copy action to imap on incoming pop3 mail fails with quarantining turned on for antivirus (quarantine option=on/mailnews.downloadToTempFile=true, COPY to IMAP folder) → msg copy action to imap on incoming pop3 mail fails with quarantining turned on for antivirus (quarantine option=on/mailnews.downloadToTempFile=true, COPY to any of IMAP folder and local mail folder)
WADA, we have a patch that should fix the bug, so I don't think we need more diagnosis.

rkent, I'm not sure what to do about the mac test. I'll go make sure the problem doesn't also happen on windows.
rkent, the test is just as slow on Windows. A couple minutes at least. The test hangs here:

TEST-PASS | ../../mailnews/fakeserver/pop3d.js | [readFile : 17] true == true
WARNING: NS_ENSURE_SUCCESS(rv, result) failed with result 0x80520012: file C:/mo
zilla-build/msys/tbirdhq/mailnews/local/src/nsPop3Protocol.cpp, line 214
WARNING: NS_ENSURE_TRUE(identity) failed: file C:/mozilla-build/msys/tbirdhq/mai
lnews/base/util/nsMsgIncomingServer.cpp, line 1941
Begin mail message delivery.
GetDiskSpaceAvailable returned: 159301271552 bytes
Incorporate message begin:
msgAdded to folder <Inbox> subject <[Bug 397009] A filter will let me tag, but n
ot untag>
Incorporate message complete.
End mail message delivery.
TEST-PASS | ../../mailnews/resources/POP3pump.js | [OnStopRunningUrl : 53] 0 ==
0
waiting for POP3Pump done
TEST-INFO | (xpcshell/head.js) | test 3 finished
TEST-INFO | (xpcshell/head.js) | test 2 finished

Seems odd that test 2 should finish after test 3...
Comment on attachment 448424 [details] [diff] [review]
fix movemail so this compiles on mac/linux

reluctantly minusing based on test slowness - I suspect the test is timing out instead of finishing cleanly, and we really need clean tests.
Attachment #448424 - Flags: superreview?(bienvenu)
Attachment #448424 - Flags: superreview-
Attachment #448424 - Flags: review?(bienvenu)
Attachment #448424 - Flags: review-
OK I'll try to duplicate this on Windows.
Let me know if I can help - perhaps the pop3pump is taking a long time to shutdown. I'd like to get this in soon because it's going to cause conflicts with my pluggable storage work, but perhaps also simplify some edge cases, and I'd like to get that resolved soon.
do_timeout no longer accepts strings.
Attachment #448424 - Attachment is obsolete: true
Attachment #449700 - Flags: superreview?(bienvenu)
Attachment #449700 - Flags: review?(bienvenu)
Comment on attachment 449700 [details] [diff] [review]
use function for onDone

great, thx. Does this mean an error was getting swallowed and not dumped to the console?
Attachment #449700 - Flags: superreview?(bienvenu)
Attachment #449700 - Flags: superreview+
Attachment #449700 - Flags: review?(bienvenu)
Attachment #449700 - Flags: review+
I have found that timeouts frequently stop the test without generating errors. I think that is what was happening here. I don't know if that is my code or inherent in the infrastructure, but it is obviously not ideal. I'm pretty sure though that it is not unique to this test and bug.
Status: ASSIGNED → RESOLVED
Closed: 10 years ago9 years ago
Resolution: --- → FIXED
Whiteboard: [needs r/sr bienvenu]
Depends on: 571693
I think this checkin broke msg filters for POP3. I've been seeing a problem with my message filters for some time now: An incoming message is at first stored in Inbox, then my message filter tries to copy it to its destination folder. The result is, that the message disappears from Inbox and shows up in the destination folder (as expected) - but it cannot be opened. Source view shows nothing. After starting repair folder on both Inbox an the filter's destination folder, the message is again shown in Inbox, where it can now be opened normally, and its entry in the filter's destination folder disappears.

I today tried to track down the date on which the bug was introduced. Nightly 2010-06-08-01-comm-central-trunk.zip works as expected while nightly 2010-06-09-01-comm-central-trunk.zip shows the bug as described. The comm-central pushlog tells me that between 2010-06-08 00:00:00 and 2010-06-09 00:00:00 only two checkins happened: One for this bug and one for bug 479200.

So I come to the conclusion, that probably this checkin caused the bug.
Do you have an anti-virus program active, and if so which one? Do you have quarantining selected?
With mailnews.downloadToTempFile=true the bug does not depend on whether my antivirus program is enabled or disabled. With mailnews.downloadToTempFile=false the bug disappears.
Blocks: 582918
The status of the patches in this bug got confused by the reopening (which is a good reason to not reopen bugs that have patches checked in).

What was checked into 1.9.2 (and TB 3.1) was simply a test. The later attachment 449700 [details] [diff] [review] was only checked into trunk, and is not in TB 3.1  Since that is the patch that could affect the actual application, I'm going to remove the 3.1 status to make that clearer.
changing target milestore too per coment #48.
Target Milestone: Thunderbird 3.1b2 → Thunderbird 3.2a1
Duplicate of this bug: 383425
No longer blocks: 582918
Depends on: 582918
Depends on: 595814
Depends on: 596184
You need to log in before you can comment on or make changes to this bug.