547783 - Subscribed folders that don't exist could be handled better, so we don't get "Command not successful. The mail server replied: Mailbox does not exist, or must be subscribed to."

Status: NEW

(MailNews Core :: Networking: IMAP, defect)

Description

[Jens Müller (:tessarakt)]

User-Agent:       Mozilla/5.0 (X11; U; Linux i686 (x86_64); de; rv:1.9.2) Gecko/20100115 Firefox/3.1b4pre
Build Identifier: Mozilla/5.0 (X11; U; Linux i686 (x86_64); de; rv:1.9.1.7) Gecko/20100111 Lightning/1.0b2pre Thunderbird/3.0.1

I have some messages like the following in my activity manager:

* "Command not successful. The mail server replied: Mailbox does not exist, or must be subscribed to."

* "Command not successful. The mail server replied: Mailbox doesn't exist: Trash.[...]."

I translated the string "Command not successful. The mail server replied:" back into English from de_DE, so it's not the exact string.

The message does not give any hint what went wrong here, and if it should concern me.

It does not indicate what TB tried to do when it hit the error message from the server. I suppose it is at startup when it synchronises the folders with an IMAP account. It's listed under an IMAP account (btw, it's not really visible to which account a message belongs). I also suppose TB is creating a lot of these problems itself by bad synchronisation.

Reproducible: Sometimes

Steps to Reproduce:
I think it happens at startup.

Comment 1

[Ludovic Hirlimann [:Usul]]

Jens, is this happening often ?

Comment 2

[Jens Müller (:tessarakt)]

Yes, I currently have it on this computer with two messages:

* "Command not successful. The mail server replied: Mailbox does not exist, or
must be subscribed to."

* "Command not successful. The mail server replied: Mailbox doesn't exist:
Trash.[...]."


It's a different computer than yesterday, but the same account.

The messages get repeated about every 12 to 15 minutes, I don't know which pattern that follows.

Comment 3

[Ludovic Hirlimann [:Usul]]

Can you provide imap:5 and ImapAutoSync logs ? so we can correlate what's in those logs with the error message that you get in your Activity manager ?

Comment 4

[Nathan Bailey]

Using the information from https://wiki.mozilla.org/MailNews:Logging, I created tbird.bat:
set NSPR_LOG_MODULES=imap:5,ImapAutoSync
set NSPR_LOG_FILE=C:\Users\nate\imap.log
"C:\Program Files\Mozilla Thunderbird\thunderbird.exe"

And I have lots of messages like:
4528[89e2040]: 89f1c00:mail.monash.edu.au:A:ProcessCurrentURL: entering
4528[89e2040]: 89f1c00:mail.monash.edu.au:A:ProcessCurrentURL:imap://[e-mail]:993/folderstatus%3E/%40Inbox/Not%20inbox/%40Monash:  = currentUrl
4528[89e2040]: 89f1c00:mail.monash.edu.au:A:SendData: 11 STATUS "@Inbox/Not inbox/@Monash" (UIDNEXT MESSAGES UNSEEN RECENT)^M
4528[89e2040]: ReadNextLine [stream=8cb3b08 nb=30 needmore=0]
4528[89e2040]: 89f1c00:mail.monash.edu.au:A:CreateNewLineFromSocket: 11 NO Mailbox does not exist^M

which I presume is what results in 'The current command did not succeed. The mail server responded:Mailbox does not exist'

It's right - that folder doesn't exist any more, but if I go to the account, click on subscribe and click 'Refresh', the folder still appears in my list.

Two comments from me:
1. Why doesn't the error message report *which* folder doesn't exist? (cf. an end user having to do the above debug?), ie. can the error message be changed to "The current command did not succeed. The mail server responded: 'Mailbox does not exist' for mailbox '@Inbox/Not inbox/@Monash'"
2. Why doesn't refresh reflect the current reality of my folder hierarchy? [ Sorry if this is a separate bug, but presumably if this was sync'd, the above bug wouldn't happen? ]

Comment 5

[Nathan Bailey]

Oops, I see that Jens is getting error messages exactly like that; I'm running Thunderbird v3.0.1, I'll try with the latest version and see if both the above are still true. If it doesn't fix the 'refresh' part, I'll hand update my subscriptions and see if I still get any of the above errors. (FWIW, I also get modal dialogs with a similar message that require clicking 'OK' (or pressing Esc). Having 20+ of those is quite annoying - especially without the folder detail => information to fix the problem - which I have now, with the tbird.bat logfile)

Comment 6

[Jens Müller (:tessarakt)]

Now (Lanikai nightly) these error messages come as notifications (however this UI element is called), even when TB is in background. I have no opinion yet about what is more annoying ...

Anyway, the underlying bug, which is that deleted folders on the IMAP side are apparently not synced correctly, needs to be fixed, not the error message hidden somewhere where no one notices it ...

Comment 7

[Ludovic Hirlimann [:Usul]]

(In reply to comment #4)
> Using the information from https://wiki.mozilla.org/MailNews:Logging, I created
> tbird.bat:
> set NSPR_LOG_MODULES=imap:5,ImapAutoSync
> set NSPR_LOG_FILE=C:\Users\nate\imap.log
> "C:\Program Files\Mozilla Thunderbird\thunderbird.exe"

> 2. Why doesn't refresh reflect the current reality of my folder hierarchy? [
> Sorry if this is a separate bug, but presumably if this was sync'd, the above
> bug wouldn't happen? ]

can we have a bit more log context please ?

Comment 8

[Wayne Mery (:wsmwk)]

Jens, can you supply a log?

Nathan,
> can we have a bit more log context please ?

Comment 9

[Jens Müller (:tessarakt)]

As it is very time-consuming to anonymize those logs: No, not at the moment.

But it would first be nice to have a better indication in the activitymgr about what (which "command") TB tried when it hit the error message from the server ...

Maybe Nathan has more context?

Comment 10

[Jens Müller (:tessarakt)]

From the log:

6008[467d100]: ImapThreadMainLoop entering [this=4717800]
0[202c140]: 4717800:mail.beckendorf.de:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
6008[467d100]: 4717800:mail.beckendorf.de:NA:ProcessCurrentURL: entering
6008[467d100]: 4717800:mail.beckendorf.de:NA:ProcessCurrentURL:imap://[e-mail]:143/select%3E.Trash.Listen.Politik%26-Recht.ak-vds-diskussion:  = currentUrl
6008[467d100]: ReadNextLine [stream=aede4c8 nb=21 needmore=0]
6008[467d100]: 4717800:mail.beckendorf.de:NA:CreateNewLineFromSocket: * OK dovecot ready.




and later:

6008[467d100]: login succeeded
6008[467d100]: 4717800:mail.beckendorf.de:A:SendData: 5 select "Trash.Listen.Politik&-Recht.ak-vds-diskussion"

6008[467d100]: ReadNextLine [stream=aede4c8 nb=75 needmore=0]
6008[467d100]: 4717800:mail.beckendorf.de:A:CreateNewLineFromSocket: 5 NO Mailbox doesn't exist: Trash.Listen.Politik&-Recht.ak-vds-diskussion

6008[467d100]: 4717800:mail.beckendorf.de:A:ProcessCurrentURL: entering
6008[467d100]: 4717800:mail.beckendorf.de:A:ProcessCurrentURL:imap://[e-mail]:143/delete%3E.Trash.Listen:  = currentUrl
6008[467d100]: 4717800:mail.beckendorf.de:A:SendData: 6 list "" "Trash.Listen.*"

6008[467d100]: ReadNextLine [stream=aede4c8 nb=22 needmore=0]
6008[467d100]: 4717800:mail.beckendorf.de:A:CreateNewLineFromSocket: 6 OK List completed.

6008[467d100]: 4717800:mail.beckendorf.de:A:SendData: 7 unsubscribe "Trash.Listen"

6008[467d100]: ReadNextLine [stream=aede4c8 nb=29 needmore=0]
6008[467d100]: 4717800:mail.beckendorf.de:A:CreateNewLineFromSocket: 7 OK Unsubscribe completed.

2728[467bd00]: 3823800:mail.beckendorf.de:S-Trash:SendData: DONE



Now the problem is solved for me, because the folder is gone.

I guess the & irritated TB or the IMAP server. N.B. that it is first encoded and then not!

Comment 11

[Jens Müller (:tessarakt)]

OK, on another account:

2516[7640b40]: ReadNextLine [stream=6d4e9c8 nb=46 needmore=0]
2516[7640b40]: a434800:imap.ira.uka.de:A:CreateNewLineFromSocket: * LSUB (\HasNoChildren) "." "INBOX.Trash.D3"

....


4400[6093400]: 3d70800:imap.ira.uka.de:S-INBOX.TAS3.TAS3WP01:ProcessCurrentURL: entering
4400[6093400]: 3d70800:imap.ira.uka.de:S-INBOX.TAS3.TAS3WP01:ProcessCurrentURL:imap://[e-mail]:993/select%3E.INBOX.Trash.D3:  = currentUrl
4400[6093400]: 3d70800:imap.ira.uka.de:S-INBOX.TAS3.TAS3WP01:SendData: 188 select "INBOX.Trash.D3"

4400[6093400]: ReadNextLine [stream=5faa0c8 nb=58 needmore=0]
4400[6093400]: 3d70800:imap.ira.uka.de:S-INBOX.Trash.D3:CreateNewLineFromSocket: 188 NO Mailbox does not exist, or must be subscribed to.

4400[6093400]: 3d70800:imap.ira.uka.de:A:SendData: 189 myrights "INBOX.Trash.D3"

4400[6093400]: ReadNextLine [stream=5faa0c8 nb=58 needmore=0]
4400[6093400]: 3d70800:imap.ira.uka.de:A:CreateNewLineFromSocket: 189 NO Mailbox does not exist, or must be subscribed to.

4400[6093400]: 3d70800:imap.ira.uka.de:A:ProcessCurrentURL: entering
4400[6093400]: 3d70800:imap.ira.uka.de:A:ProcessCurrentURL:imap://[e-mail]:993/delete%3E.INBOX.Trash.D3:  = currentUrl
4400[6093400]: 3d70800:imap.ira.uka.de:A:SendData: 190 list "" "INBOX.Trash.D3.*"

4400[6093400]: ReadNextLine [stream=5faa0c8 nb=23 needmore=0]
4400[6093400]: 3d70800:imap.ira.uka.de:A:CreateNewLineFromSocket: 190 OK LIST completed

4400[6093400]: 3d70800:imap.ira.uka.de:A:SendData: 191 delete "INBOX.Trash.D3"

4400[6093400]: ReadNextLine [stream=5faa0c8 nb=58 needmore=0]
4400[6093400]: 3d70800:imap.ira.uka.de:A:CreateNewLineFromSocket: 191 NO Mailbox does not exist, or must be subscribed to.

Comment 12

[Jens Müller (:tessarakt)]

> Now the problem is solved for me, because the folder is gone.
> 

Hmm, unfortunately not, at least for the other folder. I have to do logs again to find out which folder is causing this now ...

Comment 13

[Jens Müller (:tessarakt)]

(In reply to comment #4)
> Two comments from me:
> 1. Why doesn't the error message report *which* folder doesn't exist? (cf. an
> end user having to do the above debug?), ie. can the error message be changed
> to "The current command did not succeed. The mail server responded: 'Mailbox
> does not exist' for mailbox '@Inbox/Not inbox/@Monash'"

That does not sound doable. TB does not know what the string sent by the server means. But yes, it should say _which_ command was not successful.

> 2. Why doesn't refresh reflect the current reality of my folder hierarchy? [
> Sorry if this is a separate bug, but presumably if this was sync'd, the above
> bug wouldn't happen? ]

That's probably the underlying problem ...

P.S.: My logs above come from Mozilla/5.0 (Windows; U; Windows NT 6.1; de; rv:1.9.2.5pre) Gecko/20100511 Lightning/1.0b2pre Lanikai/3.1pre (well, one or two nighlies before, but the bug is still occuring today).

Comment 14

[Jens Müller (:tessarakt)]

Damn, even Squirrelmail webmail gets confused: The folder is shown but I cannot access it:

FEHLER:
FEHLER : Aktion konnte nicht ausgeführt werden.
Anfrage: SELECT "Trash.Listen.Politik&-Recht.ak-vds-diskussion"
Grund: Mailbox doesn't exist: Trash.Listen.Politik&-Recht.ak-vds-diskussion

Comment 15

[WADA:World Anti-bad-Duping Agency]

(In reply to comment #11)
> * LSUB (\HasNoChildren) "." "INBOX.Trash.D3"
> 188 select "INBOX.Trash.D3"
> 188 NO Mailbox does not exist, or must be subscribed to.

This situation is:
  INBOX.Trash.D3 is still subscribed, but somehow INBOX.Trash.D3 doesn't exist.
You can produce this situation by;
 1. Create INBOX.Trash.D3, subscribe INBOX.Trash.D3
 2. Delete folder of INBOX.Trash.D3 by other than IMAP client who doesn't
    request unsubscribe of INBOX.Trash.D3.
Other possible case.
 1. IMAP client request to create INBOX.Trash.D3.
    If Tb, IMAP delete model=Move to Trash, and if trash folder="Trash",
    and if namespace="INBOX.", Tb requests rename of INBOX.D3 to INBOX.Trash.D3
    when you requestd to delete D3.
    Server returns OK.
 2. IMAP client requests subscribe INBOX.Trash.D3, and server returns OK
 3. However, rename of Inbox.D3 to INBOX.Trash.D3 somehow fails at server
    or it's incomplete at server.
    For IMAP server, both Inbox.D3 and INBOX.Trash.D3 doesn't exist.
    Accessing to INBOX.D3 at Web may interface "rename Inbox.D3 INBOX.Trash.D3"

By the way, please don't paste long log data. Save in text file and attach to this bug via "Add an attachment" link of this bug if relatively long, please.

Comment 16

[Wayne Mery (:wsmwk)]

so what do we need to add to the summary?
and is this bug confirmed (we are bad), or invalid ("they" are bad)?

Comment 17

[David :Bienvenu]

(In reply to comment #16)
> so what do we need to add to the summary?
> and is this bug confirmed (we are bad), or invalid ("they" are bad)?

It's perfectly legal to have a subscribed folder that doesn't exist, unfortunately. It's also possible that other clients may delete folders without unsubscribing you from them. It would be great to handle this better, but it's not a high priority since the user should be able to use the subscribe UI to unsubscribe.

Comment 18

[Ludovic Hirlimann [:Usul]]

Removing myslef on all the bugs I'm cced on. Please NI me if you need something on MailNews Core bugs from me.