Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
[cf-dev] Build failed in Jenkins: 2.0.x #675

See <https://ci.eclipse.org/californium/job/2.0.x/675/display/redirect>

------------------------------------------
[...truncated 397.38 KB...]
Wait until deduplicator should be empty (2.97 seconds)
Wait until deduplicator should be empty (2.97 seconds)


Client binds to port 8269
Proactive cancel
Wait until deduplicator should be empty (2.97 seconds)
Wait until deduplicator should be empty (2.97 seconds)

0002: CON [MID=5770, T=95BB7BB7220B38A3], GET, /test, observe(0)    ----->
0003: <-----   ACK [MID=5770, T=95BB7BB7220B38A3], 2.05, observe(1)
0004: <-----   CON [MID=8001, T=95BB7BB7220B38A3], 2.05, observe(3)
0004: ACK [MID=8001]   ----->
0005: CON [MID=5771, T=95BB7BB7220B38A3], GET, /test, observe(1)    ----->
0006: <-----   ACK [MID=5771, T=95BB7BB7220B38A3], 2.05
0007: <-----   CON [MID=8002, T=95BB7BB7220B38A3], 2.05, observe(4)
0007: RST [MID=8002]   ----->
0007: <-----   NON [MID=8003, T=95BB7BB7220B38A3], 2.05, observe(5)
0007: RST [MID=8003]   ----->

End ObserveClientSideTest
[INFO] Tests run: 18, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 12.107 s - in org.eclipse.californium.core.test.lockstep.ObserveClientSideTest
[INFO] Running org.eclipse.californium.core.test.maninmiddle.LossyBlockwiseTransferTest

StartLossyBlockwiseTransferTest
Starting man in the middle...
client at localhost:8271, middle at 127.0.0.1:8273, server at localhost:8272


doing a blockwise GET on: coap://localhost:8273/test
Received 250 bytes after 2761 ms
Man in the middle will drop packets [5, 6, 8, 9, 15]
0011: CON [MID=51772, T=301E02E1374EE633], GET, /test    ----->
0012: <-----   ACK [MID=51772, T=301E02E1374EE633], 2.05, 2:0/1/32, size2(250)
0013: CON [MID=51773, T=301E02E1374EE633], GET, /test, 2:1/0/32    ----->
0014: <-----   ACK [MID=51773, T=301E02E1374EE633], 2.05, 2:1/1/32
0015: CON [MID=51774, T=301E02E1374EE633], GET, /test, 2:2/0/32    -----> Dropping packet 5 (burst 1/4) from server
0316: CON [MID=51774, T=301E02E1374EE633], GET, /test, 2:2/0/32    -----> Dropping packet 6 (burst 2/4) from client
0766: CON [MID=51774, T=301E02E1374EE633], GET, /test, 2:2/0/32    -----> Dropping packet 8 (burst 3/4) from server
1442: CON [MID=51774, T=301E02E1374EE633], GET, /test, 2:2/0/32    -----> Dropping packet 9 (burst 4/4) from client
2455: CON [MID=51774, T=301E02E1374EE633], GET, /test, 2:2/0/32    ----->
2457: <-----   ACK [MID=51774, T=301E02E1374EE633], 2.05, 2:2/1/32
2457: CON [MID=51775, T=301E02E1374EE633], GET, /test, 2:3/0/32    ----->
2459: <-----   ACK [MID=51775, T=301E02E1374EE633], 2.05, 2:3/1/32
2459: CON [MID=51776, T=301E02E1374EE633], GET, /test, 2:4/0/32    -----> Dropping packet 15 (burst 1/4) from server
2760: CON [MID=51776, T=301E02E1374EE633], GET, /test, 2:4/0/32    ----->
2762: <-----   ACK [MID=51776, T=301E02E1374EE633], 2.05, 2:4/1/32
2762: CON [MID=51777, T=301E02E1374EE633], GET, /test, 2:5/0/32    ----->
2764: <-----   ACK [MID=51777, T=301E02E1374EE633], 2.05, 2:5/1/32
2764: CON [MID=51778, T=301E02E1374EE633], GET, /test, 2:6/0/32    ----->
2766: <-----   ACK [MID=51778, T=301E02E1374EE633], 2.05, 2:6/1/32
2766: CON [MID=51779, T=301E02E1374EE633], GET, /test, 2:7/0/32    ----->
2767: <-----   ACK [MID=51779, T=301E02E1374EE633], 2.05, 2:7/0/32

doing a blockwise GET on: coap://localhost:8273/test
Received 250 bytes after 3507 ms
Man in the middle will drop packets [2, 2, 5, 7, 7, 11, 12, 12, 14, 15]
2770: CON [MID=51780, T=F653EEAEE0CD14E3], GET, /test    ----->
2771: <-----   ACK [MID=51780, T=F653EEAEE0CD14E3], 2.05, 2:0/1/32, size2(250)
2771: CON [MID=51781, T=F653EEAEE0CD14E3], GET, /test, 2:1/0/32    -----> Dropping packet 2 (burst 1/4) from client
3072: CON [MID=51781, T=F653EEAEE0CD14E3], GET, /test, 2:1/0/32    ----->
3074: <-----   ACK [MID=51781, T=F653EEAEE0CD14E3], 2.05, 2:1/1/32
3074: CON [MID=51782, T=F653EEAEE0CD14E3], GET, /test, 2:2/0/32    -----> Dropping packet 5 (burst 1/4) from client
3375: CON [MID=51782, T=F653EEAEE0CD14E3], GET, /test, 2:2/0/32    -----> Dropping packet 7 (burst 2/4) from server
3825: CON [MID=51782, T=F653EEAEE0CD14E3], GET, /test, 2:2/0/32    ----->
3827: <-----   ACK [MID=51782, T=F653EEAEE0CD14E3], 2.05, 2:2/1/32
3827: CON [MID=51783, T=F653EEAEE0CD14E3], GET, /test, 2:3/0/32    -----> Dropping packet 11 (burst 1/4) from server
4128: CON [MID=51783, T=F653EEAEE0CD14E3], GET, /test, 2:3/0/32    -----> Dropping packet 12 (burst 2/4) from client
4579: CON [MID=51783, T=F653EEAEE0CD14E3], GET, /test, 2:3/0/32    -----> Dropping packet 14 (burst 3/4) from server
5256: CON [MID=51783, T=F653EEAEE0CD14E3], GET, /test, 2:3/0/32    -----> Dropping packet 15 (burst 4/4) from client
6269: CON [MID=51783, T=F653EEAEE0CD14E3], GET, /test, 2:3/0/32    ----->
6270: <-----   ACK [MID=51783, T=F653EEAEE0CD14E3], 2.05, 2:3/1/32
6271: CON [MID=51784, T=F653EEAEE0CD14E3], GET, /test, 2:4/0/32    ----->
6272: <-----   ACK [MID=51784, T=F653EEAEE0CD14E3], 2.05, 2:4/1/32
6272: CON [MID=51785, T=F653EEAEE0CD14E3], GET, /test, 2:5/0/32    ----->
6273: <-----   ACK [MID=51785, T=F653EEAEE0CD14E3], 2.05, 2:5/1/32
6273: CON [MID=51786, T=F653EEAEE0CD14E3], GET, /test, 2:6/0/32    ----->
6274: <-----   ACK [MID=51786, T=F653EEAEE0CD14E3], 2.05, 2:6/1/32
6275: CON [MID=51787, T=F653EEAEE0CD14E3], GET, /test, 2:7/0/32    ----->
6276: <-----   ACK [MID=51787, T=F653EEAEE0CD14E3], 2.05, 2:7/0/32

doing a blockwise GET on: coap://localhost:8273/test
Received 250 bytes after 5970 ms
Man in the middle will drop packets [1, 5, 5, 7, 11, 13, 14, 14, 15, 15]
6277: CON [MID=51788, T=06E53C4661F6663C], GET, /test    -----> Dropping packet 1 (burst 1/4) from server
6578: CON [MID=51788, T=06E53C4661F6663C], GET, /test    ----->
6579: <-----   ACK [MID=51788, T=06E53C4661F6663C], 2.05, 2:0/1/32, size2(250)
6580: CON [MID=51789, T=06E53C4661F6663C], GET, /test, 2:1/0/32    -----> Dropping packet 5 (burst 1/4) from server
6881: CON [MID=51789, T=06E53C4661F6663C], GET, /test, 2:1/0/32    -----> Dropping packet 7 (burst 2/4) from server
7332: CON [MID=51789, T=06E53C4661F6663C], GET, /test, 2:1/0/32    ----->
7333: <-----   ACK [MID=51789, T=06E53C4661F6663C], 2.05, 2:1/1/32
7333: CON [MID=51790, T=06E53C4661F6663C], GET, /test, 2:2/0/32    -----> Dropping packet 11 (burst 1/4) from server
7634: CON [MID=51790, T=06E53C4661F6663C], GET, /test, 2:2/0/32    -----> Dropping packet 13 (burst 2/4) from server
8085: CON [MID=51790, T=06E53C4661F6663C], GET, /test, 2:2/0/32    -----> Dropping packet 14 (burst 3/4) from client
8761: CON [MID=51790, T=06E53C4661F6663C], GET, /test, 2:2/0/32    -----> Dropping packet 15 (burst 4/4) from client
9774: CON [MID=51790, T=06E53C4661F6663C], GET, /test, 2:2/0/32    ----->
9775: <-----   ACK [MID=51790, T=06E53C4661F6663C], 2.05, 2:2/1/32
9775: CON [MID=51791, T=06E53C4661F6663C], GET, /test, 2:3/0/32    ----->
9777: <-----   ACK [MID=51791, T=06E53C4661F6663C], 2.05, 2:3/1/32
9777: CON [MID=51792, T=06E53C4661F6663C], GET, /test, 2:4/0/32    ----->
9779: <-----   ACK [MID=51792, T=06E53C4661F6663C], 2.05, 2:4/1/32
9779: CON [MID=51793, T=06E53C4661F6663C], GET, /test, 2:5/0/32    ----->
9780: <-----   ACK [MID=51793, T=06E53C4661F6663C], 2.05, 2:5/1/32
9781: CON [MID=51794, T=06E53C4661F6663C], GET, /test, 2:6/0/32    ----->
9782: <-----   ACK [MID=51794, T=06E53C4661F6663C], 2.05, 2:6/1/32
9783: CON [MID=51795, T=06E53C4661F6663C], GET, /test, 2:7/0/32    ----->
9784: <-----   ACK [MID=51795, T=06E53C4661F6663C], 2.05, 2:7/0/32

doing a blockwise GET on: coap://localhost:8273/test
Received 250 bytes after 2948 ms
Man in the middle will drop packets [0, 1, 7, 8, 11, 12, 12, 14, 14, 14]
12248: CON [MID=51796, T=4E1A26BC9CCCB0E8], GET, /test    -----> Dropping packet 0 (burst 1/4) from client
12553: CON [MID=51796, T=4E1A26BC9CCCB0E8], GET, /test    -----> Dropping packet 1 (burst 2/4) from client
13004: CON [MID=51796, T=4E1A26BC9CCCB0E8], GET, /test    ----->
13005: <-----   ACK [MID=51796, T=4E1A26BC9CCCB0E8], 2.05, 2:0/1/32, size2(250)
13006: CON [MID=51797, T=4E1A26BC9CCCB0E8], GET, /test, 2:1/0/32    ----->
13007: <-----   ACK [MID=51797, T=4E1A26BC9CCCB0E8], 2.05, 2:1/1/32
13008: CON [MID=51798, T=4E1A26BC9CCCB0E8], GET, /test, 2:2/0/32    -----> Dropping packet 7 (burst 1/4) from server
13308: CON [MID=51798, T=4E1A26BC9CCCB0E8], GET, /test, 2:2/0/32    -----> Dropping packet 8 (burst 2/4) from client
13759: CON [MID=51798, T=4E1A26BC9CCCB0E8], GET, /test, 2:2/0/32    ----->
13760: <-----   ACK [MID=51798, T=4E1A26BC9CCCB0E8], 2.05, 2:2/1/32
13761: CON [MID=51799, T=4E1A26BC9CCCB0E8], GET, /test, 2:3/0/32    -----> Dropping packet 11 (burst 2/4) from client
14061: CON [MID=51799, T=4E1A26BC9CCCB0E8], GET, /test, 2:3/0/32    -----> Dropping packet 12 (burst 3/4) from client
14512: CON [MID=51799, T=4E1A26BC9CCCB0E8], GET, /test, 2:3/0/32    -----> Dropping packet 14 (burst 4/4) from server
15188: CON [MID=51799, T=4E1A26BC9CCCB0E8], GET, /test, 2:3/0/32    ----->
15189: <-----   ACK [MID=51799, T=4E1A26BC9CCCB0E8], 2.05, 2:3/1/32
15190: CON [MID=51800, T=4E1A26BC9CCCB0E8], GET, /test, 2:4/0/32    ----->
15191: <-----   ACK [MID=51800, T=4E1A26BC9CCCB0E8], 2.05, 2:4/1/32
15191: CON [MID=51801, T=4E1A26BC9CCCB0E8], GET, /test, 2:5/0/32    ----->
15193: <-----   ACK [MID=51801, T=4E1A26BC9CCCB0E8], 2.05, 2:5/1/32
15193: CON [MID=51802, T=4E1A26BC9CCCB0E8], GET, /test, 2:6/0/32    ----->
15194: <-----   ACK [MID=51802, T=4E1A26BC9CCCB0E8], 2.05, 2:6/1/32
15195: CON [MID=51803, T=4E1A26BC9CCCB0E8], GET, /test, 2:7/0/32    ----->
15196: <-----   ACK [MID=51803, T=4E1A26BC9CCCB0E8], 2.05, 2:7/0/32

doing a blockwise GET on: coap://localhost:8273/test
Received 250 bytes after 3356 ms
Man in the middle will drop packets [0, 2, 3, 4, 5, 7, 7, 8, 11, 14]
15198: CON [MID=51804, T=3215A30381037C1A], GET, /test    -----> Dropping packet 0 (burst 1/4) from client
15498: CON [MID=51804, T=3215A30381037C1A], GET, /test    -----> Dropping packet 2 (burst 2/4) from server
15949: CON [MID=51804, T=3215A30381037C1A], GET, /test    -----> Dropping packet 3 (burst 3/4) from client
16625: CON [MID=51804, T=3215A30381037C1A], GET, /test    -----> Dropping packet 4 (burst 4/4) from client
17638: CON [MID=51804, T=3215A30381037C1A], GET, /test    ----->
17640: <-----   ACK [MID=51804, T=3215A30381037C1A], 2.05, 2:0/1/32, size2(250)
17640: CON [MID=51805, T=3215A30381037C1A], GET, /test, 2:1/0/32    -----> Dropping packet 8 (burst 1/4) from server
17941: CON [MID=51805, T=3215A30381037C1A], GET, /test, 2:1/0/32    ----->
17942: <-----   ACK [MID=51805, T=3215A30381037C1A], 2.05, 2:1/1/32
17942: CON [MID=51806, T=3215A30381037C1A], GET, /test, 2:2/0/32    -----> Dropping packet 11 (burst 1/4) from client
18243: CON [MID=51806, T=3215A30381037C1A], GET, /test, 2:2/0/32    ----->
18245: <-----   ACK [MID=51806, T=3215A30381037C1A], 2.05, 2:2/1/32
18245: CON [MID=51807, T=3215A30381037C1A], GET, /test, 2:3/0/32    -----> Dropping packet 14 (burst 1/4) from client
18546: CON [MID=51807, T=3215A30381037C1A], GET, /test, 2:3/0/32    ----->
18547: <-----   ACK [MID=51807, T=3215A30381037C1A], 2.05, 2:3/1/32
18548: CON [MID=51808, T=3215A30381037C1A], GET, /test, 2:4/0/32    ----->
18549: <-----   ACK [MID=51808, T=3215A30381037C1A], 2.05, 2:4/1/32
18549: CON [MID=51809, T=3215A30381037C1A], GET, /test, 2:5/0/32    ----->
18550: <-----   ACK [MID=51809, T=3215A30381037C1A], 2.05, 2:5/1/32
18551: CON [MID=51810, T=3215A30381037C1A], GET, /test, 2:6/0/32    ----->
18552: <-----   ACK [MID=51810, T=3215A30381037C1A], 2.05, 2:6/1/32
18552: CON [MID=51811, T=3215A30381037C1A], GET, /test, 2:7/0/32    ----->
18553: <-----   ACK [MID=51811, T=3215A30381037C1A], 2.05, 2:7/0/32

doing a blockwise GET on: coap://localhost:8273/test
Received 250 bytes after 2270 ms

End LossyBlockwiseTransferTestMan in the middle will drop packets [1, 1, 1, 2, 7, 8, 8, 13, 13, 15]
18555: CON [MID=51812, T=763D75EAEFEC5722], GET, /test    -----> Dropping packet 1 (burst 1/4) from server
18855: CON [MID=51812, T=763D75EAEFEC5722], GET, /test    -----> Dropping packet 2 (burst 2/4) from client
19306: CON [MID=51812, T=763D75EAEFEC5722], GET, /test    ----->
19307: <-----   ACK [MID=51812, T=763D75EAEFEC5722], 2.05, 2:0/1/32, size2(250)
19308: CON [MID=51813, T=763D75EAEFEC5722], GET, /test, 2:1/0/32    ----->
19309: <-----   ACK [MID=51813, T=763D75EAEFEC5722], 2.05, 2:1/1/32
19309: CON [MID=51814, T=763D75EAEFEC5722], GET, /test, 2:2/0/32    -----> Dropping packet 7 (burst 1/4) from client
19610: CON [MID=51814, T=763D75EAEFEC5722], GET, /test, 2:2/0/32    -----> Dropping packet 8 (burst 2/4) from client
20061: CON [MID=51814, T=763D75EAEFEC5722], GET, /test, 2:2/0/32    ----->
20062: <-----   ACK [MID=51814, T=763D75EAEFEC5722], 2.05, 2:2/1/32
20063: CON [MID=51815, T=763D75EAEFEC5722], GET, /test, 2:3/0/32    ----->
20064: <-----   ACK [MID=51815, T=763D75EAEFEC5722], 2.05, 2:3/1/32
20065: CON [MID=51816, T=763D75EAEFEC5722], GET, /test, 2:4/0/32    -----> Dropping packet 13 (burst 1/4) from client
20365: CON [MID=51816, T=763D75EAEFEC5722], GET, /test, 2:4/0/32    -----> Dropping packet 15 (burst 2/4) from server
20816: CON [MID=51816, T=763D75EAEFEC5722], GET, /test, 2:4/0/32    ----->
20818: <-----   ACK [MID=51816, T=763D75EAEFEC5722], 2.05, 2:4/1/32
20818: CON [MID=51817, T=763D75EAEFEC5722], GET, /test, 2:5/0/32    ----->
20820: <-----   ACK [MID=51817, T=763D75EAEFEC5722], 2.05, 2:5/1/32
20820: CON [MID=51818, T=763D75EAEFEC5722], GET, /test, 2:6/0/32    ----->
20822: <-----   ACK [MID=51818, T=763D75EAEFEC5722], 2.05, 2:6/1/32
20822: CON [MID=51819, T=763D75EAEFEC5722], GET, /test, 2:7/0/32    ----->
20823: <-----   ACK [MID=51819, T=763D75EAEFEC5722], 2.05, 2:7/0/32
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 20.82 s - in org.eclipse.californium.core.test.maninmiddle.LossyBlockwiseTransferTest
[INFO] 
[INFO] Results:
[INFO] 
[ERROR] Failures: 
[ERROR]   BlockwiseServerSideTest.testIncompletePUT:385 expected:<2.31> but was:<4.08>
[INFO] 
[ERROR] Tests run: 39, Failures: 1, Errors: 0, Skipped: 0
[INFO] 
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary:
[INFO] 
[INFO] Californium (Cf) Parent 2.0.0-SNAPSHOT ............. SUCCESS [  3.511 s]
[INFO] Legal Documents .................................... SUCCESS [  1.850 s]
[INFO] Californium (Cf) Demo Certificates ................. SUCCESS [  0.208 s]
[INFO] element-connector .................................. SUCCESS [01:01 min]
[INFO] Scandium (Sc) Core ................................. SUCCESS [01:38 min]
[INFO] element-connector-tcp .............................. SUCCESS [ 38.396 s]
[INFO] Californium (Cf) Core .............................. FAILURE [01:50 min]
[INFO] Californium (Cf) Demo Applications ................. SKIPPED
[INFO] Cf-NAT ............................................. SKIPPED
[INFO] Californium (Cf) Integration Tests ................. SKIPPED
[INFO] Californium (Cf) Proxy ............................. SKIPPED
[INFO] Californium (Cf) OSGi .............................. 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-ExtendedPlugtestClient .......................... SKIPPED
[INFO] Cf-ExtendedPlugtestServer .......................... SKIPPED
[INFO] Cf-HelloWorldClient ................................ SKIPPED
[INFO] Cf-HelloWorldServer ................................ SKIPPED
[INFO] Cf-SimpleFileServer ................................ SKIPPED
[INFO] Cf-CoCoAClient ..................................... SKIPPED
[INFO] Cf-SecureServer .................................... SKIPPED
[INFO] Cf-ExampleCrossProxy ............................... SKIPPED
[INFO] Cf-BenchmarkServer ................................. SKIPPED
[INFO] Cf-ObserveBenchmarkClient .......................... SKIPPED
[INFO] Cf-OSCORE 2.0.0-SNAPSHOT ........................... SKIPPED
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 05:18 min
[INFO] Finished at: 2019-03-01T10:31:23-05:00
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.22.1:test (large-tests) on project californium-core: There are test failures.
[ERROR] 
[ERROR] Please refer to /jobs/genie.californium/2.0.x/workspace/californium-core/target/surefire-reports for the individual test results.
[ERROR] Please refer to dump files (if any exist) [date].dump, [date]-jvmRun[N].dump and [date].dumpstream.
[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
Build step 'Invoke top-level Maven targets' marked build as failure


Back to the top