Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Receiving NPE in Utility.toMessageSet after MOVE command is issues #477

Closed
nikowitt opened this issue Aug 30, 2022 · 5 comments
Closed

Receiving NPE in Utility.toMessageSet after MOVE command is issues #477

nikowitt opened this issue Aug 30, 2022 · 5 comments
Labels
backport_1_6_x Backport to old bugfixing branch 1.6.x bug
Milestone

Comments

@nikowitt
Copy link
Contributor

Hi there,
I am currently trying to update GreenMail 1.6.5 to 1.6.10. With 1.6.6, the MOVE capability was implemented. This breaks my tests and I am currently wondering if it is a regression in GreenMail or if our MOVE implementation is flawed. Maybe you can give me a hint:

Test case: 2 Mails are put on an IMAP servers. Mail 1 is processed and then moved (or copied and deleted if MOVE is not supported) to another folder, then the same happens for mail 2:

 Move filed message from inbox

   Given logged in user is "system"
     And mail fixtures exist on running IMAP server 

     	#	Value                               
     	1	fixture-mail-with-attachment.txt    
     	2	fixture-mail-with-notes-timezone.txt

     And connection to mail server is established
    When mails are filed at once as sample entity
    Then mails have been filed and removed from inbox

GreenMail 1.6.5 output:

DEBUG: getProvider() returning javax.mail.Provider[STORE,imap,com.sun.mail.imap.IMAPStore,Oracle]
DEBUG IMAP: mail.imap.fetchsize: 16384
DEBUG IMAP: mail.imap.ignorebodystructuresize: false
DEBUG IMAP: mail.imap.statuscachetimeout: 1000
DEBUG IMAP: mail.imap.appendbuffersize: -1
DEBUG IMAP: mail.imap.minidletime: 10
DEBUG IMAP: closeFoldersOnStoreFailure
DEBUG IMAP: trying to connect to host "localhost", port 40026, isSSL false
* OK IMAP4rev1 Server GreenMail v1.6.5 ready
B0 CAPABILITY
* CAPABILITY IMAP4rev1 LITERAL+ SORT UIDPLUS IDLE QUOTA
B0 OK CAPABILITY completed.
DEBUG IMAP: protocolConnect login, host=localhost, user=default, password=<non-null>
DEBUG IMAP: mechanism NTLM not supported by server
DEBUG IMAP: mechanism LOGIN not supported by server
DEBUG IMAP: mechanism PLAIN not supported by server
DEBUG IMAP: LOGIN command trace suppressed
DEBUG IMAP: LOGIN command result: B1 OK LOGIN completed.
B2 CAPABILITY
* CAPABILITY IMAP4rev1 LITERAL+ SORT UIDPLUS IDLE QUOTA
B2 OK CAPABILITY completed.
(...)

B8 SELECT INBOX
* FLAGS (\Answered \Deleted \Draft \Flagged \Seen \*)
* 2 EXISTS
* 2 RECENT
* OK [UIDVALIDITY 1661867469]
* OK [UIDNEXT 3]
* OK [UNSEEN 1] Message 1 is the first unseen
* OK [PERMANENTFLAGS (\Answered \Deleted \Draft \Flagged \Seen \*)]
B8 OK [READ-WRITE] SELECT completed.
B9 LIST INBOX ""
* LIST (\Noselect) "." ""
B9 OK LIST completed.
* OK IMAP4rev1 Server GreenMail v1.6.5 ready
C0 CAPABILITY
* CAPABILITY IMAP4rev1 LITERAL+ SORT UIDPLUS IDLE QUOTA
C0 OK CAPABILITY completed.
DEBUG IMAP: mechanism NTLM not supported by server
DEBUG IMAP: mechanism LOGIN not supported by server
DEBUG IMAP: mechanism PLAIN not supported by server
DEBUG IMAP: LOGIN command trace suppressed
DEBUG IMAP: LOGIN command result: C1 OK LOGIN completed.
C2 CAPABILITY
* CAPABILITY IMAP4rev1 LITERAL+ SORT UIDPLUS IDLE QUOTA
C2 OK CAPABILITY completed.
DEBUG IMAP: IMAPProtocol noop
C3 NOOP
C3 OK NOOP completed.
B10 UID FETCH 1 (UID)
* 1 FETCH (UID 1)
B10 OK FETCH completed.
B11 FETCH 1 (BODY.PEEK[])
* 1 FETCH (BODY[] {2396}
From: pirs.testuser@test.sobis.com
Subject: Coverage test mail with attachment
(...)
B11 OK FETCH completed.
DEBUG IMAP: IMAPProtocol noop
C4 NOOP
C4 OK NOOP completed.
DEBUG IMAP: IMAPProtocol noop
C5 NOOP
C5 OK NOOP completed.
C6 LIST "" ""
* LIST (\Noselect) "." ""
C6 OK LIST completed.
DEBUG IMAP: IMAPProtocol noop
C7 NOOP
C7 OK NOOP completed.
DEBUG IMAP: IMAPProtocol noop
C8 NOOP
C8 OK NOOP completed.
C9 LIST "" "Moved to.Test Folder-2022830-1113205371"
C9 OK LIST completed.
C10 CREATE "Moved to.Test Folder-2022830-1113205371"
C10 OK CREATE completed.
C11 LIST "" "Moved to.Test Folder-2022830-1113205371"
* LIST () "." "Moved to.Test Folder-2022830-1113205371"
C11 OK LIST completed.
C12 LSUB "" "Moved to.Test Folder-2022830-1113205371"
C12 OK LSUB completed.
C13 SUBSCRIBE "Moved to.Test Folder-2022830-1113205371"
C13 OK SUBSCRIBE completed.
B12 COPY 1 "Moved to.Test Folder-2022830-1113205371"
B12 OK [COPYUID 1661867469 1 1] COPY completed.
B13 STORE 1 +FLAGS (\Deleted)
* 1 FETCH (FLAGS (\Deleted))
B13 OK STORE completed.
B14 EXPUNGE
* 1 EXPUNGE
B14 OK EXPUNGE completed.
DEBUG IMAP: IMAPProtocol noop
C14 NOOP
C14 OK NOOP completed.
B15 UID FETCH 2 (UID)
* 1 FETCH (UID 2)
B15 OK FETCH completed.
B16 FETCH 1 (BODY.PEEK[])
* 1 FETCH (BODY[] {190290}
Received: (beginning of headers)
 (...)
DQpzdGFydHhyZWYNCjEzNTY3NA0KJSVFT0Y=


--=_mixed 0039CCCD42257ABC_=--
)
B16 OK FETCH completed.
DEBUG IMAP: IMAPProtocol noop
C15 NOOP
C15 OK NOOP completed.
B17 COPY 1 "Moved to.Test Folder-2022830-1113205371"
B17 OK [COPYUID 1661867469 2 2] COPY completed.
B18 STORE 1 +FLAGS (\Deleted)
* 1 FETCH (FLAGS (\Deleted))
B18 OK STORE completed.
B19 EXPUNGE
* 1 EXPUNGE
B19 OK EXPUNGE completed.
DEBUG IMAP: IMAPProtocol noop
C16 NOOP
C16 OK NOOP completed.
DEBUG IMAP: pool is full, not adding an Authenticated connection
B20 CLOSE
B20 OK CLOSE completed.
B21 LOGOUT
* BYE IMAP4rev1 Server logging out
B21 OK LOGOUT completed.

Here we can see that mails are read, copied to the MOVED TO folder and are deleted from the inbox. * 1 FETCH (UID 2) is issued, following by a body.peek.

GreenMail 1.6.7 output that uses the MOVE command (but also valid for 1.6.10):

DEBUG: getProvider() returning javax.mail.Provider[STORE,imap,com.sun.mail.imap.IMAPStore,Oracle]
DEBUG IMAP: mail.imap.fetchsize: 16384
DEBUG IMAP: mail.imap.ignorebodystructuresize: false
DEBUG IMAP: mail.imap.statuscachetimeout: 1000
DEBUG IMAP: mail.imap.appendbuffersize: -1
DEBUG IMAP: mail.imap.minidletime: 10
DEBUG IMAP: closeFoldersOnStoreFailure
DEBUG IMAP: trying to connect to host "localhost", port 44103, isSSL false
* OK IMAP4rev1 Server GreenMail v1.6.7 ready
B0 CAPABILITY
* CAPABILITY IMAP4rev1 LITERAL+ UIDPLUS SORT IDLE MOVE QUOTA
B0 OK CAPABILITY completed.
DEBUG IMAP: protocolConnect login, host=localhost, user=default, password=<non-null>
DEBUG IMAP: mechanism NTLM not supported by server
DEBUG IMAP: mechanism LOGIN not supported by server
DEBUG IMAP: mechanism PLAIN not supported by server
DEBUG IMAP: LOGIN command trace suppressed
DEBUG IMAP: LOGIN command result: B1 OK LOGIN completed.
B2 CAPABILITY
* CAPABILITY IMAP4rev1 LITERAL+ UIDPLUS SORT IDLE MOVE QUOTA
B2 OK CAPABILITY completed.
(...)
B8 SELECT INBOX
* FLAGS (\Answered \Deleted \Draft \Flagged \Seen \*)
* 2 EXISTS
* 2 RECENT
* OK [UIDVALIDITY 1661867351]
* OK [UIDNEXT 3]
* OK [UNSEEN 1] Message 1 is the first unseen
* OK [PERMANENTFLAGS (\Answered \Deleted \Draft \Flagged \Seen \*)]
B8 OK [READ-WRITE] SELECT completed.
B9 LIST INBOX ""
* LIST (\Noselect) "." ""
B9 OK LIST completed.
* OK IMAP4rev1 Server GreenMail v1.6.7 ready
C0 CAPABILITY
* CAPABILITY IMAP4rev1 LITERAL+ UIDPLUS SORT IDLE MOVE QUOTA
C0 OK CAPABILITY completed.
DEBUG IMAP: mechanism NTLM not supported by server
DEBUG IMAP: mechanism LOGIN not supported by server
DEBUG IMAP: mechanism PLAIN not supported by server
DEBUG IMAP: LOGIN command trace suppressed
DEBUG IMAP: LOGIN command result: C1 OK LOGIN completed.
C2 CAPABILITY
* CAPABILITY IMAP4rev1 LITERAL+ UIDPLUS SORT IDLE MOVE QUOTA
C2 OK CAPABILITY completed.
DEBUG IMAP: IMAPProtocol noop
C3 NOOP
C3 OK NOOP completed.
B10 UID FETCH 1 (UID)
* 1 FETCH (UID 1)
B10 OK FETCH completed.
B11 FETCH 1 (BODY.PEEK[])
* 1 FETCH (BODY[] {2396}
From: pirs.testuser@test.sobis.com
Subject: Coverage test mail with attachment
(...)
B11 OK FETCH completed.
(...)
C6 LIST "" ""
* LIST (\Noselect) "." ""
C6 OK LIST completed.
DEBUG IMAP: IMAPProtocol noop
C7 NOOP
C7 OK NOOP completed.
DEBUG IMAP: IMAPProtocol noop
C8 NOOP
C8 OK NOOP completed.
C9 LIST "" "Moved to.Test Folder-2022830-1258145195"
C9 OK LIST completed.
C10 CREATE "Moved to.Test Folder-2022830-1258145195"
C10 OK CREATE completed.
C11 LIST "" "Moved to.Test Folder-2022830-1258145195"
* LIST () "." "Moved to.Test Folder-2022830-1258145195"
C11 OK LIST completed.
C12 LSUB "" "Moved to.Test Folder-2022830-1258145195"
C12 OK LSUB completed.
C13 SUBSCRIBE "Moved to.Test Folder-2022830-1258145195"
C13 OK SUBSCRIBE completed.
B12 MOVE 1 "Moved to.Test Folder-2022830-1258145195"
* OK [COPYUID 1661867353 1,1:2 1,1:2]
* 1 EXPUNGE
* 1 EXPUNGE
B12 OK MOVE completed.
DEBUG IMAP: IMAPProtocol noop
C14 NOOP
C14 OK NOOP completed.
B13 UID FETCH 2 (UID)
B13 OK FETCH completed.
DEBUG IMAP: IMAPProtocol noop
C15 NOOP
C15 OK NOOP completed.
DEBUG IMAP: pool is full, not adding an Authenticated connection
B14 CLOSE
B14 OK CLOSE completed.
B15 LOGOUT
* BYE IMAP4rev1 Server logging out
B15 OK LOGOUT completed.
271) §> Done purging entities created in this test.
DEBUG IMAP: IMAPStore cleanup, force false
C16 LOGOUT
* BYE IMAP4rev1 Server logging out
C16 OK LOGOUT completed.
DEBUG IMAP: IMAPStore cleanup done

Here, B13 UID FETCH 2 (UID) is issued, but the next body.peek is simply missing. This results in a

Caused by: java.lang.NullPointerException
	at com.sun.mail.imap.Utility.toMessageSet(Utility.java:62) ~[jakarta.mail-1.6.7.jar:1.6.7]
	at com.sun.mail.imap.Utility.toMessageSetSorted(Utility.java:138) ~[jakarta.mail-1.6.7.jar:1.6.7]
	at com.sun.mail.imap.IMAPFolder.fetch(IMAPFolder.java:1280) ~[jakarta.mail-1.6.7.jar:1.6.7]

Does this behaviour ring any bells? Thanks in advance!

Regards, Niko

@marcelmay
Copy link
Member

Hi @nikowitt ,

can you provide a test case to provoke the issue?

This is the current test for MOVE-with-COPYUID, if it helps:
https://github.com/greenmail-mail-test/greenmail/blob/master/greenmail-core/src/test/java/com/icegreen/greenmail/test/ImapServerTest.java#L413

I will try to reproduce ~ this weekend.

@marcelmay marcelmay added the bug label Aug 31, 2022
@nikowitt
Copy link
Contributor Author

nikowitt commented Sep 1, 2022

Yes, I will try to do this today.

nikowitt pushed a commit to nikowitt/greenmail that referenced this issue Sep 1, 2022
@nikowitt
Copy link
Contributor Author

nikowitt commented Sep 1, 2022

Guess I am on the right track, please check testFolderMoveMessagesBasedOnUid. I guess it is related to the fact that in our code, we rely on picking references to messages based on the UID. Maybe this helps tracking down the issue.


java.lang.NullPointerException
	at com.sun.mail.imap.Utility.toMessageSet(Utility.java:62)
	at com.sun.mail.imap.IMAPFolder.copymoveMessages(IMAPFolder.java:2085)
	at com.sun.mail.imap.IMAPFolder.moveMessages(IMAPFolder.java:2037)
	at com.icegreen.greenmail.test.ImapServerTest.testFolderMoveMessagesBasedOnUid(ImapServerTest.java:440)

@marcelmay marcelmay added this to the 2.0.0-alpha-3 milestone Oct 3, 2022
@marcelmay marcelmay added the backport_1_6_x Backport to old bugfixing branch 1.6.x label Oct 3, 2022
@nikowitt
Copy link
Contributor Author

Seems to work fine with 1.6.11, thanks!

@marcelmay
Copy link
Member

Good to hear & appreciate the feedback!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
backport_1_6_x Backport to old bugfixing branch 1.6.x bug
Projects
None yet
Development

No branches or pull requests

2 participants