See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/1928/changes>
Changes: [niklas] Changed SIGKILL to SIGTERM in command executor shutdown. ------------------------------------------ [...truncated 10916 lines...] I0228 17:37:40.019311 3318 exec.cpp:217] Executor::registered took 10688ns I0228 17:37:40.019354 3318 exec.cpp:292] Executor asked to run task '0' I0228 17:37:40.019384 3318 exec.cpp:301] Executor::launchTask took 19193ns I0228 17:37:40.020138 3318 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 37b5f4b5-54ce-4573-adcd-8fc39c892091) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.020202 3318 slave.cpp:1650] Handling status update TASK_RUNNING (UUID: 37b5f4b5-54ce-4573-adcd-8fc39c892091) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 from executor(23)@67.195.138.9:46443 I0228 17:37:40.020279 3318 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 37b5f4b5-54ce-4573-adcd-8fc39c892091) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.020290 3318 status_update_manager.cpp:499] Creating StatusUpdate stream for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.020339 3318 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: 37b5f4b5-54ce-4573-adcd-8fc39c892091) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 to [email protected]:46443 I0228 17:37:40.020445 3318 master.cpp:2040] Status update TASK_RUNNING (UUID: 37b5f4b5-54ce-4573-adcd-8fc39c892091) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 from slave(52)@67.195.138.9:46443 I0228 17:37:40.020473 3320 slave.cpp:1770] Status update manager successfully handled status update TASK_RUNNING (UUID: 37b5f4b5-54ce-4573-adcd-8fc39c892091) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.020491 3320 slave.cpp:1776] Sending acknowledgement for status update TASK_RUNNING (UUID: 37b5f4b5-54ce-4573-adcd-8fc39c892091) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 to executor(23)@67.195.138.9:46443 I0228 17:37:40.020524 3318 sched.cpp:619] Scheduler::statusUpdate took 23072ns I0228 17:37:40.020568 3317 exec.cpp:338] Executor received status update acknowledgement 37b5f4b5-54ce-4573-adcd-8fc39c892091 for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.020727 3318 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 37b5f4b5-54ce-4573-adcd-8fc39c892091) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.020772 3318 slave.cpp:1263] Status update manager successfully handled status update acknowledgement (UUID: 37b5f4b5-54ce-4573-adcd-8fc39c892091) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.022289 3318 slave.cpp:2054] Executor 'default' of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 has exited with status 0 I0228 17:37:40.023046 3318 slave.cpp:1650] Handling status update TASK_LOST (UUID: d139ae67-8c12-4438-81fb-943a3c71d49a) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 from @0.0.0.0:0 I0228 17:37:40.023061 3318 slave.cpp:3149] Terminating task 0 I0228 17:37:40.023170 3318 status_update_manager.cpp:320] Received status update TASK_LOST (UUID: d139ae67-8c12-4438-81fb-943a3c71d49a) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.023187 3318 status_update_manager.cpp:373] Forwarding status update TASK_LOST (UUID: d139ae67-8c12-4438-81fb-943a3c71d49a) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 to [email protected]:46443 I0228 17:37:40.023263 3318 master.cpp:2113] Executor default of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 on slave 2014-02-28-17:37:39-160088899-46443-3296-0 (vesta.apache.org) has exited with status 0 I0228 17:37:40.023339 3318 master.cpp:2040] Status update TASK_LOST (UUID: d139ae67-8c12-4438-81fb-943a3c71d49a) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 from slave(52)@67.195.138.9:46443 I0228 17:37:40.023373 3318 master.hpp:441] Removing task 0 with resources cpus(*):2; mem(*):1024 on slave 2014-02-28-17:37:39-160088899-46443-3296-0 (vesta.apache.org) I0228 17:37:40.023427 3318 slave.cpp:1770] Status update manager successfully handled status update TASK_LOST (UUID: d139ae67-8c12-4438-81fb-943a3c71d49a) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.023484 3318 hierarchical_allocator_process.hpp:637] Recovered cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave 2014-02-28-17:37:39-160088899-46443-3296-0 from framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.023533 3318 sched.cpp:619] Scheduler::statusUpdate took 7302ns I0228 17:37:40.023607 3318 status_update_manager.cpp:398] Received status update acknowledgement (UUID: d139ae67-8c12-4438-81fb-943a3c71d49a) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.023624 3318 status_update_manager.cpp:530] Cleaning up status update stream for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.023672 3318 slave.cpp:1263] Status update manager successfully handled status update acknowledgement (UUID: d139ae67-8c12-4438-81fb-943a3c71d49a) for task 0 of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.023682 3318 slave.cpp:3172] Completing task 0 I0228 17:37:40.023689 3318 slave.cpp:2193] Cleaning up executor 'default' of framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.038621 3318 slave.cpp:2268] Cleaning up framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.038632 3322 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_zJ7RnB/slaves/2014-02-28-17:37:39-160088899-46443-3296-0/frameworks/2014-02-28-17:37:39-160088899-46443-3296-0000/executors/default/runs/1bdc197e-75db-4985-8e58-4f95f91a7376' for gc 6.99999974351704days in the future I0228 17:37:40.038683 3318 status_update_manager.cpp:282] Closing status update streams for framework 2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.038693 3322 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_zJ7RnB/slaves/2014-02-28-17:37:39-160088899-46443-3296-0/frameworks/2014-02-28-17:37:39-160088899-46443-3296-0000/executors/default' for gc 6.99999974351704days in the future I0228 17:37:40.038727 3322 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_zJ7RnB/slaves/2014-02-28-17:37:39-160088899-46443-3296-0/frameworks/2014-02-28-17:37:39-160088899-46443-3296-0000' for gc 6.99999974351704days in the future I0228 17:37:40.126873 3317 slave.cpp:2518] Current usage 90.00%. Max allowed age: 0ns I0228 17:37:40.126912 3317 gc.cpp:167] Pruning directories with remaining removal time 6.99999974351704days I0228 17:37:40.126937 3317 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_zJ7RnB/slaves/2014-02-28-17:37:39-160088899-46443-3296-0/frameworks/2014-02-28-17:37:39-160088899-46443-3296-0000/executors/default/runs/1bdc197e-75db-4985-8e58-4f95f91a7376 I0228 17:37:40.127007 3317 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_zJ7RnB/slaves/2014-02-28-17:37:39-160088899-46443-3296-0/frameworks/2014-02-28-17:37:39-160088899-46443-3296-0000/executors/default/runs/1bdc197e-75db-4985-8e58-4f95f91a7376' I0228 17:37:40.127038 3317 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_zJ7RnB/slaves/2014-02-28-17:37:39-160088899-46443-3296-0/frameworks/2014-02-28-17:37:39-160088899-46443-3296-0000/executors/default I0228 17:37:40.127140 3317 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_zJ7RnB/slaves/2014-02-28-17:37:39-160088899-46443-3296-0/frameworks/2014-02-28-17:37:39-160088899-46443-3296-0000/executors/default' I0228 17:37:40.127156 3317 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_zJ7RnB/slaves/2014-02-28-17:37:39-160088899-46443-3296-0/frameworks/2014-02-28-17:37:39-160088899-46443-3296-0000 I0228 17:37:40.127226 3317 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_zJ7RnB/slaves/2014-02-28-17:37:39-160088899-46443-3296-0/frameworks/2014-02-28-17:37:39-160088899-46443-3296-0000' I0228 17:37:40.147260 3321 process.cpp:3189] Handling HTTP event for process 'files' with path: '/files/browse.json' I0228 17:37:40.147605 3325 process.cpp:1008] Socket closed while receiving I0228 17:37:40.157423 3321 sched.cpp:730] Stopping framework '2014-02-28-17:37:39-160088899-46443-3296-0000' I0228 17:37:40.157445 3296 master.cpp:527] Master terminating I0228 17:37:40.157659 3318 slave.cpp:1851] [email protected]:46443 exited W0228 17:37:40.157676 3318 slave.cpp:1854] Master disconnected! Waiting for a new master to be elected I0228 17:37:40.158140 3296 slave.cpp:294] Slave terminating [ OK ] GarbageCollectorIntegrationTest.DiskUsage (243 ms) [ RUN ] GarbageCollectorIntegrationTest.Unschedule I0228 17:37:40.166539 3296 master.cpp:252] Master ID: 2014-02-28-17:37:40-160088899-46443-3296 Hostname: vesta.apache.org I0228 17:37:40.166626 3319 master.cpp:262] Master started on 67.195.138.9:46443 I0228 17:37:40.166646 3319 master.cpp:265] Master only allowing authenticated frameworks to register! I0228 17:37:40.167100 3319 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : [email protected]:46443 I0228 17:37:40.167129 3319 master.cpp:96] No whitelist given. Advertising offers for all slaves I0228 17:37:40.167315 3319 master.cpp:770] The newly elected leader is [email protected]:46443 with id 2014-02-28-17:37:40-160088899-46443-3296 I0228 17:37:40.167327 3319 master.cpp:780] Elected as the leading master! I0228 17:37:40.168789 3319 slave.cpp:119] Slave started on 53)@67.195.138.9:46443 I0228 17:37:40.168898 3319 slave.cpp:129] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I0228 17:37:40.168957 3319 slave.cpp:157] Slave hostname: vesta.apache.org I0228 17:37:40.168970 3319 slave.cpp:158] Slave checkpoint: false I0228 17:37:40.169332 3319 state.cpp:33] Recovering state from '/tmp/GarbageCollectorIntegrationTest_Unschedule_9e6lVq/meta' I0228 17:37:40.169430 3319 status_update_manager.cpp:193] Recovering status update manager I0228 17:37:40.169544 3319 slave.cpp:2677] Finished recovery I0228 17:37:40.169793 3324 slave.cpp:404] New master detected at [email protected]:46443 I0228 17:37:40.169850 3324 slave.cpp:429] Detecting new master I0228 17:37:40.169873 3323 status_update_manager.cpp:167] New master detected at [email protected]:46443 I0228 17:37:40.169939 3324 master.cpp:1857] Attempting to register slave on vesta.apache.org at slave(53)@67.195.138.9:46443 I0228 17:37:40.169967 3324 master.cpp:2840] Adding slave 2014-02-28-17:37:40-160088899-46443-3296-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I0228 17:37:40.170063 3319 slave.cpp:447] Registered with master [email protected]:46443; given slave ID 2014-02-28-17:37:40-160088899-46443-3296-0 I0228 17:37:40.170137 3321 hierarchical_allocator_process.hpp:445] Added slave 2014-02-28-17:37:40-160088899-46443-3296-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) I0228 17:37:40.170173 3321 hierarchical_allocator_process.hpp:708] Performed allocation for slave 2014-02-28-17:37:40-160088899-46443-3296-0 in 8213ns I0228 17:37:40.171315 3296 sched.cpp:121] Version: 0.19.0 I0228 17:37:40.171475 3317 sched.cpp:217] New master detected at [email protected]:46443 I0228 17:37:40.171497 3317 sched.cpp:267] Authenticating with master [email protected]:46443 I0228 17:37:40.171556 3324 authenticatee.hpp:128] Creating new client SASL connection I0228 17:37:40.171686 3320 master.cpp:2353] Authenticating framework at scheduler(70)@67.195.138.9:46443 I0228 17:37:40.171836 3318 authenticator.hpp:148] Creating new server SASL connection I0228 17:37:40.171907 3321 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0228 17:37:40.171933 3321 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0228 17:37:40.171975 3321 authenticator.hpp:254] Received SASL authentication start I0228 17:37:40.172005 3321 authenticator.hpp:342] Authentication requires more steps I0228 17:37:40.172040 3321 authenticatee.hpp:265] Received SASL authentication step I0228 17:37:40.172096 3321 authenticator.hpp:282] Received SASL authentication step I0228 17:37:40.172116 3321 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 I0228 17:37:40.172127 3321 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0228 17:37:40.172145 3321 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0228 17:37:40.172154 3321 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 I0228 17:37:40.172160 3321 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0228 17:37:40.172165 3321 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0228 17:37:40.172175 3321 authenticator.hpp:334] Authentication success I0228 17:37:40.172229 3320 master.cpp:2393] Successfully authenticated framework at scheduler(70)@67.195.138.9:46443 I0228 17:37:40.172235 3319 authenticatee.hpp:305] Authentication success I0228 17:37:40.172308 3319 sched.cpp:341] Successfully authenticated with master [email protected]:46443 I0228 17:37:40.172325 3319 sched.cpp:460] Sending registration request to [email protected]:46443 I0228 17:37:40.172389 3321 master.cpp:828] Received registration request from scheduler(70)@67.195.138.9:46443 I0228 17:37:40.172415 3321 master.cpp:846] Registering framework 2014-02-28-17:37:40-160088899-46443-3296-0000 at scheduler(70)@67.195.138.9:46443 I0228 17:37:40.172488 3319 sched.cpp:391] Framework registered with 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.172502 3321 hierarchical_allocator_process.hpp:332] Added framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.172520 3319 sched.cpp:405] Scheduler::registered took 19259ns I0228 17:37:40.172549 3321 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 2014-02-28-17:37:40-160088899-46443-3296-0 to framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.172693 3321 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 176801ns I0228 17:37:40.172735 3324 master.hpp:451] Adding offer 2014-02-28-17:37:40-160088899-46443-3296-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) I0228 17:37:40.172778 3324 master.cpp:2308] Sending 1 offers to framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.173001 3324 sched.cpp:528] Scheduler::resourceOffers took 139950ns I0228 17:37:40.173148 3321 master.hpp:461] Removing offer 2014-02-28-17:37:40-160088899-46443-3296-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) I0228 17:37:40.173195 3321 master.cpp:1584] Processing reply for offers: [ 2014-02-28-17:37:40-160088899-46443-3296-0 ] on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) for framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.173266 3321 master.hpp:423] Adding task 0 with resources cpus(*):2; mem(*):1024 on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) I0228 17:37:40.173310 3321 master.cpp:2477] Launching task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 with resources cpus(*):2; mem(*):1024 on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) I0228 17:37:40.173430 3321 slave.cpp:632] Got assigned task 0 for framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.173437 3324 hierarchical_allocator_process.hpp:547] Framework 2014-02-28-17:37:40-160088899-46443-3296-0000 left disk(*):1024; ports(*):[31000-32000] unused on slave 2014-02-28-17:37:40-160088899-46443-3296-0 I0228 17:37:40.173486 3324 hierarchical_allocator_process.hpp:590] Framework 2014-02-28-17:37:40-160088899-46443-3296-0000 filtered slave 2014-02-28-17:37:40-160088899-46443-3296-0 for 5secs I0228 17:37:40.173585 3321 slave.cpp:741] Launching task 0 for framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.252043 3321 exec.cpp:131] Version: 0.19.0 I0228 17:37:40.252099 3324 exec.cpp:181] Executor started at: executor(24)@67.195.138.9:46443 with pid 3296 I0228 17:37:40.252122 3321 slave.cpp:851] Queuing task '0' for executor executor-1 of framework '2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.252163 3321 slave.cpp:365] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_Unschedule_9e6lVq/slaves/2014-02-28-17:37:40-160088899-46443-3296-0/frameworks/2014-02-28-17:37:40-160088899-46443-3296-0000/executors/executor-1/runs/6845598d-3d49-4f71-94ba-4bd30f827e9f' I0228 17:37:40.252185 3321 slave.cpp:1996] Monitoring executor 'executor-1' of framework '2014-02-28-17:37:40-160088899-46443-3296-0000' in container '6845598d-3d49-4f71-94ba-4bd30f827e9f' I0228 17:37:40.252238 3321 slave.cpp:1323] Got registration for executor 'executor-1' of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.252310 3321 slave.cpp:1441] Flushing queued task 0 for executor 'executor-1' of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.252398 3321 exec.cpp:205] Executor registered on slave 2014-02-28-17:37:40-160088899-46443-3296-0 I0228 17:37:40.253141 3321 exec.cpp:217] Executor::registered took 11006ns I0228 17:37:40.253180 3321 exec.cpp:292] Executor asked to run task '0' I0228 17:37:40.253207 3321 exec.cpp:301] Executor::launchTask took 19541ns I0228 17:37:40.253968 3321 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 8595edeb-491e-4219-8840-c567c6c201b1) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.254029 3321 slave.cpp:1650] Handling status update TASK_RUNNING (UUID: 8595edeb-491e-4219-8840-c567c6c201b1) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 from executor(24)@67.195.138.9:46443 I0228 17:37:40.254091 3321 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 8595edeb-491e-4219-8840-c567c6c201b1) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.254108 3321 status_update_manager.cpp:499] Creating StatusUpdate stream for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.254156 3321 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: 8595edeb-491e-4219-8840-c567c6c201b1) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 to [email protected]:46443 I0228 17:37:40.254259 3321 master.cpp:2040] Status update TASK_RUNNING (UUID: 8595edeb-491e-4219-8840-c567c6c201b1) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 from slave(53)@67.195.138.9:46443 I0228 17:37:40.254283 3321 slave.cpp:1770] Status update manager successfully handled status update TASK_RUNNING (UUID: 8595edeb-491e-4219-8840-c567c6c201b1) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.254292 3321 slave.cpp:1776] Sending acknowledgement for status update TASK_RUNNING (UUID: 8595edeb-491e-4219-8840-c567c6c201b1) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 to executor(24)@67.195.138.9:46443 I0228 17:37:40.254344 3321 sched.cpp:619] Scheduler::statusUpdate took 11906ns I0228 17:37:40.254395 3321 exec.cpp:338] Executor received status update acknowledgement 8595edeb-491e-4219-8840-c567c6c201b1 for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.254483 3321 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 8595edeb-491e-4219-8840-c567c6c201b1) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.254746 3321 slave.cpp:1263] Status update manager successfully handled status update acknowledgement (UUID: 8595edeb-491e-4219-8840-c567c6c201b1) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.254809 3321 slave.cpp:2054] Executor 'executor-1' of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 has exited with status 0 I0228 17:37:40.255630 3321 slave.cpp:1650] Handling status update TASK_LOST (UUID: e4fd4752-d824-4350-a54d-ab39a65e69fe) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 from @0.0.0.0:0 I0228 17:37:40.255648 3321 slave.cpp:3149] Terminating task 0 I0228 17:37:40.255764 3320 status_update_manager.cpp:320] Received status update TASK_LOST (UUID: e4fd4752-d824-4350-a54d-ab39a65e69fe) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.255794 3321 master.cpp:2113] Executor executor-1 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) has exited with status 0 I0228 17:37:40.255794 3320 status_update_manager.cpp:373] Forwarding status update TASK_LOST (UUID: e4fd4752-d824-4350-a54d-ab39a65e69fe) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 to [email protected]:46443 I0228 17:37:40.255892 3321 master.cpp:2040] Status update TASK_LOST (UUID: e4fd4752-d824-4350-a54d-ab39a65e69fe) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 from slave(53)@67.195.138.9:46443 I0228 17:37:40.255920 3320 slave.cpp:1770] Status update manager successfully handled status update TASK_LOST (UUID: e4fd4752-d824-4350-a54d-ab39a65e69fe) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.255934 3321 master.hpp:441] Removing task 0 with resources cpus(*):2; mem(*):1024 on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) I0228 17:37:40.255974 3320 sched.cpp:619] Scheduler::statusUpdate took 7575ns I0228 17:37:40.256026 3321 hierarchical_allocator_process.hpp:637] Recovered cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave 2014-02-28-17:37:40-160088899-46443-3296-0 from framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.256072 3320 status_update_manager.cpp:398] Received status update acknowledgement (UUID: e4fd4752-d824-4350-a54d-ab39a65e69fe) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.256091 3320 status_update_manager.cpp:530] Cleaning up status update stream for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.256187 3324 slave.cpp:1263] Status update manager successfully handled status update acknowledgement (UUID: e4fd4752-d824-4350-a54d-ab39a65e69fe) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.256213 3324 slave.cpp:3172] Completing task 0 I0228 17:37:40.256225 3324 slave.cpp:2193] Cleaning up executor 'executor-1' of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.256320 3323 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_9e6lVq/slaves/2014-02-28-17:37:40-160088899-46443-3296-0/frameworks/2014-02-28-17:37:40-160088899-46443-3296-0000/executors/executor-1/runs/6845598d-3d49-4f71-94ba-4bd30f827e9f' for gc 6.99999705256889days in the future I0228 17:37:40.256331 3324 slave.cpp:2268] Cleaning up framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.256425 3323 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_9e6lVq/slaves/2014-02-28-17:37:40-160088899-46443-3296-0/frameworks/2014-02-28-17:37:40-160088899-46443-3296-0000/executors/executor-1' for gc 6.99999705256889days in the future I0228 17:37:40.256417 3317 status_update_manager.cpp:282] Closing status update streams for framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.256469 3323 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_9e6lVq/slaves/2014-02-28-17:37:40-160088899-46443-3296-0/frameworks/2014-02-28-17:37:40-160088899-46443-3296-0000' for gc 6.99999705256889days in the future I0228 17:37:40.345496 3319 hierarchical_allocator_process.hpp:752] Offering disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 2014-02-28-17:37:40-160088899-46443-3296-0 to framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.345625 3319 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 181842ns I0228 17:37:40.345690 3324 master.hpp:451] Adding offer 2014-02-28-17:37:40-160088899-46443-3296-1 with resources disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) I0228 17:37:40.345757 3324 master.cpp:2308] Sending 1 offers to framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.346017 3317 sched.cpp:528] Scheduler::resourceOffers took 149017ns I0228 17:37:40.346189 3324 master.hpp:461] Removing offer 2014-02-28-17:37:40-160088899-46443-3296-1 with resources disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) I0228 17:37:40.346241 3324 master.cpp:1584] Processing reply for offers: [ 2014-02-28-17:37:40-160088899-46443-3296-1 ] on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) for framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.346303 3324 master.hpp:423] Adding task 0 with resources cpus(*):2; mem(*):1024 on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) I0228 17:37:40.346340 3324 master.cpp:2477] Launching task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 with resources cpus(*):2; mem(*):1024 on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) I0228 17:37:40.346473 3322 hierarchical_allocator_process.hpp:547] Framework 2014-02-28-17:37:40-160088899-46443-3296-0000 left disk(*):1024; ports(*):[31000-32000] unused on slave 2014-02-28-17:37:40-160088899-46443-3296-0 I0228 17:37:40.346541 3322 hierarchical_allocator_process.hpp:590] Framework 2014-02-28-17:37:40-160088899-46443-3296-0000 filtered slave 2014-02-28-17:37:40-160088899-46443-3296-0 for 5secs I0228 17:37:40.346406 3317 slave.cpp:632] Got assigned task 0 for framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.346803 3317 gc.cpp:84] Unscheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_9e6lVq/slaves/2014-02-28-17:37:40-160088899-46443-3296-0/frameworks/2014-02-28-17:37:40-160088899-46443-3296-0000' from gc I0228 17:37:40.346890 3317 slave.cpp:741] Launching task 0 for framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.406200 3317 exec.cpp:131] Version: 0.19.0 I0228 17:37:40.406255 3319 exec.cpp:181] Executor started at: executor(25)@67.195.138.9:46443 with pid 3296 I0228 17:37:40.406280 3317 slave.cpp:851] Queuing task '0' for executor executor-2 of framework '2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.406324 3317 slave.cpp:365] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_Unschedule_9e6lVq/slaves/2014-02-28-17:37:40-160088899-46443-3296-0/frameworks/2014-02-28-17:37:40-160088899-46443-3296-0000/executors/executor-2/runs/8355e407-cf03-43b7-8ade-a8e0d345e4a2' I0228 17:37:40.406345 3317 slave.cpp:1996] Monitoring executor 'executor-2' of framework '2014-02-28-17:37:40-160088899-46443-3296-0000' in container '8355e407-cf03-43b7-8ade-a8e0d345e4a2' I0228 17:37:40.406406 3317 slave.cpp:1323] Got registration for executor 'executor-2' of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.406549 3317 slave.cpp:1441] Flushing queued task 0 for executor 'executor-2' of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.406565 3324 exec.cpp:205] Executor registered on slave 2014-02-28-17:37:40-160088899-46443-3296-0 I0228 17:37:40.407325 3324 exec.cpp:217] Executor::registered took 13226ns I0228 17:37:40.407367 3324 exec.cpp:292] Executor asked to run task '0' I0228 17:37:40.407389 3324 exec.cpp:301] Executor::launchTask took 14068ns I0228 17:37:40.408138 3324 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 7327bb22-febc-4aa1-aa85-958e683f2439) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.408203 3324 slave.cpp:1650] Handling status update TASK_RUNNING (UUID: 7327bb22-febc-4aa1-aa85-958e683f2439) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 from executor(25)@67.195.138.9:46443 I0228 17:37:40.408300 3319 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 7327bb22-febc-4aa1-aa85-958e683f2439) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.408320 3319 status_update_manager.cpp:499] Creating StatusUpdate stream for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.408371 3319 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: 7327bb22-febc-4aa1-aa85-958e683f2439) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 to [email protected]:46443 I0228 17:37:40.408469 3322 slave.cpp:1770] Status update manager successfully handled status update TASK_RUNNING (UUID: 7327bb22-febc-4aa1-aa85-958e683f2439) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.408488 3322 slave.cpp:1776] Sending acknowledgement for status update TASK_RUNNING (UUID: 7327bb22-febc-4aa1-aa85-958e683f2439) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 to executor(25)@67.195.138.9:46443 I0228 17:37:40.408490 3324 master.cpp:2040] Status update TASK_RUNNING (UUID: 7327bb22-febc-4aa1-aa85-958e683f2439) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 from slave(53)@67.195.138.9:46443 I0228 17:37:40.408552 3324 exec.cpp:338] Executor received status update acknowledgement 7327bb22-febc-4aa1-aa85-958e683f2439 for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.408557 3320 sched.cpp:619] Scheduler::statusUpdate took 9599ns I0228 17:37:40.408673 3320 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 7327bb22-febc-4aa1-aa85-958e683f2439) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.408726 3320 slave.cpp:1263] Status update manager successfully handled status update acknowledgement (UUID: 7327bb22-febc-4aa1-aa85-958e683f2439) for task 0 of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.425818 3322 sched.cpp:730] Stopping framework '2014-02-28-17:37:40-160088899-46443-3296-0000' I0228 17:37:40.425827 3296 master.cpp:527] Master terminating I0228 17:37:40.425880 3296 master.hpp:441] Removing task 0 with resources cpus(*):2; mem(*):1024 on slave 2014-02-28-17:37:40-160088899-46443-3296-0 (vesta.apache.org) I0228 17:37:40.425988 3318 hierarchical_allocator_process.hpp:637] Recovered cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave 2014-02-28-17:37:40-160088899-46443-3296-0 from framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.426138 3319 slave.cpp:1851] [email protected]:46443 exited W0228 17:37:40.426205 3319 slave.cpp:1854] Master disconnected! Waiting for a new master to be elected I0228 17:37:40.426458 3296 slave.cpp:294] Slave terminating I0228 17:37:40.426491 3296 slave.cpp:1034] Asked to shut down framework 2014-02-28-17:37:40-160088899-46443-3296-0000 by @0.0.0.0:0 I0228 17:37:40.426504 3296 slave.cpp:1059] Shutting down framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.426517 3296 slave.cpp:2339] Shutting down executor 'executor-2' of framework 2014-02-28-17:37:40-160088899-46443-3296-0000 I0228 17:37:40.426570 3320 exec.cpp:378] Executor asked to shutdown I0228 17:37:40.426590 3320 exec.cpp:393] Executor::shutdown took 8604ns [ OK ] GarbageCollectorIntegrationTest.Unschedule (269 ms) [----------] 5 tests from GarbageCollectorIntegrationTest (1136 ms total) [----------] 2 tests from CpuIsolatorTest/0, where TypeParam = mesos::internal::slave::PosixCpuIsolatorProcess [ RUN ] CpuIsolatorTest/0.UserCpuUsage I0228 17:37:40.439255 3296 launcher.cpp:120] Forked child with pid '4183' for container 'user_cpu_usage' [ OK ] CpuIsolatorTest/0.UserCpuUsage (1013 ms) [ RUN ] CpuIsolatorTest/0.SystemCpuUsage I0228 17:37:41.442122 3296 launcher.cpp:120] Forked child with pid '4187' for container 'system_cpu_usage' [ OK ] CpuIsolatorTest/0.SystemCpuUsage (1001 ms) [----------] 2 tests from CpuIsolatorTest/0 (2014 ms total) [----------] 1 test from LimitedCpuIsolatorTest [ RUN ] LimitedCpuIsolatorTest.CgroupsCfs F0228 17:37:42.441640 3296 isolator_tests.cpp:315] CHECK_SOME(isolator): Failed to create isolator: Using cgroups requires root permissions *** Check failure stack trace: *** @ 0x2af1967902fd google::LogMessage::Fail() @ 0x2af1967923ff google::LogMessage::SendToLog() @ 0x2af19678feec google::LogMessage::Flush() @ 0x2af196792c9d google::LogMessageFatal::~LogMessageFatal() @ 0x4cf64d _CheckSome::~_CheckSome() @ 0x63b089 LimitedCpuIsolatorTest_CgroupsCfs_Test::TestBody() @ 0x854fed testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x84d271 testing::Test::Run() @ 0x84d356 testing::TestInfo::Run() @ 0x84d497 testing::TestCase::Run() @ 0x84d7ee testing::internal::UnitTestImpl::RunAllTests() @ 0x854b6d testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x84c8ce testing::UnitTest::Run() @ 0x4a90cb main @ 0x2af197b5576d (unknown) @ 0x4b27b1 (unknown) make[3]: *** [check-local] Aborted make[3]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src' make[2]: *** [check-am] Error 2 make[2]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src' make[1]: *** [check] Error 2 make[1]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src' make: *** [check-recursive] Error 1 Build step 'Execute shell' marked build as failure
