Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
[cf-dev] [Hudson] Build failed in Hudson: parent #43

See <https://hudson.eclipse.org/californium/job/parent/43/changes>

Changes:

[Kai Hudalla] Use static reference to Serializer only.

[Kai Hudalla] Remove string concatenation from log statements.

------------------------------------------
[...truncated 1472 lines...]

Establish an observe relation. Cancellation after timeout. During the timeouts, the resource still changes.
302 INFO [CoapResource]: Successfully established observe relation between /127.0.0.1:37916#0c and resource /obs - (org.eclipse.californium.core.CoapResource.java:301) addObserveRelation() in thread pool-17-thread-6 at (2016-02-05 07:20:44)
Resource changed: First notification -675070728
Resource changed: Second notification -186395133
Resource changed: Third notification -200822859
311 INFO [ObserveLayer$NotificationController]: Notification 0c timed out. Cancel all relations with source /127.0.0.1:37916 - (org.eclipse.californium.core.network.stack.ObserveLayer$NotificationController.java:513) onTimeout() in thread pool-17-thread-13 at (2016-02-05 07:20:44)
CON [MID=7002], GET, /obs, observe(0)    ----->
<-----   ACK [MID=7002], 2.05, observe(5)    
Observe relation established
<-----   CON [MID=22380], 2.05, observe(6)    // lost 
<-----   CON [MID=22380], 2.05, observe(6)    // lost (1. retransmission)
<-----   CON [MID=22380], 2.05, observe(7)    // lost (2. retransmission)
<-----   CON [MID=22380], 2.05, observe(8)    // lost (3. retransmission)
<-----   CON [MID=22380], 2.05, observe(8)    // lost (4. retransmission)

Establish an observe relation. Cancellation due to a reject from the client
312 INFO [CoapResource]: Successfully established observe relation between /127.0.0.1:51174#0d and resource /obs - (org.eclipse.californium.core.CoapResource.java:301) addObserveRelation() in thread pool-17-thread-14 at (2016-02-05 07:20:44)
Resource changed: First notification -163235574
Reject notification
CON [MID=7003], GET, /obs, observe(0)    ----->
<-----   ACK [MID=7003], 2.05, observe(8)    
Observe relation established
<-----   CON [MID=22381], 2.05, observe(9)    // lost 
<-----   CON [MID=22381], 2.05, observe(9)    
RST [MID=22381], 0                        ----->

Observe with blockwise
301 INFO [CoapResource]: Successfully established observe relation between /127.0.0.1:38764#0e and resource /obs - (org.eclipse.californium.core.CoapResource.java:301) addObserveRelation() in thread pool-17-thread-5 at (2016-02-05 07:20:45)
Resource changed: 364854622-184689304113477222133389352091826705994-1625906891-1416062635-20970507
Resource changed: -569352561-1235038441465770066-14957227611508612635-954009712-1206591060-1159630
CON [MID=7004], GET, /obs, observe(0)    ----->
<-----   ACK [MID=7004], 2.05, 2:0/1/32, observe(9)    
Observe relation established
CON [MID=7005], GET, /obs, 2:1/0/32    ----->
<-----   ACK [MID=7005], 2.05, 2:1/1/32    
CON [MID=7006], GET, /obs, 2:2/0/32    ----->
<-----   ACK [MID=7006], 2.05, 2:2/0/32    
<-----   CON [MID=22382], 2.05, 2:0/1/32, observe(10)    
   === changed ===
ACK [MID=22382], 0                        ----->
CON [MID=7007], GET, /obs, 2:1/0/32    ----->
<-----   ACK [MID=7007], 2.05, 2:1/1/32    
CON [MID=7008], GET, /obs, 2:2/0/32    ----->
<-----   ACK [MID=7008], 2.05, 2:2/0/32    
<-----   CON [MID=22383], 2.05, 2:0/1/32, observe(11)    
   === changed ===
RST [MID=22383], 0                        ----->

Establish an observe relation and receive NON notifications
321 INFO [CoapResource]: Successfully established observe relation between /127.0.0.1:35301#11 and resource /obs - (org.eclipse.californium.core.CoapResource.java:301) addObserveRelation() in thread pool-17-thread-21 at (2016-02-05 07:20:45)
Resource changed: First notification -499589402
Resource changed: Second notification 2549529822
Resource changed: Third notification 44008015-1
Reject notification
NON [MID=7009], GET, /obs, observe(0)    ----->
<-----   NON [MID=22384], 2.05, observe(11)    
Observe relation established
<-----   NON [MID=22385], 2.05, observe(12)    
<-----   CON [MID=22386], 2.05, observe(13)    
ACK [MID=22386], 0                        ----->
<-----   NON [MID=22387], 2.05, observe(14)    
RST [MID=22387], 0                        ----->

Establish an observe relation and receive NON notifications
326 INFO [CoapResource]: Successfully established observe relation between /127.0.0.1:35146#12 and resource /obs - (org.eclipse.californium.core.CoapResource.java:301) addObserveRelation() in thread pool-17-thread-24 at (2016-02-05 07:20:45)
Resource changed: First notification -583985758
Resource changed: Second notification 7615777221
Resource changed: Third notification 1991110305
Resource changed: Fourth notification -193527578
Reject notification
NON [MID=7010], GET, /obs, 2:0/0/32, observe(0)    ----->
<-----   NON [MID=22388], 2.05, 2:0/0/32, observe(14)    
Observe relation established
<-----   NON [MID=22389], 2.05, observe(15)    
<-----   CON [MID=22390], 2.05, observe(16)    
ACK [MID=22390], 0                        ----->
<-----   NON [MID=22391], 2.05, observe(17)    
<-----   NON [MID=22392], 2.05, observe(18)    
RST [MID=22392], 0                        ----->

Establish an observe relation to a quickly changing resource and do no longer respond
299 INFO [CoapResource]: Successfully established observe relation between /127.0.0.1:51835#13 and resource /obs - (org.eclipse.californium.core.CoapResource.java:301) addObserveRelation() in thread pool-17-thread-3 at (2016-02-05 07:20:45)
Resource changed: First notification -187539554
Resource changed: Second notification 3342653233
Resource changed: NON notification 1 1300126648
Resource changed: NON notification 2 2092753111
Resource changed: NON notification 3 1302310426
Resource changed: NON notification 4 1493489827
305 INFO [ObserveLayer$NotificationController]: Notification 13 timed out. Cancel all relations with source /127.0.0.1:51835 - (org.eclipse.californium.core.network.stack.ObserveLayer$NotificationController.java:513) onTimeout() in thread pool-17-thread-9 at (2016-02-05 07:20:46)
CON [MID=7011], GET, /obs, observe(0)    ----->
<-----   ACK [MID=7011], 2.05, observe(18)    
Observe relation established
<-----   NON [MID=22393], 2.05, observe(19)    
<-----   CON [MID=22394], 2.05, observe(20)    
<-----   CON [MID=22394], 2.05, observe(21)    
<-----   CON [MID=22394], 2.05, observe(22)    
<-----   CON [MID=22394], 2.05, observe(23)    
<-----   CON [MID=22394], 2.05, observe(24)    
   server cancels the relation


 1 INFO [CoapServer]: Destroy server - (org.eclipse.californium.core.CoapServer.java:222) destroy() in thread main at (2016-02-05 07:20:46)
 1 INFO [CoapEndpoint]: Destroying endpoint at address 0.0.0.0/0.0.0.0:35559 - (org.eclipse.californium.core.network.CoapEndpoint.java:224) destroy() in thread main at (2016-02-05 07:20:46)
 1 INFO [CoapEndpoint]: Stopping endpoint at address 0.0.0.0/0.0.0.0:35559 - (org.eclipse.californium.core.network.CoapEndpoint.java:310) stop() in thread main at (2016-02-05 07:20:46)
 1 WARNING [CoapServer]: Server executor did not shutdown in time - (org.eclipse.californium.core.CoapServer.java:229) destroy() in thread main at (2016-02-05 07:20:51)
End ObserveServerSideTest
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 8.259 sec - in org.eclipse.californium.core.test.lockstep.ObserveServerSideTest
Running org.eclipse.californium.core.test.CoapTest
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec - in org.eclipse.californium.core.test.CoapTest
Running org.eclipse.californium.core.test.maninmiddle.LossyBlockwiseTransferTest

Start LossyBlockwiseTransferTest
 1 INFO [CoapEndpoint]: Starting endpoint at 0.0.0.0/0.0.0.0:0 - (org.eclipse.californium.core.network.CoapEndpoint.java:71) start() in thread main at (2016-02-05 07:20:51)
 1 INFO [CoapServer]: Starting server - (org.eclipse.californium.core.CoapServer.java:182) start() in thread main at (2016-02-05 07:20:51)
 1 INFO [CoapEndpoint]: Starting endpoint at 0.0.0.0/0.0.0.0:0 - (org.eclipse.californium.core.network.CoapEndpoint.java:194) start() in thread main at (2016-02-05 07:20:51)
Client at 40212, middle at 60999, server at 37363
Start man in the middle
uri: coap://localhost:60999/test
Man in the middle will drop packets [5, 6, 8, 9, 15]
Drop packet 5 (burst 1)
Drop packet 6 (burst 2)
342 INFO [Matcher]: Duplicate ongoing request: CON-GET    MID=63458, Token=10ed, OptionSet={"Uri-Port":60999, "Uri-Path":"test", "Block2":"(szx=1/32, m=false, num=2)"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-3 at (2016-02-05 07:20:51)
Drop packet 8 (burst 3)
Drop packet 9 (burst 4)
345 INFO [Matcher]: Duplicate ongoing request: CON-GET    MID=63458, Token=10ed, OptionSet={"Uri-Port":60999, "Uri-Path":"test", "Block2":"(szx=1/32, m=false, num=2)"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-6 at (2016-02-05 07:20:52)
Drop packet 15 (burst 1)
344 INFO [Matcher]: Duplicate ongoing request: CON-GET    MID=63460, Token=10ed, OptionSet={"Uri-Port":60999, "Uri-Path":"test", "Block2":"(szx=1/32, m=false, num=4)"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-5 at (2016-02-05 07:20:52)
Received 250 bytes
Man in the middle will drop packets [3, 6, 9, 9, 10, 11, 14, 14, 15, 15]
Drop packet 3 (burst 1)
347 INFO [Matcher]: Duplicate ongoing request: CON-GET    MID=63465, Token=f8f4cf4ef13f26, OptionSet={"Uri-Port":60999, "Uri-Path":"test", "Block2":"(szx=1/32, m=false, num=1)"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-8 at (2016-02-05 07:20:52)
Drop packet 6 (burst 1)
Drop packet 9 (burst 1)
Drop packet 10 (burst 2)
Drop packet 11 (burst 3)
Drop packet 14 (burst 3)
Drop packet 15 (burst 4)
Received 250 bytes
Man in the middle will drop packets [0, 0, 3, 5, 8, 10, 10, 13, 13, 14]
Drop packet 0 (burst 1)
Drop packet 3 (burst 1)
Drop packet 5 (burst 2)
361 INFO [Matcher]: Duplicate ongoing request: CON-GET    MID=63473, Token=e72c, OptionSet={"Uri-Port":60999, "Uri-Path":"test", "Block2":"(szx=1/32, m=false, num=1)"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-22 at (2016-02-05 07:20:54)
Drop packet 8 (burst 2)
Drop packet 10 (burst 3)
343 INFO [Matcher]: Duplicate ongoing request: CON-GET    MID=63474, Token=e72c, OptionSet={"Uri-Port":60999, "Uri-Path":"test", "Block2":"(szx=1/32, m=false, num=2)"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-4 at (2016-02-05 07:20:54)
Drop packet 13 (burst 3)
Drop packet 14 (burst 4)
Received 250 bytes
Man in the middle will drop packets [1, 1, 3, 7, 7, 10, 13, 14, 14, 15]
Drop packet 1 (burst 1)
350 INFO [Matcher]: Duplicate request: CON-GET    MID=63480, Token=a8cf, OptionSet={"Uri-Port":60999, "Uri-Path":"test"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-11 at (2016-02-05 07:20:55)
Drop packet 3 (burst 2)
360 INFO [Matcher]: Duplicate request: CON-GET    MID=63480, Token=a8cf, OptionSet={"Uri-Port":60999, "Uri-Path":"test"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-21 at (2016-02-05 07:20:55)
Drop packet 7 (burst 1)
362 INFO [Matcher]: Duplicate ongoing request: CON-GET    MID=63481, Token=a8cf, OptionSet={"Uri-Port":60999, "Uri-Path":"test", "Block2":"(szx=1/32, m=false, num=1)"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-23 at (2016-02-05 07:20:55)
Drop packet 10 (burst 1)
Drop packet 13 (burst 1)
Drop packet 14 (burst 2)
Drop packet 15 (burst 3)
Received 250 bytes
Man in the middle will drop packets [1, 5, 5, 8, 10, 13, 13, 14, 15, 15]
Drop packet 1 (burst 1)
357 INFO [Matcher]: Duplicate request: CON-GET    MID=63488, Token=8741ff8fec, OptionSet={"Uri-Port":60999, "Uri-Path":"test"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-18 at (2016-02-05 07:20:56)
Drop packet 5 (burst 1)
359 INFO [Matcher]: Duplicate ongoing request: CON-GET    MID=63489, Token=8741ff8fec, OptionSet={"Uri-Port":60999, "Uri-Path":"test", "Block2":"(szx=1/32, m=false, num=1)"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-20 at (2016-02-05 07:20:57)
Drop packet 8 (burst 1)
Drop packet 10 (burst 2)
361 INFO [Matcher]: Duplicate ongoing request: CON-GET    MID=63490, Token=8741ff8fec, OptionSet={"Uri-Port":60999, "Uri-Path":"test", "Block2":"(szx=1/32, m=false, num=2)"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-22 at (2016-02-05 07:20:57)
Drop packet 13 (burst 2)
Drop packet 14 (burst 3)
Drop packet 15 (burst 4)
Received 250 bytes
Man in the middle will drop packets [1, 2, 3, 3, 6, 6, 9, 10, 10, 11]
Drop packet 1 (burst 1)
Drop packet 2 (burst 2)
Drop packet 3 (burst 3)
345 INFO [Matcher]: Duplicate request: CON-GET    MID=63496, Token=7604, OptionSet={"Uri-Port":60999, "Uri-Path":"test"}, no payload - (org.eclipse.californium.core.network.Matcher.java:601) receiveRequest() in thread pool-18-thread-6 at (2016-02-05 07:20:58)
Drop packet 6 (burst 3)
Drop packet 9 (burst 3)
Drop packet 10 (burst 4)
Received 250 bytes

 1 INFO [CoapServer]: Destroy server - (org.eclipse.californium.core.CoapServer.java:222) destroy() in thread main at (2016-02-05 07:20:59)
 1 INFO [CoapEndpoint]: Destroying endpoint at address 0.0.0.0/0.0.0.0:37363 - (org.eclipse.californium.core.network.CoapEndpoint.java:224) destroy() in thread main at (2016-02-05 07:20:59)
 1 INFO [CoapEndpoint]: Stopping endpoint at address 0.0.0.0/0.0.0.0:37363 - (org.eclipse.californium.core.network.CoapEndpoint.java:310) stop() in thread main at (2016-02-05 07:20:59)
 1 INFO [CoapEndpoint]: Destroying endpoint at address 0.0.0.0/0.0.0.0:40212 - (org.eclipse.californium.core.network.CoapEndpoint.java:90) destroy() in thread main at (2016-02-05 07:20:59)
 1 INFO [CoapEndpoint]: Stopping endpoint at address 0.0.0.0/0.0.0.0:40212 - (org.eclipse.californium.core.network.CoapEndpoint.java:310) stop() in thread main at (2016-02-05 07:20:59)
End LossyBlockwiseTransferTest
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 7.886 sec - in org.eclipse.californium.core.test.maninmiddle.LossyBlockwiseTransferTest

Results :

Failed tests: 
  MemoryLeakingHashMapTest.testServer:85->testObserveBlockwise:316 expected:<0> but was:<1>

Tests run: 37, Failures: 1, Errors: 0, Skipped: 0

[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO] 
[INFO] Californium (Cf) Parent ............................ SUCCESS [  2.061 s]
[INFO] element-connector .................................. SUCCESS [  3.405 s]
[INFO] Californium (Cf) Demo Certificates ................. SUCCESS [  0.817 s]
[INFO] Scandium (Sc) Core ................................. SUCCESS [ 13.602 s]
[INFO] Californium (Cf) Core .............................. FAILURE [ 57.832 s]
[INFO] Californium (Cf) Proxy ............................. SKIPPED
[INFO] Californium (Cf) OSGi Bundle ....................... SKIPPED
[INFO] Californium (Cf) Demo Applications ................. SKIPPED
[INFO] Sc-DTLS-Example .................................... 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: 01:23 min
[INFO] Finished at: 2016-02-05T07:20:59-05:00
[INFO] Final Memory: 39M/1932M
[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 (default-test) on project californium-core: There are test failures.

Please refer to /jobs/genie.californium/parent/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 (default-test) on project californium-core: There are test failures.
[ERROR] 
[ERROR] Please refer to /jobs/genie.californium/parent/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/


Back to the top