linagora / james-project

Mirror of Apache James Project
Apache License 2.0
70 stars 63 forks source link

java.lang.NullPointerException: Cannot invoke "org.apache.james.protocols.netty.LineHandlerAware.pushLineHandler" #5104

Open chibenwa opened 6 months ago

chibenwa commented 6 months ago
java.lang.NullPointerException: Cannot invoke "org.apache.james.protocols.netty.LineHandlerAware.pushLineHandler(io.netty.channel.ChannelInboundHandlerAdapter)" because "handler" is null
    at org.apache.james.imapserver.netty.NettyImapSession.pushLineHandler(NettyImapSession.java:259)
    at org.apache.james.imap.processor.AuthenticateProcessor.lambda$processRequest$1(AuthenticateProcessor.java:98)
    at org.apache.james.imapserver.netty.NettyImapSession.lambda$executeSafely$0(NettyImapSession.java:107)
    at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
    at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
    at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:566)
    at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
    at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
    at java.base/java.lang.Thread.run(Unknown Source)

Understand when this can happen...

chibenwa commented 6 months ago

Issue is: we ALWAYS have REQUEST_DECODER onto the pipeline...

Idea 1 looks impossible: calling a not-yet initialized channel. But to execute a processor pushing a line handler we need to have decoded a request first: this do not make sense!

Idea 2: the channel somehow is closing and the corresponding pipeline is cleaned up. Then we are seeing components cleaning up it the wrong order?

Arsnael commented 1 month ago

Clarification: in here https://github.com/linagora/james-project/issues/5122 says it's linked to this issue. But that has been completed since. Did it solve this problem or not fully?

chibenwa commented 1 month ago

Likely not linked.

I found out that the timeout handler deregisters the channel without disposing current tasks.

I suspect this causes calls on a pipeline with removed handlers hence the error.

CF https://github.com/apache/james-project/commit/9813526db40a5cb02790bf4ade9a1c2e24ef368b

chibenwa commented 1 month ago

I reviewed 60 hours of logs on imap.linagora.com without seeing the issue.

I did not spotted the error within this time frame.

I enabled debugging in order to get more details if such an error happens again.