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/02/03 22:08:51 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#1867
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/1867/>
------------------------------------------
[...truncated 21279 lines...]
I0203 21:08:49.143712 29347 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 7350ns
I0203 21:08:49.143714 29354 slave.cpp:2753] Finished recovery
I0203 21:08:49.147670 29350 slave.cpp:501] New master detected at master@67.195.138.8:41693
I0203 21:08:49.147725 29350 slave.cpp:526] Detecting new master
I0203 21:08:49.147758 29350 status_update_manager.cpp:162] New master detected at master@67.195.138.8:41693
I0203 21:08:49.147797 29350 master.cpp:1812] Attempting to register slave on minerva.apache.org at slave(139)@67.195.138.8:41693
I0203 21:08:49.147806 29350 master.cpp:2782] Adding slave 201402032108-143311683-41693-29328-0 at minerva.apache.org with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0203 21:08:49.147910 29350 slave.cpp:544] Registered with master master@67.195.138.8:41693; given slave ID 201402032108-143311683-41693-29328-0
I0203 21:08:49.148025 29350 slave.cpp:557] Checkpointing SlaveInfo to '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/meta/slaves/201402032108-143311683-41693-29328-0/slave.info'
I0203 21:08:49.148138 29350 hierarchical_allocator_process.hpp:445] Added slave 201402032108-143311683-41693-29328-0 (minerva.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I0203 21:08:49.148188 29350 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201402032108-143311683-41693-29328-0 to framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.148296 29350 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201402032108-143311683-41693-29328-0 in 131475ns
I0203 21:08:49.148355 29350 master.hpp:431] Adding offer 201402032108-143311683-41693-29328-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
I0203 21:08:49.148394 29350 master.cpp:2250] Sending 1 offers to framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.148476 29350 sched.cpp:518] Scheduler::resourceOffers took 14853ns
I0203 21:08:49.148840 29349 master.hpp:441] Removing offer 201402032108-143311683-41693-29328-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
I0203 21:08:49.148887 29349 master.cpp:1546] Processing reply for offers: [ 201402032108-143311683-41693-29328-0 ] on slave 201402032108-143311683-41693-29328-0 (minerva.apache.org) for framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.148998 29349 master.hpp:403] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
I0203 21:08:49.149044 29349 master.cpp:2419] Launching task 1 of framework 201402032108-143311683-41693-29328-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
I0203 21:08:49.149165 29349 slave.cpp:729] Got assigned task 1 for framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.149219 29349 slave.cpp:2892] Checkpointing FrameworkInfo to '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/framework.info'
I0203 21:08:49.149327 29349 slave.cpp:2899] Checkpointing framework pid 'scheduler(132)@67.195.138.8:41693' to '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/framework.pid'
I0203 21:08:49.149497 29349 slave.cpp:838] Launching task 1 for framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.153285 29349 slave.cpp:3162] Checkpointing ExecutorInfo to '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/executor.info'
I0203 21:08:49.156380 29349 slave.cpp:3250] Checkpointing TaskInfo to '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/runs/e09adb5b-4ecf-4f7e-9f73-bf3d443daf30/tasks/1/task.info'
I0203 21:08:49.156551 29349 slave.cpp:948] Queuing task '1' for executor default of framework '201402032108-143311683-41693-29328-0000
I0203 21:08:49.156628 29349 slave.cpp:466] Successfully attached file '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/runs/e09adb5b-4ecf-4f7e-9f73-bf3d443daf30'
I0203 21:08:49.157335 29350 exec.cpp:178] Executor started at: executor(43)@67.195.138.8:41693 with pid 29328
I0203 21:08:49.157403 29352 slave.cpp:2091] Monitoring executor default of framework 201402032108-143311683-41693-29328-0000 forked at pid 29328
I0203 21:08:49.157505 29352 slave.cpp:1424] Got registration for executor 'default' of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.157541 29352 slave.cpp:1509] Checkpointing executor pid 'executor(43)@67.195.138.8:41693' to '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/runs/e09adb5b-4ecf-4f7e-9f73-bf3d443daf30/pids/libprocess.pid'
I0203 21:08:49.157786 29352 slave.cpp:1545] Flushing queued task 1 for executor 'default' of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.157804 29353 exec.cpp:202] Executor registered on slave 201402032108-143311683-41693-29328-0
I0203 21:08:49.158578 29353 exec.cpp:214] Executor::registered took 11099ns
I0203 21:08:49.158627 29353 exec.cpp:289] Executor asked to run task '1'
I0203 21:08:49.158669 29353 exec.cpp:298] Executor::launchTask took 33671ns
I0203 21:08:49.159435 29353 exec.cpp:521] Executor sending status update TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.159499 29353 slave.cpp:1758] Handling status update TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework 201402032108-143311683-41693-29328-0000 from executor(43)@67.195.138.8:41693
I0203 21:08:49.159517 29353 slave.cpp:3207] Terminating task 1
I0203 21:08:49.159662 29354 status_update_manager.cpp:314] Received status update TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.159695 29354 status_update_manager.cpp:493] Creating StatusUpdate stream for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.159881 29354 status_update_manager.hpp:342] Checkpointing UPDATE for status update TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.161545 29354 status_update_manager.cpp:367] Forwarding status update TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework 201402032108-143311683-41693-29328-0000 to master@67.195.138.8:41693
I0203 21:08:49.161676 29350 master.cpp:1998] Status update TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework 201402032108-143311683-41693-29328-0000 from slave(139)@67.195.138.8:41693
I0203 21:08:49.161710 29348 slave.cpp:1877] Status update manager successfully handled status update TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.161722 29348 slave.cpp:1883] Sending acknowledgement for status update TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework 201402032108-143311683-41693-29328-0000 to executor(43)@67.195.138.8:41693
I0203 21:08:49.161736 29350 master.hpp:421] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
I0203 21:08:49.161767 29348 exec.cpp:335] Executor received status update acknowledgement 2335534b-f780-4663-a16d-aa08c5fc11c1 for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.161875 29351 sched.cpp:609] Scheduler::statusUpdate took 26659ns
I0203 21:08:49.161947 29349 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 201402032108-143311683-41693-29328-0 from framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.162017 29351 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.162040 29351 status_update_manager.hpp:342] Checkpointing ACK for status update TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.162626 29351 status_update_manager.cpp:524] Cleaning up status update stream for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.162783 29348 slave.cpp:1364] Status update manager successfully handled status update acknowledgement (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.162801 29348 slave.cpp:3230] Completing task 1
I0203 21:08:49.163753 29348 exec.cpp:521] Executor sending status update TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.163817 29348 slave.cpp:1758] Handling status update TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework 201402032108-143311683-41693-29328-0000 from executor(43)@67.195.138.8:41693
W0203 21:08:49.163832 29348 slave.cpp:1789] Could not find the executor for status update TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.163913 29349 status_update_manager.cpp:314] Received status update TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.163933 29349 status_update_manager.cpp:493] Creating StatusUpdate stream for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.163988 29349 status_update_manager.cpp:367] Forwarding status update TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework 201402032108-143311683-41693-29328-0000 to master@67.195.138.8:41693
I0203 21:08:49.164114 29350 slave.cpp:1877] Status update manager successfully handled status update TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.164126 29350 slave.cpp:1883] Sending acknowledgement for status update TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework 201402032108-143311683-41693-29328-0000 to executor(43)@67.195.138.8:41693
I0203 21:08:49.164167 29350 exec.cpp:335] Executor received status update acknowledgement 5d9aac8e-adce-4123-9357-9878fa357ea5 for task 1 of framework 201402032108-143311683-41693-29328-0000
W0203 21:08:49.164165 29352 master.cpp:1991] Status update TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework 201402032108-143311683-41693-29328-0000 from slave(139)@67.195.138.8:41693 (minerva.apache.org): error, couldn't lookup task
I0203 21:08:49.164229 29350 sched.cpp:609] Scheduler::statusUpdate took 20305ns
I0203 21:08:49.164381 29350 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.164403 29350 status_update_manager.cpp:524] Cleaning up status update stream for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.164485 29350 slave.cpp:1364] Status update manager successfully handled status update acknowledgement (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework 201402032108-143311683-41693-29328-0000
E0203 21:08:49.164496 29350 slave.cpp:1388] Status update acknowledgement (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of unknown executor
I0203 21:08:49.174721 29328 master.cpp:561] Master terminating
I0203 21:08:49.174751 29328 master.cpp:209] Shutting down master
I0203 21:08:49.174773 29352 slave.cpp:1958] master@67.195.138.8:41693 exited
I0203 21:08:49.174784 29328 master.cpp:252] Removing slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
I0203 21:08:49.174789 29353 sched.cpp:720] Stopping framework '201402032108-143311683-41693-29328-0000'
W0203 21:08:49.174787 29352 slave.cpp:1961] Master disconnected! Waiting for a new master to be elected
I0203 21:08:49.175235 29328 slave.cpp:391] Slave terminating
I0203 21:08:49.175298 29348 exec.cpp:446] Slave exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with slave 201402032108-143311683-41693-29328-0
[ OK ] StatusUpdateManagerTest.DuplicateTerminalUpdateAfterAck (36 ms)
[ RUN ] StatusUpdateManagerTest.DuplicateUpdateBeforeAck
I0203 21:08:49.189065 29349 master.cpp:284] Master started on 67.195.138.8:41693
I0203 21:08:49.189100 29349 master.cpp:299] Master ID: 201402032108-143311683-41693-29328
I0203 21:08:49.189107 29349 master.cpp:302] Master only allowing authenticated frameworks to register!
I0203 21:08:49.189429 29353 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : master@67.195.138.8:41693
I0203 21:08:49.189517 29353 master.cpp:85] No whitelist given. Advertising offers for all slaves
I0203 21:08:49.189842 29353 master.cpp:734] The newly elected leader is master@67.195.138.8:41693
I0203 21:08:49.189857 29353 master.cpp:742] Elected as the leading master!
I0203 21:08:49.190803 29354 slave.cpp:112] Slave started on 140)@67.195.138.8:41693
I0203 21:08:49.190894 29354 slave.cpp:212] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0203 21:08:49.191236 29351 sched.cpp:210] New master detected at master@67.195.138.8:41693
I0203 21:08:49.191262 29351 sched.cpp:261] Authenticating with master master@67.195.138.8:41693
I0203 21:08:49.191316 29351 sched.cpp:230] Detecting new master
I0203 21:08:49.191337 29352 authenticatee.hpp:124] Creating new client SASL connection
I0203 21:08:49.191503 29351 master.cpp:2295] Authenticating framework at scheduler(133)@67.195.138.8:41693
I0203 21:08:49.191592 29349 authenticator.hpp:140] Creating new server SASL connection
I0203 21:08:49.191845 29347 state.cpp:33] Recovering state from '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta'
I0203 21:08:49.191849 29352 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0203 21:08:49.191896 29352 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0203 21:08:49.191946 29349 authenticator.hpp:243] Received SASL authentication start
I0203 21:08:49.191973 29347 status_update_manager.cpp:188] Recovering status update manager
I0203 21:08:49.191984 29349 authenticator.hpp:325] Authentication requires more steps
I0203 21:08:49.192018 29349 authenticatee.hpp:258] Received SASL authentication step
I0203 21:08:49.192062 29349 authenticator.hpp:271] Received SASL authentication step
I0203 21:08:49.192085 29349 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'minerva.apache.org' server FQDN: 'minerva.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0203 21:08:49.192093 29349 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0203 21:08:49.192107 29349 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0203 21:08:49.192118 29349 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'minerva.apache.org' server FQDN: 'minerva.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0203 21:08:49.192126 29349 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0203 21:08:49.192129 29351 slave.cpp:2753] Finished recovery
I0203 21:08:49.192131 29349 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0203 21:08:49.192162 29349 authenticator.hpp:317] Authentication success
I0203 21:08:49.192203 29352 authenticatee.hpp:298] Authentication success
I0203 21:08:49.192205 29349 master.cpp:2335] Successfully authenticated framework at scheduler(133)@67.195.138.8:41693
I0203 21:08:49.192272 29352 sched.cpp:335] Successfully authenticated with master master@67.195.138.8:41693
I0203 21:08:49.192316 29349 master.cpp:790] Received registration request from scheduler(133)@67.195.138.8:41693
I0203 21:08:49.192339 29349 master.cpp:808] Registering framework 201402032108-143311683-41693-29328-0000 at scheduler(133)@67.195.138.8:41693
I0203 21:08:49.192405 29347 sched.cpp:384] Framework registered with 201402032108-143311683-41693-29328-0000
I0203 21:08:49.192409 29349 slave.cpp:501] New master detected at master@67.195.138.8:41693
I0203 21:08:49.192435 29352 hierarchical_allocator_process.hpp:332] Added framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.192440 29347 sched.cpp:398] Scheduler::registered took 10679ns
I0203 21:08:49.192443 29352 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I0203 21:08:49.192462 29352 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 18489ns
I0203 21:08:49.192469 29349 slave.cpp:526] Detecting new master
I0203 21:08:49.192469 29347 status_update_manager.cpp:162] New master detected at master@67.195.138.8:41693
I0203 21:08:49.192508 29352 master.cpp:1812] Attempting to register slave on minerva.apache.org at slave(140)@67.195.138.8:41693
I0203 21:08:49.192523 29352 master.cpp:2782] Adding slave 201402032108-143311683-41693-29328-0 at minerva.apache.org with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0203 21:08:49.192576 29349 slave.cpp:544] Registered with master master@67.195.138.8:41693; given slave ID 201402032108-143311683-41693-29328-0
I0203 21:08:49.192653 29352 hierarchical_allocator_process.hpp:445] Added slave 201402032108-143311683-41693-29328-0 (minerva.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I0203 21:08:49.192705 29352 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201402032108-143311683-41693-29328-0 to framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.192826 29352 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201402032108-143311683-41693-29328-0 in 142705ns
I0203 21:08:49.192872 29353 master.hpp:431] Adding offer 201402032108-143311683-41693-29328-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
I0203 21:08:49.192921 29353 master.cpp:2250] Sending 1 offers to framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.193009 29352 sched.cpp:518] Scheduler::resourceOffers took 19081ns
I0203 21:08:49.193531 29350 master.hpp:441] Removing offer 201402032108-143311683-41693-29328-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
I0203 21:08:49.193581 29350 master.cpp:1546] Processing reply for offers: [ 201402032108-143311683-41693-29328-0 ] on slave 201402032108-143311683-41693-29328-0 (minerva.apache.org) for framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.193691 29350 master.hpp:403] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
I0203 21:08:49.193742 29350 master.cpp:2419] Launching task 1 of framework 201402032108-143311683-41693-29328-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
I0203 21:08:49.201921 29349 slave.cpp:557] Checkpointing SlaveInfo to '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta/slaves/201402032108-143311683-41693-29328-0/slave.info'
I0203 21:08:49.202033 29349 slave.cpp:729] Got assigned task 1 for framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.202093 29349 slave.cpp:2892] Checkpointing FrameworkInfo to '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/framework.info'
I0203 21:08:49.202229 29349 slave.cpp:2899] Checkpointing framework pid 'scheduler(133)@67.195.138.8:41693' to '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/framework.pid'
I0203 21:08:49.202404 29349 slave.cpp:838] Launching task 1 for framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.203378 29349 slave.cpp:3162] Checkpointing ExecutorInfo to '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/executor.info'
I0203 21:08:49.203694 29349 slave.cpp:3250] Checkpointing TaskInfo to '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/runs/57d931fe-ab43-4c00-ab78-edd1d760c57a/tasks/1/task.info'
I0203 21:08:49.203835 29349 slave.cpp:948] Queuing task '1' for executor default of framework '201402032108-143311683-41693-29328-0000
I0203 21:08:49.203871 29349 slave.cpp:466] Successfully attached file '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/runs/57d931fe-ab43-4c00-ab78-edd1d760c57a'
I0203 21:08:49.204656 29351 exec.cpp:178] Executor started at: executor(44)@67.195.138.8:41693 with pid 29328
I0203 21:08:49.204674 29348 slave.cpp:2091] Monitoring executor default of framework 201402032108-143311683-41693-29328-0000 forked at pid 29328
I0203 21:08:49.204773 29348 slave.cpp:1424] Got registration for executor 'default' of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.204803 29348 slave.cpp:1509] Checkpointing executor pid 'executor(44)@67.195.138.8:41693' to '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/runs/57d931fe-ab43-4c00-ab78-edd1d760c57a/pids/libprocess.pid'
I0203 21:08:49.205044 29348 slave.cpp:1545] Flushing queued task 1 for executor 'default' of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.205052 29350 exec.cpp:202] Executor registered on slave 201402032108-143311683-41693-29328-0
I0203 21:08:49.205812 29350 exec.cpp:214] Executor::registered took 10475ns
I0203 21:08:49.205858 29350 exec.cpp:289] Executor asked to run task '1'
I0203 21:08:49.205891 29350 exec.cpp:298] Executor::launchTask took 21126ns
I0203 21:08:49.206679 29350 exec.cpp:521] Executor sending status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.206784 29350 slave.cpp:1758] Handling status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000 from executor(44)@67.195.138.8:41693
I0203 21:08:49.206920 29352 status_update_manager.cpp:314] Received status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.206953 29352 status_update_manager.cpp:493] Creating StatusUpdate stream for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.207113 29352 status_update_manager.hpp:342] Checkpointing UPDATE for status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.208637 29352 status_update_manager.cpp:367] Forwarding status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000 to master@67.195.138.8:41693
I0203 21:08:49.208755 29349 slave.cpp:1877] Status update manager successfully handled status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.208770 29349 slave.cpp:1883] Sending acknowledgement for status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000 to executor(44)@67.195.138.8:41693
I0203 21:08:49.208789 29350 master.cpp:1998] Status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000 from slave(140)@67.195.138.8:41693
I0203 21:08:49.208848 29349 exec.cpp:335] Executor received status update acknowledgement d55f3413-0d93-44ff-bfc5-93ae5553070b for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.208899 29347 sched.cpp:609] Scheduler::statusUpdate took 24488ns
I0203 21:08:49.209245 29352 slave.cpp:1758] Handling status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000 from executor(44)@67.195.138.8:41693
I0203 21:08:49.209337 29353 status_update_manager.cpp:314] Received status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000
W0203 21:08:49.209358 29353 status_update_manager.hpp:231] Ignoring duplicate status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.209414 29352 slave.cpp:1877] Status update manager successfully handled status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.209432 29352 slave.cpp:1883] Sending acknowledgement for status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000 to executor(44)@67.195.138.8:41693
I0203 21:08:49.209569 29349 exec.cpp:335] Executor received status update acknowledgement d55f3413-0d93-44ff-bfc5-93ae5553070b for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.209821 29352 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 28403ns
W0203 21:08:49.209966 29353 status_update_manager.cpp:471] Resending status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.209985 29353 status_update_manager.cpp:367] Forwarding status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000 to master@67.195.138.8:41693
I0203 21:08:49.209995 29354 master.cpp:85] No whitelist given. Advertising offers for all slaves
I0203 21:08:49.210062 29354 master.cpp:1998] Status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000 from slave(140)@67.195.138.8:41693
I0203 21:08:49.210149 29351 sched.cpp:609] Scheduler::statusUpdate took 16366ns
I0203 21:08:49.210310 29351 status_update_manager.cpp:392] Received status update acknowledgement (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.210341 29351 status_update_manager.hpp:342] Checkpointing ACK for status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.211158 29351 slave.cpp:1364] Status update manager successfully handled status update acknowledgement (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.219751 29328 master.cpp:561] Master terminating
I0203 21:08:49.219769 29351 sched.cpp:720] Stopping framework '201402032108-143311683-41693-29328-0000'
I0203 21:08:49.219782 29328 master.cpp:209] Shutting down master
I0203 21:08:49.219862 29351 slave.cpp:1958] master@67.195.138.8:41693 exited
W0203 21:08:49.219892 29351 slave.cpp:1961] Master disconnected! Waiting for a new master to be elected
I0203 21:08:49.219873 29328 master.hpp:421] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
I0203 21:08:49.220011 29328 master.cpp:252] Removing slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
I0203 21:08:49.220096 29348 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 201402032108-143311683-41693-29328-0 from framework 201402032108-143311683-41693-29328-0000
I0203 21:08:49.220463 29328 slave.cpp:391] Slave terminating
I0203 21:08:49.220556 29349 exec.cpp:446] Slave exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with slave 201402032108-143311683-41693-29328-0
[ OK ] StatusUpdateManagerTest.DuplicateUpdateBeforeAck (46 ms)
[----------] 7 tests from StatusUpdateManagerTest (246 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 (0 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 (0 ms total)
[----------] 3 tests from FsTest
[ RUN ] FsTest.MountTableRead
[ OK ] FsTest.MountTableRead (2 ms)
[ RUN ] FsTest.MountTableHasOption
[ OK ] FsTest.MountTableHasOption (0 ms)
[ RUN ] FsTest.FileSystemTableRead
[ OK ] FsTest.FileSystemTableRead (9 ms)
[----------] 3 tests from FsTest (11 ms total)
[----------] Global test environment tear-down
../../src/tests/environment.cpp:247: Failure
Failed
Tests completed with child processes remaining:
-+- 29328 <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src/.libs/lt-mesos-tests>
\-+- 30536 sh -c <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src/mesos-executor>
\-+- 30554 <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src/.libs/lt-mesos-executor>
\-+- 30577 sh -c sleep 10
\--- 30578 sleep 10
[==========] 220 tests from 39 test cases ran. (44746 ms total)
[ PASSED ] 220 tests.
[ FAILED ] 0 tests, listed below:
0 FAILED TESTS
YOU HAVE 2 DISABLED TESTS
I0203 21:08:49.295567 30576 process.cpp:1009] Socket closed while receiving
make[3]: *** [check-local] Error 1
I0203 21:08:49.295672 30573 exec.cpp:446] Slave exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with slave 201402032108-143311683-41693-29328-0
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make: *** [check-recursive] Error 1
Command exited with status 0 (pid: 30577)
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins: Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#1867
Posted by Benjamin Mahler <bm...@twitter.com>.
I have a fix out for this, see MESOS-960.
On Mon, Feb 3, 2014 at 1:08 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/1867/
> >
>
> ------------------------------------------
> [...truncated 21279 lines...]
> I0203 21:08:49.143712 29347 hierarchical_allocator_process.hpp:688]
> Performed allocation for 0 slaves in 7350ns
> I0203 21:08:49.143714 29354 slave.cpp:2753] Finished recovery
> I0203 21:08:49.147670 29350 slave.cpp:501] New master detected at
> master@67.195.138.8:41693
> I0203 21:08:49.147725 29350 slave.cpp:526] Detecting new master
> I0203 21:08:49.147758 29350 status_update_manager.cpp:162] New master
> detected at master@67.195.138.8:41693
> I0203 21:08:49.147797 29350 master.cpp:1812] Attempting to register slave
> on minerva.apache.org at slave(139)@67.195.138.8:41693
> I0203 21:08:49.147806 29350 master.cpp:2782] Adding slave
> 201402032108-143311683-41693-29328-0 at minerva.apache.org with
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0203 21:08:49.147910 29350 slave.cpp:544] Registered with master
> master@67.195.138.8:41693; given slave ID
> 201402032108-143311683-41693-29328-0
> I0203 21:08:49.148025 29350 slave.cpp:557] Checkpointing SlaveInfo to
> '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/meta/slaves/201402032108-143311683-41693-29328-0/
> slave.info'
> I0203 21:08:49.148138 29350 hierarchical_allocator_process.hpp:445] Added
> slave 201402032108-143311683-41693-29328-0 (minerva.apache.org) with
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> I0203 21:08:49.148188 29350 hierarchical_allocator_process.hpp:752]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 201402032108-143311683-41693-29328-0 to framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.148296 29350 hierarchical_allocator_process.hpp:708]
> Performed allocation for slave 201402032108-143311683-41693-29328-0 in
> 131475ns
> I0203 21:08:49.148355 29350 master.hpp:431] Adding offer
> 201402032108-143311683-41693-29328-0 with resources cpus(*):2; mem(*):1024;
> disk(*):1024; ports(*):[31000-32000] on slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org)
> I0203 21:08:49.148394 29350 master.cpp:2250] Sending 1 offers to framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.148476 29350 sched.cpp:518] Scheduler::resourceOffers took
> 14853ns
> I0203 21:08:49.148840 29349 master.hpp:441] Removing offer
> 201402032108-143311683-41693-29328-0 with resources cpus(*):2; mem(*):1024;
> disk(*):1024; ports(*):[31000-32000] on slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org)
> I0203 21:08:49.148887 29349 master.cpp:1546] Processing reply for offers:
> [ 201402032108-143311683-41693-29328-0 ] on slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org) for framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.148998 29349 master.hpp:403] Adding task 1 with resources
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org)
> I0203 21:08:49.149044 29349 master.cpp:2419] Launching task 1 of framework
> 201402032108-143311683-41693-29328-0000 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org)
> I0203 21:08:49.149165 29349 slave.cpp:729] Got assigned task 1 for
> framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.149219 29349 slave.cpp:2892] Checkpointing FrameworkInfo to
> '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/
> framework.info'
> I0203 21:08:49.149327 29349 slave.cpp:2899] Checkpointing framework pid
> 'scheduler(132)@67.195.138.8:41693' to
> '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/framework.pid'
> I0203 21:08:49.149497 29349 slave.cpp:838] Launching task 1 for framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.153285 29349 slave.cpp:3162] Checkpointing ExecutorInfo to
> '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/
> executor.info'
> I0203 21:08:49.156380 29349 slave.cpp:3250] Checkpointing TaskInfo to
> '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/runs/e09adb5b-4ecf-4f7e-9f73-bf3d443daf30/tasks/1/
> task.info'
> I0203 21:08:49.156551 29349 slave.cpp:948] Queuing task '1' for executor
> default of framework '201402032108-143311683-41693-29328-0000
> I0203 21:08:49.156628 29349 slave.cpp:466] Successfully attached file
> '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/runs/e09adb5b-4ecf-4f7e-9f73-bf3d443daf30'
> I0203 21:08:49.157335 29350 exec.cpp:178] Executor started at:
> executor(43)@67.195.138.8:41693 with pid 29328
> I0203 21:08:49.157403 29352 slave.cpp:2091] Monitoring executor default of
> framework 201402032108-143311683-41693-29328-0000 forked at pid 29328
> I0203 21:08:49.157505 29352 slave.cpp:1424] Got registration for executor
> 'default' of framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.157541 29352 slave.cpp:1509] Checkpointing executor pid
> 'executor(43)@67.195.138.8:41693' to
> '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_tWW3Ds/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/runs/e09adb5b-4ecf-4f7e-9f73-bf3d443daf30/pids/libprocess.pid'
> I0203 21:08:49.157786 29352 slave.cpp:1545] Flushing queued task 1 for
> executor 'default' of framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.157804 29353 exec.cpp:202] Executor registered on slave
> 201402032108-143311683-41693-29328-0
> I0203 21:08:49.158578 29353 exec.cpp:214] Executor::registered took 11099ns
> I0203 21:08:49.158627 29353 exec.cpp:289] Executor asked to run task '1'
> I0203 21:08:49.158669 29353 exec.cpp:298] Executor::launchTask took 33671ns
> I0203 21:08:49.159435 29353 exec.cpp:521] Executor sending status update
> TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of
> framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.159499 29353 slave.cpp:1758] Handling status update
> TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of
> framework 201402032108-143311683-41693-29328-0000 from executor(43)@
> 67.195.138.8:41693
> I0203 21:08:49.159517 29353 slave.cpp:3207] Terminating task 1
> I0203 21:08:49.159662 29354 status_update_manager.cpp:314] Received status
> update TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task
> 1 of framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.159695 29354 status_update_manager.cpp:493] Creating
> StatusUpdate stream for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.159881 29354 status_update_manager.hpp:342] Checkpointing
> UPDATE for status update TASK_FINISHED (UUID:
> 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.161545 29354 status_update_manager.cpp:367] Forwarding
> status update TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1)
> for task 1 of framework 201402032108-143311683-41693-29328-0000 to
> master@67.195.138.8:41693
> I0203 21:08:49.161676 29350 master.cpp:1998] Status update TASK_FINISHED
> (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework
> 201402032108-143311683-41693-29328-0000 from slave(139)@67.195.138.8:41693
> I0203 21:08:49.161710 29348 slave.cpp:1877] Status update manager
> successfully handled status update TASK_FINISHED (UUID:
> 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.161722 29348 slave.cpp:1883] Sending acknowledgement for
> status update TASK_FINISHED (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1)
> for task 1 of framework 201402032108-143311683-41693-29328-0000 to
> executor(43)@67.195.138.8:41693
> I0203 21:08:49.161736 29350 master.hpp:421] Removing task 1 with
> resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 201402032108-143311683-41693-29328-0 (minerva.apache.org)
> I0203 21:08:49.161767 29348 exec.cpp:335] Executor received status update
> acknowledgement 2335534b-f780-4663-a16d-aa08c5fc11c1 for task 1 of
> framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.161875 29351 sched.cpp:609] Scheduler::statusUpdate took
> 26659ns
> I0203 21:08:49.161947 29349 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 201402032108-143311683-41693-29328-0 from
> framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.162017 29351 status_update_manager.cpp:392] Received status
> update acknowledgement (UUID: 2335534b-f780-4663-a16d-aa08c5fc11c1) for
> task 1 of framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.162040 29351 status_update_manager.hpp:342] Checkpointing
> ACK for status update TASK_FINISHED (UUID:
> 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.162626 29351 status_update_manager.cpp:524] Cleaning up
> status update stream for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.162783 29348 slave.cpp:1364] Status update manager
> successfully handled status update acknowledgement (UUID:
> 2335534b-f780-4663-a16d-aa08c5fc11c1) for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.162801 29348 slave.cpp:3230] Completing task 1
> I0203 21:08:49.163753 29348 exec.cpp:521] Executor sending status update
> TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of
> framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.163817 29348 slave.cpp:1758] Handling status update
> TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of
> framework 201402032108-143311683-41693-29328-0000 from executor(43)@
> 67.195.138.8:41693
> W0203 21:08:49.163832 29348 slave.cpp:1789] Could not find the executor
> for status update TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5)
> for task 1 of framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.163913 29349 status_update_manager.cpp:314] Received status
> update TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1
> of framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.163933 29349 status_update_manager.cpp:493] Creating
> StatusUpdate stream for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.163988 29349 status_update_manager.cpp:367] Forwarding
> status update TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for
> task 1 of framework 201402032108-143311683-41693-29328-0000 to
> master@67.195.138.8:41693
> I0203 21:08:49.164114 29350 slave.cpp:1877] Status update manager
> successfully handled status update TASK_KILLED (UUID:
> 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.164126 29350 slave.cpp:1883] Sending acknowledgement for
> status update TASK_KILLED (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for
> task 1 of framework 201402032108-143311683-41693-29328-0000 to executor(43)@
> 67.195.138.8:41693
> I0203 21:08:49.164167 29350 exec.cpp:335] Executor received status update
> acknowledgement 5d9aac8e-adce-4123-9357-9878fa357ea5 for task 1 of
> framework 201402032108-143311683-41693-29328-0000
> W0203 21:08:49.164165 29352 master.cpp:1991] Status update TASK_KILLED
> (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework
> 201402032108-143311683-41693-29328-0000 from slave(139)@67.195.138.8:41693(
> minerva.apache.org): error, couldn't lookup task
> I0203 21:08:49.164229 29350 sched.cpp:609] Scheduler::statusUpdate took
> 20305ns
> I0203 21:08:49.164381 29350 status_update_manager.cpp:392] Received status
> update acknowledgement (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for
> task 1 of framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.164403 29350 status_update_manager.cpp:524] Cleaning up
> status update stream for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.164485 29350 slave.cpp:1364] Status update manager
> successfully handled status update acknowledgement (UUID:
> 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> E0203 21:08:49.164496 29350 slave.cpp:1388] Status update acknowledgement
> (UUID: 5d9aac8e-adce-4123-9357-9878fa357ea5) for task 1 of unknown executor
> I0203 21:08:49.174721 29328 master.cpp:561] Master terminating
> I0203 21:08:49.174751 29328 master.cpp:209] Shutting down master
> I0203 21:08:49.174773 29352 slave.cpp:1958] master@67.195.138.8:41693exited
> I0203 21:08:49.174784 29328 master.cpp:252] Removing slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org)
> I0203 21:08:49.174789 29353 sched.cpp:720] Stopping framework
> '201402032108-143311683-41693-29328-0000'
> W0203 21:08:49.174787 29352 slave.cpp:1961] Master disconnected! Waiting
> for a new master to be elected
> I0203 21:08:49.175235 29328 slave.cpp:391] Slave terminating
> I0203 21:08:49.175298 29348 exec.cpp:446] Slave exited, but framework has
> checkpointing enabled. Waiting 15mins to reconnect with slave
> 201402032108-143311683-41693-29328-0
> [ OK ] StatusUpdateManagerTest.DuplicateTerminalUpdateAfterAck (36
> ms)
> [ RUN ] StatusUpdateManagerTest.DuplicateUpdateBeforeAck
> I0203 21:08:49.189065 29349 master.cpp:284] Master started on
> 67.195.138.8:41693
> I0203 21:08:49.189100 29349 master.cpp:299] Master ID:
> 201402032108-143311683-41693-29328
> I0203 21:08:49.189107 29349 master.cpp:302] Master only allowing
> authenticated frameworks to register!
> I0203 21:08:49.189429 29353 hierarchical_allocator_process.hpp:302]
> Initializing hierarchical allocator process with master :
> master@67.195.138.8:41693
> I0203 21:08:49.189517 29353 master.cpp:85] No whitelist given. Advertising
> offers for all slaves
> I0203 21:08:49.189842 29353 master.cpp:734] The newly elected leader is
> master@67.195.138.8:41693
> I0203 21:08:49.189857 29353 master.cpp:742] Elected as the leading master!
> I0203 21:08:49.190803 29354 slave.cpp:112] Slave started on 140)@
> 67.195.138.8:41693
> I0203 21:08:49.190894 29354 slave.cpp:212] Slave resources: cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0203 21:08:49.191236 29351 sched.cpp:210] New master detected at
> master@67.195.138.8:41693
> I0203 21:08:49.191262 29351 sched.cpp:261] Authenticating with master
> master@67.195.138.8:41693
> I0203 21:08:49.191316 29351 sched.cpp:230] Detecting new master
> I0203 21:08:49.191337 29352 authenticatee.hpp:124] Creating new client
> SASL connection
> I0203 21:08:49.191503 29351 master.cpp:2295] Authenticating framework at
> scheduler(133)@67.195.138.8:41693
> I0203 21:08:49.191592 29349 authenticator.hpp:140] Creating new server
> SASL connection
> I0203 21:08:49.191845 29347 state.cpp:33] Recovering state from
> '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta'
> I0203 21:08:49.191849 29352 authenticatee.hpp:212] Received SASL
> authentication mechanisms: CRAM-MD5
> I0203 21:08:49.191896 29352 authenticatee.hpp:238] Attempting to
> authenticate with mechanism 'CRAM-MD5'
> I0203 21:08:49.191946 29349 authenticator.hpp:243] Received SASL
> authentication start
> I0203 21:08:49.191973 29347 status_update_manager.cpp:188] Recovering
> status update manager
> I0203 21:08:49.191984 29349 authenticator.hpp:325] Authentication requires
> more steps
> I0203 21:08:49.192018 29349 authenticatee.hpp:258] Received SASL
> authentication step
> I0203 21:08:49.192062 29349 authenticator.hpp:271] Received SASL
> authentication step
> I0203 21:08:49.192085 29349 auxprop.cpp:81] Request to lookup properties
> for user: 'test-principal' realm: 'minerva.apache.org' server FQDN: '
> minerva.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0203 21:08:49.192093 29349 auxprop.cpp:153] Looking up auxiliary
> property '*userPassword'
> I0203 21:08:49.192107 29349 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0203 21:08:49.192118 29349 auxprop.cpp:81] Request to lookup properties
> for user: 'test-principal' realm: 'minerva.apache.org' server FQDN: '
> minerva.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0203 21:08:49.192126 29349 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0203 21:08:49.192129 29351 slave.cpp:2753] Finished recovery
> I0203 21:08:49.192131 29349 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0203 21:08:49.192162 29349 authenticator.hpp:317] Authentication success
> I0203 21:08:49.192203 29352 authenticatee.hpp:298] Authentication success
> I0203 21:08:49.192205 29349 master.cpp:2335] Successfully authenticated
> framework at scheduler(133)@67.195.138.8:41693
> I0203 21:08:49.192272 29352 sched.cpp:335] Successfully authenticated with
> master master@67.195.138.8:41693
> I0203 21:08:49.192316 29349 master.cpp:790] Received registration request
> from scheduler(133)@67.195.138.8:41693
> I0203 21:08:49.192339 29349 master.cpp:808] Registering framework
> 201402032108-143311683-41693-29328-0000 at scheduler(133)@
> 67.195.138.8:41693
> I0203 21:08:49.192405 29347 sched.cpp:384] Framework registered with
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.192409 29349 slave.cpp:501] New master detected at
> master@67.195.138.8:41693
> I0203 21:08:49.192435 29352 hierarchical_allocator_process.hpp:332] Added
> framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.192440 29347 sched.cpp:398] Scheduler::registered took
> 10679ns
> I0203 21:08:49.192443 29352 hierarchical_allocator_process.hpp:726] No
> resources available to allocate!
> I0203 21:08:49.192462 29352 hierarchical_allocator_process.hpp:688]
> Performed allocation for 0 slaves in 18489ns
> I0203 21:08:49.192469 29349 slave.cpp:526] Detecting new master
> I0203 21:08:49.192469 29347 status_update_manager.cpp:162] New master
> detected at master@67.195.138.8:41693
> I0203 21:08:49.192508 29352 master.cpp:1812] Attempting to register slave
> on minerva.apache.org at slave(140)@67.195.138.8:41693
> I0203 21:08:49.192523 29352 master.cpp:2782] Adding slave
> 201402032108-143311683-41693-29328-0 at minerva.apache.org with
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0203 21:08:49.192576 29349 slave.cpp:544] Registered with master
> master@67.195.138.8:41693; given slave ID
> 201402032108-143311683-41693-29328-0
> I0203 21:08:49.192653 29352 hierarchical_allocator_process.hpp:445] Added
> slave 201402032108-143311683-41693-29328-0 (minerva.apache.org) with
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> I0203 21:08:49.192705 29352 hierarchical_allocator_process.hpp:752]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 201402032108-143311683-41693-29328-0 to framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.192826 29352 hierarchical_allocator_process.hpp:708]
> Performed allocation for slave 201402032108-143311683-41693-29328-0 in
> 142705ns
> I0203 21:08:49.192872 29353 master.hpp:431] Adding offer
> 201402032108-143311683-41693-29328-0 with resources cpus(*):2; mem(*):1024;
> disk(*):1024; ports(*):[31000-32000] on slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org)
> I0203 21:08:49.192921 29353 master.cpp:2250] Sending 1 offers to framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.193009 29352 sched.cpp:518] Scheduler::resourceOffers took
> 19081ns
> I0203 21:08:49.193531 29350 master.hpp:441] Removing offer
> 201402032108-143311683-41693-29328-0 with resources cpus(*):2; mem(*):1024;
> disk(*):1024; ports(*):[31000-32000] on slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org)
> I0203 21:08:49.193581 29350 master.cpp:1546] Processing reply for offers:
> [ 201402032108-143311683-41693-29328-0 ] on slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org) for framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.193691 29350 master.hpp:403] Adding task 1 with resources
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org)
> I0203 21:08:49.193742 29350 master.cpp:2419] Launching task 1 of framework
> 201402032108-143311683-41693-29328-0000 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org)
> I0203 21:08:49.201921 29349 slave.cpp:557] Checkpointing SlaveInfo to
> '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta/slaves/201402032108-143311683-41693-29328-0/
> slave.info'
> I0203 21:08:49.202033 29349 slave.cpp:729] Got assigned task 1 for
> framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.202093 29349 slave.cpp:2892] Checkpointing FrameworkInfo to
> '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/
> framework.info'
> I0203 21:08:49.202229 29349 slave.cpp:2899] Checkpointing framework pid
> 'scheduler(133)@67.195.138.8:41693' to
> '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/framework.pid'
> I0203 21:08:49.202404 29349 slave.cpp:838] Launching task 1 for framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.203378 29349 slave.cpp:3162] Checkpointing ExecutorInfo to
> '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/
> executor.info'
> I0203 21:08:49.203694 29349 slave.cpp:3250] Checkpointing TaskInfo to
> '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/runs/57d931fe-ab43-4c00-ab78-edd1d760c57a/tasks/1/
> task.info'
> I0203 21:08:49.203835 29349 slave.cpp:948] Queuing task '1' for executor
> default of framework '201402032108-143311683-41693-29328-0000
> I0203 21:08:49.203871 29349 slave.cpp:466] Successfully attached file
> '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/runs/57d931fe-ab43-4c00-ab78-edd1d760c57a'
> I0203 21:08:49.204656 29351 exec.cpp:178] Executor started at:
> executor(44)@67.195.138.8:41693 with pid 29328
> I0203 21:08:49.204674 29348 slave.cpp:2091] Monitoring executor default of
> framework 201402032108-143311683-41693-29328-0000 forked at pid 29328
> I0203 21:08:49.204773 29348 slave.cpp:1424] Got registration for executor
> 'default' of framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.204803 29348 slave.cpp:1509] Checkpointing executor pid
> 'executor(44)@67.195.138.8:41693' to
> '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_dbtUxt/meta/slaves/201402032108-143311683-41693-29328-0/frameworks/201402032108-143311683-41693-29328-0000/executors/default/runs/57d931fe-ab43-4c00-ab78-edd1d760c57a/pids/libprocess.pid'
> I0203 21:08:49.205044 29348 slave.cpp:1545] Flushing queued task 1 for
> executor 'default' of framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.205052 29350 exec.cpp:202] Executor registered on slave
> 201402032108-143311683-41693-29328-0
> I0203 21:08:49.205812 29350 exec.cpp:214] Executor::registered took 10475ns
> I0203 21:08:49.205858 29350 exec.cpp:289] Executor asked to run task '1'
> I0203 21:08:49.205891 29350 exec.cpp:298] Executor::launchTask took 21126ns
> I0203 21:08:49.206679 29350 exec.cpp:521] Executor sending status update
> TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of
> framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.206784 29350 slave.cpp:1758] Handling status update
> TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of
> framework 201402032108-143311683-41693-29328-0000 from executor(44)@
> 67.195.138.8:41693
> I0203 21:08:49.206920 29352 status_update_manager.cpp:314] Received status
> update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1
> of framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.206953 29352 status_update_manager.cpp:493] Creating
> StatusUpdate stream for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.207113 29352 status_update_manager.hpp:342] Checkpointing
> UPDATE for status update TASK_RUNNING (UUID:
> d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.208637 29352 status_update_manager.cpp:367] Forwarding
> status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for
> task 1 of framework 201402032108-143311683-41693-29328-0000 to
> master@67.195.138.8:41693
> I0203 21:08:49.208755 29349 slave.cpp:1877] Status update manager
> successfully handled status update TASK_RUNNING (UUID:
> d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.208770 29349 slave.cpp:1883] Sending acknowledgement for
> status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for
> task 1 of framework 201402032108-143311683-41693-29328-0000 to executor(44)@
> 67.195.138.8:41693
> I0203 21:08:49.208789 29350 master.cpp:1998] Status update TASK_RUNNING
> (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework
> 201402032108-143311683-41693-29328-0000 from slave(140)@67.195.138.8:41693
> I0203 21:08:49.208848 29349 exec.cpp:335] Executor received status update
> acknowledgement d55f3413-0d93-44ff-bfc5-93ae5553070b for task 1 of
> framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.208899 29347 sched.cpp:609] Scheduler::statusUpdate took
> 24488ns
> I0203 21:08:49.209245 29352 slave.cpp:1758] Handling status update
> TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of
> framework 201402032108-143311683-41693-29328-0000 from executor(44)@
> 67.195.138.8:41693
> I0203 21:08:49.209337 29353 status_update_manager.cpp:314] Received status
> update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1
> of framework 201402032108-143311683-41693-29328-0000
> W0203 21:08:49.209358 29353 status_update_manager.hpp:231] Ignoring
> duplicate status update TASK_RUNNING (UUID:
> d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.209414 29352 slave.cpp:1877] Status update manager
> successfully handled status update TASK_RUNNING (UUID:
> d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.209432 29352 slave.cpp:1883] Sending acknowledgement for
> status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for
> task 1 of framework 201402032108-143311683-41693-29328-0000 to executor(44)@
> 67.195.138.8:41693
> I0203 21:08:49.209569 29349 exec.cpp:335] Executor received status update
> acknowledgement d55f3413-0d93-44ff-bfc5-93ae5553070b for task 1 of
> framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.209821 29352 hierarchical_allocator_process.hpp:688]
> Performed allocation for 1 slaves in 28403ns
> W0203 21:08:49.209966 29353 status_update_manager.cpp:471] Resending
> status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for
> task 1 of framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.209985 29353 status_update_manager.cpp:367] Forwarding
> status update TASK_RUNNING (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for
> task 1 of framework 201402032108-143311683-41693-29328-0000 to
> master@67.195.138.8:41693
> I0203 21:08:49.209995 29354 master.cpp:85] No whitelist given. Advertising
> offers for all slaves
> I0203 21:08:49.210062 29354 master.cpp:1998] Status update TASK_RUNNING
> (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework
> 201402032108-143311683-41693-29328-0000 from slave(140)@67.195.138.8:41693
> I0203 21:08:49.210149 29351 sched.cpp:609] Scheduler::statusUpdate took
> 16366ns
> I0203 21:08:49.210310 29351 status_update_manager.cpp:392] Received status
> update acknowledgement (UUID: d55f3413-0d93-44ff-bfc5-93ae5553070b) for
> task 1 of framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.210341 29351 status_update_manager.hpp:342] Checkpointing
> ACK for status update TASK_RUNNING (UUID:
> d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.211158 29351 slave.cpp:1364] Status update manager
> successfully handled status update acknowledgement (UUID:
> d55f3413-0d93-44ff-bfc5-93ae5553070b) for task 1 of framework
> 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.219751 29328 master.cpp:561] Master terminating
> I0203 21:08:49.219769 29351 sched.cpp:720] Stopping framework
> '201402032108-143311683-41693-29328-0000'
> I0203 21:08:49.219782 29328 master.cpp:209] Shutting down master
> I0203 21:08:49.219862 29351 slave.cpp:1958] master@67.195.138.8:41693exited
> W0203 21:08:49.219892 29351 slave.cpp:1961] Master disconnected! Waiting
> for a new master to be elected
> I0203 21:08:49.219873 29328 master.hpp:421] Removing task 1 with resources
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org)
> I0203 21:08:49.220011 29328 master.cpp:252] Removing slave
> 201402032108-143311683-41693-29328-0 (minerva.apache.org)
> I0203 21:08:49.220096 29348 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 201402032108-143311683-41693-29328-0 from
> framework 201402032108-143311683-41693-29328-0000
> I0203 21:08:49.220463 29328 slave.cpp:391] Slave terminating
> I0203 21:08:49.220556 29349 exec.cpp:446] Slave exited, but framework has
> checkpointing enabled. Waiting 15mins to reconnect with slave
> 201402032108-143311683-41693-29328-0
> [ OK ] StatusUpdateManagerTest.DuplicateUpdateBeforeAck (46 ms)
> [----------] 7 tests from StatusUpdateManagerTest (246 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 (0 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 (0 ms total)
>
> [----------] 3 tests from FsTest
> [ RUN ] FsTest.MountTableRead
> [ OK ] FsTest.MountTableRead (2 ms)
> [ RUN ] FsTest.MountTableHasOption
> [ OK ] FsTest.MountTableHasOption (0 ms)
> [ RUN ] FsTest.FileSystemTableRead
> [ OK ] FsTest.FileSystemTableRead (9 ms)
> [----------] 3 tests from FsTest (11 ms total)
>
> [----------] Global test environment tear-down
> ../../src/tests/environment.cpp:247: Failure
> Failed
> Tests completed with child processes remaining:
> -+- 29328 <
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src/.libs/lt-mesos-tests
> >
> \-+- 30536 sh -c <
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src/mesos-executor
> >
> \-+- 30554 <
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src/.libs/lt-mesos-executor
> >
> \-+- 30577 sh -c sleep 10
> \--- 30578 sleep 10
> [==========] 220 tests from 39 test cases ran. (44746 ms total)
> [ PASSED ] 220 tests.
> [ FAILED ] 0 tests, listed below:
>
> 0 FAILED TESTS
>
> YOU HAVE 2 DISABLED TESTS
>
> I0203 21:08:49.295567 30576 process.cpp:1009] Socket closed while receiving
> make[3]: *** [check-local] Error 1
> I0203 21:08:49.295672 30573 exec.cpp:446] Slave exited, but framework has
> checkpointing enabled. Waiting 15mins to reconnect with slave
> 201402032108-143311683-41693-29328-0
> make[3]: Leaving directory `<
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src
> '>
> make[2]: *** [check-am] Error 2
> make[2]: Leaving directory `<
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src
> '>
> make[1]: *** [check] Error 2
> make[1]: Leaving directory `<
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src
> '>
> make: *** [check-recursive] Error 1
> Command exited with status 0 (pid: 30577)
> 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
#1868
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/1868/changes>