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/01/30 03:51:29 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#1860
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/1860/changes>
Changes:
[bmahler] Added a missing lock acquisition in /__processes__.
[bmahler] Updated the semantics of Clock::resume.
[bmahler] Fixed the use of a raw unix time in the Slave.
[bmahler] Added a child Reaper utility in libprocess.
[bmahler] Update the slave to use the libprocess Reaper.
[bmahler] Added an asynchronous subprocess utility.
------------------------------------------
[...truncated 21217 lines...]
I0130 02:51:28.241621 28337 slave.cpp:501] New master detected at master@67.195.138.9:50515
I0130 02:51:28.241650 28342 master.cpp:808] Registering framework 201401300251-160088899-50515-28317-0000 at scheduler(132)@67.195.138.9:50515
I0130 02:51:28.241663 28336 status_update_manager.cpp:162] New master detected at master@67.195.138.9:50515
I0130 02:51:28.241682 28337 slave.cpp:526] Detecting new master
I0130 02:51:28.241710 28336 sched.cpp:384] Framework registered with 201401300251-160088899-50515-28317-0000
I0130 02:51:28.241725 28336 sched.cpp:398] Scheduler::registered took 7047ns
I0130 02:51:28.241729 28337 hierarchical_allocator_process.hpp:332] Added framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.241739 28337 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I0130 02:51:28.241744 28337 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 6469ns
I0130 02:51:28.241837 28342 master.cpp:1812] Attempting to register slave on vesta.apache.org at slave(139)@67.195.138.9:50515
I0130 02:51:28.241849 28342 master.cpp:2782] Adding slave 201401300251-160088899-50515-28317-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0130 02:51:28.241910 28336 slave.cpp:544] Registered with master master@67.195.138.9:50515; given slave ID 201401300251-160088899-50515-28317-0
I0130 02:51:28.242009 28336 slave.cpp:557] Checkpointing SlaveInfo to '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_POnIV2/meta/slaves/201401300251-160088899-50515-28317-0/slave.info'
I0130 02:51:28.242012 28337 hierarchical_allocator_process.hpp:445] Added slave 201401300251-160088899-50515-28317-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)
I0130 02:51:28.242066 28337 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201401300251-160088899-50515-28317-0 to framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.242207 28337 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201401300251-160088899-50515-28317-0 in 162627ns
I0130 02:51:28.242250 28336 master.hpp:431] Adding offer 201401300251-160088899-50515-28317-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201401300251-160088899-50515-28317-0 (vesta.apache.org)
I0130 02:51:28.242296 28336 master.cpp:2250] Sending 1 offers to framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.242385 28337 sched.cpp:518] Scheduler::resourceOffers took 16705ns
I0130 02:51:28.242727 28337 master.hpp:441] Removing offer 201401300251-160088899-50515-28317-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201401300251-160088899-50515-28317-0 (vesta.apache.org)
I0130 02:51:28.242781 28337 master.cpp:1546] Processing reply for offers: [ 201401300251-160088899-50515-28317-0 ] on slave 201401300251-160088899-50515-28317-0 (vesta.apache.org) for framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.242892 28337 master.hpp:403] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201401300251-160088899-50515-28317-0 (vesta.apache.org)
I0130 02:51:28.242946 28337 master.cpp:2419] Launching task 1 of framework 201401300251-160088899-50515-28317-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201401300251-160088899-50515-28317-0 (vesta.apache.org)
I0130 02:51:28.243074 28337 slave.cpp:729] Got assigned task 1 for framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.243139 28337 slave.cpp:2892] Checkpointing FrameworkInfo to '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_POnIV2/meta/slaves/201401300251-160088899-50515-28317-0/frameworks/201401300251-160088899-50515-28317-0000/framework.info'
I0130 02:51:28.254217 28337 slave.cpp:2899] Checkpointing framework pid 'scheduler(132)@67.195.138.9:50515' to '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_POnIV2/meta/slaves/201401300251-160088899-50515-28317-0/frameworks/201401300251-160088899-50515-28317-0000/framework.pid'
I0130 02:51:28.254401 28337 slave.cpp:838] Launching task 1 for framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.259707 28337 slave.cpp:3162] Checkpointing ExecutorInfo to '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_POnIV2/meta/slaves/201401300251-160088899-50515-28317-0/frameworks/201401300251-160088899-50515-28317-0000/executors/default/executor.info'
I0130 02:51:28.262984 28337 slave.cpp:3250] Checkpointing TaskInfo to '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_POnIV2/meta/slaves/201401300251-160088899-50515-28317-0/frameworks/201401300251-160088899-50515-28317-0000/executors/default/runs/16c1a38a-45d5-4212-b1e9-604bc352d3ee/tasks/1/task.info'
I0130 02:51:28.263823 28343 exec.cpp:178] Executor started at: executor(43)@67.195.138.9:50515 with pid 28317
I0130 02:51:28.270881 28337 slave.cpp:948] Queuing task '1' for executor default of framework '201401300251-160088899-50515-28317-0000
I0130 02:51:28.270921 28337 slave.cpp:466] Successfully attached file '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_POnIV2/slaves/201401300251-160088899-50515-28317-0/frameworks/201401300251-160088899-50515-28317-0000/executors/default/runs/16c1a38a-45d5-4212-b1e9-604bc352d3ee'
I0130 02:51:28.270942 28337 slave.cpp:2091] Monitoring executor default of framework 201401300251-160088899-50515-28317-0000 forked at pid 28317
I0130 02:51:28.270997 28337 slave.cpp:1424] Got registration for executor 'default' of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.271018 28337 slave.cpp:1509] Checkpointing executor pid 'executor(43)@67.195.138.9:50515' to '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_POnIV2/meta/slaves/201401300251-160088899-50515-28317-0/frameworks/201401300251-160088899-50515-28317-0000/executors/default/runs/16c1a38a-45d5-4212-b1e9-604bc352d3ee/pids/libprocess.pid'
I0130 02:51:28.271224 28337 slave.cpp:1545] Flushing queued task 1 for executor 'default' of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.271366 28339 exec.cpp:202] Executor registered on slave 201401300251-160088899-50515-28317-0
I0130 02:51:28.272161 28339 exec.cpp:214] Executor::registered took 10282ns
I0130 02:51:28.272212 28339 exec.cpp:289] Executor asked to run task '1'
I0130 02:51:28.272260 28339 exec.cpp:298] Executor::launchTask took 17361ns
I0130 02:51:28.273025 28339 exec.cpp:521] Executor sending status update TASK_FINISHED (UUID: 36d44b82-87a5-47e4-8dcb-a32e40efba7b) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.273087 28339 slave.cpp:1758] Handling status update TASK_FINISHED (UUID: 36d44b82-87a5-47e4-8dcb-a32e40efba7b) for task 1 of framework 201401300251-160088899-50515-28317-0000 from executor(43)@67.195.138.9:50515
I0130 02:51:28.273103 28339 slave.cpp:3207] Terminating task 1
I0130 02:51:28.273263 28336 status_update_manager.cpp:314] Received status update TASK_FINISHED (UUID: 36d44b82-87a5-47e4-8dcb-a32e40efba7b) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.273279 28336 status_update_manager.cpp:493] Creating StatusUpdate stream for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.273414 28336 status_update_manager.hpp:342] Checkpointing UPDATE for status update TASK_FINISHED (UUID: 36d44b82-87a5-47e4-8dcb-a32e40efba7b) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.404253 28336 status_update_manager.cpp:367] Forwarding status update TASK_FINISHED (UUID: 36d44b82-87a5-47e4-8dcb-a32e40efba7b) for task 1 of framework 201401300251-160088899-50515-28317-0000 to master@67.195.138.9:50515
I0130 02:51:28.404387 28339 slave.cpp:1877] Status update manager successfully handled status update TASK_FINISHED (UUID: 36d44b82-87a5-47e4-8dcb-a32e40efba7b) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.404418 28341 master.cpp:1998] Status update TASK_FINISHED (UUID: 36d44b82-87a5-47e4-8dcb-a32e40efba7b) for task 1 of framework 201401300251-160088899-50515-28317-0000 from slave(139)@67.195.138.9:50515
I0130 02:51:28.404422 28339 slave.cpp:1883] Sending acknowledgement for status update TASK_FINISHED (UUID: 36d44b82-87a5-47e4-8dcb-a32e40efba7b) for task 1 of framework 201401300251-160088899-50515-28317-0000 to executor(43)@67.195.138.9:50515
I0130 02:51:28.404497 28343 sched.cpp:609] Scheduler::statusUpdate took 28373ns
I0130 02:51:28.404496 28341 master.hpp:421] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201401300251-160088899-50515-28317-0 (vesta.apache.org)
I0130 02:51:28.404503 28336 exec.cpp:335] Executor received status update acknowledgement 36d44b82-87a5-47e4-8dcb-a32e40efba7b for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.404744 28339 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 36d44b82-87a5-47e4-8dcb-a32e40efba7b) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.404752 28342 hierarchical_allocator_process.hpp:637] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 201401300251-160088899-50515-28317-0 from framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.404773 28339 status_update_manager.hpp:342] Checkpointing ACK for status update TASK_FINISHED (UUID: 36d44b82-87a5-47e4-8dcb-a32e40efba7b) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.464143 28339 status_update_manager.cpp:524] Cleaning up status update stream for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.464259 28339 slave.cpp:1364] Status update manager successfully handled status update acknowledgement (UUID: 36d44b82-87a5-47e4-8dcb-a32e40efba7b) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.464274 28339 slave.cpp:3230] Completing task 1
I0130 02:51:28.465324 28343 exec.cpp:521] Executor sending status update TASK_KILLED (UUID: 6f987ce9-80a0-44e8-b184-b9d5a6529c32) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.465394 28343 slave.cpp:1758] Handling status update TASK_KILLED (UUID: 6f987ce9-80a0-44e8-b184-b9d5a6529c32) for task 1 of framework 201401300251-160088899-50515-28317-0000 from executor(43)@67.195.138.9:50515
W0130 02:51:28.465420 28343 slave.cpp:1789] Could not find the executor for status update TASK_KILLED (UUID: 6f987ce9-80a0-44e8-b184-b9d5a6529c32) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.465522 28339 status_update_manager.cpp:314] Received status update TASK_KILLED (UUID: 6f987ce9-80a0-44e8-b184-b9d5a6529c32) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.465543 28339 status_update_manager.cpp:493] Creating StatusUpdate stream for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.465595 28339 status_update_manager.cpp:367] Forwarding status update TASK_KILLED (UUID: 6f987ce9-80a0-44e8-b184-b9d5a6529c32) for task 1 of framework 201401300251-160088899-50515-28317-0000 to master@67.195.138.9:50515
I0130 02:51:28.465718 28343 slave.cpp:1877] Status update manager successfully handled status update TASK_KILLED (UUID: 6f987ce9-80a0-44e8-b184-b9d5a6529c32) for task 1 of framework 201401300251-160088899-50515-28317-0000
W0130 02:51:28.465723 28342 master.cpp:1991] Status update TASK_KILLED (UUID: 6f987ce9-80a0-44e8-b184-b9d5a6529c32) for task 1 of framework 201401300251-160088899-50515-28317-0000 from slave(139)@67.195.138.9:50515 (vesta.apache.org): error, couldn't lookup task
I0130 02:51:28.465741 28343 slave.cpp:1883] Sending acknowledgement for status update TASK_KILLED (UUID: 6f987ce9-80a0-44e8-b184-b9d5a6529c32) for task 1 of framework 201401300251-160088899-50515-28317-0000 to executor(43)@67.195.138.9:50515
I0130 02:51:28.465808 28341 exec.cpp:335] Executor received status update acknowledgement 6f987ce9-80a0-44e8-b184-b9d5a6529c32 for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.465845 28337 sched.cpp:609] Scheduler::statusUpdate took 32539ns
I0130 02:51:28.466028 28336 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 6f987ce9-80a0-44e8-b184-b9d5a6529c32) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.466073 28336 status_update_manager.cpp:524] Cleaning up status update stream for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.466207 28336 slave.cpp:1364] Status update manager successfully handled status update acknowledgement (UUID: 6f987ce9-80a0-44e8-b184-b9d5a6529c32) for task 1 of framework 201401300251-160088899-50515-28317-0000
E0130 02:51:28.466224 28336 slave.cpp:1388] Status update acknowledgement (UUID: 6f987ce9-80a0-44e8-b184-b9d5a6529c32) for task 1 of unknown executor
I0130 02:51:28.476503 28317 master.cpp:561] Master terminating
I0130 02:51:28.476533 28339 sched.cpp:720] Stopping framework '201401300251-160088899-50515-28317-0000'
I0130 02:51:28.476546 28317 master.cpp:209] Shutting down master
I0130 02:51:28.476565 28343 slave.cpp:1958] master@67.195.138.9:50515 exited
W0130 02:51:28.476582 28343 slave.cpp:1961] Master disconnected! Waiting for a new master to be elected
I0130 02:51:28.476591 28317 master.cpp:252] Removing slave 201401300251-160088899-50515-28317-0 (vesta.apache.org)
I0130 02:51:28.477208 28341 slave.cpp:391] Slave terminating
I0130 02:51:28.477360 28337 exec.cpp:446] Slave exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with slave 201401300251-160088899-50515-28317-0
[ OK ] StatusUpdateManagerTest.DuplicateTerminalUpdateAfterAck (239 ms)
[ RUN ] StatusUpdateManagerTest.DuplicateUpdateBeforeAck
I0130 02:51:28.478569 28336 master.cpp:284] Master started on 67.195.138.9:50515
I0130 02:51:28.478615 28336 master.cpp:299] Master ID: 201401300251-160088899-50515-28317
I0130 02:51:28.478626 28336 master.cpp:302] Master only allowing authenticated frameworks to register!
I0130 02:51:28.478862 28342 master.cpp:85] No whitelist given. Advertising offers for all slaves
I0130 02:51:28.478946 28337 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : master@67.195.138.9:50515
I0130 02:51:28.479367 28343 master.cpp:734] The newly elected leader is master@67.195.138.9:50515
I0130 02:51:28.479383 28343 master.cpp:742] Elected as the leading master!
I0130 02:51:28.485651 28339 slave.cpp:112] Slave started on 140)@67.195.138.9:50515
I0130 02:51:28.485754 28339 slave.cpp:212] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0130 02:51:28.486006 28337 sched.cpp:210] New master detected at master@67.195.138.9:50515
I0130 02:51:28.486023 28337 sched.cpp:261] Authenticating with master master@67.195.138.9:50515
I0130 02:51:28.486065 28337 sched.cpp:230] Detecting new master
I0130 02:51:28.486166 28342 authenticatee.hpp:124] Creating new client SASL connection
I0130 02:51:28.486249 28336 master.cpp:2295] Authenticating framework at scheduler(133)@67.195.138.9:50515
I0130 02:51:28.486322 28342 authenticator.hpp:140] Creating new server SASL connection
I0130 02:51:28.486392 28342 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0130 02:51:28.486404 28342 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0130 02:51:28.486472 28339 state.cpp:33] Recovering state from '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_B43NaM/meta'
I0130 02:51:28.486507 28341 authenticator.hpp:243] Received SASL authentication start
I0130 02:51:28.486562 28341 authenticator.hpp:325] Authentication requires more steps
I0130 02:51:28.486621 28336 status_update_manager.cpp:188] Recovering status update manager
I0130 02:51:28.486655 28341 authenticatee.hpp:258] Received SASL authentication step
I0130 02:51:28.486721 28341 slave.cpp:2753] Finished recovery
I0130 02:51:28.486783 28336 authenticator.hpp:271] Received SASL authentication step
I0130 02:51:28.486804 28336 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
I0130 02:51:28.486811 28336 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0130 02:51:28.486824 28336 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0130 02:51:28.486835 28336 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
I0130 02:51:28.486855 28336 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0130 02:51:28.486860 28336 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0130 02:51:28.486871 28336 authenticator.hpp:317] Authentication success
I0130 02:51:28.486915 28339 master.cpp:2335] Successfully authenticated framework at scheduler(133)@67.195.138.9:50515
I0130 02:51:28.486939 28337 slave.cpp:501] New master detected at master@67.195.138.9:50515
I0130 02:51:28.486989 28336 status_update_manager.cpp:162] New master detected at master@67.195.138.9:50515
I0130 02:51:28.487004 28337 slave.cpp:526] Detecting new master
I0130 02:51:28.487042 28336 master.cpp:1812] Attempting to register slave on vesta.apache.org at slave(140)@67.195.138.9:50515
I0130 02:51:28.487056 28336 master.cpp:2782] Adding slave 201401300251-160088899-50515-28317-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0130 02:51:28.487117 28337 slave.cpp:544] Registered with master master@67.195.138.9:50515; given slave ID 201401300251-160088899-50515-28317-0
I0130 02:51:28.487190 28336 hierarchical_allocator_process.hpp:445] Added slave 201401300251-160088899-50515-28317-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)
I0130 02:51:28.487226 28336 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201401300251-160088899-50515-28317-0 in 8072ns
I0130 02:51:28.487300 28341 authenticatee.hpp:298] Authentication success
I0130 02:51:28.487351 28341 sched.cpp:335] Successfully authenticated with master master@67.195.138.9:50515
I0130 02:51:28.487387 28341 master.cpp:790] Received registration request from scheduler(133)@67.195.138.9:50515
I0130 02:51:28.487411 28341 master.cpp:808] Registering framework 201401300251-160088899-50515-28317-0000 at scheduler(133)@67.195.138.9:50515
I0130 02:51:28.487453 28341 sched.cpp:384] Framework registered with 201401300251-160088899-50515-28317-0000
I0130 02:51:28.487470 28341 sched.cpp:398] Scheduler::registered took 8836ns
I0130 02:51:28.487494 28341 hierarchical_allocator_process.hpp:332] Added framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.487526 28341 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201401300251-160088899-50515-28317-0 to framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.487639 28341 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 135256ns
I0130 02:51:28.487686 28341 master.hpp:431] Adding offer 201401300251-160088899-50515-28317-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201401300251-160088899-50515-28317-0 (vesta.apache.org)
I0130 02:51:28.487727 28341 master.cpp:2250] Sending 1 offers to framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.487812 28341 sched.cpp:518] Scheduler::resourceOffers took 17911ns
I0130 02:51:28.488325 28342 master.hpp:441] Removing offer 201401300251-160088899-50515-28317-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201401300251-160088899-50515-28317-0 (vesta.apache.org)
I0130 02:51:28.488386 28342 master.cpp:1546] Processing reply for offers: [ 201401300251-160088899-50515-28317-0 ] on slave 201401300251-160088899-50515-28317-0 (vesta.apache.org) for framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.488503 28342 master.hpp:403] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201401300251-160088899-50515-28317-0 (vesta.apache.org)
I0130 02:51:28.488554 28342 master.cpp:2419] Launching task 1 of framework 201401300251-160088899-50515-28317-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201401300251-160088899-50515-28317-0 (vesta.apache.org)
I0130 02:51:28.533069 28337 slave.cpp:557] Checkpointing SlaveInfo to '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_B43NaM/meta/slaves/201401300251-160088899-50515-28317-0/slave.info'
I0130 02:51:28.533188 28337 slave.cpp:729] Got assigned task 1 for framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.533262 28337 slave.cpp:2892] Checkpointing FrameworkInfo to '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_B43NaM/meta/slaves/201401300251-160088899-50515-28317-0/frameworks/201401300251-160088899-50515-28317-0000/framework.info'
I0130 02:51:28.533359 28337 slave.cpp:2899] Checkpointing framework pid 'scheduler(133)@67.195.138.9:50515' to '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_B43NaM/meta/slaves/201401300251-160088899-50515-28317-0/frameworks/201401300251-160088899-50515-28317-0000/framework.pid'
I0130 02:51:28.533531 28337 slave.cpp:838] Launching task 1 for framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.542696 28337 slave.cpp:3162] Checkpointing ExecutorInfo to '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_B43NaM/meta/slaves/201401300251-160088899-50515-28317-0/frameworks/201401300251-160088899-50515-28317-0000/executors/default/executor.info'
I0130 02:51:28.555276 28337 slave.cpp:3250] Checkpointing TaskInfo to '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_B43NaM/meta/slaves/201401300251-160088899-50515-28317-0/frameworks/201401300251-160088899-50515-28317-0000/executors/default/runs/9231020d-0e1e-45c8-bd8c-7b82a34b1223/tasks/1/task.info'
I0130 02:51:28.556120 28341 exec.cpp:178] Executor started at: executor(44)@67.195.138.9:50515 with pid 28317
I0130 02:51:28.565021 28337 slave.cpp:948] Queuing task '1' for executor default of framework '201401300251-160088899-50515-28317-0000
I0130 02:51:28.565080 28337 slave.cpp:466] Successfully attached file '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_B43NaM/slaves/201401300251-160088899-50515-28317-0/frameworks/201401300251-160088899-50515-28317-0000/executors/default/runs/9231020d-0e1e-45c8-bd8c-7b82a34b1223'
I0130 02:51:28.565104 28337 slave.cpp:2091] Monitoring executor default of framework 201401300251-160088899-50515-28317-0000 forked at pid 28317
I0130 02:51:28.565160 28337 slave.cpp:1424] Got registration for executor 'default' of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.565187 28337 slave.cpp:1509] Checkpointing executor pid 'executor(44)@67.195.138.9:50515' to '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_B43NaM/meta/slaves/201401300251-160088899-50515-28317-0/frameworks/201401300251-160088899-50515-28317-0000/executors/default/runs/9231020d-0e1e-45c8-bd8c-7b82a34b1223/pids/libprocess.pid'
I0130 02:51:28.565759 28337 slave.cpp:1545] Flushing queued task 1 for executor 'default' of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.565765 28341 exec.cpp:202] Executor registered on slave 201401300251-160088899-50515-28317-0
I0130 02:51:28.566541 28341 exec.cpp:214] Executor::registered took 9870ns
I0130 02:51:28.566594 28341 exec.cpp:289] Executor asked to run task '1'
I0130 02:51:28.566629 28341 exec.cpp:298] Executor::launchTask took 27060ns
I0130 02:51:28.567395 28341 exec.cpp:521] Executor sending status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.567545 28341 slave.cpp:1758] Handling status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000 from executor(44)@67.195.138.9:50515
I0130 02:51:28.567683 28342 status_update_manager.cpp:314] Received status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.567703 28342 status_update_manager.cpp:493] Creating StatusUpdate stream for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.567975 28342 status_update_manager.hpp:342] Checkpointing UPDATE for status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.666493 28342 status_update_manager.cpp:367] Forwarding status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000 to master@67.195.138.9:50515
I0130 02:51:28.666615 28339 slave.cpp:1877] Status update manager successfully handled status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.666630 28339 slave.cpp:1883] Sending acknowledgement for status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000 to executor(44)@67.195.138.9:50515
I0130 02:51:28.666646 28340 master.cpp:1998] Status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000 from slave(140)@67.195.138.9:50515
I0130 02:51:28.666697 28340 exec.cpp:335] Executor received status update acknowledgement 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91 for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.666735 28339 sched.cpp:609] Scheduler::statusUpdate took 21us
I0130 02:51:28.667131 28337 slave.cpp:1758] Handling status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000 from executor(44)@67.195.138.9:50515
I0130 02:51:28.667222 28337 status_update_manager.cpp:314] Received status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000
W0130 02:51:28.667238 28337 status_update_manager.hpp:231] Ignoring duplicate status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.667287 28337 slave.cpp:1877] Status update manager successfully handled status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.667299 28337 slave.cpp:1883] Sending acknowledgement for status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000 to executor(44)@67.195.138.9:50515
I0130 02:51:28.667347 28337 exec.cpp:335] Executor received status update acknowledgement 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91 for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.667744 28342 master.cpp:85] No whitelist given. Advertising offers for all slaves
I0130 02:51:28.667776 28339 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 30436ns
W0130 02:51:28.667804 28337 status_update_manager.cpp:471] Resending status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.667829 28337 status_update_manager.cpp:367] Forwarding status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000 to master@67.195.138.9:50515
I0130 02:51:28.667963 28336 master.cpp:1998] Status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000 from slave(140)@67.195.138.9:50515
I0130 02:51:28.668035 28343 sched.cpp:609] Scheduler::statusUpdate took 34734ns
I0130 02:51:28.668181 28343 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.668197 28343 status_update_manager.hpp:342] Checkpointing ACK for status update TASK_RUNNING (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.726238 28343 slave.cpp:1364] Status update manager successfully handled status update acknowledgement (UUID: 3b0043d3-42b2-4d9e-8ab6-254a6ae11d91) for task 1 of framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.727848 28337 sched.cpp:720] Stopping framework '201401300251-160088899-50515-28317-0000'
I0130 02:51:28.727871 28317 master.cpp:561] Master terminating
I0130 02:51:28.727953 28317 master.cpp:209] Shutting down master
I0130 02:51:28.727995 28341 slave.cpp:1958] master@67.195.138.9:50515 exited
W0130 02:51:28.728008 28341 slave.cpp:1961] Master disconnected! Waiting for a new master to be elected
I0130 02:51:28.728006 28317 master.hpp:421] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201401300251-160088899-50515-28317-0 (vesta.apache.org)
I0130 02:51:28.728127 28317 master.cpp:252] Removing slave 201401300251-160088899-50515-28317-0 (vesta.apache.org)
I0130 02:51:28.728216 28336 hierarchical_allocator_process.hpp:637] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 201401300251-160088899-50515-28317-0 from framework 201401300251-160088899-50515-28317-0000
I0130 02:51:28.728659 28317 slave.cpp:391] Slave terminating
I0130 02:51:28.728803 28337 exec.cpp:446] Slave exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with slave 201401300251-160088899-50515-28317-0
[ OK ] StatusUpdateManagerTest.DuplicateUpdateBeforeAck (251 ms)
[----------] 7 tests from StatusUpdateManagerTest (1787 ms total)
[----------] 1 test from ZooKeeper
[ RUN ] ZooKeeper.URL
[ OK ] ZooKeeper.URL (0 ms)
[----------] 1 test from ZooKeeper (0 ms total)
[----------] 5 tests from CgroupsCpusetTest
[ RUN ] CgroupsCpusetTest.OneCPUOneCpuset
[ OK ] CgroupsCpusetTest.OneCPUOneCpuset (11 ms)
[ RUN ] CgroupsCpusetTest.OneCPUManyCpusets
[ OK ] CgroupsCpusetTest.OneCPUManyCpusets (0 ms)
[ RUN ] CgroupsCpusetTest.ManyCPUOneCpuset
[ OK ] CgroupsCpusetTest.ManyCPUOneCpuset (0 ms)
[ RUN ] CgroupsCpusetTest.ManyCPUManyCpusets
[ OK ] CgroupsCpusetTest.ManyCPUManyCpusets (0 ms)
[ RUN ] CgroupsCpusetTest.IntegerAllocations
[ OK ] CgroupsCpusetTest.IntegerAllocations (0 ms)
[----------] 5 tests from CgroupsCpusetTest (11 ms total)
[----------] 3 tests from FsTest
[ RUN ] FsTest.MountTableRead
[ OK ] FsTest.MountTableRead (4 ms)
[ RUN ] FsTest.MountTableHasOption
[ OK ] FsTest.MountTableHasOption (0 ms)
[ RUN ] FsTest.FileSystemTableRead
[ OK ] FsTest.FileSystemTableRead (12 ms)
[----------] 3 tests from FsTest (16 ms total)
[----------] Global test environment tear-down
../../src/tests/environment.cpp:247: Failure
Failed
Tests completed with child processes remaining:
-+- 28317 /home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src/.libs/lt-mesos-tests
\-+- 29538 sh -c /home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src/mesos-executor
\--- 29556 /home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src/.libs/lt-mesos-executor
[==========] 220 tests from 39 test cases ran. (76643 ms total)
[ PASSED ] 220 tests.
[ FAILED ] 0 tests, listed below:
0 FAILED TESTS
YOU HAVE 2 DISABLED TESTS
Imake[3]: 0130 02:51:28.820462 29578 process.cpp:1009] Socket closed while receiving
*** [check-local] Error 1
I0130 02:51:28.820689 29573 exec.cpp:446] Slave exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with slave 201401300251-160088899-50515-28317-0
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
#1861
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/1861/changes>