Skipping 8,913 KB..
Full Log18 98 1f c3 3e 58 28 8d 9e 11 b9 da dc 54 84 ec 21 f4 72 3e 9a 86 b7 ac 2e ca c0 62 50 e1 c6 47
f0 37 57 ad 8c 76 b8 7e f4 39 60 ff d6 4d 07 53 fd e6 ba ee 5b cb 54 a1 af 1d c4 70 83 a0 7f fd
ab 5f 67 6e a8 de a9 27 f9 3f e8 b3 94 ca 4c cb 0f 75 b1 41 4f 39 6c 27 88 28 70 8d e4 9b f1 06
3a c0 73 85 d0 97 87 e5 9e f0 eb d3 e2 2b 7d 5a c8 8f 2f 36 4c 52 9d 98 9a ef a0 1a 2b 27 76 c6
f0 d6 71 19 d6 09 08 c1 53 7b 39 f6 48 95 57 aa ab f9 af 01 d0 4c 0f 5c 69 3e b5 5a 1e 99 34 b2
d5 e2 8e 80 79 5f 33 17 7a 56 52 c1 20 97 c0 1f fb c6 99 82 d4 65 6b 3d 79 ca e3 de 98 f7 ae 82
0f ed 8c 3c 50 fa 24 19 bf d0 55 e6 e6 90 0e 27 1e 62 49 ff dc 9a 1d 79 16 1f bd 11 a6 f8 9a 8c
.. 266 bytes, failed transmissions: 0
09:11:29.199 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R164, complete]!
09:11:29.199 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R164, complete] completed ACK-2.04 MID=55766, Token=14A796E08A88B51E, OptionSet={"Object-Security":0x, "Block1":"(szx=1/32, m=false, num=4)"},
18 c2 85 0b 9b 68 13 59 59 b3 74 c9 ab d1 cf 53 0d 88 b9 0c c3 b0 da b4 92 c5 1d 79 ed 9e b0 02
18 98 1f c3 3e 58 28 8d 9e 11 b9 da dc 54 84 ec 21 f4 72 3e 9a 86 b7 ac 2e ca c0 62 50 e1 c6 47
f0 37 57 ad 8c 76 b8 7e f4 39 60 ff d6 4d 07 53 fd e6 ba ee 5b cb 54 a1 af 1d c4 70 83 a0 7f fd
ab 5f 67 6e a8 de a9 27 f9 3f e8 b3 94 ca 4c cb 0f 75 b1 41 4f 39 6c 27 88 28 70 8d e4 9b f1 06
3a c0 73 85 d0 97 87 e5 9e f0 eb d3 e2 2b 7d 5a c8 8f 2f 36 4c 52 9d 98 9a ef a0 1a 2b 27 76 c6
f0 d6 71 19 d6 09 08 c1 53 7b 39 f6 48 95 57 aa ab f9 af 01 d0 4c 0f 5c 69 3e b5 5a 1e 99 34 b2
d5 e2 8e 80 79 5f 33 17 7a 56 52 c1 20 97 c0 1f fb c6 99 82 d4 65 6b 3d 79 ca e3 de 98 f7 ae 82
0f ed 8c 3c 50 fa 24 19 bf d0 55 e6 e6 90 0e 27 1e 62 49 ff dc 9a 1d 79 16 1f bd 11 a6 f8 9a 8c
.. 266 bytes!
09:11:29.200 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 283 bytes to /127.0.0.1:8279
09:11:29.201 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E242,T680) 127.0.0.1:8,278 ==> :8,279 [ACK-2.04 MID=55766, Token=14A796E08A88B51E, OptionSet={"Object-Security":0x, "Block1":"(szx=1/32, m=false, num=4)"},
18 c2 85 0b 9b 68 13 59 59 b3 74 c9 ab d1 cf 53 0d 88 b9 0c c3 b0 da b4 92 c5 1d 79 ed 9e b0 02
18 98 1f c3 3e 58 28 8d 9e 11 b9 da dc 54 84 ec 21 f4 72 3e 9a 86 b7 ac 2e ca c0 62 50 e1 c6 47
f0 37 57 ad 8c 76 b8 7e f4 39 60 ff d6 4d 07 53 fd e6 ba ee 5b cb 54 a1 af 1d c4 70 83 a0 7f fd
ab 5f 67 6e a8 de a9 27 f9 3f e8 b3 94 ca 4c cb 0f 75 b1 41 4f 39 6c 27 88 28 70 8d e4 9b f1 06
3a c0 73 85 d0 97 87 e5 9e f0 eb d3 e2 2b 7d 5a c8 8f 2f 36 4c 52 9d 98 9a ef a0 1a 2b 27 76 c6
f0 d6 71 19 d6 09 08 c1 53 7b 39 f6 48 95 57 aa ab f9 af 01 d0 4c 0f 5c 69 3e b5 5a 1e 99 34 b2
d5 e2 8e 80 79 5f 33 17 7a 56 52 c1 20 97 c0 1f fb c6 99 82 d4 65 6b 3d 79 ca e3 de 98 f7 ae 82
0f ed 8c 3c 50 fa 24 19 bf d0 55 e6 e6 90 0e 27 1e 62 49 ff dc 9a 1d 79 16 1f bd 11 a6 f8 9a 8c
.. 266 bytes]
09:11:29.201 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8279) received 283 bytes from localhost/127.0.0.1:8278
09:11:29.201 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is OSCORE protected
09:11:29.201 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ResponseDecryptor - Removes E options from outer options which are not allowed there
09:11:29.201 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:29.201 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not considered due to it being disabled for this context
09:11:29.202 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L163, complete]!
09:11:29.202 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L163, complete] for token KeyToken[127.0.0.1:8278-14A796E08A88B51E]
09:11:29.202 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L163, complete] for MID KeyMID[127.0.0.1:8278-55766]
09:11:29.202 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - local Exchange[L163, complete] completed CON-POST MID= -1, Token=14A796E08A88B51E, OptionSet={"Object-Security":0x, "Content-Format":"text/plain", "Accept":"text/plain", "Proxy-Uri":"coap://127.0.0.1:8277/resource"}, "982573870057647435266673".. 128 bytes -/- CON-POST MID=55766, Token=14A796E08A88B51E, OptionSet={"Object-Security":0x0900, "Proxy-Uri":"coap://127.0.0.1:8277"}, acked
ad 81 2c 10 62 83 58 e4 dd e3 c6 2c 3d d8 6a 71 04 62 0c ae 80 e1 65 13 43 05 a1 0a 0c bc 8f a9
19 1a 41 82 85 24 58 93 23 a0 c3 06 1e 6c 72 ad 20 c4 2c 56 9c 4e 6c 83 3f 2b bf 21 12 21 fa 37
e5 f0 f3 29 70 8d c4 02 e8 81 44 bb 3f ec ef 1b 98 ab 7c 5d ee 41 e5 50 60 82 45 a5 be ca d2 4b
78 2a e2 c6 8d 15 52 35 76 80 0b 70 79 be ca 2d a8 66 5b 05 0a 25 b6 a3 37 99 39 6e 66 9e 24 ab
ef 9c 91 fd 5e 02 91 9d 23 ff 96 04 85 00 45 d5 01 fe a2 d7 00 !
==[ CoAP Response ]============================================
MID : 55766
Token : 14A796E08A88B51E
Type : ACK
Status : 2.05 - CONTENT
Options: {"Object-Security":0x}
RTT : 52 ms
Payload: 256 Bytes
---------------------------------------------------------------
9825738700576474352666735053512878218700320913599900364160263437163052680218709341331217088868805914495093768541575311672954009898257387005764743526667350535128782187003209135999003641602634371630526802187093413312170888688059144950937685415753116729540098
===============================================================
09:11:29.203 [main] DEBUG org.eclipse.californium.rule.CoapThreadsRule - shutdown
09:11:29.203 [main] INFO org.eclipse.californium.core.CoapServer - Destroying server
09:11:29.203 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://127.0.0.1:8277
09:11:29.204 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://127.0.0.1:8277
09:11:29.204 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8277, address localhost/127.0.0.1
09:11:29.204 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [localhost/127.0.0.1:8277] has stopped.
09:11:29.204 [main] INFO org.eclipse.californium.core.CoapServer - CoAP server has been destroyed
09:11:29.204 [main] DEBUG org.eclipse.californium.rule.CoapThreadsRule - shutdown
09:11:29.204 [main] INFO org.eclipse.californium.core.CoapServer - Destroying server
09:11:29.204 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://127.0.0.1:8278
09:11:29.204 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://127.0.0.1:8278
09:11:29.205 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8278, address localhost/127.0.0.1
09:11:29.205 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [localhost/127.0.0.1:8278] has stopped.
09:11:29.205 [main] INFO org.eclipse.californium.core.CoapServer - CoAP server has been destroyed
09:11:29.205 [main] DEBUG org.eclipse.californium.rule.CoapThreadsRule - shutdown
09:11:29.205 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://0.0.0.0:8279
09:11:29.205 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://0.0.0.0:8279
09:11:29.205 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8279, address 0.0.0.0/0.0.0.0
09:11:29.205 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [0.0.0.0/0.0.0.0:8279] has stopped.
09:11:29.205 [main] DEBUG org.eclipse.californium.rule.CoapThreadsRule - shutdown
09:11:29.206 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://0.0.0.0:8280
09:11:29.206 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://0.0.0.0:8280
09:11:29.206 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8280, address 0.0.0.0/0.0.0.0
09:11:29.206 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [0.0.0.0/0.0.0.0:8280] has stopped.
09:11:29.206 [main] INFO org.eclipse.californium.elements.rule.TestNameLoggerRule - Test testOuterBlockwisePostProxyServerBW
09:11:29.207 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 0 rules active.
09:11:29.207 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
[INFO] Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.8 s - in org.eclipse.californium.oscore.OSCoreOuterBlockwiseTest
[INFO] Running org.eclipse.californium.oscore.OSCoreServerClientTest
Start OSCoreServerClientTest
09:11:29.208 [main] INFO org.eclipse.californium.core.network.RandomTokenGenerator - using tokens of 8 bytes in length
09:11:29.208 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap using TokenProvider org.eclipse.californium.core.network.RandomTokenGenerator
09:11:29.208 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap CoapEndpoint uses udp plain
09:11:29.208 [main] INFO org.eclipse.californium.core.network.stack.ReliabilityLayer - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
09:11:29.208 [main] INFO org.eclipse.californium.core.network.stack.BlockwiseLayer - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
09:11:29.209 [main] INFO org.eclipse.californium.core.CoapServer - Starting server
09:11:29.209 [main] DEBUG org.eclipse.californium.elements.util.ExecutorsUtil - remove on cancel: false, split: true, log-diff: 10000
09:11:29.209 [main] DEBUG org.eclipse.californium.core.network.CoapEndpoint - coap Starting endpoint at coap://127.0.0.1:0
09:11:29.210 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap no MessageIdProvider set, using default org.eclipse.californium.core.network.InMemoryMessageIdProvider
09:11:29.210 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
09:11:29.210 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - binding to port 0, address localhost/127.0.0.1
09:11:29.210 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - assigned port 8281
09:11:29.210 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector starts up 1 sender threads and 1 receiver threads
09:11:29.210 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector listening on localhost/127.0.0.1:8281, recv buf = 0, send buf = 0, recv packet size = 2048
09:11:29.210 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Receiver-localhost/127.0.0.1:0[0]]
09:11:29.210 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Started endpoint at coap://127.0.0.1:8281
09:11:29.210 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Sender-localhost/127.0.0.1:0[0]]
09:11:29.211 [main] INFO org.eclipse.californium.core.network.RandomTokenGenerator - using tokens of 8 bytes in length
09:11:29.211 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap using TokenProvider org.eclipse.californium.core.network.RandomTokenGenerator
09:11:29.211 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap CoapEndpoint uses udp plain
09:11:29.211 [main] INFO org.eclipse.californium.core.network.stack.ReliabilityLayer - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
09:11:29.211 [main] INFO org.eclipse.californium.core.network.stack.BlockwiseLayer - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
09:11:29.212 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Endpoint [coap://0.0.0.0:0] requires an executor to start, using default single-threaded daemon executor
09:11:29.212 [main] DEBUG org.eclipse.californium.core.network.CoapEndpoint - coap Starting endpoint at coap://0.0.0.0:0
09:11:29.212 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap no MessageIdProvider set, using default org.eclipse.californium.core.network.InMemoryMessageIdProvider
09:11:29.212 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
09:11:29.212 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - binding to port 0, address 0.0.0.0/0.0.0.0
09:11:29.212 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - assigned port 8282
09:11:29.212 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector starts up 1 sender threads and 1 receiver threads
09:11:29.212 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]]
09:11:29.212 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector listening on 0.0.0.0/0.0.0.0:8282, recv buf = 0, send buf = 0, recv packet size = 2048
09:11:29.213 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Started endpoint at coap://0.0.0.0:8282
09:11:29.213 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Sender-0.0.0.0/0.0.0.0:0[0]]
09:11:29.213 [main] INFO org.eclipse.californium.core.network.EndpointManager - created implicit endpoint coap://0.0.0.0:8282 for coap
client sent request
09:11:29.213 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityContextLayer - Request: CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x}, "client says hi"
09:11:29.213 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L171] send request, failed transmissions: 0
09:11:29.213 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L171] prepare retransmission for CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x}, "client says hi"
09:11:29.214 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Request: CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x}, "client says hi"
09:11:29.214 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L171] replace CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x}, "client says hi" by CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x0900},
fe a4 f9 3e 93 68 a0 1f 0c 85 30 2b 44 f3 d2 fe 86 8a 22 9c c3 6d 28 85
09:11:29.214 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L171] added with KeyMID[localhost/127.0.0.1:8281-10000], CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x0900},
fe a4 f9 3e 93 68 a0 1f 0c 85 30 2b 44 f3 d2 fe 86 8a 22 9c c3 6d 28 85
09:11:29.215 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L171] added with generated token KeyToken[localhost/127.0.0.1:8281-2CD80398ADE00278], CON-POST MID=10000, Token=2CD80398ADE00278, OptionSet={"Object-Security":0x0900},
fe a4 f9 3e 93 68 a0 1f 0c 85 30 2b 44 f3 d2 fe 86 8a 22 9c c3 6d 28 85
09:11:29.215 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.UdpMatcher - tracking open request [KeyMID[localhost/127.0.0.1:8281-10000], KeyToken[localhost/127.0.0.1:8281-2CD80398ADE00278]]
09:11:29.215 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.HashMapCtxDB - Token exists, but this could be a refresh if not there is a problem
09:11:29.215 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:0[0],5,Californium/Elements]) sent 40 bytes to localhost/127.0.0.1:8281
09:11:29.216 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E243,T702) 127.0.0.1:8,282 ==> :8,281 [CON-POST MID=10000, Token=2CD80398ADE00278, OptionSet={"Object-Security":0x0900},
fe a4 f9 3e 93 68 a0 1f 0c 85 30 2b 44 f3 d2 fe 86 8a 22 9c c3 6d 28 85 ]
09:11:29.216 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (localhost:8281) received 40 bytes from localhost/127.0.0.1:8282
09:11:29.216 [CoapServer(main)#4] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[localhost/127.0.0.1:8282-10000]
09:11:29.216 [CoapServer(main)#5] INFO org.eclipse.californium.oscore.RequestDecryptor - Removes E options from outer options which are not allowed there
09:11:29.217 [CoapServer(main)#5] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:29.217 [CoapServer(main)#5] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not initiated due to it being disabled for this context
09:11:29.217 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R172] replace CON-POST MID=10000, Token=2CD80398ADE00278, OptionSet={"Object-Security":0x}, "client says hi" by CON-POST MID=10000, Token=2CD80398ADE00278, OptionSet={"Object-Security":0x}, "client says hi"
server received request
09:11:29.217 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[R172] send response NON-2.05 MID=10000, Token=null, OptionSet={}, "server responds hi", failed transmissions: 0
09:11:29.218 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R172, complete]!
09:11:29.218 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R172, complete] completed NON-2.04 MID=10000, Token=2CD80398ADE00278, OptionSet={"Object-Security":0x},
6d f4 a2 33 14 f7 c2 24 6c 7f 0d 89 f2 a1 51 d8 4e b4 cc 0b 0d b9 c6 f5 d6 dc a7 11 !
09:11:29.218 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 42 bytes to localhost/127.0.0.1:8282
09:11:29.218 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E244,T705) 127.0.0.1:8,281 ==> :8,282 [NON-2.04 MID=10000, Token=2CD80398ADE00278, OptionSet={"Object-Security":0x},
6d f4 a2 33 14 f7 c2 24 6c 7f 0d 89 f2 a1 51 d8 4e b4 cc 0b 0d b9 c6 f5 d6 dc a7 11 ]
09:11:29.219 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8282) received 42 bytes from localhost/127.0.0.1:8281
09:11:29.219 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[localhost/127.0.0.1:8281-10000]
09:11:29.219 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is OSCORE protected
09:11:29.219 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ResponseDecryptor - Removes E options from outer options which are not allowed there
09:11:29.219 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:29.219 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not considered due to it being disabled for this context
09:11:29.219 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L171, complete]!
09:11:29.219 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L171, complete] for token KeyToken[localhost/127.0.0.1:8281-2CD80398ADE00278]
09:11:29.219 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L171, complete] for MID KeyMID[localhost/127.0.0.1:8281-10000]
09:11:29.219 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - local Exchange[L171, complete] completed CON-POST MID=10000, Token=2CD80398ADE00278, OptionSet={"Object-Security":0x}, "client says hi" -/- CON-POST MID=10000, Token=2CD80398ADE00278, OptionSet={"Object-Security":0x0900}, acked
fe a4 f9 3e 93 68 a0 1f 0c 85 30 2b 44 f3 d2 fe 86 8a 22 9c c3 6d 28 85 !
client received response
09:11:29.220 [main] INFO org.eclipse.californium.core.CoapServer - Destroying server
09:11:29.220 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://127.0.0.1:8281
09:11:29.220 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://127.0.0.1:8281
09:11:29.220 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8281, address localhost/127.0.0.1
09:11:29.221 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [localhost/127.0.0.1:8281] has stopped.
09:11:29.221 [main] INFO org.eclipse.californium.core.CoapServer - CoAP server has been destroyed
End OSCoreServerClientTest
Start OSCoreServerClientTest
09:11:29.221 [main] INFO org.eclipse.californium.core.network.RandomTokenGenerator - using tokens of 8 bytes in length
09:11:29.221 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap using TokenProvider org.eclipse.californium.core.network.RandomTokenGenerator
09:11:29.222 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap CoapEndpoint uses udp plain
09:11:29.222 [main] INFO org.eclipse.californium.core.network.stack.ReliabilityLayer - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
09:11:29.222 [main] INFO org.eclipse.californium.core.network.stack.BlockwiseLayer - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
09:11:29.222 [main] INFO org.eclipse.californium.core.CoapServer - Starting server
09:11:29.222 [main] DEBUG org.eclipse.californium.elements.util.ExecutorsUtil - remove on cancel: false, split: true, log-diff: 10000
09:11:29.223 [main] DEBUG org.eclipse.californium.core.network.CoapEndpoint - coap Starting endpoint at coap://127.0.0.1:0
09:11:29.223 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap no MessageIdProvider set, using default org.eclipse.californium.core.network.InMemoryMessageIdProvider
09:11:29.223 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
09:11:29.223 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - binding to port 0, address localhost/127.0.0.1
09:11:29.223 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - assigned port 8283
09:11:29.223 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector starts up 1 sender threads and 1 receiver threads
09:11:29.224 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Receiver-localhost/127.0.0.1:0[0]]
09:11:29.224 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector listening on localhost/127.0.0.1:8283, recv buf = 0, send buf = 0, recv packet size = 2048
09:11:29.224 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Sender-localhost/127.0.0.1:0[0]]
09:11:29.224 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Started endpoint at coap://127.0.0.1:8283
client sent request
09:11:29.225 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityContextLayer - Request: CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x}, "client says hi"
09:11:29.225 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L173] send request, failed transmissions: 0
09:11:29.225 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L173] prepare retransmission for CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x}, "client says hi"
09:11:29.225 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Request: CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x}, "client says hi"
09:11:29.225 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L173] replace CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x}, "client says hi" by CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x090077},
5e 5d b6 cf 0c b0 66 2f 4a 67 7b dc ae 8b f0 fb e0 e5 f9 4b 44 13 c8 41
09:11:29.226 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L173] added with KeyMID[localhost/127.0.0.1:8283-10000], CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x090077},
5e 5d b6 cf 0c b0 66 2f 4a 67 7b dc ae 8b f0 fb e0 e5 f9 4b 44 13 c8 41
09:11:29.226 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L173] added with generated token KeyToken[localhost/127.0.0.1:8283-8082D30528394163], CON-POST MID=10000, Token=8082D30528394163, OptionSet={"Object-Security":0x090077},
5e 5d b6 cf 0c b0 66 2f 4a 67 7b dc ae 8b f0 fb e0 e5 f9 4b 44 13 c8 41
09:11:29.226 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.UdpMatcher - tracking open request [KeyMID[localhost/127.0.0.1:8283-10000], KeyToken[localhost/127.0.0.1:8283-8082D30528394163]]
09:11:29.226 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.HashMapCtxDB - Token exists, but this could be a refresh if not there is a problem
09:11:29.226 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:0[0],5,Californium/Elements]) sent 41 bytes to localhost/127.0.0.1:8283
09:11:29.227 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E245,T714) 127.0.0.1:8,282 ==> :8,283 [CON-POST MID=10000, Token=8082D30528394163, OptionSet={"Object-Security":0x090077},
5e 5d b6 cf 0c b0 66 2f 4a 67 7b dc ae 8b f0 fb e0 e5 f9 4b 44 13 c8 41 ]
09:11:29.227 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (localhost:8283) received 41 bytes from localhost/127.0.0.1:8282
09:11:29.227 [CoapServer(main)#4] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[localhost/127.0.0.1:8282-10000]
09:11:29.227 [CoapServer(main)#5] INFO org.eclipse.californium.oscore.RequestDecryptor - Removes E options from outer options which are not allowed there
09:11:29.227 [CoapServer(main)#5] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:29.227 [CoapServer(main)#5] ERROR org.eclipse.californium.oscore.RequestDecryptor - Security context not found
09:11:29.227 [CoapServer(main)#5] ERROR org.eclipse.californium.oscore.ObjectSecurityLayer - Error while receiving OSCore request: Security context not found
09:11:29.228 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R174, complete]!
09:11:29.228 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R174, complete] completed ACK-4.01 MID=10000, Token=8082D30528394163, OptionSet={"Content-Format":"text/plain", "Max-Age":0}, "Security context not fou".. 26 bytes!
09:11:29.228 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 41 bytes to localhost/127.0.0.1:8282
09:11:29.228 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E246,T705) 127.0.0.1:8,283 ==> :8,282 [ACK-4.01 MID=10000, Token=8082D30528394163, OptionSet={"Content-Format":"text/plain", "Max-Age":0}, "Security context not fou".. 26 bytes]
09:11:29.229 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8282) received 41 bytes from localhost/127.0.0.1:8283
09:11:29.229 [:CoapEndpoint-UDP-0.0.0.0:0#1] WARN org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is NOT OSCORE protected!
09:11:29.229 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L173, complete]!
09:11:29.229 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L173, complete] for token KeyToken[localhost/127.0.0.1:8283-8082D30528394163]
09:11:29.229 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L173, complete] for MID KeyMID[localhost/127.0.0.1:8283-10000]
09:11:29.229 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - local Exchange[L173, complete] completed CON-POST MID=10000, Token=8082D30528394163, OptionSet={"Object-Security":0x}, "client says hi" -/- CON-POST MID=10000, Token=8082D30528394163, OptionSet={"Object-Security":0x090077}, acked
5e 5d b6 cf 0c b0 66 2f 4a 67 7b dc ae 8b f0 fb e0 e5 f9 4b 44 13 c8 41 !
client received response
09:11:29.229 [main] INFO org.eclipse.californium.core.CoapServer - Destroying server
09:11:29.230 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://127.0.0.1:8283
09:11:29.230 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://127.0.0.1:8283
09:11:29.230 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8283, address localhost/127.0.0.1
09:11:29.230 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [localhost/127.0.0.1:8283] has stopped.
09:11:29.230 [main] INFO org.eclipse.californium.core.CoapServer - CoAP server has been destroyed
End OSCoreServerClientTest
Start OSCoreServerClientTest
09:11:29.231 [main] INFO org.eclipse.californium.core.network.RandomTokenGenerator - using tokens of 8 bytes in length
09:11:29.231 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap using TokenProvider org.eclipse.californium.core.network.RandomTokenGenerator
09:11:29.231 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap CoapEndpoint uses udp plain
09:11:29.231 [main] INFO org.eclipse.californium.core.network.stack.ReliabilityLayer - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
09:11:29.231 [main] INFO org.eclipse.californium.core.network.stack.BlockwiseLayer - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
09:11:29.231 [main] INFO org.eclipse.californium.core.CoapServer - Starting server
09:11:29.232 [main] DEBUG org.eclipse.californium.elements.util.ExecutorsUtil - remove on cancel: false, split: true, log-diff: 10000
09:11:29.275 [main] DEBUG org.eclipse.californium.core.network.CoapEndpoint - coap Starting endpoint at coap://127.0.0.1:0
09:11:29.275 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap no MessageIdProvider set, using default org.eclipse.californium.core.network.InMemoryMessageIdProvider
09:11:29.275 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
09:11:29.275 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - binding to port 0, address localhost/127.0.0.1
09:11:29.275 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - assigned port 8284
09:11:29.276 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector starts up 1 sender threads and 1 receiver threads
09:11:29.276 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Receiver-localhost/127.0.0.1:0[0]]
09:11:29.276 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector listening on localhost/127.0.0.1:8284, recv buf = 0, send buf = 0, recv packet size = 2048
09:11:29.276 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Sender-localhost/127.0.0.1:0[0]]
09:11:29.276 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Started endpoint at coap://127.0.0.1:8284
client sent request
09:11:29.278 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityContextLayer - Request: CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x}, "client says hi"
09:11:29.278 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L175] send request, failed transmissions: 0
09:11:29.278 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L175] prepare retransmission for CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x}, "client says hi"
09:11:29.278 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Request: CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x}, "client says hi"
09:11:29.278 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L175] replace CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x}, "client says hi" by CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x0900},
fe a4 f9 3e 93 68 a0 1f 0c 85 30 2b 44 f3 d2 fe 86 8a 22 9c c3 6d 28 85
09:11:29.279 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L175] added with KeyMID[localhost/127.0.0.1:8284-10000], CON-POST MID=10000, Token=null, OptionSet={"Object-Security":0x0900},
fe a4 f9 3e 93 68 a0 1f 0c 85 30 2b 44 f3 d2 fe 86 8a 22 9c c3 6d 28 85
09:11:29.279 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L175] added with generated token KeyToken[localhost/127.0.0.1:8284-3C3A4E67BC494271], CON-POST MID=10000, Token=3C3A4E67BC494271, OptionSet={"Object-Security":0x0900},
fe a4 f9 3e 93 68 a0 1f 0c 85 30 2b 44 f3 d2 fe 86 8a 22 9c c3 6d 28 85
09:11:29.279 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.UdpMatcher - tracking open request [KeyMID[localhost/127.0.0.1:8284-10000], KeyToken[localhost/127.0.0.1:8284-3C3A4E67BC494271]]
09:11:29.279 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.HashMapCtxDB - Token exists, but this could be a refresh if not there is a problem
09:11:29.279 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:0[0],5,Californium/Elements]) sent 40 bytes to localhost/127.0.0.1:8284
09:11:29.280 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E247,T723) 127.0.0.1:8,282 ==> :8,284 [CON-POST MID=10000, Token=3C3A4E67BC494271, OptionSet={"Object-Security":0x0900},
fe a4 f9 3e 93 68 a0 1f 0c 85 30 2b 44 f3 d2 fe 86 8a 22 9c c3 6d 28 85 ]
09:11:29.280 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (localhost:8284) received 40 bytes from localhost/127.0.0.1:8282
09:11:29.280 [CoapServer(main)#4] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[localhost/127.0.0.1:8282-10000]
09:11:29.281 [CoapServer(main)#5] ERROR org.eclipse.californium.oscore.ObjectSecurityLayer - Error while receiving OSCore request: Security context not found (resend with ID Context)
09:11:29.281 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R176, complete]!
09:11:29.281 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R176, complete] completed ACK-4.01 MID=10000, Token=3C3A4E67BC494271, OptionSet={"Content-Format":"text/plain", "Max-Age":0}, "Security context not fou".. 51 bytes!
09:11:29.281 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 66 bytes to localhost/127.0.0.1:8282
09:11:29.281 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E248,T705) 127.0.0.1:8,284 ==> :8,282 [ACK-4.01 MID=10000, Token=3C3A4E67BC494271, OptionSet={"Content-Format":"text/plain", "Max-Age":0}, "Security context not fou".. 51 bytes]
09:11:29.281 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8282) received 66 bytes from localhost/127.0.0.1:8284
09:11:29.282 [:CoapEndpoint-UDP-0.0.0.0:0#1] WARN org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is NOT OSCORE protected!
09:11:29.282 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L175, complete]!
09:11:29.282 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L175, complete] for token KeyToken[localhost/127.0.0.1:8284-3C3A4E67BC494271]
09:11:29.282 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L175, complete] for MID KeyMID[localhost/127.0.0.1:8284-10000]
09:11:29.282 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - local Exchange[L175, complete] completed CON-POST MID=10000, Token=3C3A4E67BC494271, OptionSet={"Object-Security":0x}, "client says hi" -/- CON-POST MID=10000, Token=3C3A4E67BC494271, OptionSet={"Object-Security":0x0900}, acked
fe a4 f9 3e 93 68 a0 1f 0c 85 30 2b 44 f3 d2 fe 86 8a 22 9c c3 6d 28 85 !
client received response
client sent request
09:11:29.282 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityContextLayer - Request: CON-POST MID=10001, Token=null, OptionSet={"Object-Security":0x}, "client says hi"
09:11:29.282 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L177] send request, failed transmissions: 0
09:11:29.282 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L177] prepare retransmission for CON-POST MID=10001, Token=null, OptionSet={"Object-Security":0x}, "client says hi"
09:11:29.283 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Request: CON-POST MID=10001, Token=null, OptionSet={"Object-Security":0x}, "client says hi"
09:11:29.283 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L177] replace CON-POST MID=10001, Token=null, OptionSet={"Object-Security":0x}, "client says hi" by CON-POST MID=10001, Token=null, OptionSet={"Object-Security":0x1901087465737474657374},
54 db d3 64 a0 36 bd 2e 8c 33 a1 00 20 19 5d c0 c0 b4 1b 6d ed 17 14 2a
09:11:29.283 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L177] added with KeyMID[localhost/127.0.0.1:8284-10001], CON-POST MID=10001, Token=null, OptionSet={"Object-Security":0x1901087465737474657374},
54 db d3 64 a0 36 bd 2e 8c 33 a1 00 20 19 5d c0 c0 b4 1b 6d ed 17 14 2a
09:11:29.283 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L177] added with generated token KeyToken[localhost/127.0.0.1:8284-1827362D8578455C], CON-POST MID=10001, Token=1827362D8578455C, OptionSet={"Object-Security":0x1901087465737474657374},
54 db d3 64 a0 36 bd 2e 8c 33 a1 00 20 19 5d c0 c0 b4 1b 6d ed 17 14 2a
09:11:29.284 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.UdpMatcher - tracking open request [KeyMID[localhost/127.0.0.1:8284-10001], KeyToken[localhost/127.0.0.1:8284-1827362D8578455C]]
09:11:29.284 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.HashMapCtxDB - Token exists, but this could be a refresh if not there is a problem
09:11:29.284 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:0[0],5,Californium/Elements]) sent 49 bytes to localhost/127.0.0.1:8284
09:11:29.284 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E249,T723) 127.0.0.1:8,282 ==> :8,284 [CON-POST MID=10001, Token=1827362D8578455C, OptionSet={"Object-Security":0x1901087465737474657374},
54 db d3 64 a0 36 bd 2e 8c 33 a1 00 20 19 5d c0 c0 b4 1b 6d ed 17 14 2a ]
09:11:29.284 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (localhost:8284) received 49 bytes from localhost/127.0.0.1:8282
09:11:29.285 [CoapServer(main)#6] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[localhost/127.0.0.1:8282-10001]
09:11:29.285 [CoapServer(main)#7] INFO org.eclipse.californium.oscore.RequestDecryptor - Removes E options from outer options which are not allowed there
09:11:29.285 [CoapServer(main)#7] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:29.285 [CoapServer(main)#7] INFO org.eclipse.californium.oscore.Decryptor - Received KID Context: [7465737474657374]
09:11:29.285 [CoapServer(main)#7] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not initiated due to it being disabled for this context
09:11:29.286 [CoapServer(main)#7] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R178] replace CON-POST MID=10001, Token=1827362D8578455C, OptionSet={"Object-Security":0x}, "client says hi" by CON-POST MID=10001, Token=1827362D8578455C, OptionSet={"Object-Security":0x}, "client says hi"
server received request
09:11:29.286 [CoapServer(main)#7] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[R178] send response NON-2.05 MID=10001, Token=null, OptionSet={}, "server responds hi", failed transmissions: 0
09:11:29.287 [CoapServer(main)#7] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R178, complete]!
09:11:29.287 [CoapServer(main)#7] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R178, complete] completed NON-2.04 MID=10001, Token=1827362D8578455C, OptionSet={"Object-Security":0x},
e8 23 1b 45 31 f2 d2 c2 4b 05 8e 21 3f 44 2b c9 5b eb 47 7a ae ef 6c 53 db a7 10 bc !
09:11:29.287 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 42 bytes to localhost/127.0.0.1:8282
09:11:29.287 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E250,T705) 127.0.0.1:8,284 ==> :8,282 [NON-2.04 MID=10001, Token=1827362D8578455C, OptionSet={"Object-Security":0x},
e8 23 1b 45 31 f2 d2 c2 4b 05 8e 21 3f 44 2b c9 5b eb 47 7a ae ef 6c 53 db a7 10 bc ]
09:11:29.288 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8282) received 42 bytes from localhost/127.0.0.1:8284
09:11:29.288 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[localhost/127.0.0.1:8284-10001]
09:11:29.288 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is OSCORE protected
09:11:29.288 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ResponseDecryptor - Removes E options from outer options which are not allowed there
09:11:29.288 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:29.288 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not considered due to it being disabled for this context
09:11:29.288 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L177, complete]!
09:11:29.288 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L177, complete] for token KeyToken[localhost/127.0.0.1:8284-1827362D8578455C]
09:11:29.288 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L177, complete] for MID KeyMID[localhost/127.0.0.1:8284-10001]
09:11:29.288 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - local Exchange[L177, complete] completed CON-POST MID=10001, Token=1827362D8578455C, OptionSet={"Object-Security":0x}, "client says hi" -/- CON-POST MID=10001, Token=1827362D8578455C, OptionSet={"Object-Security":0x1901087465737474657374}, acked
54 db d3 64 a0 36 bd 2e 8c 33 a1 00 20 19 5d c0 c0 b4 1b 6d ed 17 14 2a !
client received response
09:11:29.289 [main] INFO org.eclipse.californium.core.CoapServer - Destroying server
09:11:29.289 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://127.0.0.1:8284
09:11:29.289 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://127.0.0.1:8284
09:11:29.289 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8284, address localhost/127.0.0.1
09:11:29.290 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [localhost/127.0.0.1:8284] has stopped.
09:11:29.290 [main] INFO org.eclipse.californium.core.CoapServer - CoAP server has been destroyed
End OSCoreServerClientTest
09:11:29.290 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 0 rules active.
09:11:29.290 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://0.0.0.0:8282
09:11:29.290 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://0.0.0.0:8282
09:11:29.290 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8282, address 0.0.0.0/0.0.0.0
09:11:29.290 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [0.0.0.0/0.0.0.0:8282] has stopped.
09:11:29.291 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
[INFO] Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.082 s - in org.eclipse.californium.oscore.OSCoreServerClientTest
[INFO] Running org.eclipse.californium.oscore.EndpointContextInfoTest
Start EndpointContextInfoTest
09:11:29.292 [main] INFO org.eclipse.californium.core.network.RandomTokenGenerator - using tokens of 8 bytes in length
09:11:29.292 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap using TokenProvider org.eclipse.californium.core.network.RandomTokenGenerator
09:11:29.292 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap CoapEndpoint uses udp plain
09:11:29.292 [main] INFO org.eclipse.californium.core.network.stack.ReliabilityLayer - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
09:11:29.292 [main] INFO org.eclipse.californium.core.network.stack.BlockwiseLayer - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
09:11:29.293 [main] INFO org.eclipse.californium.core.CoapServer - Starting server
09:11:29.293 [main] DEBUG org.eclipse.californium.elements.util.ExecutorsUtil - remove on cancel: false, split: true, log-diff: 10000
09:11:29.294 [main] DEBUG org.eclipse.californium.core.network.CoapEndpoint - coap Starting endpoint at coap://127.0.0.1:0
09:11:29.294 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap no MessageIdProvider set, using default org.eclipse.californium.core.network.InMemoryMessageIdProvider
09:11:29.294 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
09:11:29.294 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - binding to port 0, address localhost/127.0.0.1
09:11:29.294 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - assigned port 8285
09:11:29.294 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector starts up 1 sender threads and 1 receiver threads
09:11:29.294 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector listening on localhost/127.0.0.1:8285, recv buf = 0, send buf = 0, recv packet size = 2048
09:11:29.294 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Receiver-localhost/127.0.0.1:0[0]]
09:11:29.295 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Started endpoint at coap://127.0.0.1:8285
09:11:29.295 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Sender-localhost/127.0.0.1:0[0]]
09:11:29.295 [main] INFO org.eclipse.californium.core.network.RandomTokenGenerator - using tokens of 8 bytes in length
09:11:29.296 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap using TokenProvider org.eclipse.californium.core.network.RandomTokenGenerator
09:11:29.296 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap CoapEndpoint uses udp plain
09:11:29.296 [main] INFO org.eclipse.californium.core.network.stack.ReliabilityLayer - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
09:11:29.296 [main] INFO org.eclipse.californium.core.network.stack.BlockwiseLayer - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
09:11:29.296 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Endpoint [coap://0.0.0.0:0] requires an executor to start, using default single-threaded daemon executor
09:11:29.296 [main] DEBUG org.eclipse.californium.core.network.CoapEndpoint - coap Starting endpoint at coap://0.0.0.0:0
09:11:29.296 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap no MessageIdProvider set, using default org.eclipse.californium.core.network.InMemoryMessageIdProvider
09:11:29.296 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
09:11:29.296 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - binding to port 0, address 0.0.0.0/0.0.0.0
09:11:29.297 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - assigned port 8286
09:11:29.297 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector starts up 1 sender threads and 1 receiver threads
09:11:29.297 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector listening on 0.0.0.0/0.0.0.0:8286, recv buf = 0, send buf = 0, recv packet size = 2048
09:11:29.297 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]]
09:11:29.297 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Sender-0.0.0.0/0.0.0.0:0[0]]
09:11:29.297 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Started endpoint at coap://0.0.0.0:8286
09:11:29.297 [main] INFO org.eclipse.californium.core.network.EndpointManager - created implicit endpoint coap://0.0.0.0:8286 for coap
client sent request
09:11:29.298 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityContextLayer - Request: CON-GET MID= -1, Token=null, OptionSet={"Object-Security":0x}, no payload
09:11:29.298 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L179] send request, failed transmissions: 0
09:11:29.298 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L179] prepare retransmission for CON-GET MID= -1, Token=null, OptionSet={"Object-Security":0x}, no payload
09:11:29.299 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Request: CON-GET MID= -1, Token=null, OptionSet={"Object-Security":0x}, no payload
09:11:29.299 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L179] replace CON-GET MID= -1, Token=null, OptionSet={"Object-Security":0x}, no payload by CON-POST MID= -1, Token=null, OptionSet={"Object-Security":0x090077665544}, 47 95 96 04 da cd 5c df 79
09:11:29.299 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L179] added with generated mid KeyMID[127.0.0.1:8285-50902], CON-POST MID=50902, Token=null, OptionSet={"Object-Security":0x090077665544}, 47 95 96 04 da cd 5c df 79
09:11:29.299 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L179] added with generated token KeyToken[127.0.0.1:8285-642F8A0E74CD6DD6], CON-POST MID=50902, Token=642F8A0E74CD6DD6, OptionSet={"Object-Security":0x090077665544}, 47 95 96 04 da cd 5c df 79
09:11:29.299 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.UdpMatcher - tracking open request [KeyMID[127.0.0.1:8285-50902], KeyToken[127.0.0.1:8285-642F8A0E74CD6DD6]]
09:11:29.299 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.HashMapCtxDB - Token exists, but this could be a refresh if not there is a problem
Client: Request endpoint context type: class org.eclipse.californium.elements.MapBasedEndpointContext
09:11:29.300 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:0[0],5,Californium/Elements]) sent 29 bytes to /127.0.0.1:8285
09:11:29.300 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E251,T734) 127.0.0.1:8,286 ==> :8,285 [CON-POST MID=50902, Token=642F8A0E74CD6DD6, OptionSet={"Object-Security":0x090077665544}, 47 95 96 04 da cd 5c df 79 ]
09:11:29.300 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (localhost:8285) received 29 bytes from /127.0.0.1:8286
09:11:29.301 [CoapServer(main)#4] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[127.0.0.1:8286-50902]
09:11:29.301 [CoapServer(main)#5] INFO org.eclipse.californium.oscore.RequestDecryptor - Removes E options from outer options which are not allowed there
09:11:29.301 [CoapServer(main)#5] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:29.301 [CoapServer(main)#5] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not initiated due to it being disabled for this context
09:11:29.302 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R180] replace CON-POST MID=50902, Token=642F8A0E74CD6DD6, OptionSet={"Object-Security":0x77665544}, no payload by CON-GET MID=50902, Token=642F8A0E74CD6DD6, OptionSet={"Object-Security":0x}, no payload
server received request
Server: Request source context type: class org.eclipse.californium.elements.MapBasedEndpointContext
09:11:29.302 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[R180] send response null-2.05 MID= -1, Token=null, OptionSet={}, "server responds hi", failed transmissions: 0
09:11:29.302 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R180, complete]!
09:11:29.302 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R180, complete] completed ACK-2.04 MID=50902, Token=642F8A0E74CD6DD6, OptionSet={"Object-Security":0x},
20 3b 16 70 eb 54 b7 48 b8 ae 38 17 01 81 8a e9 f5 6f 6d 8c 50 71 dc 1d 31 91 52 ba !
Server: Response destination context type: class org.eclipse.californium.elements.MapBasedEndpointContext
09:11:29.303 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 42 bytes to /127.0.0.1:8286
09:11:29.303 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E252,T737) 127.0.0.1:8,285 ==> :8,286 [ACK-2.04 MID=50902, Token=642F8A0E74CD6DD6, OptionSet={"Object-Security":0x},
20 3b 16 70 eb 54 b7 48 b8 ae 38 17 01 81 8a e9 f5 6f 6d 8c 50 71 dc 1d 31 91 52 ba ]
09:11:29.303 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8286) received 42 bytes from localhost/127.0.0.1:8285
09:11:29.303 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is OSCORE protected
09:11:29.304 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ResponseDecryptor - Removes E options from outer options which are not allowed there
09:11:29.304 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:29.304 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not considered due to it being disabled for this context
09:11:29.304 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L179, complete]!
09:11:29.304 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L179, complete] for token KeyToken[127.0.0.1:8285-642F8A0E74CD6DD6]
09:11:29.304 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L179, complete] for MID KeyMID[127.0.0.1:8285-50902]
09:11:29.304 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - local Exchange[L179, complete] completed CON-GET MID= -1, Token=642F8A0E74CD6DD6, OptionSet={"Object-Security":0x}, no payload -/- CON-POST MID=50902, Token=642F8A0E74CD6DD6, OptionSet={"Object-Security":0x090077665544}, acked 47 95 96 04 da cd 5c df 79 !
client received response
09:11:29.304 [main] INFO org.eclipse.californium.core.CoapServer - Destroying server
09:11:29.305 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://127.0.0.1:8285
09:11:29.305 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://127.0.0.1:8285
09:11:29.305 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8285, address localhost/127.0.0.1
09:11:29.305 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [localhost/127.0.0.1:8285] has stopped.
09:11:29.305 [main] INFO org.eclipse.californium.core.CoapServer - CoAP server has been destroyed
End EndpointContextInfoTest
Start EndpointContextInfoTest
09:11:29.306 [main] INFO org.eclipse.californium.core.network.RandomTokenGenerator - using tokens of 8 bytes in length
09:11:29.306 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap using TokenProvider org.eclipse.californium.core.network.RandomTokenGenerator
09:11:29.306 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap CoapEndpoint uses udp plain
09:11:29.306 [main] INFO org.eclipse.californium.core.network.stack.ReliabilityLayer - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
09:11:29.306 [main] INFO org.eclipse.californium.core.network.stack.BlockwiseLayer - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
09:11:29.307 [main] INFO org.eclipse.californium.core.CoapServer - Starting server
09:11:29.307 [main] DEBUG org.eclipse.californium.elements.util.ExecutorsUtil - remove on cancel: false, split: true, log-diff: 10000
09:11:29.307 [main] DEBUG org.eclipse.californium.core.network.CoapEndpoint - coap Starting endpoint at coap://127.0.0.1:0
09:11:29.308 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap no MessageIdProvider set, using default org.eclipse.californium.core.network.InMemoryMessageIdProvider
09:11:29.308 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
09:11:29.308 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - binding to port 0, address localhost/127.0.0.1
09:11:29.308 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - assigned port 8287
09:11:29.308 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector starts up 1 sender threads and 1 receiver threads
09:11:29.308 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector listening on localhost/127.0.0.1:8287, recv buf = 0, send buf = 0, recv packet size = 2048
09:11:29.308 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Receiver-localhost/127.0.0.1:0[0]]
09:11:29.308 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Sender-localhost/127.0.0.1:0[0]]
09:11:29.308 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Started endpoint at coap://127.0.0.1:8287
client sent request
Client: Request destination context type: class org.eclipse.californium.elements.AddressEndpointContext
09:11:29.309 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityContextLayer - Request: CON-GET MID= -1, Token=null, OptionSet={"Object-Security":0x}, no payload
09:11:29.310 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L181] send request, failed transmissions: 0
09:11:29.310 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L181] prepare retransmission for CON-GET MID= -1, Token=null, OptionSet={"Object-Security":0x}, no payload
09:11:29.310 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Request: CON-GET MID= -1, Token=null, OptionSet={"Object-Security":0x}, no payload
09:11:29.310 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L181] replace CON-GET MID= -1, Token=null, OptionSet={"Object-Security":0x}, no payload by CON-POST MID= -1, Token=null, OptionSet={"Object-Security":0x090077665544}, 47 95 96 04 da cd 5c df 79
09:11:29.310 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L181] added with generated mid KeyMID[127.0.0.1:8287-27917], CON-POST MID=27917, Token=null, OptionSet={"Object-Security":0x090077665544}, 47 95 96 04 da cd 5c df 79
09:11:29.311 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L181] added with generated token KeyToken[127.0.0.1:8287-3023CACE7FF340FA], CON-POST MID=27917, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x090077665544}, 47 95 96 04 da cd 5c df 79
09:11:29.311 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.UdpMatcher - tracking open request [KeyMID[127.0.0.1:8287-27917], KeyToken[127.0.0.1:8287-3023CACE7FF340FA]]
09:11:29.311 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.HashMapCtxDB - Token exists, but this could be a refresh if not there is a problem
09:11:29.311 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:0[0],5,Californium/Elements]) sent 29 bytes to /127.0.0.1:8287
09:11:29.311 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E253,T746) 127.0.0.1:8,286 ==> :8,287 [CON-POST MID=27917, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x090077665544}, 47 95 96 04 da cd 5c df 79 ]
09:11:29.311 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (localhost:8287) received 29 bytes from /127.0.0.1:8286
09:11:29.312 [CoapServer(main)#4] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[127.0.0.1:8286-27917]
09:11:29.312 [CoapServer(main)#5] INFO org.eclipse.californium.oscore.RequestDecryptor - Removes E options from outer options which are not allowed there
09:11:29.312 [CoapServer(main)#5] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:29.312 [CoapServer(main)#5] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not initiated due to it being disabled for this context
09:11:29.313 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R182] replace CON-POST MID=27917, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x77665544}, no payload by CON-GET MID=27917, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x}, no payload
server received request
Server: Request source context type: class org.eclipse.californium.elements.MapBasedEndpointContext
09:11:29.313 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[R182] send response null-2.05 MID= -1, Token=null, OptionSet={}, "server responds hi", failed transmissions: 0
09:11:29.313 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R182, complete]!
09:11:29.313 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R182, complete] completed ACK-2.04 MID=27917, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x},
20 3b 16 70 eb 54 b7 48 b8 ae 38 17 01 81 8a e9 f5 6f 6d 8c 50 71 dc 1d 31 91 52 ba !
Server: Response destination context type: class org.eclipse.californium.elements.MapBasedEndpointContext
09:11:29.314 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 42 bytes to /127.0.0.1:8286
09:11:29.314 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E254,T737) 127.0.0.1:8,287 ==> :8,286 [ACK-2.04 MID=27917, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x},
20 3b 16 70 eb 54 b7 48 b8 ae 38 17 01 81 8a e9 f5 6f 6d 8c 50 71 dc 1d 31 91 52 ba ]
09:11:29.314 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8286) received 42 bytes from localhost/127.0.0.1:8287
09:11:29.315 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is OSCORE protected
09:11:29.315 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ResponseDecryptor - Removes E options from outer options which are not allowed there
09:11:29.315 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:29.315 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not considered due to it being disabled for this context
09:11:29.315 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L181, complete]!
09:11:29.315 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L181, complete] for token KeyToken[127.0.0.1:8287-3023CACE7FF340FA]
09:11:29.315 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L181, complete] for MID KeyMID[127.0.0.1:8287-27917]
09:11:29.315 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - local Exchange[L181, complete] completed CON-GET MID= -1, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x}, no payload -/- CON-POST MID=27917, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x090077665544}, acked 47 95 96 04 da cd 5c df 79 !
client received response
Client: Response source context type: class org.eclipse.californium.elements.MapBasedEndpointContext
client sent second request
09:11:29.316 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityContextLayer - Request: CON-GET MID= -1, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x}, no payload
09:11:29.316 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L183] send request, failed transmissions: 0
09:11:29.316 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L183] prepare retransmission for CON-GET MID= -1, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x}, no payload
09:11:29.316 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Request: CON-GET MID= -1, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x}, no payload
09:11:29.316 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L183] replace CON-GET MID= -1, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x}, no payload by CON-POST MID= -1, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x090177665544}, 37 88 6d 3b 6c 12 ff 8c 24
09:11:29.317 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L183] added with generated mid KeyMID[127.0.0.1:8287-27918], CON-POST MID=27918, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x090177665544}, 37 88 6d 3b 6c 12 ff 8c 24
09:11:29.317 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L183] added with token KeyToken[127.0.0.1:8287-3023CACE7FF340FA], CON-POST MID=27918, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x090177665544}, 37 88 6d 3b 6c 12 ff 8c 24
09:11:29.317 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.UdpMatcher - tracking open request [KeyMID[127.0.0.1:8287-27918], KeyToken[127.0.0.1:8287-3023CACE7FF340FA]]
09:11:29.317 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.HashMapCtxDB - Token exists, but this could be a refresh if not there is a problem
09:11:29.317 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:0[0],5,Californium/Elements]) sent 29 bytes to /127.0.0.1:8287
09:11:29.317 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E255,T746) 127.0.0.1:8,286 ==> :8,287 [CON-POST MID=27918, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x090177665544}, 37 88 6d 3b 6c 12 ff 8c 24 ]
09:11:29.318 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (localhost:8287) received 29 bytes from /127.0.0.1:8286
09:11:29.318 [CoapServer(main)#6] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[127.0.0.1:8286-27918]
09:11:29.318 [CoapServer(main)#7] INFO org.eclipse.californium.oscore.RequestDecryptor - Removes E options from outer options which are not allowed there
09:11:29.318 [CoapServer(main)#7] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:29.318 [CoapServer(main)#7] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not initiated due to it being disabled for this context
09:11:29.319 [CoapServer(main)#7] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R184] replace CON-POST MID=27918, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x77665544}, no payload by CON-GET MID=27918, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x}, no payload
server received request
Server: Request source context type: class org.eclipse.californium.elements.MapBasedEndpointContext
09:11:29.319 [CoapServer(main)#7] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[R184] send response null-2.05 MID= -1, Token=null, OptionSet={}, "server responds hi", failed transmissions: 0
09:11:29.319 [CoapServer(main)#7] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R184, complete]!
09:11:29.319 [CoapServer(main)#7] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R184, complete] completed ACK-2.04 MID=27918, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x},
ce 8b 83 11 cf aa b8 7a a3 46 da f0 99 f2 e9 a7 92 61 e0 e4 b1 60 06 34 15 f8 1c 50 !
Server: Response destination context type: class org.eclipse.californium.elements.MapBasedEndpointContext
09:11:29.320 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 42 bytes to /127.0.0.1:8286
09:11:29.320 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E256,T737) 127.0.0.1:8,287 ==> :8,286 [ACK-2.04 MID=27918, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x},
ce 8b 83 11 cf aa b8 7a a3 46 da f0 99 f2 e9 a7 92 61 e0 e4 b1 60 06 34 15 f8 1c 50 ]
09:11:29.320 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8286) received 42 bytes from localhost/127.0.0.1:8287
09:11:29.320 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is OSCORE protected
09:11:29.320 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ResponseDecryptor - Removes E options from outer options which are not allowed there
09:11:29.320 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:29.320 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not considered due to it being disabled for this context
09:11:29.321 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L183, complete]!
09:11:29.321 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L183, complete] for token KeyToken[127.0.0.1:8287-3023CACE7FF340FA]
09:11:29.321 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L183, complete] for MID KeyMID[127.0.0.1:8287-27918]
09:11:29.321 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - local Exchange[L183, complete] completed CON-GET MID= -1, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x}, no payload -/- CON-POST MID=27918, Token=3023CACE7FF340FA, OptionSet={"Object-Security":0x090177665544}, acked 37 88 6d 3b 6c 12 ff 8c 24 !
client received response
09:11:29.321 [main] INFO org.eclipse.californium.core.CoapServer - Destroying server
09:11:29.322 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://127.0.0.1:8287
09:11:29.322 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://127.0.0.1:8287
09:11:29.322 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8287, address localhost/127.0.0.1
09:11:29.322 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [localhost/127.0.0.1:8287] has stopped.
09:11:29.322 [main] INFO org.eclipse.californium.core.CoapServer - CoAP server has been destroyed
End EndpointContextInfoTest
09:11:29.322 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 0 rules active.
09:11:29.322 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://0.0.0.0:8286
09:11:29.322 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://0.0.0.0:8286
09:11:29.322 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8286, address 0.0.0.0/0.0.0.0
09:11:29.323 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [0.0.0.0/0.0.0.0:8286] has stopped.
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.031 s - in org.eclipse.californium.oscore.EndpointContextInfoTest
[INFO]
[INFO] Results:
[INFO]
[INFO] Tests run: 34, Failures: 0, Errors: 0, Skipped: 0
[INFO]
[INFO]
[INFO] --- jar:3.2.0:jar (default-jar) @ cf-oscore ---
[INFO]
[INFO] --- javadoc:3.3.0:jar (attach-javadocs) @ cf-oscore ---
[INFO] Toolchain in maven-javadoc-plugin: JDK[/opt/tools/java/oracle/jdk-7/latest]
[ERROR] Error fetching link: /home/jenkins/agent/workspace/californium-2.8.x-nightly/legal/target/apidocs. Ignored it.
[INFO] Configuration changed, re-generating javadoc.
[INFO]
Loading source files for package org.eclipse.californium.cose...
Loading source files for package org.eclipse.californium.oscore...
Constructing Javadoc information...
Standard Doclet version 1.7.0_80
Building tree for all the packages and classes...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/AlgorithmID.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/Attribute.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/CoseException.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/Encrypt0Message.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/EncryptCommon.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/HeaderKeys.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/Message.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/MessageTag.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/ByteId.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/CoapOSException.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/CoapOSExceptionHandler.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/ContextRederivation.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/ContextRederivation.PHASE.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/Decryptor.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/Encryptor.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/ErrorDescriptions.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/HashMapCtxDB.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/ObjectSecurityContextLayer.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/ObjectSecurityLayer.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/OptionJuggle.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/OSCoreCoapStackFactory.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/OSCoreCtx.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/OSCoreCtxDB.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/OSCoreEndpointContextInfo.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/OSCoreResource.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/OSCoreStack.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/OSException.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/OSSerializer.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/RequestDecryptor.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/RequestEncryptor.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/ResponseDecryptor.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/ResponseEncryptor.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/overview-frame.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/package-frame.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/package-summary.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/package-tree.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/package-frame.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/package-summary.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/package-tree.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/constant-values.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/serialized-form.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/class-use/MessageTag.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/class-use/Message.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/class-use/HeaderKeys.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/class-use/EncryptCommon.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/class-use/Encrypt0Message.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/class-use/CoseException.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/class-use/Attribute.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/class-use/AlgorithmID.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/ResponseEncryptor.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/ResponseDecryptor.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/RequestEncryptor.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/RequestDecryptor.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/OptionJuggle.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/ObjectSecurityLayer.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/ObjectSecurityContextLayer.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/OSSerializer.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/OSException.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/OSCoreStack.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/OSCoreResource.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/OSCoreEndpointContextInfo.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/OSCoreCtxDB.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/OSCoreCtx.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/OSCoreCoapStackFactory.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/HashMapCtxDB.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/ErrorDescriptions.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/Encryptor.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/Decryptor.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/ContextRederivation.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/ContextRederivation.PHASE.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/CoapOSExceptionHandler.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/CoapOSException.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/class-use/ByteId.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/cose/package-use.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/org/eclipse/californium/oscore/package-use.html...
Building index for all the packages and classes...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/overview-tree.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/index-all.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/deprecated-list.html...
Building index for all classes...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/allclasses-frame.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/allclasses-noframe.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/index.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/overview-summary.html...
Generating /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/apidocs/help-doc.html...
[INFO] Building jar: /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/cf-oscore-2.8.1-SNAPSHOT-javadoc.jar
[INFO]
[INFO] --- assembly:3.3.0:single (make-assembly) @ cf-oscore ---
[WARNING] Parameter 'localRepository' is deprecated core expression; Avoid use of ArtifactRepository type. If you need access to local repository, switch to '${repositorySystemSession}' expression and get LRM from it instead.
[INFO] Building jar: /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/cf-oscore-2.8.1-SNAPSHOT.jar
[INFO]
[INFO] --- surefire:2.22.2:test (large-tests) @ cf-oscore ---
[WARNING] Parameter 'localRepository' is deprecated core expression; Avoid use of ArtifactRepository type. If you need access to local repository, switch to '${repositorySystemSession}' expression and get LRM from it instead.
[INFO] Toolchain in maven-surefire-plugin: JDK[/opt/tools/java/oracle/jdk-7/latest]
[INFO]
[INFO] -------------------------------------------------------
[INFO] T E S T S
[INFO] -------------------------------------------------------
09:11:34.335 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
[INFO] Running org.eclipse.californium.oscore.OSCoreObserveTest
09:11:34.370 [main] INFO org.eclipse.californium.elements.rule.TestNameLoggerRule - Test testObserve
09:11:34.668 [main] INFO org.eclipse.californium.core.network.RandomTokenGenerator - using tokens of 8 bytes in length
09:11:34.677 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap using TokenProvider org.eclipse.californium.core.network.RandomTokenGenerator
09:11:34.681 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap CoapEndpoint uses udp plain
09:11:34.695 [main] INFO org.eclipse.californium.core.network.stack.ReliabilityLayer - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
09:11:34.704 [main] INFO org.eclipse.californium.core.network.stack.BlockwiseLayer - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
09:11:34.720 [main] INFO org.eclipse.californium.core.CoapServer - Starting server
09:11:34.723 [main] DEBUG org.eclipse.californium.elements.util.ExecutorsUtil - remove on cancel: false, split: true, log-diff: 10000
09:11:34.725 [main] DEBUG org.eclipse.californium.core.network.CoapEndpoint - coap Starting endpoint at coap://127.0.0.1:0
09:11:34.729 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap no MessageIdProvider set, using default org.eclipse.californium.core.network.InMemoryMessageIdProvider
09:11:34.734 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
09:11:34.734 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - binding to port 0, address localhost/127.0.0.1
09:11:34.735 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - assigned port 8192
09:11:34.735 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector starts up 1 sender threads and 1 receiver threads
09:11:34.738 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector listening on localhost/127.0.0.1:8192, recv buf = 0, send buf = 0, recv packet size = 2048
09:11:34.738 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Receiver-localhost/127.0.0.1:0[0]]
09:11:34.738 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Sender-localhost/127.0.0.1:0[0]]
09:11:34.738 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Started endpoint at coap://127.0.0.1:8192
09:11:34.751 [main] DEBUG org.eclipse.californium.elements.util.NetworkInterfacesUtil - Found broadcast address /10.40.25.255 - eth0.
09:11:34.751 [main] INFO org.eclipse.californium.core.network.RandomTokenGenerator - using tokens of 8 bytes in length
09:11:34.751 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap using TokenProvider org.eclipse.californium.core.network.RandomTokenGenerator
09:11:34.752 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap CoapEndpoint uses udp plain
09:11:34.752 [main] INFO org.eclipse.californium.core.network.stack.ReliabilityLayer - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
09:11:34.752 [main] INFO org.eclipse.californium.core.network.stack.BlockwiseLayer - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
09:11:34.753 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Endpoint [coap://0.0.0.0:0] requires an executor to start, using default single-threaded daemon executor
09:11:34.755 [main] DEBUG org.eclipse.californium.core.network.CoapEndpoint - coap Starting endpoint at coap://0.0.0.0:0
09:11:34.755 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap no MessageIdProvider set, using default org.eclipse.californium.core.network.InMemoryMessageIdProvider
09:11:34.755 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
09:11:34.755 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - binding to port 0, address 0.0.0.0/0.0.0.0
09:11:34.755 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - assigned port 8193
09:11:34.755 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector starts up 1 sender threads and 1 receiver threads
09:11:34.756 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector listening on 0.0.0.0/0.0.0.0:8193, recv buf = 0, send buf = 0, recv packet size = 2048
09:11:34.756 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]]
09:11:34.756 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Sender-0.0.0.0/0.0.0.0:0[0]]
09:11:34.756 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Started endpoint at coap://0.0.0.0:8193
09:11:34.756 [main] INFO org.eclipse.californium.core.network.EndpointManager - created implicit endpoint coap://0.0.0.0:8193 for coap
09:11:34.783 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityContextLayer - Request: CON-GET MID= -1, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:34.786 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L1] send request, failed transmissions: 0
09:11:34.786 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L1] prepare retransmission for CON-GET MID= -1, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:34.799 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Request: CON-GET MID= -1, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:34.799 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L1] replace CON-GET MID= -1, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload by CON-FETCH MID= -1, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x0900},
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8
09:11:34.802 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.BaseMatcher - registering observe request CON-FETCH MID= 5313, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x0900},
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8
09:11:34.804 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.observe.InMemoryObservationStore - added observation for Token=96E647E5BA0946F9
09:11:34.806 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L1] added with KeyMID[127.0.0.1:8192-5313], CON-FETCH MID= 5313, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x0900},
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8
09:11:34.809 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L1] added with token KeyToken[96E647E5BA0946F9], CON-FETCH MID= 5313, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x0900},
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8
09:11:34.811 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.UdpMatcher - tracking open request [KeyMID[127.0.0.1:8192-5313], KeyToken[96E647E5BA0946F9]]
09:11:34.811 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.HashMapCtxDB - Token exists, but this could be a refresh if not there is a problem
09:11:34.820 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:0[0],5,Californium/Elements]) sent 43 bytes to /127.0.0.1:8192
09:11:34.824 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E1,T16) 127.0.0.1:8,193 ==> :8,192 [CON-FETCH MID= 5313, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x0900},
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8 ]
09:11:34.824 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (localhost:8192) received 43 bytes from /127.0.0.1:8193
09:11:34.826 [CoapServer(main)#4] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[127.0.0.1:8193-5313]
09:11:34.829 [CoapServer(main)#5] INFO org.eclipse.californium.oscore.RequestDecryptor - Removes E options from outer options which are not allowed there
09:11:34.829 [CoapServer(main)#5] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:34.829 [CoapServer(main)#5] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not initiated due to it being disabled for this context
09:11:34.830 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R2] replace CON-FETCH MID= 5313, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload by CON-GET MID= 5313, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:34.831 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.server.ServerMessageDeliverer - initiating an observe relation between /127.0.0.1:8193 and resource /oscore/observe2, Exchange[R2]
09:11:34.839 [CoapServer(main)#5] INFO org.eclipse.californium.core.CoapResource - successfully established observe relation between 127.0.0.1:8193#96E647E5BA0946F9 and resource /oscore/observe2 (Exchange[R2], size 1)
09:11:34.839 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[R2] send response null-2.05 MID= -1, Token=null, OptionSet={"Observe":0, "Content-Format":"text/plain"}, "one", failed transmissions: 0
09:11:34.842 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R2, complete]!
09:11:34.842 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R2, complete] completed ACK-2.04 MID= 5313, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x0100}, 4d d3 3b fc 90 86 bc 88 2f c2 a2 05 c2 2e 96 !
09:11:34.845 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 32 bytes to /127.0.0.1:8193
09:11:34.846 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E2,T19) 127.0.0.1:8,192 ==> :8,193 [ACK-2.04 MID= 5313, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x0100}, 4d d3 3b fc 90 86 bc 88 2f c2 a2 05 c2 2e 96 ]
09:11:34.847 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8193) received 32 bytes from localhost/127.0.0.1:8192
09:11:34.848 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is OSCORE protected
09:11:34.849 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ResponseDecryptor - Removes E options from outer options which are not allowed there
09:11:34.849 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:34.849 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not considered due to it being disabled for this context
09:11:34.850 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L1, complete]!
09:11:34.850 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L1, complete] for token KeyToken[96E647E5BA0946F9]
09:11:34.850 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L1, complete] for MID KeyMID[127.0.0.1:8192-5313]
09:11:34.850 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - local Exchange[L1, complete] completed CON-GET MID= -1, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload -/- CON-FETCH MID= 5313, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x0900}, acked
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8 !
NOTIFICATION: one
09:11:34.855 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.core.test.CountingCoapHandler - Received 1. Notification: ACK-2.05 MID= 5313, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x0100, "Content-Format":"text/plain"}, "one"
09:11:35.472 [CoapServer(main)#6] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[R2] send response NON-2.05 MID= -1, Token=null, OptionSet={"Observe":1, "Content-Format":"text/plain"}, "two", failed transmissions: 0
09:11:35.473 [CoapServer(main)#6] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[R2] added with generated mid KeyMID[127.0.0.1:8193-19214], NON-2.04 MID=19214, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x0101}, 52 82 a2 6b 2d 57 56 04 a8 18 12 c6 9a 79 95 9e
09:11:35.474 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 34 bytes to /127.0.0.1:8193
09:11:35.476 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E3,T19) 127.0.0.1:8,192 ==> :8,193 [NON-2.04 MID=19214, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x0101}, 52 82 a2 6b 2d 57 56 04 a8 18 12 c6 9a 79 95 9e ]
09:11:35.476 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8193) received 34 bytes from localhost/127.0.0.1:8192
09:11:35.477 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.observe.InMemoryObservationStore - looking up observation for token Token=96E647E5BA0946F9: CON-FETCH MID= 5313, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x0900}, acked
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8
09:11:35.480 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.BaseMatcher - re-created exchange from original observe request: CON-FETCH MID= 5313, Token=96E647E5BA0946F9, OptionSet={"Observe":0, "Object-Security":0x0900},
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8
09:11:35.482 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[localhost/127.0.0.1:8192-19214]
09:11:35.482 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is OSCORE protected
09:11:35.482 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ResponseDecryptor - Removes E options from outer options which are not allowed there
09:11:35.482 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:35.482 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not considered due to it being disabled for this context
09:11:35.483 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L3, complete]!
NOTIFICATION: two
09:11:35.483 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.core.test.CountingCoapHandler - Received 2. Notification: NON-2.05 MID=19214, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x0101, "Content-Format":"text/plain"}, "two"
09:11:35.484 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityContextLayer - Request: CON-GET MID= -1, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:35.484 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L4] send request, failed transmissions: 0
09:11:35.485 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L4] prepare retransmission for CON-GET MID= -1, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:35.486 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Request: CON-GET MID= -1, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:35.486 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L4] replace CON-GET MID= -1, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload by CON-FETCH MID= -1, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x0901},
19 95 45 75 db c3 a5 25 33 d0 8d 43 5b fd 48 b9 fb 14 0c c6 c9 b9 4b 14 b1 a5 0a
09:11:35.488 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L4] added with generated mid KeyMID[127.0.0.1:8192-5314], CON-FETCH MID= 5314, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x0901},
19 95 45 75 db c3 a5 25 33 d0 8d 43 5b fd 48 b9 fb 14 0c c6 c9 b9 4b 14 b1 a5 0a
09:11:35.490 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L4] added with token KeyToken[96E647E5BA0946F9], CON-FETCH MID= 5314, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x0901},
19 95 45 75 db c3 a5 25 33 d0 8d 43 5b fd 48 b9 fb 14 0c c6 c9 b9 4b 14 b1 a5 0a
09:11:35.491 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.UdpMatcher - tracking open request [KeyMID[127.0.0.1:8192-5314], KeyToken[96E647E5BA0946F9]]
09:11:35.492 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.HashMapCtxDB - Token exists, but this could be a refresh if not there is a problem
09:11:35.492 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:0[0],5,Californium/Elements]) sent 45 bytes to /127.0.0.1:8192
09:11:35.494 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E4,T16) 127.0.0.1:8,193 ==> :8,192 [CON-FETCH MID= 5314, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x0901},
19 95 45 75 db c3 a5 25 33 d0 8d 43 5b fd 48 b9 fb 14 0c c6 c9 b9 4b 14 b1 a5 0a ]
09:11:35.494 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (localhost:8192) received 45 bytes from /127.0.0.1:8193
09:11:35.494 [CoapServer(main)#7] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[127.0.0.1:8193-5314]
09:11:35.495 [CoapServer(main)#8] INFO org.eclipse.californium.oscore.RequestDecryptor - Removes E options from outer options which are not allowed there
09:11:35.495 [CoapServer(main)#8] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:35.495 [CoapServer(main)#8] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not initiated due to it being disabled for this context
09:11:35.496 [CoapServer(main)#8] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R5] replace CON-FETCH MID= 5314, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload by CON-GET MID= 5314, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:35.497 [CoapServer(main)#8] DEBUG org.eclipse.californium.core.observe.ObserveRelation - Canceling observe relation 127.0.0.1:8193#96E647E5BA0946F9 with /oscore/observe2 (Exchange[R2])
09:11:35.497 [CoapServer(main)#8] INFO org.eclipse.californium.core.CoapResource - remove observe relation between 127.0.0.1:8193#96E647E5BA0946F9 and resource /oscore/observe2 (Exchange[R2], size 0)
09:11:35.498 [CoapServer(main)#9] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R2, complete]!
09:11:35.498 [CoapServer(main)#9] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[R2, complete] for MID KeyMID[127.0.0.1:8193-19214]
09:11:35.498 [CoapServer(main)#8] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[R5] send response null-2.05 MID= -1, Token=null, OptionSet={"Content-Format":"text/plain"}, "two", failed transmissions: 0
09:11:35.499 [CoapServer(main)#8] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R5, complete]!
09:11:35.498 [CoapServer(main)#9] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R2, complete] completed NON-2.04 MID=19214, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x0101}, canceled 52 82 a2 6b 2d 57 56 04 a8 18 12 c6 9a 79 95 9e !
09:11:35.499 [CoapServer(main)#8] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R5, complete] completed ACK-2.04 MID= 5314, Token=96E647E5BA0946F9, OptionSet={"Object-Security":0x0102}, 37 10 24 e0 c9 5c 0f c8 ad ee 14 bd b2 0e !
09:11:35.500 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 30 bytes to /127.0.0.1:8193
09:11:35.502 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E5,T19) 127.0.0.1:8,192 ==> :8,193 [ACK-2.04 MID= 5314, Token=96E647E5BA0946F9, OptionSet={"Object-Security":0x0102}, 37 10 24 e0 c9 5c 0f c8 ad ee 14 bd b2 0e ]
09:11:35.502 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8193) received 30 bytes from localhost/127.0.0.1:8192
09:11:35.502 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is OSCORE protected
09:11:35.502 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ResponseDecryptor - Removes E options from outer options which are not allowed there
09:11:35.502 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:35.502 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not considered due to it being disabled for this context
09:11:35.503 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L4, complete]!
09:11:35.503 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L4, complete] for token KeyToken[96E647E5BA0946F9]
09:11:35.503 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L4, complete] for MID KeyMID[127.0.0.1:8192-5314]
09:11:35.503 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - local Exchange[L4, complete] completed CON-GET MID= -1, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload -/- CON-FETCH MID= 5314, Token=96E647E5BA0946F9, OptionSet={"Observe":1, "Object-Security":0x0901}, acked
19 95 45 75 db c3 a5 25 33 d0 8d 43 5b fd 48 b9 fb 14 0c c6 c9 b9 4b 14 b1 a5 0a !
09:11:35.506 [main] DEBUG org.eclipse.californium.rule.CoapThreadsRule - shutdown
09:11:35.506 [main] INFO org.eclipse.californium.core.CoapServer - Destroying server
09:11:35.507 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://127.0.0.1:8192
09:11:35.508 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://127.0.0.1:8192
09:11:35.508 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8192, address localhost/127.0.0.1
09:11:35.508 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [localhost/127.0.0.1:8192] has stopped.
09:11:35.508 [main] INFO org.eclipse.californium.core.CoapServer - CoAP server has been destroyed
09:11:35.509 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://0.0.0.0:8193
09:11:35.509 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://0.0.0.0:8193
09:11:35.509 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8193, address 0.0.0.0/0.0.0.0
09:11:35.509 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [0.0.0.0/0.0.0.0:8193] has stopped.
09:11:35.509 [main] INFO org.eclipse.californium.elements.rule.TestNameLoggerRule - Test testObserve
09:11:35.510 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 0 rules active.
09:11:35.511 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
09:11:35.511 [main] INFO org.eclipse.californium.elements.rule.TestNameLoggerRule - Test testObserve
09:11:35.512 [main] INFO org.eclipse.californium.core.network.RandomTokenGenerator - using tokens of 8 bytes in length
09:11:35.512 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap using TokenProvider org.eclipse.californium.core.network.RandomTokenGenerator
09:11:35.513 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap CoapEndpoint uses udp plain
09:11:35.513 [main] INFO org.eclipse.californium.core.network.stack.ReliabilityLayer - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
09:11:35.513 [main] INFO org.eclipse.californium.core.network.stack.BlockwiseLayer - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
09:11:35.514 [main] INFO org.eclipse.californium.core.CoapServer - Starting server
09:11:35.514 [main] DEBUG org.eclipse.californium.elements.util.ExecutorsUtil - remove on cancel: false, split: true, log-diff: 10000
09:11:35.515 [main] DEBUG org.eclipse.californium.core.network.CoapEndpoint - coap Starting endpoint at coap://127.0.0.1:0
09:11:35.515 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap no MessageIdProvider set, using default org.eclipse.californium.core.network.InMemoryMessageIdProvider
09:11:35.515 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
09:11:35.515 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - binding to port 0, address localhost/127.0.0.1
09:11:35.515 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - assigned port 8194
09:11:35.515 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector starts up 1 sender threads and 1 receiver threads
09:11:35.516 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector listening on localhost/127.0.0.1:8194, recv buf = 0, send buf = 0, recv packet size = 2048
09:11:35.516 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Receiver-localhost/127.0.0.1:0[0]]
09:11:35.516 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Sender-localhost/127.0.0.1:0[0]]
09:11:35.516 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Started endpoint at coap://127.0.0.1:8194
09:11:35.517 [main] INFO org.eclipse.californium.core.network.RandomTokenGenerator - using tokens of 8 bytes in length
09:11:35.517 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap using TokenProvider org.eclipse.californium.core.network.RandomTokenGenerator
09:11:35.518 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap CoapEndpoint uses udp plain
09:11:35.518 [main] INFO org.eclipse.californium.core.network.stack.ReliabilityLayer - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
09:11:35.518 [main] INFO org.eclipse.californium.core.network.stack.BlockwiseLayer - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
09:11:35.518 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Endpoint [coap://0.0.0.0:0] requires an executor to start, using default single-threaded daemon executor
09:11:35.519 [main] DEBUG org.eclipse.californium.core.network.CoapEndpoint - coap Starting endpoint at coap://0.0.0.0:0
09:11:35.519 [main] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap no MessageIdProvider set, using default org.eclipse.californium.core.network.InMemoryMessageIdProvider
09:11:35.519 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 1 rules active.
09:11:35.519 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - binding to port 0, address 0.0.0.0/0.0.0.0
09:11:35.519 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - assigned port 8195
09:11:35.519 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector starts up 1 sender threads and 1 receiver threads
09:11:35.520 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector listening on 0.0.0.0/0.0.0.0:8195, recv buf = 0, send buf = 0, recv packet size = 2048
09:11:35.520 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]]
09:11:35.520 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - Starting network stage thread [UDP-Sender-0.0.0.0/0.0.0.0:0[0]]
09:11:35.520 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Started endpoint at coap://0.0.0.0:8195
09:11:35.520 [main] INFO org.eclipse.californium.core.network.EndpointManager - created implicit endpoint coap://0.0.0.0:8195 for coap
09:11:35.521 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityContextLayer - Request: CON-GET MID= -1, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:35.521 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L6] send request, failed transmissions: 0
09:11:35.521 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L6] prepare retransmission for CON-GET MID= -1, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:35.523 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Request: CON-GET MID= -1, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:35.523 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L6] replace CON-GET MID= -1, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload by CON-FETCH MID= -1, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x0900},
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8
09:11:35.525 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.BaseMatcher - registering observe request CON-FETCH MID=20322, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x0900},
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8
09:11:35.526 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.observe.InMemoryObservationStore - added observation for Token=334030B2ADABBE88
09:11:35.526 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L6] added with KeyMID[127.0.0.1:8194-20322], CON-FETCH MID=20322, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x0900},
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8
09:11:35.528 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L6] added with token KeyToken[334030B2ADABBE88], CON-FETCH MID=20322, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x0900},
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8
09:11:35.529 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.UdpMatcher - tracking open request [KeyMID[127.0.0.1:8194-20322], KeyToken[334030B2ADABBE88]]
09:11:35.529 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.HashMapCtxDB - Token exists, but this could be a refresh if not there is a problem
09:11:35.530 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:0[0],5,Californium/Elements]) sent 43 bytes to /127.0.0.1:8194
09:11:35.531 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E6,T34) 127.0.0.1:8,195 ==> :8,194 [CON-FETCH MID=20322, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x0900},
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8 ]
09:11:35.531 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (localhost:8194) received 43 bytes from /127.0.0.1:8195
09:11:35.532 [CoapServer(main)#4] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[127.0.0.1:8195-20322]
09:11:35.532 [CoapServer(main)#5] INFO org.eclipse.californium.oscore.RequestDecryptor - Removes E options from outer options which are not allowed there
09:11:35.532 [CoapServer(main)#5] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:35.533 [CoapServer(main)#5] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not initiated due to it being disabled for this context
09:11:35.533 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R7] replace CON-FETCH MID=20322, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload by CON-GET MID=20322, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:35.534 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.server.ServerMessageDeliverer - initiating an observe relation between /127.0.0.1:8195 and resource /oscore/observe2, Exchange[R7]
09:11:35.534 [CoapServer(main)#5] INFO org.eclipse.californium.core.CoapResource - successfully established observe relation between 127.0.0.1:8195#334030B2ADABBE88 and resource /oscore/observe2 (Exchange[R7], size 1)
09:11:35.534 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[R7] send response null-2.05 MID= -1, Token=null, OptionSet={"Observe":0, "Content-Format":"text/plain"}, "one", failed transmissions: 0
09:11:35.535 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R7, complete]!
09:11:35.535 [CoapServer(main)#5] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R7, complete] completed ACK-2.04 MID=20322, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x0100}, 4d d3 3b fc 90 86 bc 88 2f c2 a2 05 c2 2e 96 !
09:11:35.536 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 32 bytes to /127.0.0.1:8195
09:11:35.537 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E7,T37) 127.0.0.1:8,194 ==> :8,195 [ACK-2.04 MID=20322, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x0100}, 4d d3 3b fc 90 86 bc 88 2f c2 a2 05 c2 2e 96 ]
09:11:35.537 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8195) received 32 bytes from localhost/127.0.0.1:8194
09:11:35.538 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is OSCORE protected
09:11:35.538 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ResponseDecryptor - Removes E options from outer options which are not allowed there
09:11:35.538 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:35.538 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not considered due to it being disabled for this context
09:11:35.538 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L6, complete]!
09:11:35.539 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L6, complete] for token KeyToken[334030B2ADABBE88]
09:11:35.539 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L6, complete] for MID KeyMID[127.0.0.1:8194-20322]
09:11:35.539 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - local Exchange[L6, complete] completed CON-GET MID= -1, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload -/- CON-FETCH MID=20322, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x0900}, acked
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8 !
NOTIFICATION: one
09:11:35.541 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.core.test.CountingCoapHandler - Received 1. Notification: ACK-2.05 MID=20322, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x0100, "Content-Format":"text/plain"}, "one"
09:11:36.264 [CoapServer(main)#6] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[R7] send response NON-2.05 MID= -1, Token=null, OptionSet={"Observe":1, "Content-Format":"text/plain"}, "two", failed transmissions: 0
09:11:36.266 [CoapServer(main)#6] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[R7] added with generated mid KeyMID[127.0.0.1:8195-29828], NON-2.04 MID=29828, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x0101}, 52 82 a2 6b 2d 57 56 04 a8 18 12 c6 9a 79 95 9e
09:11:36.267 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 34 bytes to /127.0.0.1:8195
09:11:36.268 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E8,T37) 127.0.0.1:8,194 ==> :8,195 [NON-2.04 MID=29828, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x0101}, 52 82 a2 6b 2d 57 56 04 a8 18 12 c6 9a 79 95 9e ]
09:11:36.268 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8195) received 34 bytes from localhost/127.0.0.1:8194
09:11:36.269 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.observe.InMemoryObservationStore - looking up observation for token Token=334030B2ADABBE88: CON-FETCH MID=20322, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x0900}, acked
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8
09:11:36.270 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.BaseMatcher - re-created exchange from original observe request: CON-FETCH MID=20322, Token=334030B2ADABBE88, OptionSet={"Observe":0, "Object-Security":0x0900},
ae 59 08 1a 62 8f 42 e4 db 8e b9 1e b1 84 20 35 54 67 ff fd 23 1a 19 90 25 a8
09:11:36.272 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[localhost/127.0.0.1:8194-29828]
09:11:36.272 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is OSCORE protected
09:11:36.272 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ResponseDecryptor - Removes E options from outer options which are not allowed there
09:11:36.272 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:36.272 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not considered due to it being disabled for this context
09:11:36.272 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L8, complete]!
NOTIFICATION: two
09:11:36.273 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.core.test.CountingCoapHandler - Received 2. Notification: NON-2.05 MID=29828, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x0101, "Content-Format":"text/plain"}, "two"
09:11:36.274 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityContextLayer - Request: CON-GET MID= -1, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:36.274 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L9] send request, failed transmissions: 0
09:11:36.274 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[L9] prepare retransmission for CON-GET MID= -1, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:36.276 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Request: CON-GET MID= -1, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:36.276 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L9] replace CON-GET MID= -1, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload by CON-FETCH MID= -1, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x0901},
19 95 45 75 db c3 a5 25 33 d0 8d 43 5b fd 48 b9 fb 14 0c c6 c9 b9 4b 14 b1 a5 0a
09:11:36.278 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L9] added with generated mid KeyMID[127.0.0.1:8194-20323], CON-FETCH MID=20323, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x0901},
19 95 45 75 db c3 a5 25 33 d0 8d 43 5b fd 48 b9 fb 14 0c c6 c9 b9 4b 14 b1 a5 0a
09:11:36.279 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap Exchange[L9] added with token KeyToken[334030B2ADABBE88], CON-FETCH MID=20323, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x0901},
19 95 45 75 db c3 a5 25 33 d0 8d 43 5b fd 48 b9 fb 14 0c c6 c9 b9 4b 14 b1 a5 0a
09:11:36.281 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.UdpMatcher - tracking open request [KeyMID[127.0.0.1:8194-20323], KeyToken[334030B2ADABBE88]]
09:11:36.281 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.HashMapCtxDB - Token exists, but this could be a refresh if not there is a problem
09:11:36.281 [UDP-Sender-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:0[0],5,Californium/Elements]) sent 45 bytes to /127.0.0.1:8194
09:11:36.283 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E9,T34) 127.0.0.1:8,195 ==> :8,194 [CON-FETCH MID=20323, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x0901},
19 95 45 75 db c3 a5 25 33 d0 8d 43 5b fd 48 b9 fb 14 0c c6 c9 b9 4b 14 b1 a5 0a ]
09:11:36.283 [UDP-Receiver-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (localhost:8194) received 45 bytes from /127.0.0.1:8195
09:11:36.283 [CoapServer(main)#7] DEBUG org.eclipse.californium.core.network.deduplication.SweepDeduplicator - add exchange for KeyMID[127.0.0.1:8195-20323]
09:11:36.284 [CoapServer(main)#8] INFO org.eclipse.californium.oscore.RequestDecryptor - Removes E options from outer options which are not allowed there
09:11:36.284 [CoapServer(main)#8] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:36.284 [CoapServer(main)#8] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not initiated due to it being disabled for this context
09:11:36.285 [CoapServer(main)#8] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R10] replace CON-FETCH MID=20323, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload by CON-GET MID=20323, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload
09:11:36.285 [CoapServer(main)#8] DEBUG org.eclipse.californium.core.observe.ObserveRelation - Canceling observe relation 127.0.0.1:8195#334030B2ADABBE88 with /oscore/observe2 (Exchange[R7])
09:11:36.286 [CoapServer(main)#8] INFO org.eclipse.californium.core.CoapResource - remove observe relation between 127.0.0.1:8195#334030B2ADABBE88 and resource /oscore/observe2 (Exchange[R7], size 0)
09:11:36.286 [CoapServer(main)#9] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R7, complete]!
09:11:36.286 [CoapServer(main)#9] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[R7, complete] for MID KeyMID[127.0.0.1:8195-29828]
09:11:36.286 [CoapServer(main)#8] DEBUG org.eclipse.californium.core.network.stack.ReliabilityLayer - Exchange[R10] send response null-2.05 MID= -1, Token=null, OptionSet={"Content-Format":"text/plain"}, "two", failed transmissions: 0
09:11:36.287 [CoapServer(main)#8] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[R10, complete]!
09:11:36.286 [CoapServer(main)#9] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R7, complete] completed NON-2.04 MID=29828, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x0101}, canceled 52 82 a2 6b 2d 57 56 04 a8 18 12 c6 9a 79 95 9e !
09:11:36.287 [CoapServer(main)#8] DEBUG org.eclipse.californium.core.network.Exchange - Remote Exchange[R10, complete] completed ACK-2.04 MID=20323, Token=334030B2ADABBE88, OptionSet={"Object-Security":0x0102}, 37 10 24 e0 c9 5c 0f c8 ad ee 14 bd b2 0e !
09:11:36.288 [UDP-Sender-localhost/127.0.0.1:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (Thread[UDP-Sender-localhost/127.0.0.1:0[0],5,Californium/Elements]) sent 30 bytes to /127.0.0.1:8195
09:11:36.289 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - >> (E10,T37) 127.0.0.1:8,194 ==> :8,195 [ACK-2.04 MID=20323, Token=334030B2ADABBE88, OptionSet={"Object-Security":0x0102}, 37 10 24 e0 c9 5c 0f c8 ad ee 14 bd b2 0e ]
09:11:36.289 [UDP-Receiver-0.0.0.0/0.0.0.0:0[0]] DEBUG org.eclipse.californium.elements.UDPConnector - UDPConnector (0.0.0.0:8195) received 30 bytes from localhost/127.0.0.1:8194
09:11:36.289 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ObjectSecurityLayer - Incoming response is OSCORE protected
09:11:36.289 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.ResponseDecryptor - Removes E options from outer options which are not allowed there
09:11:36.289 [:CoapEndpoint-UDP-0.0.0.0:0#1] INFO org.eclipse.californium.oscore.OptionJuggle - Removing inner only E options from the outer options
09:11:36.289 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.oscore.ContextRederivation - Context re-derivation not considered due to it being disabled for this context
09:11:36.290 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - Exchange[L9, complete]!
09:11:36.290 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L9, complete] for token KeyToken[334030B2ADABBE88]
09:11:36.290 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.InMemoryMessageExchangeStore - coap removing Exchange[L9, complete] for MID KeyMID[127.0.0.1:8194-20323]
09:11:36.290 [:CoapEndpoint-UDP-0.0.0.0:0#1] DEBUG org.eclipse.californium.core.network.Exchange - local Exchange[L9, complete] completed CON-GET MID= -1, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x, "Uri-Path":["oscore","observe2"]}, no payload -/- CON-FETCH MID=20323, Token=334030B2ADABBE88, OptionSet={"Observe":1, "Object-Security":0x0901}, acked
19 95 45 75 db c3 a5 25 33 d0 8d 43 5b fd 48 b9 fb 14 0c c6 c9 b9 4b 14 b1 a5 0a !
09:11:36.292 [main] DEBUG org.eclipse.californium.rule.CoapThreadsRule - shutdown
09:11:36.292 [main] INFO org.eclipse.californium.core.CoapServer - Destroying server
09:11:36.293 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://127.0.0.1:8194
09:11:36.293 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://127.0.0.1:8194
09:11:36.293 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8194, address localhost/127.0.0.1
09:11:36.293 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [localhost/127.0.0.1:8194] has stopped.
09:11:36.293 [main] INFO org.eclipse.californium.core.CoapServer - CoAP server has been destroyed
09:11:36.293 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Destroying endpoint at coap://0.0.0.0:8195
09:11:36.294 [main] INFO org.eclipse.californium.core.network.CoapEndpoint - coap Stopping endpoint at coap://0.0.0.0:8195
09:11:36.294 [main] DEBUG org.eclipse.californium.elements.util.DirectDatagramSocketImpl - closing port 8195, address 0.0.0.0/0.0.0.0
09:11:36.294 [main] INFO org.eclipse.californium.elements.UDPConnector - UDPConnector on [0.0.0.0/0.0.0.0:8195] has stopped.
09:11:36.294 [main] INFO org.eclipse.californium.elements.rule.TestNameLoggerRule - Test testObserve
09:11:36.295 [main] INFO org.eclipse.californium.elements.rule.NetworkRule - 0 rules active.
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.927 s - in org.eclipse.californium.oscore.OSCoreObserveTest
[INFO]
[INFO] Results:
[INFO]
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0
[INFO]
[INFO]
[INFO] --- surefire:2.22.2:test (native-tests) @ cf-oscore ---
[WARNING] Parameter 'localRepository' is deprecated core expression; Avoid use of ArtifactRepository type. If you need access to local repository, switch to '${repositorySystemSession}' expression and get LRM from it instead.
[INFO] Toolchain in maven-surefire-plugin: JDK[/opt/tools/java/oracle/jdk-7/latest]
[INFO]
[INFO] -------------------------------------------------------
[INFO] T E S T S
[INFO] -------------------------------------------------------
[INFO]
[INFO] Results:
[INFO]
[INFO] Tests run: 0, Failures: 0, Errors: 0, Skipped: 0
[INFO]
[INFO]
[INFO] --- source:3.2.1:jar-no-fork (attach-sources) @ cf-oscore ---
[INFO]
[INFO] --- eclipse-jarsigner:1.3.1:sign (sign-jars) @ cf-oscore ---
[INFO] Signing jar: /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/cf-oscore-2.8.1-SNAPSHOT.jar
[INFO] Signing jar: /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/cf-oscore-2.8.1-SNAPSHOT-javadoc.jar
[INFO] Signing jar: /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/cf-oscore-2.8.1-SNAPSHOT-sources.jar
[INFO]
[INFO] --- install:2.5.2:install (default-install) @ cf-oscore ---
[INFO] Installing /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/cf-oscore-2.8.1-SNAPSHOT.jar to /home/jenkins/.m2/repository/org/eclipse/californium/cf-oscore/2.8.1-SNAPSHOT/cf-oscore-2.8.1-SNAPSHOT.jar
[INFO] Installing /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/pom.xml to /home/jenkins/.m2/repository/org/eclipse/californium/cf-oscore/2.8.1-SNAPSHOT/cf-oscore-2.8.1-SNAPSHOT.pom
[INFO] Installing /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/cf-oscore-2.8.1-SNAPSHOT-javadoc.jar to /home/jenkins/.m2/repository/org/eclipse/californium/cf-oscore/2.8.1-SNAPSHOT/cf-oscore-2.8.1-SNAPSHOT-javadoc.jar
[INFO] Installing /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/cf-oscore-2.8.1-SNAPSHOT-sources.jar to /home/jenkins/.m2/repository/org/eclipse/californium/cf-oscore/2.8.1-SNAPSHOT/cf-oscore-2.8.1-SNAPSHOT-sources.jar
[INFO]
[INFO] --- nexus-staging:1.6.8:deploy (injected-nexus-deploy) @ cf-oscore ---
[INFO] Performing deferred deploys (gathering into "/home/jenkins/agent/workspace/californium-2.8.x-nightly/target/nexus-staging/deferred")...
[INFO] Installing /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/cf-oscore-2.8.1-SNAPSHOT.jar to /home/jenkins/agent/workspace/californium-2.8.x-nightly/target/nexus-staging/deferred/org/eclipse/californium/cf-oscore/2.8.1-SNAPSHOT/cf-oscore-2.8.1-SNAPSHOT.jar
[INFO] Installing /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/pom.xml to /home/jenkins/agent/workspace/californium-2.8.x-nightly/target/nexus-staging/deferred/org/eclipse/californium/cf-oscore/2.8.1-SNAPSHOT/cf-oscore-2.8.1-SNAPSHOT.pom
[INFO] Installing /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/cf-oscore-2.8.1-SNAPSHOT-javadoc.jar to /home/jenkins/agent/workspace/californium-2.8.x-nightly/target/nexus-staging/deferred/org/eclipse/californium/cf-oscore/2.8.1-SNAPSHOT/cf-oscore-2.8.1-SNAPSHOT-javadoc.jar
[INFO] Installing /home/jenkins/agent/workspace/californium-2.8.x-nightly/cf-oscore/target/cf-oscore-2.8.1-SNAPSHOT-sources.jar to /home/jenkins/agent/workspace/californium-2.8.x-nightly/target/nexus-staging/deferred/org/eclipse/californium/cf-oscore/2.8.1-SNAPSHOT/cf-oscore-2.8.1-SNAPSHOT-sources.jar
[INFO] Deploying remotely...
[INFO] Bulk deploying locally gathered artifacts from directory:
[INFO] * Bulk deploying locally gathered snapshot artifacts
[INFO] * Bulk deploy of locally gathered snapshot artifacts finished.
[INFO] Remote deploy finished with success.
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary for Californium (Cf) Parent 2.8.1-SNAPSHOT:
[INFO]
[INFO] Californium (Cf) Parent ............................ SUCCESS [ 6.201 s]
[INFO] Californium (Cf) Custom Assembly Descriptors ....... SUCCESS [ 3.625 s]
[INFO] Californium (Cf) BOM ............................... SUCCESS [ 0.022 s]
[INFO] Californium (Cf) Legal Documents ................... SUCCESS [ 1.510 s]
[INFO] Californium (Cf) Demo Certificates ................. SUCCESS [ 0.885 s]
[INFO] Californium (Cf) Element Connector ................. SUCCESS [ 20.000 s]
[INFO] Scandium (Sc) Core ................................. SUCCESS [02:11 min]
[INFO] Californium (Cf) Element Connector TCP netty ....... SUCCESS [ 39.047 s]
[INFO] Californium (Cf) Core .............................. SUCCESS [02:03 min]
[INFO] Cf-Unix-Health ..................................... SUCCESS [ 5.050 s]
[INFO] Cf-command-line-interface .......................... SUCCESS [ 6.410 s]
[INFO] Cf-cli-tcp-netty ................................... SUCCESS [ 8.819 s]
[INFO] Californium (Cf) Proxy ............................. SUCCESS [ 8.434 s]
[INFO] Californium (Cf) Proxy2 ............................ SUCCESS [ 12.322 s]
[INFO] Californium (Cf) OSGi .............................. SUCCESS [ 10.693 s]
[INFO] Californium (Cf) Demo Applications ................. SUCCESS [ 1.616 s]
[INFO] Cf-PlugtestServer .................................. SUCCESS [ 12.866 s]
[INFO] Cf-PlugtestClient .................................. SUCCESS [ 6.582 s]
[INFO] Cf-ExampleCrossProxy2 .............................. SUCCESS [ 9.663 s]
[INFO] Cf-OSCORE .......................................... SUCCESS [ 45.586 s]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 07:36 min
[INFO] Finished at: 2023-06-29T09:12:05Z
[INFO] ------------------------------------------------------------------------
Recording test results
[Checks API] No suitable checks publisher found.
Finished: SUCCESS
![[Jenkins]](/californium/static/1d85bb5a/images/svgs/logo.svg){kind=logo}
