search

ProtonMail / proton-bridge

Proton Mail Bridge application
GNU General Public License v3.0
1.16k stars 157 forks source link

NO UID EXPUNGE - Possible violation of RFC3501 and 2119 #123

Closed mvcisback closed 3 years ago

mvcisback commented 3 years ago

When moving folders, protonmail bridge refuses UID EXPUNGE.

Suspected violation of RFC3501 and 2119.

Expected Behavior

UID EXPUNGE should work or not be advertised as working.

Current Behavior

Querying bridge yields the following extensions:

IMAP4rev1 UNSELECT SASL-IR UIDPLUS MOVE SPECIAL-USE IMPORTANT LITERAL+ ID QUOTA IDLE "APPENDLIMIT=26214400"

However, when moving a message, UID EXPUNGE does not work.

Steps to Reproduce

  1. Setup protonmail bridge with geary mail
  2. Move any email to another folder.
  3. Check logs for NO UID EXPUNGE

Context (Environment)

Using Geary Mail

mvcisback commented 3 years ago

Looking at the change logs, I believe this may have been introduced in v1.4.5 which explicitly lists "bulletproofing" against data loss and fixing a bug regarding moving from the spam folder.

dkabus commented 3 years ago

I believe I am experiencing something related to this bug. (see issue #61 ) When I am moving a mail to another folder, its the UID changes.

elshize commented 3 years ago

I'm having a similar issue when using Geary.

pera commented 3 years ago

I am experiencing the same issue with Evolution.

hmsta commented 3 years ago

I get the same error when I try to delete an email with em client or empty trash.

andrzejsza commented 3 years ago

@mipak which client are you using?

hmsta commented 3 years ago

@andrzejsza http://emclient.com

ehrlichja commented 3 years ago

I have this problem using neomutt and isync

jameshoulahan commented 3 years ago

Bridge claims support for the UIDPLUS extension. This extension defines the UID EXPUNGE command, which we unfortunately reject.

That sucks -- we shouldn't claim to support an extension and yet not implement all parts of the extension. I've opened an internal issue to sort it out (ref GODT-972).

jaor commented 3 years ago

Seems to be not oly EXPUNGE, i also get:

                  Server supports UIDPLUS but got no APPENDUID appending a message. Got: None.

when /copying/ emails.

cpfiffer commented 3 years ago

I have this issue for Geary.

andrzejsza commented 3 years ago

could you guys try this early beta build (with added support of UID EXPUNGE with UID)? it's not that stable just yet, but just wanted to check if it will help with your issues.

mac https://protonmail.com/download/bridge/Bridge-Installer.dmg win https://protonmail.com/download/bridge/Bridge-Installer.exe DEB: https://protonmail.com/download/bridge/protonmail-bridge_1.6.2-1_amd64.deb RPM: https://protonmail.com/download/bridge/protonmail-bridge-1.6.2-1.x86_64.rpm PKGBUILD: https://protonmail.com/download/bridge/PKGBUILD

elshize commented 3 years ago

Just installed the PKGBUILD, and so far so good!

dkabus commented 3 years ago

This beta build of 1.6.2 does not seem to solve my issue. I have re-initialised my local maildirs to test it: Moving a mail to another folder still changes its UID for me. Therefore, mbsync still complains that it "lost track of 1 pushed message(s)". The full diff of the moved mail before and after syncing with bridge is:

43c43
< X-TUID: tHZfR3y6psB0
---
> X-TUID: DNZneZY02WS7

i.e. the UID still changes.

jaor commented 3 years ago

i've tried in debian unstable with offlineimap3, but moving accross labels behaves as before. when i move a message from label A to B, the next sync command always times out, with:

ERROR: Failed to start TLS connection: command: CAPABILITY => no response after 30.0 secs

and, when i sync again i get:

Copy message UID -1 (1/1) maildir:B -> protonbridge:Labels/B
Server supports UIDPLUS but got no APPENDUID appending a message. Got: None.

hope this helps, and thanks for working on this!

cpfiffer commented 3 years ago

The 1.6.2 version works for me.

jaor commented 3 years ago

The 1.6.2 version works for me.

what are you using to talk to protonbridge? maybe this only happens with mbsync/offlineimap?

elshize commented 3 years ago

FYI, I'm using Geary, and I don't get any errors or warnings anymore, but I didn't test any deeper than that.

hmsta commented 3 years ago

UID EXPUNGE works for me now perfectly with emclient. thanks for the fix.

I guess APPENDUID discussed above is a different missing command from UIDPLUS - which I can't test/use.

andrzejsza commented 3 years ago

glad to hear this works as expected. yes, APPENDUID is definitely a separate issue. I'll close this one once the version in testing is live and will consider APPENDUID separately.

cpfiffer commented 3 years ago

Thanks, @andrzejsza!

mvcisback commented 3 years ago

Works for me :)

cuthix commented 3 years ago

i've tried in debian unstable with offlineimap3, but moving accross labels behaves as before. when i move a message from label A to B, the next sync command always times out, with: ERROR: Failed to start TLS connection: command: CAPABILITY => no response after 30.0 secs and, when i sync again i get: Copy message UID -1 (1/1) maildir:B -> protonbridge:Labels/B Server supports UIDPLUS but got no APPENDUID appending a message. Got: None. hope this helps, and thanks for working on this!

jaor commented 3 years ago

On Wed, Feb 17 2021, cuthix wrote:

i've tried in debian unstable with offlineimap3, but moving accross labels behaves as before. when i move
a message from label A to B, the next sync command always times out, with: ERROR: Failed to start TLS
connection: command: CAPABILITY => no response after 30.0 secs and, when i sync again i get: Copy message
UID -1 (1/1) maildir:B -> protonbridge:Labels/B Server supports UIDPLUS but got no APPENDUID appending a
message. Got: None. hope this helps, and thanks for working on this!

• TLS is not supported. You can use plaintext or STARTTLS. The cert is self singed so you probably need to add it allow-list

I am using plaintext. The same SMTP requests that give that timeout after having moved a message, work fine otherwise most of the time. So it's probably just offlineimap giving a misleading error message when it encounters a timeout talking to the bridge. The root problem seems to be that sometimes there's no response, or that offlineimap thinks so, and it could possibly be a bug in offlineimap too.

• I believe we support APPENDUID and COPYUID can you pick up exact IMAP requests so we can try to reproduce on our side?

Yes, i'll try to get those traces (have to check how to do it). I think the same problem also appears with mbsync, maybe there it's possible to get traces too.

I'll follow up when i have something... Thanks!

andrzejsza commented 3 years ago

cool. I'll close this issues as the main problem here is fixed. @jaor best to follow up with bridge@protonmail.ch or if you have some findings just open a new issue.

jaor commented 3 years ago

this is what happens, at the imap level, when i move an email from a folder Folders/mdk to another called Folders/hacking (i've just edited the contents of the email, which is short): the append operation seems to be progressing well, but at the very end the client issues a set that has no response (sorry if i'm saying something silly, i don't know much about the protocol), and the transaction isn't finished.

(there are more traces, including the onw that shows the message being copied, successfully, to its destination).

Syncing messages Maildir[hacking] -> IMAP[Folders/hacking]
Copy message UID -1 (1/1) maildir_pmfolders:hacking -> proton_folders:Folders/hacking
[imap]: Write mail 'Folders/hacking:-1' with flags {'S'}
[]: deletemessageheaders: called to delete []
[]: getmessageheader: called to get message-id
[]: getmessageheader: eoh = 3490
[]: getmessageheader: headers = '<<<<MESSAGE HEADERS: EDITED: they look fine>>>'
[imap]: savemessage: date: "18-Jan-2021 02:30:22 +0000", content: 'Authentication-Results: mailin012.protonmail.ch; dmarc=pass (p=none dis=none) header.from=gnu.org

Authentication-Results: mailin012.protonmail.ch; sp...ll-of-Famer (https://internethalloffame.org)

'
[imap]:   07:43.70 Account sync proton [sync] SELECT ('"Folders/hacking"',)
[imap]:   07:43.70 Account sync proton state_change_pending.acquire
[imap]:   07:43.70 Account sync proton _request_push(b'GKPO13', SELECT, {}) = b'GKPO13'
[imap]:   07:43.70 Account sync proton data=b'GKPO13 SELECT "Folders/hacking"'
[imap]:   07:43.70 Account sync proton SELECT:b'GKPO13'.ready.wait
[imap]:   07:43.70 localhost writer > b'GKPO13 SELECT "Folders/hacking"\r\n'
[imap]:   07:43.71 localhost reader poll => [(4, 1)]
[imap]:   07:43.71 localhost reader rcvd 92
[imap]:   07:43.71 localhost reader < b'* FLAGS (\\Seen \\SEEN \\Flagged \\FLAGGED \\Deleted \\DELETED \\Draft \\DRAFT $junk junk nonjunk)\r\n'
[imap]:   07:43.71 localhost handler _put_response(b'* FLAGS (\\Seen \\SEEN \\Flagged \\FLAGGED \\Deleted \\DELETED \\Draft \\DRAFT $junk junk nonjunk)')
[imap]:   07:43.71 localhost handler untagged_responses[FLAGS] 0 += ["b'(\\Seen \\SEEN \\Flagged \\FLAGGED \\Deleted \\DELETED \\Draft \\DRAFT $junk j"]
[imap]:   07:43.71 localhost reader poll => [(4, 1)]
[imap]:   07:43.71 localhost reader rcvd 123
[imap]:   07:43.71 localhost reader < b'* OK [PERMANENTFLAGS (\\Seen \\SEEN \\Flagged \\FLAGGED \\Deleted \\DELETED \\Draft \\DRAFT $junk junk nonjunk)] Flags permitted.\r\n'
[imap]:   07:43.71 localhost reader poll => [(4, 1)]
[imap]:   07:43.71 localhost handler _put_response(b'* OK [PERMANENTFLAGS (\\Seen \\SEEN \\Flagged \\FLAGGED \\Deleted \\DELETED \\Draft \\DRAFT $junk junk nonjunk)] Flags permitted.')
[imap]:   07:43.71 localhost handler untagged_responses[OK] 0 += ["b'[PERMANENTFLAGS (\\Seen \\SEEN \\Flagged \\FLAGGED \\Deleted \\DELETED \\Draft"]
[imap]:   07:43.71 localhost handler untagged_responses[PERMANENTFLAGS] 0 += ["b'(\\Seen \\SEEN \\Flagged \\FLAGGED \\Deleted \\DELETED \\Draft \\DRAFT $junk j"]
[imap]:   07:43.71 localhost reader rcvd 13
[imap]:   07:43.71 localhost reader < b'* 36 EXISTS\r\n'
[imap]:   07:43.71 localhost reader poll => [(4, 1)]
[imap]:   07:43.71 localhost handler _put_response(b'* 36 EXISTS')
[imap]:   07:43.71 localhost handler untagged_responses[EXISTS] 0 += ["b'36'"]
[imap]:   07:43.71 localhost reader rcvd 12
[imap]:   07:43.71 localhost reader < b'* 0 RECENT\r\n'
[imap]:   07:43.71 localhost handler _put_response(b'* 0 RECENT')
[imap]:   07:43.78 localhost reader poll => [(4, 1)]
[imap]:   07:43.78 localhost handler untagged_responses[RECENT] 0 += ["b'0'"]
[imap]:   07:43.78 localhost reader rcvd 39
[imap]:   07:43.78 localhost reader < b'* OK [UIDNEXT 108] Predicted next UID\r\n'
[imap]:   07:43.78 localhost handler _put_response(b'* OK [UIDNEXT 108] Predicted next UID')
[imap]:   07:43.78 localhost reader poll => [(4, 1)]
[imap]:   07:43.78 localhost handler untagged_responses[OK] 0 += ["b'[UIDNEXT 108] Predicted next UID'"]
[imap]:   07:43.78 localhost reader rcvd 33
[imap]:   07:43.78 localhost reader < b'* OK [UIDVALIDITY 4] UIDs valid\r\n'
[imap]:   07:43.78 localhost handler untagged_responses[UIDNEXT] 0 += ["b'108'"]
[imap]:   07:43.78 localhost reader poll => [(4, 1)]
[imap]:   07:43.78 localhost handler _put_response(b'* OK [UIDVALIDITY 4] UIDs valid')
[imap]:   07:43.78 localhost reader rcvd 41
[imap]:   07:43.78 localhost reader < b'GKPO13 OK [READ-WRITE] SELECT completed\r\n'
[imap]:   07:43.78 localhost handler untagged_responses[OK] 0 += ["b'[UIDVALIDITY 4] UIDs valid'"]
[imap]:   07:43.78 localhost handler untagged_responses[UIDVALIDITY] 0 += ["b'4'"]
[imap]:   07:43.78 localhost handler _put_response(b'GKPO13 OK [READ-WRITE] SELECT completed')
[imap]:   07:43.78 localhost handler untagged_responses[READ-WRITE] 0 += ["b''"]
[imap]:   07:43.78 localhost handler _request_pop(b'GKPO13', ('OK', [b'[READ-WRITE] SELECT completed'])) [0] = b'GKPO13'
[imap]:   07:43.78 localhost handler SELECT:b'GKPO13'.ready.set
[imap]:   07:43.78 Account sync proton state => SELECTED
[imap]:   07:43.78 localhost handler state_change_free.set
[imap]:   07:43.78 Account sync proton state_change_pending.release
[imap]:   07:43.78 Account sync proton _get_untagged_response(EXISTS) => [b'36']
[imap]:   07:43.78 Account sync proton _untagged_response(OK, ?, EXISTS) => [b'36']
[imap]:   07:43.78 Account sync proton [sync] APPEND ('"Folders/hacking"', '(\\Seen)', '"18-Jan-2021 02:30:22 +0000"')
[imap]:   07:43.78 Account sync proton state_change_pending.acquire
[imap]:   07:43.78 Account sync proton _get_untagged_response(OK) => [b'[PERMANENTFLAGS (\\Seen \\SEEN \\Flagged \\FLAGGED \\Deleted \\DELETED \\Draf
[imap]:   07:43.78 Account sync proton _get_untagged_response(OK) => [b'[UIDNEXT 108] Predicted next UID']
[imap]:   07:43.79 Account sync proton _get_untagged_response(OK) => [b'[UIDVALIDITY 4] UIDs valid']
[imap]:   07:43.79 Account sync proton _request_push(b'GKPO14', APPEND, {}) = b'GKPO14'
[imap]:   07:43.79 Account sync proton data=b'GKPO14 APPEND "Folders/hacking" (\\Seen) "18-Jan-2021 02:30:22 +0000" {3490}'
[imap]:   07:43.79 Account sync proton _request_push(continuation, b'APPEND', {}) = b'GKPO15'
[imap]:   07:43.79 Account sync proton b'APPEND':b'GKPO15'.ready.wait
[imap]:   07:43.79 localhost writer > b'GKPO14 APPEND "Folders/hacking" (\\Seen) "18-Jan-2021 02:30:22 +0000" {3490}\r\n'
[imap]:   07:43.79 localhost reader poll => [(4, 1)]
[imap]:   07:43.79 localhost reader rcvd 16
[imap]:   07:43.79 localhost reader < b'+ send literal\r\n'
[imap]:   07:43.79 localhost handler _put_response(b'+ send literal')
[imap]:   07:43.79 localhost handler _request_pop(continuation, (True, b'send literal')) [1] = b'GKPO15'
[imap]:   07:43.79 localhost handler b'APPEND':b'GKPO15'.ready.set
[imap]:   07:43.79 Account sync proton continuation => True, b'send literal'
[imap]:   07:43.79 Account sync proton write literal size 3490
[imap]:   07:43.79 Account sync proton APPEND:b'GKPO14'.ready.wait
[imap]:   07:43.79 localhost writer > b'<<<EDITED: MESSAGE CONTENTS, IT LOOKS CORRECT'
[imap]:   07:44.92 localhost reader poll => [(4, 1)]
[imap]:   07:44.92 localhost reader rcvd 44
[imap]:   07:44.92 localhost reader < b'* 37 FETCH (FLAGS (\\Seen nonjunk) UID 108)\r\n'
[imap]:   07:44.92 localhost reader poll => [(4, 1)]
[imap]:   07:44.92 localhost handler _put_response(b'* 37 FETCH (FLAGS (\\Seen nonjunk) UID 108)')
[imap]:   07:44.92 localhost handler untagged_responses[FETCH] 0 += ["b'37 (FLAGS (\\Seen nonjunk) UID 108)'"]
[imap]:   07:44.92 localhost reader rcvd 13
[imap]:   07:44.92 localhost reader < b'* 37 EXISTS\r\n'
[imap]:   07:44.92 localhost handler _put_response(b'* 37 EXISTS')
[imap]:   07:44.92 localhost handler untagged_responses[EXISTS] 0 += ["b'37'"]
[imap]:   07:45.05 localhost reader poll => [(4, 1)]
[imap]:   07:45.05 localhost reader rcvd 28
[imap]:   07:45.05 localhost reader < b'GKPO14 OK APPEND completed\r\n'
[imap]:   07:45.05 localhost handler _put_response(b'GKPO14 OK APPEND completed')
[imap]:   07:45.05 localhost handler _request_pop(b'GKPO14', ('OK', [b'APPEND completed'])) [0] = b'GKPO14'
[imap]:   07:45.05 localhost handler APPEND:b'GKPO14'.ready.set
[imap]:   07:45.05 localhost handler state_change_free.set
[imap]:   07:45.05 Account sync proton state_change_pending.release
[imap]:   07:45.05 Account sync proton [async] CHECK ()
[imap]:   07:45.05 Account sync proton state_change_pending.acquire
[imap]:   07:45.05 Account sync proton state_change_pending.release
[imap]:   07:45.05 Account sync proton _request_push(b'GKPO16', CHECK, {}) = b'GKPO16'
[imap]:   07:45.05 Account sync proton data=b'GKPO16 CHECK'
[imap]:   07:45.05 Account sync proton CHECK:b'GKPO16'.ready.wait
[imap]:   07:45.05 localhost writer > b'GKPO16 CHECK\r\n'
[imap]:   07:45.05 localhost reader poll => [(4, 1)]
[imap]:   07:45.05 localhost reader rcvd 27
[imap]:   07:45.05 localhost reader < b'GKPO16 OK CHECK completed\r\n'
[imap]:   07:45.05 localhost handler _put_response(b'GKPO16 OK CHECK completed')
[imap]:   07:45.05 localhost handler _request_pop(b'GKPO16', ('OK', [b'CHECK completed'])) [0] = b'GKPO16'
[imap]:   07:45.05 localhost handler CHECK:b'GKPO16'.ready.set
Server supports UIDPLUS but got no APPENDUID appending a message. Got: None.
[imap]:   07:45.05 localhost handler state_change_free.set