You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/06/13 05:44:49 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2173
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2173/changes>
Changes:
[vinod] Fixed SlaveRecoveryTest.RestartBeforeContainerizerLaunch test.
------------------------------------------
[...truncated 49705 lines...]
I0613 03:44:46.897430 9049 master.cpp:3381] Successfully authenticated principal 'test-principal' at slave(180)@67.195.138.9:58255
I0613 03:44:46.897476 9049 authenticatee.hpp:305] Authentication success
I0613 03:44:46.897502 9049 authenticator.hpp:156] Creating new server SASL connection
I0613 03:44:46.897553 9049 slave.cpp:670] Successfully authenticated with master master@67.195.138.9:58255
I0613 03:44:46.897593 9049 slave.cpp:908] Will retry registration in 5.75444ms if necessary
I0613 03:44:46.897629 9049 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0613 03:44:46.897642 9049 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0613 03:44:46.897691 9049 master.cpp:2620] Registering slave at slave(180)@67.195.138.9:58255 (vesta.apache.org) with id 20140613-034446-160088899-58255-9025-0
I0613 03:44:46.897759 9049 authenticator.hpp:262] Received SASL authentication start
I0613 03:44:46.897783 9049 authenticator.hpp:384] Authentication requires more steps
I0613 03:44:46.897831 9049 registrar.cpp:422] Attempting to update the 'registry'
I0613 03:44:46.898763 9049 authenticatee.hpp:265] Received SASL authentication step
I0613 03:44:46.898838 9049 authenticator.hpp:290] Received SASL authentication step
I0613 03:44:46.898861 9049 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0613 03:44:46.898869 9049 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0613 03:44:46.898876 9049 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0613 03:44:46.898885 9049 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0613 03:44:46.898892 9049 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0613 03:44:46.898897 9049 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0613 03:44:46.898905 9049 authenticator.hpp:376] Authentication success
I0613 03:44:46.898927 9049 authenticatee.hpp:305] Authentication success
I0613 03:44:46.898947 9049 master.cpp:3381] Successfully authenticated principal 'test-principal' at scheduler(170)@67.195.138.9:58255
I0613 03:44:46.898994 9049 sched.cpp:348] Successfully authenticated with master master@67.195.138.9:58255
I0613 03:44:46.899006 9049 sched.cpp:467] Sending registration request to master@67.195.138.9:58255
I0613 03:44:46.899042 9049 master.cpp:1080] Received registration request from scheduler(170)@67.195.138.9:58255
I0613 03:44:46.899060 9049 master.cpp:1040] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0613 03:44:46.899168 9049 master.cpp:1139] Registering framework 20140613-034446-160088899-58255-9025-0000 at scheduler(170)@67.195.138.9:58255
I0613 03:44:46.899226 9049 sched.cpp:398] Framework registered with 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.899246 9049 sched.cpp:412] Scheduler::registered took 9500ns
I0613 03:44:46.899274 9049 hierarchical_allocator_process.hpp:331] Added framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.899286 9049 hierarchical_allocator_process.hpp:724] No resources available to allocate!
I0613 03:44:46.899291 9049 hierarchical_allocator_process.hpp:686] Performed allocation for 0 slaves in 7491ns
I0613 03:44:46.900604 9050 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 6.921269ms
I0613 03:44:46.900624 9050 replica.cpp:676] Persisted action at 2
I0613 03:44:46.901018 9045 replica.cpp:655] Replica received learned notice for position 2
I0613 03:44:46.903856 9046 slave.cpp:908] Will retry registration in 30.92897ms if necessary
I0613 03:44:46.903898 9044 master.cpp:2608] Ignoring register slave message from slave(180)@67.195.138.9:58255 (vesta.apache.org) as admission is already in progress
I0613 03:44:46.908589 9045 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 7.557692ms
I0613 03:44:46.908629 9045 leveldb.cpp:401] Deleting ~1 keys from leveldb took 22293ns
I0613 03:44:46.908638 9045 replica.cpp:676] Persisted action at 2
I0613 03:44:46.908645 9045 replica.cpp:661] Replica learned TRUNCATE action at position 2
I0613 03:44:46.908974 9047 log.cpp:680] Attempting to append 325 bytes to the log
I0613 03:44:46.909055 9045 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3
I0613 03:44:46.909438 9045 replica.cpp:508] Replica received write request for position 3
I0613 03:44:46.916559 9045 leveldb.cpp:343] Persisting action (344 bytes) to leveldb took 7.102594ms
I0613 03:44:46.916576 9045 replica.cpp:676] Persisted action at 3
I0613 03:44:46.916926 9050 replica.cpp:655] Replica received learned notice for position 3
I0613 03:44:46.924535 9050 leveldb.cpp:343] Persisting action (346 bytes) to leveldb took 7.571739ms
I0613 03:44:46.924553 9050 replica.cpp:676] Persisted action at 3
I0613 03:44:46.924562 9050 replica.cpp:661] Replica learned APPEND action at position 3
I0613 03:44:46.924984 9050 registrar.cpp:479] Successfully updated 'registry'
I0613 03:44:46.925125 9049 log.cpp:699] Attempting to truncate the log to 3
I0613 03:44:46.925161 9046 master.cpp:2660] Registered slave 20140613-034446-160088899-58255-9025-0 at slave(180)@67.195.138.9:58255 (vesta.apache.org)
I0613 03:44:46.925263 9046 master.cpp:3763] Adding slave 20140613-034446-160088899-58255-9025-0 at slave(180)@67.195.138.9:58255 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0613 03:44:46.925302 9047 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4
I0613 03:44:46.925379 9048 slave.cpp:704] Registered with master master@67.195.138.9:58255; given slave ID 20140613-034446-160088899-58255-9025-0
I0613 03:44:46.925586 9047 hierarchical_allocator_process.hpp:444] Added slave 20140613-034446-160088899-58255-9025-0 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I0613 03:44:46.925672 9047 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140613-034446-160088899-58255-9025-0 to framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.925680 9046 replica.cpp:508] Replica received write request for position 4
I0613 03:44:46.925797 9047 hierarchical_allocator_process.hpp:706] Performed allocation for slave 20140613-034446-160088899-58255-9025-0 in 163233ns
I0613 03:44:46.925895 9051 master.hpp:720] Adding offer 20140613-034446-160088899-58255-9025-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140613-034446-160088899-58255-9025-0 (vesta.apache.org)
I0613 03:44:46.925993 9051 master.cpp:3288] Sending 1 offers to framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.926177 9051 sched.cpp:535] Scheduler::resourceOffers took 26332ns
I0613 03:44:46.927397 9044 master.hpp:730] Removing offer 20140613-034446-160088899-58255-9025-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140613-034446-160088899-58255-9025-0 (vesta.apache.org)
I0613 03:44:46.927459 9044 master.cpp:1964] Processing reply for offers: [ 20140613-034446-160088899-58255-9025-0 ] on slave 20140613-034446-160088899-58255-9025-0 at slave(180)@67.195.138.9:58255 (vesta.apache.org) for framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.927489 9044 master.cpp:2050] Authorizing framework principal 'test-principal' to launch task 80560b27-2e23-4888-ade4-9102b27be756 as user 'jenkins'
I0613 03:44:46.927824 9044 master.hpp:692] Adding task 80560b27-2e23-4888-ade4-9102b27be756 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140613-034446-160088899-58255-9025-0 (vesta.apache.org)
I0613 03:44:46.927860 9044 master.cpp:2116] Launching task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140613-034446-160088899-58255-9025-0 at slave(180)@67.195.138.9:58255 (vesta.apache.org)
I0613 03:44:46.927988 9044 slave.cpp:939] Got assigned task 80560b27-2e23-4888-ade4-9102b27be756 for framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.928164 9044 slave.cpp:1049] Launching task 80560b27-2e23-4888-ade4-9102b27be756 for framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.930016 9044 exec.cpp:131] Version: 0.20.0
I0613 03:44:46.930112 9044 slave.cpp:1159] Queuing task '80560b27-2e23-4888-ade4-9102b27be756' for executor default of framework '20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.930152 9044 slave.cpp:2361] Monitoring executor 'default' of framework '20140613-034446-160088899-58255-9025-0000' in container 'e1b411bb-cd5a-48fe-81a7-de4b7e5099e7'
I0613 03:44:46.930233 9044 exec.cpp:181] Executor started at: executor(55)@67.195.138.9:58255 with pid 9025
I0613 03:44:46.930289 9044 slave.cpp:498] Successfully attached file '/tmp/SlaveTest_IgnoreNonLeaderStatusUpdateAcknowledgement_mOKJWQ/slaves/20140613-034446-160088899-58255-9025-0/frameworks/20140613-034446-160088899-58255-9025-0000/executors/default/runs/e1b411bb-cd5a-48fe-81a7-de4b7e5099e7'
I0613 03:44:46.930311 9044 slave.cpp:1670] Got registration for executor 'default' of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.930398 9044 slave.cpp:1789] Flushing queued task 80560b27-2e23-4888-ade4-9102b27be756 for executor 'default' of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.930460 9044 exec.cpp:205] Executor registered on slave 20140613-034446-160088899-58255-9025-0
I0613 03:44:46.931202 9044 exec.cpp:217] Executor::registered took 10077ns
I0613 03:44:46.931252 9044 exec.cpp:292] Executor asked to run task '80560b27-2e23-4888-ade4-9102b27be756'
I0613 03:44:46.931284 9044 exec.cpp:301] Executor::launchTask took 23869ns
I0613 03:44:46.932031 9044 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 9eb81d99-9c60-4d1f-b3cd-944837ea1305) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.932099 9044 slave.cpp:2024] Handling status update TASK_RUNNING (UUID: 9eb81d99-9c60-4d1f-b3cd-944837ea1305) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000 from executor(55)@67.195.138.9:58255
I0613 03:44:46.932164 9044 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 9eb81d99-9c60-4d1f-b3cd-944837ea1305) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.932174 9044 status_update_manager.cpp:499] Creating StatusUpdate stream for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.932222 9044 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: 9eb81d99-9c60-4d1f-b3cd-944837ea1305) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000 to master@67.195.138.9:58255
I0613 03:44:46.932317 9044 master.cpp:2946] Status update TASK_RUNNING (UUID: 9eb81d99-9c60-4d1f-b3cd-944837ea1305) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000 from slave 20140613-034446-160088899-58255-9025-0 at slave(180)@67.195.138.9:58255 (vesta.apache.org)
I0613 03:44:46.932343 9044 slave.cpp:2145] Status update manager successfully handled status update TASK_RUNNING (UUID: 9eb81d99-9c60-4d1f-b3cd-944837ea1305) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.932351 9044 slave.cpp:2151] Sending acknowledgement for status update TASK_RUNNING (UUID: 9eb81d99-9c60-4d1f-b3cd-944837ea1305) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000 to executor(55)@67.195.138.9:58255
I0613 03:44:46.932405 9044 sched.cpp:626] Scheduler::statusUpdate took 9594ns
I0613 03:44:46.932436 9044 exec.cpp:338] Executor received status update acknowledgement 9eb81d99-9c60-4d1f-b3cd-944837ea1305 for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.932519 9046 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 6.819725ms
I0613 03:44:46.932554 9046 replica.cpp:676] Persisted action at 4
I0613 03:44:46.932842 9048 replica.cpp:655] Replica received learned notice for position 4
I0613 03:44:46.940503 9048 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 7.643288ms
I0613 03:44:46.940546 9048 leveldb.cpp:401] Deleting ~2 keys from leveldb took 16312ns
I0613 03:44:46.940554 9048 replica.cpp:676] Persisted action at 4
I0613 03:44:46.940563 9048 replica.cpp:661] Replica learned TRUNCATE action at position 4
I0613 03:44:46.957546 9051 master.cpp:2470] Forwarding status update acknowledgement 9eb81d99-9c60-4d1f-b3cd-944837ea1305 for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000 to slave 20140613-034446-160088899-58255-9025-0 at slave(180)@67.195.138.9:58255 (vesta.apache.org)
I0613 03:44:46.967747 9052 process.cpp:1096] Socket error while receiving: Connection refused
I0613 03:44:46.967787 9052 process.cpp:1140] Socket error while sending: Broken pipe
I0613 03:44:46.978112 9050 hierarchical_allocator_process.hpp:686] Performed allocation for 1 slaves in 22227ns
I0613 03:44:46.978214 9047 master.cpp:114] No whitelist given. Advertising offers for all slaves
W0613 03:44:46.978268 9045 status_update_manager.cpp:477] Resending status update TASK_RUNNING (UUID: 9eb81d99-9c60-4d1f-b3cd-944837ea1305) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.978291 9045 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: 9eb81d99-9c60-4d1f-b3cd-944837ea1305) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000 to master@67.195.138.9:58255
I0613 03:44:46.978466 9051 master.cpp:2946] Status update TASK_RUNNING (UUID: 9eb81d99-9c60-4d1f-b3cd-944837ea1305) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000 from slave 20140613-034446-160088899-58255-9025-0 at slave(180)@67.195.138.9:58255 (vesta.apache.org)
I0613 03:44:46.978559 9048 sched.cpp:626] Scheduler::statusUpdate took 19917ns
I0613 03:44:46.978709 9044 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 9eb81d99-9c60-4d1f-b3cd-944837ea1305) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:46.978801 9046 slave.cpp:1610] Status update manager successfully handled status update acknowledgement (UUID: 9eb81d99-9c60-4d1f-b3cd-944837ea1305) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:47.008046 9044 sched.cpp:731] Stopping framework '20140613-034446-160088899-58255-9025-0000'
I0613 03:44:47.008069 9025 master.cpp:575] Master terminating
I0613 03:44:47.008144 9025 master.hpp:710] Removing task 80560b27-2e23-4888-ade4-9102b27be756 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140613-034446-160088899-58255-9025-0 (vesta.apache.org)
W0613 03:44:47.008221 9025 master.cpp:4049] Removing task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000 and slave 20140613-034446-160088899-58255-9025-0 in non-terminal state TASK_RUNNING
I0613 03:44:47.008337 9050 hierarchical_allocator_process.hpp:635] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 20140613-034446-160088899-58255-9025-0 from framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:47.008501 9049 slave.cpp:2230] master@67.195.138.9:58255 exited
W0613 03:44:47.008514 9049 slave.cpp:2233] Master disconnected! Waiting for a new master to be elected
I0613 03:44:47.011050 9051 slave.cpp:2419] Executor 'default' of framework 20140613-034446-160088899-58255-9025-0000 has exited with status 0
I0613 03:44:47.011852 9051 slave.cpp:2024] Handling status update TASK_LOST (UUID: a5d8d497-bf44-459d-8807-2089bf3420ad) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000 from @0.0.0.0:0
I0613 03:44:47.011873 9051 slave.cpp:3666] Terminating task 80560b27-2e23-4888-ade4-9102b27be756
I0613 03:44:47.012044 9051 status_update_manager.cpp:320] Received status update TASK_LOST (UUID: a5d8d497-bf44-459d-8807-2089bf3420ad) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:47.012063 9051 status_update_manager.cpp:373] Forwarding status update TASK_LOST (UUID: a5d8d497-bf44-459d-8807-2089bf3420ad) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000 to master@67.195.138.9:58255
I0613 03:44:47.012122 9051 slave.cpp:2145] Status update manager successfully handled status update TASK_LOST (UUID: a5d8d497-bf44-459d-8807-2089bf3420ad) for task 80560b27-2e23-4888-ade4-9102b27be756 of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:47.012284 9025 slave.cpp:426] Slave terminating
I0613 03:44:47.012296 9025 slave.cpp:1343] Asked to shut down framework 20140613-034446-160088899-58255-9025-0000 by @0.0.0.0:0
I0613 03:44:47.012306 9025 slave.cpp:1368] Shutting down framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:47.012316 9025 slave.cpp:2558] Cleaning up executor 'default' of framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:47.012403 9025 slave.cpp:2633] Cleaning up framework 20140613-034446-160088899-58255-9025-0000
I0613 03:44:47.012444 9047 gc.cpp:56] Scheduling '/tmp/SlaveTest_IgnoreNonLeaderStatusUpdateAcknowledgement_mOKJWQ/slaves/20140613-034446-160088899-58255-9025-0/frameworks/20140613-034446-160088899-58255-9025-0000/executors/default/runs/e1b411bb-cd5a-48fe-81a7-de4b7e5099e7' for gc 6.9999998570963days in the future
I0613 03:44:47.012528 9047 gc.cpp:56] Scheduling '/tmp/SlaveTest_IgnoreNonLeaderStatusUpdateAcknowledgement_mOKJWQ/slaves/20140613-034446-160088899-58255-9025-0/frameworks/20140613-034446-160088899-58255-9025-0000/executors/default' for gc 6.99999985661037days in the future
I0613 03:44:47.012630 9047 gc.cpp:56] Scheduling '/tmp/SlaveTest_IgnoreNonLeaderStatusUpdateAcknowledgement_mOKJWQ/slaves/20140613-034446-160088899-58255-9025-0/frameworks/20140613-034446-160088899-58255-9025-0000' for gc 6.99999985592593days in the future
[ OK ] SlaveTest.IgnoreNonLeaderStatusUpdateAcknowledgement (364 ms)
[----------] 6 tests from SlaveTest (5004 ms total)
[----------] 4 tests from ReplicaTest
[ RUN ] ReplicaTest.Append
Using temporary directory '/tmp/ReplicaTest_Append_L1Nfzl'
I0613 03:44:47.104490 9025 leveldb.cpp:176] Opened db in 90.721169ms
I0613 03:44:47.106958 9025 leveldb.cpp:183] Compacted db in 2.445131ms
I0613 03:44:47.106976 9025 leveldb.cpp:198] Created db iterator in 3163ns
I0613 03:44:47.106983 9025 leveldb.cpp:204] Seeked to beginning of db in 628ns
I0613 03:44:47.106988 9025 leveldb.cpp:273] Iterated through 0 keys in the db in 303ns
I0613 03:44:47.106999 9025 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0613 03:44:47.140112 9044 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 32.866345ms
I0613 03:44:47.140133 9044 replica.cpp:320] Persisted replica status to VOTING
I0613 03:44:47.216245 9025 leveldb.cpp:176] Opened db in 75.916288ms
I0613 03:44:47.259361 9025 leveldb.cpp:183] Compacted db in 43.094051ms
I0613 03:44:47.259379 9025 leveldb.cpp:198] Created db iterator in 2960ns
I0613 03:44:47.259395 9025 leveldb.cpp:204] Seeked to beginning of db in 7779ns
I0613 03:44:47.259413 9025 leveldb.cpp:273] Iterated through 1 keys in the db in 9364ns
I0613 03:44:47.259423 9025 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0613 03:44:47.259552 9047 replica.cpp:474] Replica received implicit promise request with proposal 1
I0613 03:44:47.295909 9047 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 36.338301ms
I0613 03:44:47.295928 9047 replica.cpp:342] Persisted promised to 1
I0613 03:44:47.296143 9047 replica.cpp:508] Replica received write request for position 1
I0613 03:44:47.308668 9047 leveldb.cpp:343] Persisting action (27 bytes) to leveldb took 12.511923ms
I0613 03:44:47.308688 9047 replica.cpp:676] Persisted action at 1
I0613 03:44:47.308914 9045 leveldb.cpp:438] Reading position from leveldb took 16688ns
[ OK ] ReplicaTest.Append (296 ms)
[ RUN ] ReplicaTest.Promise
Using temporary directory '/tmp/ReplicaTest_Promise_a2lIZQ'
I0613 03:44:47.385162 9025 leveldb.cpp:176] Opened db in 75.478188ms
I0613 03:44:47.389678 9025 leveldb.cpp:183] Compacted db in 4.493669ms
I0613 03:44:47.389700 9025 leveldb.cpp:198] Created db iterator in 4532ns
I0613 03:44:47.389709 9025 leveldb.cpp:204] Seeked to beginning of db in 671ns
I0613 03:44:47.389718 9025 leveldb.cpp:273] Iterated through 0 keys in the db in 373ns
I0613 03:44:47.389735 9025 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0613 03:44:47.423782 9050 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 33.919015ms
I0613 03:44:47.423813 9050 replica.cpp:320] Persisted replica status to VOTING
I0613 03:44:47.515441 9025 leveldb.cpp:176] Opened db in 91.451642ms
I0613 03:44:47.570370 9025 leveldb.cpp:183] Compacted db in 54.908933ms
I0613 03:44:47.570399 9025 leveldb.cpp:198] Created db iterator in 4514ns
I0613 03:44:47.570495 9025 leveldb.cpp:204] Seeked to beginning of db in 45308ns
I0613 03:44:47.570513 9025 leveldb.cpp:273] Iterated through 1 keys in the db in 7335ns
I0613 03:44:47.570524 9025 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0613 03:44:47.570720 9049 replica.cpp:474] Replica received implicit promise request with proposal 2
I0613 03:44:47.611048 9049 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 40.315589ms
I0613 03:44:47.611068 9049 replica.cpp:342] Persisted promised to 2
I0613 03:44:47.611224 9049 replica.cpp:474] Replica received implicit promise request with proposal 1
I0613 03:44:47.611232 9049 replica.cpp:479] Replica denying promise request with proposal 1
I0613 03:44:47.611357 9049 replica.cpp:474] Replica received implicit promise request with proposal 3
I0613 03:44:47.619314 9049 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 7.946465ms
I0613 03:44:47.619331 9049 replica.cpp:342] Persisted promised to 3
[ OK ] ReplicaTest.Promise (310 ms)
[ RUN ] ReplicaTest.NonVoting
Using temporary directory '/tmp/ReplicaTest_NonVoting_MIexgn'
I0613 03:44:47.685881 9025 leveldb.cpp:176] Opened db in 65.994183ms
I0613 03:44:47.692308 9025 leveldb.cpp:183] Compacted db in 6.407781ms
I0613 03:44:47.692328 9025 leveldb.cpp:198] Created db iterator in 2586ns
I0613 03:44:47.692337 9025 leveldb.cpp:204] Seeked to beginning of db in 313ns
I0613 03:44:47.692344 9025 leveldb.cpp:273] Iterated through 0 keys in the db in 126ns
I0613 03:44:47.692354 9025 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0613 03:44:47.692430 9044 replica.cpp:369] Replica ignoring promise request as it is in EMPTY status
I0613 03:44:47.702604 9048 replica.cpp:503] Replica ignoring write request as it is in EMPTY status
[ OK ] ReplicaTest.NonVoting (93 ms)
[ RUN ] ReplicaTest.Restore
Using temporary directory '/tmp/ReplicaTest_Restore_ydW3MT'
I0613 03:44:47.783061 9025 leveldb.cpp:176] Opened db in 70.106761ms
I0613 03:44:47.787850 9025 leveldb.cpp:183] Compacted db in 4.770996ms
I0613 03:44:47.787870 9025 leveldb.cpp:198] Created db iterator in 2039ns
I0613 03:44:47.787878 9025 leveldb.cpp:204] Seeked to beginning of db in 316ns
I0613 03:44:47.787885 9025 leveldb.cpp:273] Iterated through 0 keys in the db in 99ns
I0613 03:44:47.787896 9025 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0613 03:44:47.822614 9047 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 34.554544ms
I0613 03:44:47.822638 9047 replica.cpp:320] Persisted replica status to VOTING
I0613 03:44:47.906781 9025 leveldb.cpp:176] Opened db in 83.890797ms
I0613 03:44:47.941228 9025 leveldb.cpp:183] Compacted db in 34.424352ms
I0613 03:44:47.941249 9025 leveldb.cpp:198] Created db iterator in 3479ns
I0613 03:44:47.941263 9025 leveldb.cpp:204] Seeked to beginning of db in 6017ns
I0613 03:44:47.941277 9025 leveldb.cpp:273] Iterated through 1 keys in the db in 5028ns
I0613 03:44:47.941288 9025 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0613 03:44:47.941442 9047 replica.cpp:474] Replica received implicit promise request with proposal 1
I0613 03:44:47.986444 9047 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 44.977285ms
I0613 03:44:47.986464 9047 replica.cpp:342] Persisted promised to 1
I0613 03:44:47.986784 9049 replica.cpp:508] Replica received write request for position 1
I0613 03:44:47.998325 9049 leveldb.cpp:343] Persisting action (27 bytes) to leveldb took 11.522065ms
I0613 03:44:47.998348 9049 replica.cpp:676] Persisted action at 1
I0613 03:44:47.998476 9048 leveldb.cpp:438] Reading position from leveldb took 13596ns
I0613 03:44:48.098044 9025 leveldb.cpp:176] Opened db in 99.361526ms
I0613 03:44:48.131186 9025 leveldb.cpp:183] Compacted db in 33.116261ms
I0613 03:44:48.131211 9025 leveldb.cpp:198] Created db iterator in 4349ns
I0613 03:44:48.131225 9025 leveldb.cpp:204] Seeked to beginning of db in 6634ns
I0613 03:44:48.131245 9025 leveldb.cpp:273] Iterated through 2 keys in the db in 12696ns
I0613 03:44:48.131259 9025 replica.cpp:741] Replica recovered with log positions 0 -> 1 with 1 holes and 1 unlearned
I0613 03:44:48.131331 9048 leveldb.cpp:438] Reading position from leveldb took 25457ns
[ OK ] ReplicaTest.Restore (419 ms)
[----------] 4 tests from ReplicaTest (1118 ms total)
[----------] 1 test from ZooKeeper
[ RUN ] ZooKeeper.URL
[ OK ] ZooKeeper.URL (1 ms)
[----------] 1 test from ZooKeeper (1 ms total)
[----------] Global test environment tear-down
[==========] 328 tests from 52 test cases ran. (179807 ms total)
[ PASSED ] 327 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] FaultToleranceTest.SlaveReregisterTerminatedExecutor
1 FAILED TEST
YOU HAVE 2 DISABLED TESTS
make[3]: *** [check-local] Error 1
make[3]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make[1]: *** [check] Error 2
make[1]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make: *** [check-recursive] Error 1
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal :
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2174
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2174/changes>