[
Date Prev][
Date Next][
Thread Prev][
Thread Next][
Date Index][
Thread Index]
[
List Home]
|
[cf-dev] [Hudson] Build failed in Hudson: master #143
|
See <https://hudson.eclipse.org/californium/job/master/143/changes>
Changes:
[Kai Hudalla] Reduce visibility of logger to private.
[Kai Hudalla] Improve readability of log statement.
[Kai Hudalla] Clean up code.
[Kai Hudalla] Lower logging level for ReliabilityLayer to FINE.
------------------------------------------
[...truncated 2474 lines...]
242 FINE [ReliabilityLayer]: Response is duplicate, ignore it - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:237) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
CON [MID=172, T=12a68a25382e8b3c], GET, /test, observe(0) ----->
<----- ACK [MID=172]
<----- CON [MID=8001, T=12a68a25382e8b3c], 2.05, observe(101)
ACK [MID=8001] -----> // lost
<----- CON [MID=8001, T=12a68a25382e8b3c], 2.05, observe(101)
ACK [MID=8001] ----->
Relation established
242 INFO [MessageTracer]: /127.0.0.1:55,711 ==> res CON-2.05 MID= 8002, Token=12a68a25382e8b3c, OptionSet={"Observe":102}, "6159682477" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
242 INFO [MessageTracer]: /127.0.0.1:55,711 <== emp ACK MID= 8002 - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:583) sendEmptyMessage() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
242 INFO [MessageTracer]: /127.0.0.1:55,711 ==> res CON-2.05 MID= 8002, Token=12a68a25382e8b3c, OptionSet={"Observe":102}, "6159682477_DUPLICATE" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
242 INFO [MessageTracer]: /127.0.0.1:55,711 <== emp ACK MID= 8002 - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:583) sendEmptyMessage() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
<----- CON [MID=8002, T=12a68a25382e8b3c], 2.05, observe(102)
ACK [MID=8002] -----> // lost
<----- CON [MID=8002, T=12a68a25382e8b3c], 2.05, observe(102)
ACK [MID=8002] ----->
242 FINE [ReliabilityLayer]: Response is duplicate, ignore it - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:237) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
1 INFO [CoapEndpoint]: Destroying endpoint at address /127.0.0.1:44566 - (org.eclipse.californium.core.network.CoapEndpoint.java:90) destroy() in thread main at (2016-12-07 04:06:14)
1 INFO [CoapEndpoint]: Stopping endpoint at address /127.0.0.1:44566 - (org.eclipse.californium.core.network.CoapEndpoint.java:396) stop() in thread main at (2016-12-07 04:06:14)
1 CONFIG [ReliabilityLayer]: ReliabilityLayer uses ACK_TIMEOUT=200, ACK_RANDOM_FACTOR=1, and ACK_TIMEOUT_SCALE=1 - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:95) <init>() in thread main at (2016-12-07 04:06:14)
1 INFO [CoapEndpoint]: Starting endpoint at localhost/127.0.0.1:0 - (org.eclipse.californium.core.network.CoapEndpoint.java:83) start() in thread main at (2016-12-07 04:06:14)
Client binds to port 47689
Blockwise Observe:
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 258, Token=6f923a7ff69be598, OptionSet={"Observe":0, "Uri-Port":36221, "Uri-Path":"test"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 258, Token=6f923a7ff69be598, OptionSet={"Observe":0, "Block2":"(szx=0/16, m=true, num=0)"}, "7496313292512852" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 259, Token=69c9b6efa541e97e, OptionSet={"Uri-Port":36221, "Uri-Path":"test", "Block2":"(szx=0/16, m=false, num=1)"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 259, Token=69c9b6efa541e97e, OptionSet={"Block2":"(szx=0/16, m=true, num=1)"}, "6248534269938674" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 260, Token=69c9b6efa541e97e, OptionSet={"Uri-Port":36221, "Uri-Path":"test", "Block2":"(szx=0/16, m=false, num=2)"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 260, Token=69c9b6efa541e97e, OptionSet={"Block2":"(szx=0/16, m=false, num=2)"}, "50666463" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
CON [MID=258, T=6f923a7ff69be598], GET, /test, observe(0) ----->
<----- ACK [MID=258, T=6f923a7ff69be598], 2.05, 2:0/1/16, observe(0)
CON [MID=259, T=69c9b6efa541e97e], GET, /test, 2:1/0/16 ----->
<----- ACK [MID=259, T=69c9b6efa541e97e], 2.05, 2:1/1/16
CON [MID=260, T=69c9b6efa541e97e], GET, /test, 2:2/0/16 ----->
<----- ACK [MID=260, T=69c9b6efa541e97e], 2.05, 2:2/0/16
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res CON-2.05 MID= 8001, Token=6f923a7ff69be598, OptionSet={"Observe":1, "Block2":"(szx=0/16, m=true, num=0)"}, "7496313292512852" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== emp ACK MID= 8001 - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:583) sendEmptyMessage() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 261, Token=8040c90328b623c0, OptionSet={"Uri-Port":36221, "Uri-Path":"test", "Block2":"(szx=0/16, m=false, num=1)"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 261, Token=8040c90328b623c0, OptionSet={"Block2":"(szx=0/16, m=true, num=1)"}, "6248534269938674" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 262, Token=8040c90328b623c0, OptionSet={"Uri-Port":36221, "Uri-Path":"test", "Block2":"(szx=0/16, m=false, num=2)"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 262, Token=8040c90328b623c0, OptionSet={"Block2":"(szx=0/16, m=false, num=2)"}, "50666463" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
<----- CON [MID=8001, T=6f923a7ff69be598], 2.05, 2:0/1/16, observe(1)
ACK [MID=8001] ----->
CON [MID=261, T=8040c90328b623c0], GET, /test, 2:1/0/16 ----->
<----- ACK [MID=261, T=8040c90328b623c0], 2.05, 2:1/1/16
CON [MID=262, T=8040c90328b623c0], GET, /test, 2:2/0/16 ----->
<----- ACK [MID=262, T=8040c90328b623c0], 2.05, 2:2/0/16
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res CON-2.05 MID= 8002, Token=6f923a7ff69be598, OptionSet={"Observe":2, "Block2":"(szx=0/16, m=true, num=0)"}, "7496313292512852" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== emp ACK MID= 8002 - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:583) sendEmptyMessage() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 263, Token=42f75f8f281ab2fc, OptionSet={"Uri-Port":36221, "Uri-Path":"test", "Block2":"(szx=0/16, m=false, num=1)"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:14)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 263, Token=42f75f8f281ab2fc, OptionSet={"Block2":"(szx=0/16, m=true, num=1)"}, "6248534269938674" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 264, Token=42f75f8f281ab2fc, OptionSet={"Uri-Port":36221, "Uri-Path":"test", "Block2":"(szx=0/16, m=false, num=2)"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res CON-2.05 MID= 8003, Token=6f923a7ff69be598, OptionSet={"Observe":3, "Block2":"(szx=0/16, m=true, num=0)"}, "abcdefghijklmnop" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== emp ACK MID= 8003 - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:583) sendEmptyMessage() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 WARNING [BlockwiseLayer]: ongoing blockwise transfer reset at num = 2 by new notification: CON-2.05 MID= 8003, Token=6f923a7ff69be598, OptionSet={"Observe":3, "Block2":"(szx=0/16, m=true, num=0)"}, "abcdefghijklmnop" - (org.eclipse.californium.core.network.stack.BlockwiseLayer.java:398) handleBlock2Response() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 265, Token=ebf3464d870225d8, OptionSet={"Uri-Port":36221, "Uri-Path":"test", "Block2":"(szx=0/16, m=false, num=1)"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 264, Token=42f75f8f281ab2fc, OptionSet={"Block2":"(szx=0/16, m=false, num=2)"}, "50666463" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 WARNING [UdpMatcher]: Possible MID reuse before lifetime end for token [42f75f8f281ab2fc], expected MID 265 but received 264 - (org.eclipse.californium.core.network.UdpMatcher.java:742) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 WARNING [BlockwiseLayer]: Wrong block number. Expected 1 but received 2: ACK-2.05 MID= 264, Token=42f75f8f281ab2fc, OptionSet={"Block2":"(szx=0/16, m=false, num=2)"}, "50666463" - (org.eclipse.californium.core.network.stack.BlockwiseLayer.java:398) handleBlock2Response() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 265, Token=ebf3464d870225d8, OptionSet={"Block2":"(szx=0/16, m=true, num=1)"}, "qrstuvwxyzabcdef" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 266, Token=ebf3464d870225d8, OptionSet={"Uri-Port":36221, "Uri-Path":"test", "Block2":"(szx=0/16, m=false, num=2)"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 266, Token=ebf3464d870225d8, OptionSet={"Block2":"(szx=0/16, m=false, num=2)"}, "ghijklmn" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
<----- CON [MID=8002, T=6f923a7ff69be598], 2.05, 2:0/1/16, observe(2)
ACK [MID=8002] ----->
CON [MID=263, T=42f75f8f281ab2fc], GET, /test, 2:1/0/16 ----->
<----- ACK [MID=263, T=42f75f8f281ab2fc], 2.05, 2:1/1/16
CON [MID=264, T=42f75f8f281ab2fc], GET, /test, 2:2/0/16 ----->
//////// Overriding notification ////////
<----- CON [MID=8003, T=6f923a7ff69be598], 2.05, 2:0/1/16, observe(3)
ACK [MID=8003] ----->
CON [MID=265, T=ebf3464d870225d8], GET, /test, 2:1/0/16 ----->
<----- ACK [MID=264, T=42f75f8f281ab2fc], 2.05, 2:2/0/16
<----- ACK [MID=265, T=ebf3464d870225d8], 2.05, 2:1/1/16
CON [MID=266, T=ebf3464d870225d8], GET, /test, 2:2/0/16 ----->
<----- ACK [MID=266, T=ebf3464d870225d8], 2.05, 2:2/0/16
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res CON-2.05 MID= 8004, Token=6f923a7ff69be598, OptionSet={"Observe":4, "Block2":"(szx=0/16, m=true, num=0)"}, "7496313292512852" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== emp ACK MID= 8004 - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:583) sendEmptyMessage() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 267, Token=6029ecaa09fbd09b, OptionSet={"Uri-Port":36221, "Uri-Path":"test", "Block2":"(szx=0/16, m=false, num=1)"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res CON-2.05 MID= 8005, Token=6f923a7ff69be598, OptionSet={"Observe":5, "Block2":"(szx=0/16, m=true, num=0)"}, "ABCDEFGHIJKLMNOP" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== emp ACK MID= 8005 - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:583) sendEmptyMessage() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 WARNING [BlockwiseLayer]: ongoing blockwise transfer reset at num = 1 by new notification: CON-2.05 MID= 8005, Token=6f923a7ff69be598, OptionSet={"Observe":5, "Block2":"(szx=0/16, m=true, num=0)"}, "ABCDEFGHIJKLMNOP" - (org.eclipse.californium.core.network.stack.BlockwiseLayer.java:398) handleBlock2Response() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 268, Token=7285fa41e3d1b9e7, OptionSet={"Uri-Port":36221, "Uri-Path":"test", "Block2":"(szx=0/16, m=false, num=1)"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 267, Token=6029ecaa09fbd09b, OptionSet={"Block2":"(szx=0/16, m=true, num=1)"}, "6248534269938674" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 WARNING [UdpMatcher]: Possible MID reuse before lifetime end for token [6029ecaa09fbd09b], expected MID 268 but received 267 - (org.eclipse.californium.core.network.UdpMatcher.java:742) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 WARNING [BlockwiseLayer]: Wrong block number. Expected 1 but received 1: ACK-2.05 MID= 267, Token=6029ecaa09fbd09b, OptionSet={"Block2":"(szx=0/16, m=true, num=1)"}, "6248534269938674" - (org.eclipse.californium.core.network.stack.BlockwiseLayer.java:398) handleBlock2Response() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 268, Token=7285fa41e3d1b9e7, OptionSet={"Block2":"(szx=0/16, m=true, num=1)"}, "QRSTUVWXYZABCDEF" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 269, Token=7285fa41e3d1b9e7, OptionSet={"Uri-Port":36221, "Uri-Path":"test", "Block2":"(szx=0/16, m=false, num=2)"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 269, Token=7285fa41e3d1b9e7, OptionSet={"Block2":"(szx=0/16, m=false, num=2)"}, "GHIJKLMN" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
<----- CON [MID=8004, T=6f923a7ff69be598], 2.05, 2:0/1/16, observe(4)
ACK [MID=8004] ----->
CON [MID=267, T=6029ecaa09fbd09b], GET, /test, 2:1/0/16 ----->
//////// Overriding notification 2 ////////
<----- CON [MID=8005, T=6f923a7ff69be598], 2.05, 2:0/1/16, observe(5)
ACK [MID=8005] ----->
CON [MID=268, T=7285fa41e3d1b9e7], GET, /test, 2:1/0/16 ----->
//////// Conflicting notification block ////////
<----- ACK [MID=267, T=6029ecaa09fbd09b], 2.05, 2:1/1/16
<----- ACK [MID=268, T=7285fa41e3d1b9e7], 2.05, 2:1/1/16
CON [MID=269, T=7285fa41e3d1b9e7], GET, /test, 2:2/0/16 ----->
<----- ACK [MID=269, T=7285fa41e3d1b9e7], 2.05, 2:2/0/16
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res CON-2.05 MID= 8006, Token=6f923a7ff69be598, OptionSet={"Observe":6, "Block2":"(szx=0/16, m=true, num=0)"}, "7496313292512852" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== emp ACK MID= 8006 - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:583) sendEmptyMessage() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== req CON-GET MID= 270, Token=13c68e8d1a7ff7a7, OptionSet={"Uri-Port":36221, "Uri-Path":"test", "Block2":"(szx=0/16, m=false, num=1)"}, no payload - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:532) sendRequest() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
//////// Notification after cancellation ////////
<----- CON [MID=8006, T=6f923a7ff69be598], 2.05, 2:0/1/16, observe(6)
ACK [MID=8006] ----->
CON [MID=270, T=13c68e8d1a7ff7a7], GET, /test, 2:1/0/16 ----->
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res ACK-2.05 MID= 270, Token=13c68e8d1a7ff7a7, OptionSet={"Block2":"(szx=0/16, m=true, num=1)"}, "6248534269938674" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 ==> res CON-2.05 MID= 8007, Token=6f923a7ff69be598, OptionSet={"Observe":7, "Block2":"(szx=0/16, m=true, num=0)"}, "7496313292512852" - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:737) receiveResponse() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
248 INFO [MessageTracer]: /127.0.0.1:36,221 <== emp RST MID= 8007 - (org.eclipse.californium.core.network.interceptors.MessageTracer.java:583) sendEmptyMessage() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:15)
<----- ACK [MID=270, T=13c68e8d1a7ff7a7], 2.05, 2:1/1/16
<----- CON [MID=8007, T=6f923a7ff69be598], 2.05, 2:0/1/16, observe(7)
RST [MID=8007] ----->
1 INFO [CoapEndpoint]: Destroying endpoint at address /127.0.0.1:47689 - (org.eclipse.californium.core.network.CoapEndpoint.java:90) destroy() in thread main at (2016-12-07 04:06:15)
1 INFO [CoapEndpoint]: Stopping endpoint at address /127.0.0.1:47689 - (org.eclipse.californium.core.network.CoapEndpoint.java:396) stop() in thread main at (2016-12-07 04:06:15)
End ObserveClientSideTest
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.145 sec - in org.eclipse.californium.core.test.lockstep.ObserveClientSideTest
Running org.eclipse.californium.core.test.maninmiddle.LossyBlockwiseTransferTest
StartLossyBlockwiseTransferTest
1 CONFIG [ReliabilityLayer]: ReliabilityLayer uses ACK_TIMEOUT=300, ACK_RANDOM_FACTOR=1, and ACK_TIMEOUT_SCALE=1 - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:95) <init>() in thread main at (2016-12-07 04:06:15)
1 INFO [CoapEndpoint]: Starting endpoint at localhost/127.0.0.1:0 - (org.eclipse.californium.core.network.CoapEndpoint.java:79) start() in thread main at (2016-12-07 04:06:15)
1 CONFIG [ReliabilityLayer]: ReliabilityLayer uses ACK_TIMEOUT=300, ACK_RANDOM_FACTOR=1, and ACK_TIMEOUT_SCALE=1 - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:95) <init>() in thread main at (2016-12-07 04:06:15)
1 INFO [CoapServer]: Starting server - (org.eclipse.californium.core.CoapServer.java:200) start() in thread main at (2016-12-07 04:06:15)
1 INFO [CoapEndpoint]: Starting endpoint at localhost/127.0.0.1:0 - (org.eclipse.californium.core.network.CoapEndpoint.java:212) start() in thread main at (2016-12-07 04:06:15)
Starting man in the middle...
client at 127.0.0.1:43309, middle at 127.0.0.1:51567, server at 127.0.0.1:46307
Man in the middle will drop packets [5, 6, 8, 9, 15]
doing a blockwise GET on: coap://localhost:51567/test
Dropping packet 5 (burst 1)
Dropping packet 6 (burst 2)
262 FINE [ReliabilityLayer]: Respond with the current response to the duplicate request - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:189) receiveRequest() in thread CoapServer#4 at (2016-12-07 04:06:15)
Dropping packet 8 (burst 3)
Dropping packet 9 (burst 4)
260 FINE [ReliabilityLayer]: Respond with the current response to the duplicate request - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:189) receiveRequest() in thread CoapServer#2 at (2016-12-07 04:06:16)
Dropping packet 15 (burst 1)
266 FINE [ReliabilityLayer]: Respond with the current response to the duplicate request - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:189) receiveRequest() in thread CoapServer#8 at (2016-12-07 04:06:16)
Received 250 bytes after 1515ms
Man in the middle will drop packets [1, 3, 5, 6, 6, 7, 7, 7, 13, 15]
doing a blockwise GET on: coap://localhost:51567/test
Dropping packet 1 (burst 1)
270 FINE [ReliabilityLayer]: Respond with the current response to the duplicate request - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:189) receiveRequest() in thread CoapServer#12 at (2016-12-07 04:06:16)
Dropping packet 3 (burst 2)
258 FINE [ReliabilityLayer]: Respond with the current response to the duplicate request - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:189) receiveRequest() in thread CoapServer#1 at (2016-12-07 04:06:17)
Dropping packet 5 (burst 3)
Dropping packet 6 (burst 4)
272 FINE [ReliabilityLayer]: Respond with the current response to the duplicate request - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:189) receiveRequest() in thread CoapServer#14 at (2016-12-07 04:06:17)
Dropping packet 13 (burst 1)
Dropping packet 15 (burst 2)
276 FINE [ReliabilityLayer]: Respond with the current response to the duplicate request - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:189) receiveRequest() in thread CoapServer#18 at (2016-12-07 04:06:18)
Received 250 bytes after 1811ms
Man in the middle will drop packets [0, 1, 2, 4, 6, 7, 12, 13, 13, 15]
doing a blockwise GET on: coap://localhost:51567/test
Dropping packet 0 (burst 1)
Dropping packet 1 (burst 2)
Dropping packet 2 (burst 3)
Dropping packet 4 (burst 4)
270 FINE [ReliabilityLayer]: Respond with the current response to the duplicate request - (org.eclipse.californium.core.network.stack.ReliabilityLayer.java:189) receiveRequest() in thread CoapServer#12 at (2016-12-07 04:06:19)
254 FINE [ReliabilityLayer$RetransmissionTask]: Timeout: retransmission limit reached, exchange failed, message: CON-GET MID= 972, Token=70eaeb9c4c543700, OptionSet={"Uri-Host":"localhost", "Uri-Port":51567, "Uri-Path":"test"}, no payload - (org.eclipse.californium.core.network.stack.ReliabilityLayer$RetransmissionTask.java:471) run() in thread CoapEndpoint-localhost/127.0.0.1:0#1 at (2016-12-07 04:06:19)
1 INFO [CoapServer]: Destroying server - (org.eclipse.californium.core.CoapServer.java:248) destroy() in thread main at (2016-12-07 04:06:20)
1 INFO [CoapEndpoint]: Destroying endpoint at address /127.0.0.1:46307 - (org.eclipse.californium.core.network.CoapEndpoint.java:270) destroy() in thread main at (2016-12-07 04:06:21)
1 INFO [CoapEndpoint]: Stopping endpoint at address /127.0.0.1:46307 - (org.eclipse.californium.core.network.CoapEndpoint.java:396) stop() in thread main at (2016-12-07 04:06:21)
1 INFO [CoapServer]: CoAP server has been destroyed - (org.eclipse.californium.core.CoapServer.java:110) destroy() in thread main at (2016-12-07 04:06:21)
1 INFO [CoapEndpoint]: Destroying endpoint at address /127.0.0.1:43309 - (org.eclipse.californium.core.network.CoapEndpoint.java:111) destroy() in thread main at (2016-12-07 04:06:21)
1 INFO [CoapEndpoint]: Stopping endpoint at address /127.0.0.1:43309 - (org.eclipse.californium.core.network.CoapEndpoint.java:396) stop() in thread main at (2016-12-07 04:06:21)
End LossyBlockwiseTransferTestTests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 6.406 sec <<< FAILURE! - in org.eclipse.californium.core.test.maninmiddle.LossyBlockwiseTransferTest
testBlockwiseTransferToleratesLostMessages(org.eclipse.californium.core.test.maninmiddle.LossyBlockwiseTransferTest) Time elapsed: 6.406 sec <<< FAILURE!
java.lang.AssertionError: Blockwise GET timed out after 2060ms
Expected: is not null
but: was null
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
at org.junit.Assert.assertThat(Assert.java:956)
at org.eclipse.californium.core.test.maninmiddle.LossyBlockwiseTransferTest.getResourceAndAssertPayload(LossyBlockwiseTransferTest.java:148)
at org.eclipse.californium.core.test.maninmiddle.LossyBlockwiseTransferTest.testBlockwiseTransferToleratesLostMessages(LossyBlockwiseTransferTest.java:137)
Results :
Failed tests:
LossyBlockwiseTransferTest.testBlockwiseTransferToleratesLostMessages:137->getResourceAndAssertPayload:148 Blockwise GET timed out after 2060ms
Expected: is not null
but: was null
Tests run: 18, Failures: 1, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO]
[INFO] Californium (Cf) Parent ............................ SUCCESS [ 2.341 s]
[INFO] element-connector .................................. SUCCESS [ 55.587 s]
[INFO] Californium (Cf) Demo Certificates ................. SUCCESS [ 1.307 s]
[INFO] Scandium (Sc) Core ................................. SUCCESS [ 22.438 s]
[INFO] Californium (Cf) Core .............................. FAILURE [ 41.222 s]
[INFO] Californium (Cf) Proxy ............................. SKIPPED
[INFO] Californium (Cf) OSGi Bundle ....................... SKIPPED
[INFO] Californium (Cf) Demo Applications ................. SKIPPED
[INFO] Sc-DTLS-Example-Server ............................. SKIPPED
[INFO] Sc-DTLS-Example-Client ............................. SKIPPED
[INFO] Cf-PlugtestClient .................................. SKIPPED
[INFO] Cf-PlugtestChecker ................................. SKIPPED
[INFO] Cf-PlugtestServer .................................. SKIPPED
[INFO] Cf-HelloWorldClient ................................ SKIPPED
[INFO] Cf-HelloWorldServer ................................ SKIPPED
[INFO] Cf-CoCoAClient ..................................... SKIPPED
[INFO] Cf-SecureServer .................................... SKIPPED
[INFO] Cf-ExampleCrossProxy ............................... SKIPPED
[INFO] Cf-BenchmarkServer ................................. SKIPPED
[INFO] Cf-ObserveBenchmarkClient .......................... SKIPPED
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 02:07 min
[INFO] Finished at: 2016-12-07T04:06:21-05:00
[INFO] Final Memory: 43M/1934M
[INFO] ------------------------------------------------------------------------
[INFO] o.h.m.e.h.MavenExecutionResultHandler - Build failed with exception(s)
[INFO] o.h.m.e.h.MavenExecutionResultHandler - [1] org.apache.maven.lifecycle.LifecycleExecutionException: Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.18.1:test (large-tests) on project californium-core: There are test failures.
Please refer to /jobs/genie.californium/master/workspace/californium-core/target/surefire-reports for the individual test results.
[DEBUG] Closing connection to remote
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.18.1:test (large-tests) on project californium-core: There are test failures.
[ERROR]
[ERROR] Please refer to /jobs/genie.californium/master/workspace/californium-core/target/surefire-reports for the individual test results.
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException
[ERROR]
[ERROR] After correcting the problems, you can resume the build with the command
[ERROR] mvn <goals> -rf :californium-core
[DEBUG] Waiting for process to finish
[DEBUG] Result: 1
Recording test results
--
This message is automatically generated by Hudson.
For more information on Hudson, see: http://hudson-ci.org/
