I have a Ciphermail installation 5.5.3.0g99d2faca on Debian 11, installed from the deb-packages.
PGP keys are configured to automatically decrypt incoming mail.
Some messages are not being decrypted by Ciphermail. The error “java.io.IOException: Stream closed” occurs.
I’ve discovered that all affected messages use BZIP2 compression for PGP encryption (compress_algo=3).
Messages using ZLIB (compress_algo=2) decrypt without error.
The problematic emails can be decrypted normally using tools like Kleopatra.
What could be causing this error?
Here is the log:
DEBUG about to open ResultSet (open ResultSets: 0, globally: 1) (org.hibernate.jdbc.AbstractBatcher) [Spool Thread #2]
DEBUG result row: EntityKey[mitm.common.security.keystore.hibernate.KeyStoreEntryHibernate#72] (org.hibernate.loader.Loader) [Spool Thread #2]
DEBUG about to close ResultSet (open ResultSets: 1, globally: 2) (org.hibernate.jdbc.AbstractBatcher) [Spool Thread #2]
DEBUG about to close PreparedStatement (open PreparedStatements: 1, globally: 2) (org.hibernate.jdbc.AbstractBatcher) [Spool Thread #2]
DEBUG resolving associations for [mitm.common.security.keystore.hibernate.KeyStoreEntryHibernate#72] (org.hibernate.engine.TwoPhaseLoad) [Spool Thread #2]
DEBUG done materializing entity [mitm.common.security.keystore.hibernate.KeyStoreEntryHibernate#72] (org.hibernate.engine.TwoPhaseLoad) [Spool Thread #2]
DEBUG initializing non-lazy collections (org.hibernate.engine.StatefulPersistenceContext) [Spool Thread #2]
DEBUG commit (org.hibernate.transaction.JDBCTransaction) [Spool Thread #2]
DEBUG processing flush-time cascades (org.hibernate.event.def.AbstractFlushingEventListener) [Spool Thread #2]
DEBUG dirty checking collections (org.hibernate.event.def.AbstractFlushingEventListener) [Spool Thread #2]
DEBUG Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects (org.hibernate.event.def.AbstractFlushingEventListener) [Spool Thread #2]
DEBUG Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections (org.hibernate.event.def.AbstractFlushingEventListener) [Spool Thread #2]
DEBUG listing entities: (org.hibernate.pretty.Printer) [Spool Thread #2]
DEBUG mitm.common.security.keystore.hibernate.KeyStoreEntryHibernate{certificateChain=[Ljava.security.cert.Certificate;@4c4c885, certificate=PGP certificate. Key ID:..., alias=PGP:..., storeName=pgp, id=72, creationDate=2022-03-23 16:13:45} (org.hibernate.pretty.Printer) [Spool Thread #2]
DEBUG committed JDBC Connection (org.hibernate.transaction.JDBCTransaction) [Spool Thread #2]
DEBUG aggressively releasing JDBC connection (org.hibernate.jdbc.ConnectionManager) [Spool Thread #2]
DEBUG releasing JDBC connection [ (open PreparedStatements: 0, globally: 1) (open ResultSets: 0, globally: 1)] (org.hibernate.jdbc.ConnectionManager) [Spool Thread #2]
DEBUG Closing iterator. (mitm.common.hibernate.AbstractScrollableResultsIterator) [Spool Thread #2]
DEBUG about to close ResultSet (open ResultSets: 1, globally: 1) (org.hibernate.jdbc.AbstractBatcher) [Spool Thread #2]
DEBUG about to close PreparedStatement (open PreparedStatements: 1, globally: 1) (org.hibernate.jdbc.AbstractBatcher) [Spool Thread #2]
DEBUG Closing iterator. (mitm.common.hibernate.AbstractScrollableResultsIterator) [Spool Thread #2]
DEBUG Closing iterator. (mitm.common.hibernate.AbstractScrollableResultsIterator) [Spool Thread #2]
DEBUG Key pair(s) for key id ... found (mitm.common.security.openpgp.PGPHandler) [Spool Thread #2]
DEBUG next PGP object. level: 1, Type: class org.bouncycastle.openpgp.PGPCompressedData (mitm.common.security.openpgp.PGPHandler) [Spool Thread #2]
DEBUG next PGP object. level: 2, Type: class org.bouncycastle.openpgp.PGPLiteralData (mitm.common.security.openpgp.PGPHandler) [Spool Thread #2]
DEBUG setSession. Object: com.sun.proxy.$Proxy67@38def13c (mitm.common.hibernate.SessionManager) [Spool Thread #2]
DEBUG rollback (org.hibernate.transaction.JDBCTransaction) [Spool Thread #2]
DEBUG rolled back JDBC Connection (org.hibernate.transaction.JDBCTransaction) [Spool Thread #2]
DEBUG aggressively releasing JDBC connection (org.hibernate.jdbc.ConnectionManager) [Spool Thread #2]
DEBUG releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] (org.hibernate.jdbc.ConnectionManager) [Spool Thread #2]
ERROR Database error servicing email. (mitm.application.djigzo.james.mailets.PGPHandler) [Spool Thread #2]
mitm.common.hibernate.DatabaseException: javax.mail.MessagingException: Error handling message;
nested exception is:
java.io.IOException: Stream closed
at mitm.application.djigzo.james.mailets.AbstractTransactedMailet$1.doAction(AbstractTransactedMailet.java:140) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.common.hibernate.DatabaseActionExecutorImpl$1.doAction(DatabaseActionExecutorImpl.java:164) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.common.hibernate.DatabaseActionExecutorImpl.executeTransaction(DatabaseActionExecutorImpl.java:81) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.common.hibernate.DatabaseActionExecutorImpl.executeTransaction(DatabaseActionExecutorImpl.java:158) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.application.djigzo.james.mailets.AbstractTransactedMailet.serviceMail(AbstractTransactedMailet.java:122) [ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.application.djigzo.james.mailets.AbstractDjigzoMailet.service(AbstractDjigzoMailet.java:281) [ciphermail-core.jar:5.5.3.0g99d2faca]
at org.apache.james.transport.LinearProcessor.service(LinearProcessor.java:424) [james-2.3.1.jar:?]
at org.apache.james.transport.JamesSpoolManager.process(JamesSpoolManager.java:405) [james-2.3.1.jar:?]
at org.apache.james.transport.JamesSpoolManager.run(JamesSpoolManager.java:309) [james-2.3.1.jar:?]
at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: javax.mail.MessagingException: Error handling message
at mitm.application.djigzo.james.mailets.PGPHandler.serviceMailTransacted(PGPHandler.java:501) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.application.djigzo.james.mailets.AbstractTransactedMailet$1.doAction(AbstractTransactedMailet.java:137) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
... 9 more
Caused by: java.io.IOException: Stream closed
at java.io.BufferedInputStream.getBufIfOpen(BufferedInputStream.java:176) ~[?:?]
at java.io.BufferedInputStream.fill(BufferedInputStream.java:220) ~[?:?]
at java.io.BufferedInputStream.read(BufferedInputStream.java:271) ~[?:?]
at org.bouncycastle.bcpg.BCPGInputStream.read(Unknown Source) ~[bcpg-jdk18on-1.81.jar:?]
at org.bouncycastle.bcpg.BCPGInputStream.nextPacketTag(Unknown Source) ~[bcpg-jdk18on-1.81.jar:?]
at org.bouncycastle.openpgp.PGPObjectFactory.nextObject(Unknown Source) ~[bcpg-jdk18on-1.81.jar:?]
at mitm.common.security.openpgp.PGPHandler.handle(PGPHandler.java:163) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.common.security.openpgp.PGPHandler.handleEncryptedDataList(PGPHandler.java:283) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.common.security.openpgp.PGPHandler.handle(PGPHandler.java:180) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.common.security.openpgp.PGPHandler.handle(PGPHandler.java:141) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.common.security.openpgp.PGPMIMEHandler.handlePGPMIMEEncrypted(PGPMIMEHandler.java:706) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.common.security.openpgp.PGPMIMEHandler.handleMessage(PGPMIMEHandler.java:270) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.common.security.openpgp.PGPRecursiveValidatingMIMEHandler.handleMessage(PGPRecursiveValidatingMIMEHandler.java:1125) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.common.security.openpgp.PGPRecursiveValidatingMIMEHandler.handleMessage(PGPRecursiveValidatingMIMEHandler.java:1102) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.application.djigzo.james.mailets.PGPHandler.serviceMailTransacted(PGPHandler.java:498) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
at mitm.application.djigzo.james.mailets.AbstractTransactedMailet$1.doAction(AbstractTransactedMailet.java:137) ~[ciphermail-core.jar:5.5.3.0g99d2faca]
... 9 more
INFO Message handling is finished. Sending to final recipient(s); MailID: 1f6c8cd3-c951-4893-b9e9-733e8d09de9c; Recipients: [...]; Originator: ...; Sender: ...; Remote address: ...; Subject: Test 1357 algo3; Message-ID: ; (mitm.application.djigzo.james.mailets.Log) [Spool Thread #2]
It’s hard to test what’s causing this without the email and private key. It could be that the issues has been fixed in a newer version of BouncyCastle (this is used for PGP).
We are close to releasing a new version. Would it be possible for you to test this with the new version? I can provide a pre-configured VM
A new version of BouncyCastle probably won’t help. I had already replaced the included version with bcpg-jdk18on-1.81.
The logs in the first post were already with this version. However, the error was identical in both the original and the new version.
I could try the new version of Ciphermail. Where can I download it?
I created the key on Debian 12. I then sent these test emails to Ciphermail using netcat. Everything works with Algo 2, but the error occurs with Algo 3.
Here are the files used for this example. I can’t upload attachments to the forum yet.