Closed Bug 601900 Opened 14 years ago Closed 14 years ago

copy messages to imap folder stops without any error message - copy to no reaction - due to insufficient return checks

Categories

(Thunderbird :: Folder and Message Lists, defect)

All
Windows XP
defect
Not set
critical

Tracking

(thunderbird3.1 .7-fixed)

RESOLVED FIXED
Tracking Status
thunderbird3.1 --- .7-fixed

People

(Reporter: eleve1, Assigned: Bienvenu)

References

Details

Attachments

(16 files)

20.52 KB, application/octet-stream
Details
33.45 KB, application/octet-stream
Details
106.96 KB, application/octet-stream
Details
2.00 KB, patch
neil
: review+
Details | Diff | Splinter Review
33.46 KB, application/octet-stream
Details
1.31 KB, patch
Details | Diff | Splinter Review
38.19 KB, application/octet-stream
Details
28.03 KB, application/octet-stream
Details
47.16 KB, application/octet-stream
Details
42.70 KB, application/octet-stream
Details
53.50 KB, application/octet-stream
Details
51.99 KB, application/octet-stream
Details
66.70 KB, application/octet-stream
Details
39.64 KB, application/octet-stream
Details
1.03 KB, patch
Details | Diff | Splinter Review
10.87 KB, patch
neil
: review+
Details | Diff | Splinter Review
User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.1; de; rv:1.9.2.10) Gecko/20100914 Firefox/3.6.10 ( .NET CLR 3.5.30729)
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.2.9) Gecko/20100915 Lightning/1.0b2 Thunderbird/3.1.4

When copying messages or folders to an imap folder the following message appears at the bottom of the window:
"Copying Message xx of yy to folder"
Thunderbird is never copying all the messages an is never coming to the end of the job, but stops by chance at any message (except if you copy only a few messages and it pass by chance)
It is the same result buy drag and drop or using the right click on the mouse.
After abandoning the job, it's impossible to copy the same job again, no reaction. You can copy the same files to any other directory but not twice in one directory, even after deleting messages or folder.
If you want to copy again you have to restart TB.

The problem persists under Windows XP and Windows 7.
Trying with an identical version under Linux, it seems that there is no problem

Windows Mail, Outlook Express are doing the job fine

Reproducible: Always

Steps to Reproduce:
1. copy messages to an imap folder from local folder oder other imap server
2. copying stops after a certain number of messages copied
3. impossible to copy some other messages to the same folder without restarting TB



The imap-server contacting is dovecot 1.0 and dovecot 2.0 (no special report in the logs)
I tried it also with uw-imapd - same result

I will classify the problem as critical because if you don't check that all messages are on the server before deleting local copy you will loose your messages.
The imap log doesn't show anything obviously wrong that I can see - your reproducible case happens with a particular local folder? Are you saying that this works with Thunderbird on linux, but not on Windows 7?

It looks to me like we're failing trying to get the next message to copy, and we're not handling that error, but it's not anything the imap protocol log is going to show. When doing a batch copy to an imap folder, the imap protocol code is responsible for chaining the next copy, which is why we don't go into idle for the imap connection doing the appends. But we never run an other imap append, so something must have gone wrong trying to get the next message to copy. So some information about the source of the copy would be helpful for me...
Ah, since we're not in the selected state on the target folder, we won't go into IDLE, so that's not evidence one way or the other about the problem. If you can reproduce this at will, it would be interesting if you could select the target folder in the UI before move/copying the messages to that folder, because we will try to use the connection that's selected on the target folder for the append, and a log will give me a little more info.
(In reply to comment #2)
> The imap log doesn't show anything obviously wrong that I can see - your
> reproducible case happens with a particular local folder? Are you saying that
> this works with Thunderbird on linux, but not on Windows 7?

The idea was to migrate my pop accounts on a local imap server and I will poll the messages with fetchmail for the different accounts. So any folder from a pop account stored localy has to be transfered to an imap account. 
Under Linux I can simply drag an drop any folder to the imap account without any problems, but under Windows XP or 7, the starting looks good but the job is not completed.

> 
> It looks to me like we're failing trying to get the next message to copy, and
> we're not handling that error, but it's not anything the imap protocol log is
> going to show. When doing a batch copy to an imap folder, the imap protocol
> code is responsible for chaining the next copy, which is why we don't go into
> idle for the imap connection doing the appends. But we never run an other imap
> append, so something must have gone wrong trying to get the next message to
> copy. So some information about the source of the copy would be helpful for
> me...
as I said a local folder, I can copy it from the pop-account to the local folders or copy it directly
but I can also copy a folder from one imap account to another, same or different server.
(In reply to comment #3)
> Ah, since we're not in the selected state on the target folder, we won't go
> into IDLE, so that's not evidence one way or the other about the problem. If
> you can reproduce this at will, it would be interesting if you could select the
> target folder in the UI before move/copying the messages to that folder,
> because we will try to use the connection that's selected on the target folder
> for the append, and a log will give me a little more info.
The only way I see in selecting the target folder is doing it just after starting the copy command and that didn't change anything.
How can I select the target folder before copying without loosing the selection of the messages I want to copy/move
(In reply to comment #5)

> How can I select the target folder before copying without loosing the selection
> of the messages I want to copy/move

I forgot that you were copying the whole folder, not just all the messages in it. So, what you could try is creating a new folder on the imap server, and then selecting it, then going back to the original source local folder, select all the messages in it, and do a drag drop of all the messages to the newly created imap folder, holding down the control key to make sure it does a copy and not a move. If that fails in the same way, a log would be interesting.
Claude, if this is a mailing list folder, would it be possible for you to just e-mail the file to me, and I can try it here?
(In reply to comment #6)
> (In reply to comment #5)
> 
> > How can I select the target folder before copying without loosing the selection
> > of the messages I want to copy/move
> 
> I forgot that you were copying the whole folder, not just all the messages in
> it. So, what you could try is creating a new folder on the imap server, and
> then selecting it, then going back to the original source local folder, select
> all the messages in it, and do a drag drop of all the messages to the newly
> created imap folder, holding down the control key to make sure it does a copy
> and not a move. If that fails in the same way, a log would be interesting.

even if I create a new folder, in the moment to select the messages in the other folder the target folder is deselected.
(In reply to comment #7)
> Claude, if this is a mailing list folder, would it be possible for you to just
> e-mail the file to me, and I can try it here?

is on the way
(In reply to comment #8)
> 
> even if I create a new folder, in the moment to select the messages in the
> other folder the target folder is deselected.

That's fine - selecting the target folder will cause us to cache a selected state connection on the imap server, which is what I wanted...

The folder you sent had 11048 messages, not 96. What's up with that?
(In reply to comment #10)
> (In reply to comment #8)
> > 
> > even if I create a new folder, in the moment to select the messages in the
> > other folder the target folder is deselected.
> 
> That's fine - selecting the target folder will cause us to cache a selected
> state connection on the imap server, which is what I wanted...
> 
> The folder you sent had 11048 messages, not 96. What's up with that?

this is a list folder I use, the other mail folder contains private or prof. mail. But I have the problem with any folder. My last try with this folder was 27 of 10943 an tb is in a state of waiting.  tomorrow I will send you a logging of tb while doing the job with the selected folder
OK, I started with that 11K message folder and got to 3000 of messages before I had to do some other stuff. I'll try it with a release build while I make supper.
One thing I see that seems very wrong is that some messages are moved to the junk folder when I'm doing the folder copy.
here is the tb logging by uploading the 11k message folder to the imap folder.
the folder has been created before starting the copying an has been reselected after the copying has been started.
the result was disappointing 18 messages have been copied
It looks like you have mail.check_all_imap_folders_for_new set to true, or you are clicking the target folder while the copy is going on, because we're doing a NOOP on the suse-linux folder. If you do have that hidden pref set to true, can you try toggling it to false using the config editor and repeat the test?
Oh, and can you add timestamps to the log, using the timestamp log module?
ok, reselecting the folder was my fault!
mail.check_all_imap_folders_for_new was all the time set to false
this time 107 messages were copied, at 17:25 the copy process stopped without any message an 5 minutes later I closed tb
This adds a bit of logging to give us a chance of seeing what the error might be...I'll try to generate a try server build and if it succeeds, I'll give you a link to it.
Assignee: nobody → bienvenu
Status: UNCONFIRMED → NEW
Ever confirmed: true
Comment on attachment 481622 [details] [diff] [review]
log copy errors, and handle error so dest folder isn't locked.

this patch also notifies the copy service that the copy failed, which should prevent the destination folder (or parent folder) from getting locked. I hope that the error code logged gives me a better idea what in particular is failing about the copy.
mac build already failed; I rather doubt the other ones will succeed. I've been pushing to try with a comm 1.9.2 hg tree, and I've never actually had a build succeed, so I must be doing something wrong.
gozer, standard8, any idea why my try server builds all fail? I'm about 0-20 in try server builds, so obviously I'm doing something wrong - here's a linux log - http://stage.mozilla.org/pub/mozilla.org/thunderbird/tryserver-builds/bienvenu@nventure.com-4f872ea49f2f/tryserver-linux/tryserver-linux-build98.txt.gz
Comment on attachment 481622 [details] [diff] [review]
log copy errors, and handle error so dest folder isn't locked.

I have no idea what's failing, but I think this should improve things.
Attachment #481622 - Flags: review?(neil)
And an installer build here - http://stage.mozilla.org/pub/mozilla.org/thunderbird/tryserver-builds/bienvenu@nventure.com-aee7bfba7d77/tryserver-win32/thunderbird-3.3a1pre.en-US.win32.installer.exe

If you want to try it, you could do a custom install, and install into a separate directory, so you can go back to 3.1.4/5 once you've generated a log with this try build
no improvement.
hope the log will help
Comment on attachment 481622 [details] [diff] [review]
log copy errors, and handle error so dest folder isn't locked.

>+    rv = imapMailFolderSink->CopyNextStreamMessage(GetServerStateParser().LastCommandSuccessful() &&
>                                               NS_SUCCEEDED(GetConnectionStatus()),
>                                               copyState);
Nit: ought to reindent the continuation lines.
Attachment #481622 - Flags: review?(neil) → review+
(In reply to comment #26)
> Created attachment 481780 [details]
> looging of tb - version 3.3a1pre
> 
> no improvement.
> hope the log will help

Thx, it helps in the sense that it tells me the problem must occur downstream of the code I fixed, most likely in the code that streams the local msg into a temp file before appending it to the imap server. I'll try to come up with a try server build today for you to try that diagnoses the problem.

Are you sharing a profile between Linux and Windows with a shared file system, by any chance?
Comment on attachment 481622 [details] [diff] [review]
log copy errors, and handle error so dest folder isn't locked.

checked in with nit addressed.
Attachment #481622 - Attachment description: log copy errors, and handle error so dest folder isn't locked. → log copy errors, and handle error so dest folder isn't locked. - checked in.
I've generated a try server build with this patch, which should log errors trying to stream the source message - try server seems to be a bit hung at the moment but I'll let you know if a win32 build gets generated.
win32 try server build failed;  I'll try one more time...
(In reply to comment #28)
> (In reply to comment #26)
> > Created attachment 481780 [details] [details]
> > looging of tb - version 3.3a1pre
> > 
> > no improvement.
> > hope the log will help
> 
> Thx, it helps in the sense that it tells me the problem must occur downstream
> of the code I fixed, most likely in the code that streams the local msg into a
> temp file before appending it to the imap server. I'll try to come up with a
> try server build today for you to try that diagnoses the problem.
> 
> Are you sharing a profile between Linux and Windows with a shared file system,
> by any chance?

I'm not sharing a profile, but I can copy it to linux host
shall I also do a report from linux?
Comment on attachment 481622 [details] [diff] [review]
log copy errors, and handle error so dest folder isn't locked.

I've currently backed this out due to the gloda tests failing on Mac. I'm not 100% confident that it was this that broke them, but this was the closest thing that looked likely.
Attachment #481622 - Attachment description: log copy errors, and handle error so dest folder isn't locked. - checked in. → log copy errors, and handle error so dest folder isn't locked.
(In reply to comment #34)
> Comment on attachment 481622 [details] [diff] [review]
> log copy errors, and handle error so dest folder isn't locked.
> 
> I've currently backed this out due to the gloda tests failing on Mac. I'm not
> 100% confident that it was this that broke them, but this was the closest thing
> that looked likely.

If this broke a test, the test was already failing, since it only changes the failure case.
oddly, that log shows a failure in the first part of the process, which is the failure my first patch was meant to log - 080004003 is NS_ERROR_INVALID_POINTER. Either you're getting multiple failures, or that first log you generated wasn't with the try server build.
redoing the logs

uninstalled shredder and reinstalled the version from 2010-10-07 20:22:11
uninstalled shredder
installed version from 2010-10-08 18:38:44

difference I see: the message copying message xx from xx messages disappears immediately, on the verion before tb stays with the message until you select another folder
just for info, if it helps.
logging under linux ftp://ftp.ltc.lu/pub/mozilla/imap.rar
Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.1.11) Gecko/20100714 SUSE/3.0.6 Thunderbird/3.0.6

copying the hole folder on remote imap folder
I've requested a try server build with a bit more logging about where exactly we're failing. Unfortunately, the 08x80004003 is pretty generic. I'll let you know when the win32 build finishes.
I've requested several try server builds but none have succeeded. I'll keep trying and let you know when one works.
Claude - tryserver for win32 seems to be broken - I'll try to generate my own win32 installer build with extra logging and e-mail it to you.
I sent Claude a zipped release build with extra logging Tuesday afternoon.
the first try of copy was very fast and stopped at about 150 messages.
activating the logging the copying stopped at 32 messages.

I want to mention one difference between linux & win: I'm not able to do the exactly the same procedure under linux, because it's impossible to select all the messages (10.000) in a folder an drag them to the destination folder. Here I can only do it with the menu on the right click.
I tried it under win with the copy menu, but no success: only 17 messages.
Unfortunately, that log didn't have any of the logging statements I added, which is surprising because the previous one did. If you do a help | about Shredder, does it have this verion info - Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0b8pre) Gecko/20101012 Thunderbird/3.3a1pre ? I'm interested in a log that has "failed" in it, because the logging I added all uses "failed" in the log string.

You don't have to do the select all messages and copy method anymore - you can drag the whole folder.

If you do a folder properties, click repair, on the source folder, before you do the drag, does it fix the issue?
I was to quick and uninstalled shredder before I saw that your upload was a zip-file. The I executed shredder from the unzipped folder.

Now I reinstalled an earlier version and unzipped the new version over the installed.
This is the version info: 
Mozilla/5.0 (Windows NT 6.1; rv:2.0b8pre) Gecko/20101012 Thunderbird/3.3a1pre
(In reply to comment #46)

> 
> If you do a folder properties, click repair, on the source folder, before you
> do the drag, does it fix the issue?

Before draging the folder I did a repair folder! The copying stopped after 50 messages.
Claude, thx for the new log. I'm going to generate a new build with some more logging, but in the meantime, can you try turning off imap autosync (tools, options, general, advanced tab, click config editor button, type autosync, and toggle mail.server.default.autosync_offline_stores to false), restart TB, and repeat the test?
mail.server.default.autosync_offline_stores still set to false as this didn't fix the issue
witch ImapAutoSync:5
and moving the mouse around during the copy process
It turns out that the failure is in nsImapMailFolder::BeginCopy

  // create a unique file, since multiple copies may be open on multiple folders
  rv = m_copyState->m_tmpFile->CreateUnique(nsIFile::NORMAL_FILE_TYPE, 00600);

This is failing with NS_ERROR_FILE_ACCESS_DENIED, which is a bit surprising since CreateUnique is supposed to handle that, and we tried to remove the tmp file a few lines above. But looking at nsLocalFileWin::Create, it only returns NS_ERROR_FILE_ALREADY_EXISTS in the case of a directory, so if the file is locked, I think this code would fail.
This fixes the issue - the temp file was getting locked by a virus scanner, which breaks CreateUnique. I'll try to figure out who can review this.
Comment on attachment 483904 [details] [diff] [review]
fix for underlying issue

We're getting a virus checker causing the same file_access_denied error on a file. It feels to me like the better fix would be to check for FILE_ACCESS_DENIED in the caller (CreateUnique), but the prev fix in this code checked here as well. Thoughts?
Attachment #483904 - Flags: review?(neil)
Won't this regress bug 402460?
(In reply to comment #56)
> Won't this regress bug 402460?

hmm, yeah, it sounds like any simple fix for this will regress that, unless we can explicitly check for a write-protected directory in some way other than getting a FILE_ACCESS_DENIED when trying to create a file.
looks like we can't tell if a directory is read-only or not on FAT

http://mxr.mozilla.org/comm-central/source/mozilla/xpcom/io/nsLocalFileWin.cpp#2298

which means there's probably not an easy way to fix this. 

A couple of less than perfect options:

1. Change CreateUnique to have a much smaller number of retries (e.g., 10 instead of 1000) when it gets FILE_ACCESS_DENIED, and change nsLocalFileWin to return FILE_ACCESS_DENIED instead of converting it to FILE_EXISTS.

2. Change the imap code to do its own unique file name generation when CreateUnique fails. 

Thoughts?

It's highly annoying that virus checkers are breaking CreateUnique. We know in this case that it's the temp dir, so we're fairly confident it's not write-only.
Attached patch alternative fixSplinter Review
This handles the failure of CreateUnique by falling back on using the message key to make the file name unique.

Are we allowed to use nsPrintfCString?
Attachment #484690 - Flags: review?(neil)
(In reply to comment #59)
> Are we allowed to use nsPrintfCString?
It's not available in experimental xulrunner builds. Also I think you have to tell it the expected maximum length of the string (it doesn't reallocate, and the default is only 15). It might be easier to use AppendInt instead.
Is the fact that we're reusing the same temp file name over and over again exacerbating the problem?
(In reply to comment #61)
> Is the fact that we're reusing the same temp file name over and over again
> exacerbating the problem?

Yes, exactly. That's what this patch falls back to not doing. Along with a lot of logging and error handling, which I think I'd like to leave in, since there are multiple reports of errors like this.
(In reply to comment #62)
> (In reply to comment #61)
> > Is the fact that we're reusing the same temp file name over and over again
> > exacerbating the problem?
> Yes, exactly. That's what this patch falls back to not doing.
I'm just wondering whether it's worth keeping the static temp file name?
(In reply to comment #63)
> I'm just wondering whether it's worth keeping the static temp file name?

Yes, I suppose the code would be marginally cleaner without the static temp file name and the fallback. A couple reasons to leave it in - a protocol log would show that a virus checker was likely interfering with our file i/o, and if there was unrelated temp-file leakage, the names in the temp directory would appear less random.
Comment on attachment 484690 [details] [diff] [review]
alternative fix

> extern PRLogModuleInfo *gAutoSyncLog;
...
>+extern PRLogModuleInfo* IMAP;
Nit: I'd prefer to keep the log modules together.

>+    nsMsgKey msgKey;
Nit: declare msgKey where you use it.

>+      nsCString tmpFileName;
>+      message->GetMessageKey(&msgKey);
>+      tmpFileName.Append(nsPrintfCString("nscpmsg-%ld.txt", msgKey));
Incorrect nsPrintfCString usage. You can either write
nsPrintfCString tmpFileName(23, "nscpmsg-%ld.txt", msgKey);
(because you need a longer buffer than the default length of 15)
or build up the string using Append and AppendInt. r=me with that fixed.
Attachment #484690 - Flags: review?(neil) → review+
Attachment #483904 - Flags: review?(neil)
fixed on trunk with comments addressed.
Status: NEW → RESOLVED
Closed: 14 years ago
Resolution: --- → FIXED
Comment on attachment 481622 [details] [diff] [review]
log copy errors, and handle error so dest folder isn't locked.

I'd like this for 3.1.7 as well, though that flag hasn't been created yet.
Attachment #481622 - Flags: approval-thunderbird3.2a1?
Comment on attachment 484690 [details] [diff] [review]
alternative fix

I'd like this for 3.1.7 as well, though that flag hasn't been created yet.
Attachment #484690 - Flags: approval-thunderbird3.2a1?
Attachment #481622 - Flags: approval-thunderbird3.1.7?
Attachment #484690 - Flags: approval-thunderbird3.1.7?
Attachment #481622 - Flags: approval-thunderbird3.2a1?
Attachment #481622 - Flags: approval-thunderbird3.1.7?
Attachment #481622 - Flags: approval-thunderbird3.1.7+
Attachment #484690 - Flags: approval-thunderbird3.2a1?
Attachment #484690 - Flags: approval-thunderbird3.1.7?
Attachment #484690 - Flags: approval-thunderbird3.1.7+
Is it really fixed? I mean, there was more than one bug here:

- as far as I can see, errors happened, but were never reported to the user
- the messages that actually were sucessfully copied were never deleted in the source folder (very annoying if you're moving messages!)
- thunderbird refused to execute further copy/move jobs

Has all that been fixed?
(In reply to comment #71)
> Is it really fixed? I mean, there was more than one bug here:
> 
> - as far as I can see, errors happened, but were never reported to the user
> - the messages that actually were sucessfully copied were never deleted in the
> source folder (very annoying if you're moving messages!)
> - thunderbird refused to execute further copy/move jobs
> 
> Has all that been fixed?

Sven, If you still see a problem in trunk builds that doesn't have a bug report, please file a new bug
Summary: copy messages to imap folder stops without any message - copy to no reaction → copy messages to imap folder stops without any error message - copy to no reaction - due to insufficient return checks

Reporter Claude, Did this fix the problem you reported? Also, was it only on windows and due to a virus checker? Others still report similar problems but not sure if on Windows only. Hoping you're still listening. Thanks.
Note: Reporter's account is disabled so can't request info. Possibly others CC'd on this bug can answer the question. The reporter was quite involved submitting logs and testing patches and then there was no response or verification from him after Bienvenu determined that the cause was virus checker and produced a fix starting at comment 54.

Actually, the problem described in comment 0 above still exists. I see it when copying from imap server A to imap server B and the connection to server A is closed during an ongoing fetch by server A: see bug 538375 comment 100.
In that case the problem has no relation to unable to create a temp file due to virus checkers as is fixed by the patch for this bug.

See Also: → 538375
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: