UNICAST3 - NPE in handleXmitRequest for message without sender when SSL_KEY_EXCHANGE and ASYM_ENCRYPT are used

[synth3]

Hello,
when running a stress test that removes and adds many entries concurrently from/to a Infinispan 14.0.7.Final (JGroups 5.2.12.Final) distributed cache with a stack based on infinispan/default-jgroups-udp.xml i see the following log messages:

UNICAST3 JGRP000043: targetNode: failed handling event: java.lang.NullPointerException: Cannot invoke "Object.hashCode()" because "key" is null

The difference to infinispan/default-jgroups-udp.xml is that I have added SSL_KEY_EXCHANGE and ASYM_ENCRYPT between VERIFY_SUSPECT2 and pbcast.NAKACK2:

<SSL_KEY_EXCHANGE
    keystore_name="${keystore.path}"
    keystore_password="${keystore.password}"
    truststore_name="${truststore.path}"
    truststore_password="${truststore.password}"
    ssl_protocol="TLSv1.2"
    bind_addr="${jgroups.bind.address:SITE_LOCAL}"
    port="${jgroups.ssl.key.exchange.bind.port:2157}"
    port_range="${jgroups.ssl.key.exchange.bind.port.range:60}"
    require_client_authentication="true"
    socket_timeout="30000"/>
<ASYM_ENCRYPT
    asym_keylength="2048"
    asym_algorithm="RSA"
    change_key_on_coord_leave = "false"
    change_key_on_leave = "false"
    use_external_key_exchange = "true"/>

So the the complete Stack looks as follows:

UDP
RED
PING
MERGE3
FD_SOCK2
FD_ALL3
VERIFY_SUSPECT2
SSL_KEY_EXCHANGE
ASYM_ENCRYPT
pbcast.NAKACK2
UNICAST3
pbcast.STABLE
pbcast.GMS
UFC
MFC
FRAG4

Without SSL_KEY_EXCHANGE and ASYM_ENCRYPT I was not able to reproduce the issue.

Debugging revealed the following additional information (unfortunately log.error(Util.getMessage("FailedHandlingEvent"), local_addr, t) does not log a StackTrace):

StackTrace:

java.lang.NullPointerException: Cannot invoke "Object.hashCode()" because "key" is null
    at java.base/java.util.concurrent.ConcurrentHashMap.get(ConcurrentHashMap.java:936)
    at org.jgroups.protocols.UNICAST3.handleXmitRequest(UNICAST3.java:1030)
    at org.jgroups.protocols.UNICAST3.handleUpEvent(UNICAST3.java:447)
    at org.jgroups.protocols.UNICAST3.up(UNICAST3.java:493)
    at org.jgroups.protocols.pbcast.NAKACK2.up(NAKACK2.java:700)
    at org.jgroups.protocols.Encrypt.up(Encrypt.java:222)
    at org.jgroups.protocols.ASYM_ENCRYPT.up(ASYM_ENCRYPT.java:179)
    at org.jgroups.stack.Protocol.up(Protocol.java:346)
    at org.jgroups.protocols.VERIFY_SUSPECT2.up(VERIFY_SUSPECT2.java:119)
    at org.jgroups.protocols.FailureDetection.up(FailureDetection.java:193)
    at org.jgroups.protocols.FD_SOCK2.up(FD_SOCK2.java:202)
    at org.jgroups.protocols.MERGE3.up(MERGE3.java:288)
    at org.jgroups.protocols.Discovery.up(Discovery.java:314)
    at org.jgroups.protocols.RED.up(RED.java:119)
    at org.jgroups.protocols.TP.passBatchUp(TP.java:1204)
    at org.jgroups.util.MaxOneThreadPerSender$BatchHandlerLoop.passBatchUp(MaxOneThreadPerSender.java:289)
    at org.jgroups.util.SubmitToThreadPool$BatchHandler.run(SubmitToThreadPool.java:150)
    at org.jgroups.util.MaxOneThreadPerSender$BatchHandlerLoop.run(MaxOneThreadPerSender.java:278)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
    at java.base/java.lang.Thread.run(Thread.java:1589)

MessageBatch details (message already removed by org.jgroups.protocols.UNICAST3.up(MessageBatch)):

dest=targetNode, sender=senderNode, mode=REG, cluster=MyCluster, 0 messages [capacity=16]

Message that led to the NPE:

[null to targetNode, 39 bytes, flags=OOB], obj: (10): {20861-20862, 20865-20866, 20869-20870, 20873-20876}
Headers: [XMIT_REQ, seqno=0, null, null, null]

Sometimes the log messages are flooding the logs, sometimes they are sporadic.

How can I avoid this problem? Can I fix it by tweaking my stack configuration?

[synth3]

I made an error in the original description: I did not mention SSL_KEY_EXCHANGE and ASYM_ENCRYPT which seem to be required to reproduce the issue. I have updated the original message accordingly.

[belaban]

I think I know what the problem is: when asking a sender for retransmission of a missing message, UNICAST3 does not set the sender's address (regular message sending via down() does!). The transport would set the sender's address, but the message doesn't get there; instead, we encrypt it into a wrapped message which is then sent. On the receiver's side, the message is decrypted (null sender) and added to a batch, this causes the NPE.

I created [1] to keep track of this.

[1] https://issues.redhat.com/browse/JGRP-2680

[belaban]

OK, JGRP-2680 has been fixed. You may want to verify that the fix works by running mvn install locally and setting JGroups to 5.2.14.Final-SNAPSHOT

[synth3]

Thank you - that was fast. :)

With 5.2.14.Final-SNAPSHOT (built from commit c41313b) I can not reproduce the issue. I could also verify that XMIT_REQ messages processed in UNICAST3 now have a src value.

[belaban]

Excellent! I'll hope to release 5.2.14 soon

[synth3]

Is it possible to provide an estimate when the next release will arrive?
Would it - hypothetically - be save to use c41313b in production? (Without afford I was not able to get the tests to succed locally, wich might be caused by my environment. Is there maybe a publicly visible test pipeline?)

[belaban]

I'm working on [1], and want to also include [2] and [3]. Once this is done, I'll release 5.2.14. I'd say 2-3 weeks.
Meanwhile, why don't you build your own version with the above commit? IMO this is safe to use in production.

[1] https://issues.redhat.com/browse/JGRP-2681
[2] https://issues.redhat.com/browse/JGRP-2684
[3] https://issues.redhat.com/browse/JGRP-2685

[synth3]

Thank you for the information! :)