eclipse-californium / californium

CoAP/DTLS Java Implementation
https://www.eclipse.org/californium/
Other
723 stars 361 forks source link

ignoring ACK, possible MID reuse before lifetime end for token #2204

Closed chen0411 closed 5 months ago

chen0411 commented 7 months ago

Issue: Coap server send a post request with MID:65535 and Token: 306CA356213CAC02 to client, MID and Token from capture, but according the log the MID of the request is 9846,when receive response, the message ignored. ignoring ACK, possible MID reuse before lifetime end for token 306CA356213CAC02, expected MID 9846 but received 65535

basic issue information

Using 2.0.0-M18

See here a log

`2024-01-09 18:45:22.595+08:00 DEBUG [CoapServer(main)#22] org.eclipse.californium.core.network.stack.ReliabilityLayer.sendRequest,97> - Exchange[L2097908] prepare retransmission for CON-POST MID= -1, Token=306CA356213CAC02, OptionSet={"Uri-Path":["10375","0"], "Content-Format":"application/vnd.oma.lwm2m+json"}, "{"e":[{"n":"30001","v":6".. 52 bytes

2024-01-09 18:45:22.596+08:00 DEBUG [CoapServer(main)#22] org.eclipse.californium.core.network.InMemoryMessageExchangeStore.registerWithMessageId,238> - Exchange[L2097908] added with generated mid KeyMID[/100.95.167.221:59787, 9846], CON-POST MID= 9846, Token=306CA356213CAC02, OptionSet={"Uri-Path":["10375","0"], "Content-Format":"application/vnd.oma.lwm2m+json"}, "{"e":[{"n":"30001","v":6".. 52 bytes

2024-01-09 18:45:22.597+08:00 DEBUG [CoapServer(main)#22] org.eclipse.californium.core.network.InMemoryMessageExchangeStore.registerWithToken,292> - Exchange[L2097908] added with token KeyToken[/100.95.167.221:59787-306CA356213CAC02], CON-POST MID= 9846, Token=306CA356213CAC02, OptionSet={"Uri-Path":["10375","0"], "Content-Format":"application/vnd.oma.lwm2m+json"}, "{"e":[{"n":"30001","v":6".. 52 bytes

2024-01-09 18:45:22.597+08:00 DEBUG [CoapServer(main)#22] org.eclipse.californium.core.network.UdpMatcher.sendRequest,132> - tracking open request [MID: 9846, Token: Token=306CA356213CAC02]

2024-01-09 18:45:23.101+08:00 DEBUG [CoapServer(main)#123] org.eclipse.californium.core.network.UdpMatcher$4.run,370> - ignoring ACK, possible MID reuse before lifetime end for token 306CA356213CAC02, expected MID 9846 but received 65535`

Packet capture information: image

boaks commented 7 months ago

Using 2.0.0-M18

That's an "years old milestone" release. Anything that prevents you from updating/migrating to the current 3.10.0? Or at least check, if the 2.8.0 is fixing it?

Coap server send a post request with MID:65535 and Token: 306CA356213CAC02 to client,

The Californium logs shows a MID with -1 (not assigned yet) and 9846 later, when a MID was assigned. Why wireshark then shows 65535 as MID is out of my knowledge. Maybe an bug in that years old californium milestone. I'm not aware, that the current release 3.10.0 shows such effects.

ignoring ACK, possible MID reuse before lifetime end for token 306CA356213CAC02, expected MID 9846 but received 65535`

The stack doesn't know how to handle an ACK with the "wrong MID". Using the "token" the stack assumes the cause of that error may be a reuse of the token. That's what I observed frequently in such cases. In your case something prevents the assigned MID 9846 from being send out.

Anyway, the only recommendation and help I can give is to migrate to 3.10.

chen0411 commented 7 months ago

ok, I will try to updating to 3.10, thank you !

boaks commented 7 months ago

MIGRATION_HINTS may help.

boaks commented 6 months ago

Any progress? Any further help needed? Or could this issue be closed?