See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/2314/changes>
Changes: [benjamin.hindman] Fix deadlock between SocketManager::send() and internal::send(). [benjamin.hindman] Add thread local to short-circuit run_in_event_loop(). ------------------------------------------ [...truncated 57342 lines...] I1124 19:50:15.584803 17889 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 263043ns I1124 19:50:15.584828 17889 replica.cpp:676] Persisted action at 0 I1124 19:50:15.584849 17889 replica.cpp:661] Replica learned NOP action at position 0 I1124 19:50:15.585364 17884 log.cpp:672] Writer started with ending position 0 I1124 19:50:15.586355 17881 leveldb.cpp:438] Reading position from leveldb took 26922ns I1124 19:50:15.589337 17892 registrar.cpp:346] Successfully fetched the registry (0B) in 10.9888ms I1124 19:50:15.589434 17892 registrar.cpp:445] Applied 1 operations in 20011ns; attempting to update the 'registry' I1124 19:50:15.592386 17890 log.cpp:680] Attempting to append 140 bytes to the log I1124 19:50:15.592550 17881 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1 I1124 19:50:15.593240 17888 replica.cpp:508] Replica received write request for position 1 I1124 19:50:15.593602 17888 leveldb.cpp:343] Persisting action (159 bytes) to leveldb took 329561ns I1124 19:50:15.593628 17888 replica.cpp:676] Persisted action at 1 I1124 19:50:15.594260 17885 replica.cpp:655] Replica received learned notice for position 1 I1124 19:50:15.594617 17885 leveldb.cpp:343] Persisting action (161 bytes) to leveldb took 329948ns I1124 19:50:15.745816 17885 replica.cpp:676] Persisted action at 1 I1124 19:50:15.745848 17885 replica.cpp:661] Replica learned APPEND action at position 1 I1124 19:50:15.746749 17892 registrar.cpp:490] Successfully updated the 'registry' in 157.262848ms I1124 19:50:15.746912 17892 registrar.cpp:376] Successfully recovered registrar I1124 19:50:15.746979 17890 log.cpp:699] Attempting to truncate the log to 1 I1124 19:50:15.747176 17884 master.cpp:1121] Recovered 0 slaves from the Registry (102B) ; allowing 10mins for slaves to re-register I1124 19:50:15.747186 17886 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2 I1124 19:50:15.747939 17891 replica.cpp:508] Replica received write request for position 2 I1124 19:50:15.748482 17891 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 510287ns I1124 19:50:15.748538 17891 replica.cpp:676] Persisted action at 2 I1124 19:50:15.749140 17886 replica.cpp:655] Replica received learned notice for position 2 I1124 19:50:15.749685 17886 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 513529ns I1124 19:50:15.749747 17886 leveldb.cpp:401] Deleting ~1 keys from leveldb took 32459ns I1124 19:50:15.749769 17886 replica.cpp:676] Persisted action at 2 I1124 19:50:15.749793 17886 replica.cpp:661] Replica learned TRUNCATE action at position 2 I1124 19:50:15.767634 17891 slave.cpp:170] Slave started on 185)@67.195.81.186:49443 I1124 19:50:15.767683 17891 credentials.hpp:84] Loading credential for authentication from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Pu3ksq/credential' I1124 19:50:15.767851 17891 slave.cpp:279] Slave using credential for: test-principal I1124 19:50:15.768074 17891 slave.cpp:292] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1124 19:50:15.768179 17891 slave.cpp:321] Slave hostname: penates.apache.org I1124 19:50:15.768196 17891 slave.cpp:322] Slave checkpoint: false W1124 19:50:15.768206 17891 slave.cpp:324] Disabling checkpointing is deprecated and the --checkpoint flag will be removed in a future release. Please avoid using this flag I1124 19:50:15.769003 17894 state.cpp:33] Recovering state from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Pu3ksq/meta' I1124 19:50:15.769266 17887 status_update_manager.cpp:197] Recovering status update manager I1124 19:50:15.769620 17891 slave.cpp:3482] Finished recovery I1124 19:50:15.770025 17885 status_update_manager.cpp:171] Pausing sending status updates I1124 19:50:15.770030 17884 slave.cpp:605] New master detected at [email protected]:49443 I1124 19:50:15.770094 17884 slave.cpp:668] Authenticating with master [email protected]:49443 I1124 19:50:15.770113 17884 slave.cpp:673] Using default CRAM-MD5 authenticatee I1124 19:50:15.770231 17884 slave.cpp:641] Detecting new master I1124 19:50:15.770395 17881 authenticatee.hpp:138] Creating new client SASL connection I1124 19:50:15.770673 17888 master.cpp:3874] Authenticating slave(185)@67.195.81.186:49443 I1124 19:50:15.770701 17888 master.cpp:3885] Using default CRAM-MD5 authenticator I1124 19:50:15.770951 17886 authenticator.hpp:170] Creating new server SASL connection I1124 19:50:15.771152 17885 authenticatee.hpp:229] Received SASL authentication mechanisms: CRAM-MD5 I1124 19:50:15.771180 17885 authenticatee.hpp:255] Attempting to authenticate with mechanism 'CRAM-MD5' I1124 19:50:15.771278 17879 authenticator.hpp:276] Received SASL authentication start I1124 19:50:15.771325 17879 authenticator.hpp:398] Authentication requires more steps I1124 19:50:15.771440 17889 authenticatee.hpp:275] Received SASL authentication step I1124 19:50:15.771606 17888 authenticator.hpp:304] Received SASL authentication step I1124 19:50:15.771641 17888 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1124 19:50:15.771654 17888 auxprop.cpp:171] Looking up auxiliary property '*userPassword' I1124 19:50:15.771692 17888 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1124 19:50:15.771718 17888 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1124 19:50:15.771729 17888 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1124 19:50:15.771739 17888 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1124 19:50:15.771755 17888 authenticator.hpp:390] Authentication success I1124 19:50:15.771837 17885 authenticatee.hpp:315] Authentication success I1124 19:50:15.771868 17894 master.cpp:3932] Successfully authenticated principal 'test-principal' at slave(185)@67.195.81.186:49443 I1124 19:50:15.772111 17886 slave.cpp:739] Successfully authenticated with master [email protected]:49443 I1124 19:50:15.772222 17886 slave.cpp:1067] Will retry registration in 1.994857ms if necessary I1124 19:50:15.772383 17880 master.cpp:3031] Registering slave at slave(185)@67.195.81.186:49443 (penates.apache.org) with id 20141124-195015-3125920579-49443-17865-S0 I1124 19:50:15.772773 17881 registrar.cpp:445] Applied 1 operations in 56001ns; attempting to update the 'registry' I1124 19:50:15.774689 17892 slave.cpp:1067] Will retry registration in 10.233729ms if necessary I1124 19:50:15.774804 17888 master.cpp:3019] Ignoring register slave message from slave(185)@67.195.81.186:49443 (penates.apache.org) as admission is already in progress I1124 19:50:15.775810 17887 log.cpp:680] Attempting to append 318 bytes to the log I1124 19:50:15.775946 17885 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3 I1124 19:50:15.776661 17886 replica.cpp:508] Replica received write request for position 3 I1124 19:50:15.777261 17886 leveldb.cpp:343] Persisting action (337 bytes) to leveldb took 567530ns I1124 19:50:15.777288 17886 replica.cpp:676] Persisted action at 3 I1124 19:50:15.777953 17887 replica.cpp:655] Replica received learned notice for position 3 I1124 19:50:15.778473 17887 leveldb.cpp:343] Persisting action (339 bytes) to leveldb took 493615ns I1124 19:50:15.778504 17887 replica.cpp:676] Persisted action at 3 I1124 19:50:15.778556 17887 replica.cpp:661] Replica learned APPEND action at position 3 I1124 19:50:15.779335 17885 registrar.cpp:490] Successfully updated the 'registry' in 6.514944ms I1124 19:50:15.779623 17894 log.cpp:699] Attempting to truncate the log to 3 I1124 19:50:15.779752 17883 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4 I1124 19:50:15.779971 17882 slave.cpp:2553] Received ping from slave-observer(164)@67.195.81.186:49443 I1124 19:50:15.780043 17881 master.cpp:3085] Registered slave 20141124-195015-3125920579-49443-17865-S0 at slave(185)@67.195.81.186:49443 (penates.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1124 19:50:15.780275 17882 slave.cpp:773] Registered with master [email protected]:49443; given slave ID 20141124-195015-3125920579-49443-17865-S0 I1124 19:50:15.780275 17893 hierarchical_allocator_process.hpp:442] Added slave 20141124-195015-3125920579-49443-17865-S0 (penates.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I1124 19:50:15.780468 17892 status_update_manager.cpp:178] Resuming sending status updates I1124 19:50:15.780468 17893 hierarchical_allocator_process.hpp:679] Performed allocation for slave 20141124-195015-3125920579-49443-17865-S0 in 76428ns I1124 19:50:15.780670 17887 replica.cpp:508] Replica received write request for position 4 I1124 19:50:15.781179 17887 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 475291ns I1124 19:50:15.781205 17887 replica.cpp:676] Persisted action at 4 I1124 19:50:15.781780 17891 replica.cpp:655] Replica received learned notice for position 4 I1124 19:50:15.787025 17865 sched.cpp:148] Version: 0.22.0 I1124 19:50:15.992419 17879 sched.cpp:245] New master detected at [email protected]:49443 I1124 19:50:15.992444 17891 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 601527ns I1124 19:50:15.992483 17879 sched.cpp:301] Authenticating with master [email protected]:49443 I1124 19:50:15.992573 17891 leveldb.cpp:401] Deleting ~2 keys from leveldb took 35756ns I1124 19:50:15.992580 17879 sched.cpp:308] Using default CRAM-MD5 authenticatee I1124 19:50:15.992615 17891 replica.cpp:676] Persisted action at 4 I1124 19:50:15.992650 17891 replica.cpp:661] Replica learned TRUNCATE action at position 4 I1124 19:50:15.992903 17889 authenticatee.hpp:138] Creating new client SASL connection I1124 19:50:15.993307 17879 master.cpp:3874] Authenticating [email protected]:49443 I1124 19:50:15.993362 17879 master.cpp:3885] Using default CRAM-MD5 authenticator I1124 19:50:15.993686 17889 authenticator.hpp:170] Creating new server SASL connection I1124 19:50:15.994011 17883 authenticatee.hpp:229] Received SASL authentication mechanisms: CRAM-MD5 I1124 19:50:15.994038 17883 authenticatee.hpp:255] Attempting to authenticate with mechanism 'CRAM-MD5' I1124 19:50:15.994120 17883 authenticator.hpp:276] Received SASL authentication start I1124 19:50:15.994171 17883 authenticator.hpp:398] Authentication requires more steps I1124 19:50:15.994248 17883 authenticatee.hpp:275] Received SASL authentication step I1124 19:50:15.994334 17883 authenticator.hpp:304] Received SASL authentication step I1124 19:50:15.994359 17883 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1124 19:50:15.994371 17883 auxprop.cpp:171] Looking up auxiliary property '*userPassword' I1124 19:50:15.994403 17883 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1124 19:50:15.994428 17883 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1124 19:50:15.994441 17883 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1124 19:50:15.994448 17883 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1124 19:50:15.994464 17883 authenticator.hpp:390] Authentication success I1124 19:50:15.994598 17879 authenticatee.hpp:315] Authentication success I1124 19:50:15.994611 17883 master.cpp:3932] Successfully authenticated principal 'test-principal' at [email protected]:49443 I1124 19:50:15.994801 17879 sched.cpp:389] Successfully authenticated with master [email protected]:49443 I1124 19:50:15.994823 17879 sched.cpp:512] Sending registration request to [email protected]:49443 I1124 19:50:15.994882 17879 sched.cpp:545] Will retry registration in 1.892636646secs if necessary I1124 19:50:15.994985 17883 master.cpp:1383] Received registration request for framework 'default' at [email protected]:49443 I1124 19:50:15.995056 17883 master.cpp:1342] Authorizing framework principal 'test-principal' to receive offers for role '*' I1124 19:50:15.995476 17883 master.cpp:1447] Registering framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 I1124 19:50:15.995805 17879 hierarchical_allocator_process.hpp:329] Added framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:15.996037 17879 hierarchical_allocator_process.hpp:734] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141124-195015-3125920579-49443-17865-S0 to framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:15.996165 17887 sched.cpp:439] Framework registered with 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:15.996247 17887 sched.cpp:453] Scheduler::registered took 54748ns I1124 19:50:15.996259 17879 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 429710ns I1124 19:50:15.996683 17891 master.cpp:3816] Sending 1 offers to framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 I1124 19:50:15.997613 17889 sched.cpp:602] Scheduler::resourceOffers took 629328ns I1124 19:50:15.998400 17888 master.cpp:2363] Processing reply for offers: [ 20141124-195015-3125920579-49443-17865-O0 ] on slave 20141124-195015-3125920579-49443-17865-S0 at slave(185)@67.195.81.186:49443 (penates.apache.org) for framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 I1124 19:50:15.998431 17888 master.cpp:2461] Authorizing framework principal 'test-principal' to launch task 0 as user 'jenkins' W1124 19:50:15.999222 17893 master.cpp:1998] Executor default for task 0 uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases. W1124 19:50:15.999261 17893 master.cpp:2010] Executor default for task 0 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases. I1124 19:50:15.999567 17893 master.hpp:759] Adding task 0 with resources cpus(*):2; mem(*):1024 on slave 20141124-195015-3125920579-49443-17865-S0 (penates.apache.org) I1124 19:50:15.999650 17893 master.cpp:2531] Launching task 0 of framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 with resources cpus(*):2; mem(*):1024 on slave 20141124-195015-3125920579-49443-17865-S0 at slave(185)@67.195.81.186:49443 (penates.apache.org) I1124 19:50:15.999938 17883 slave.cpp:1098] Got assigned task 0 for framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.000025 17884 hierarchical_allocator_process.hpp:563] Recovered disk(*):1024; ports(*):[31000-32000] (total allocatable: disk(*):1024; ports(*):[31000-32000]) on slave 20141124-195015-3125920579-49443-17865-S0 from framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.000061 17884 hierarchical_allocator_process.hpp:599] Framework 20141124-195015-3125920579-49443-17865-0000 filtered slave 20141124-195015-3125920579-49443-17865-S0 for 5secs I1124 19:50:16.000438 17883 slave.cpp:1208] Launching task 0 for framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.003166 17883 slave.cpp:3864] Launching executor default of framework 20141124-195015-3125920579-49443-17865-0000 in work directory '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Pu3ksq/slaves/20141124-195015-3125920579-49443-17865-S0/frameworks/20141124-195015-3125920579-49443-17865-0000/executors/default/runs/5329c51d-9513-44b1-840a-c236d031e176' I1124 19:50:16.006078 17883 exec.cpp:132] Version: 0.22.0 I1124 19:50:16.006383 17893 exec.cpp:182] Executor started at: executor(57)@67.195.81.186:49443 with pid 17865 I1124 19:50:16.006441 17883 slave.cpp:1331] Queuing task '0' for executor default of framework '20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.006574 17883 slave.cpp:558] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Pu3ksq/slaves/20141124-195015-3125920579-49443-17865-S0/frameworks/20141124-195015-3125920579-49443-17865-0000/executors/default/runs/5329c51d-9513-44b1-840a-c236d031e176' I1124 19:50:16.006695 17883 slave.cpp:2855] Monitoring executor 'default' of framework '20141124-195015-3125920579-49443-17865-0000' in container '5329c51d-9513-44b1-840a-c236d031e176' I1124 19:50:16.244935 17883 slave.cpp:1875] Got registration for executor 'default' of framework 20141124-195015-3125920579-49443-17865-0000 from executor(57)@67.195.81.186:49443 I1124 19:50:16.245283 17883 slave.cpp:1994] Flushing queued task 0 for executor 'default' of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.245466 17893 exec.cpp:206] Executor registered on slave 20141124-195015-3125920579-49443-17865-S0 I1124 19:50:16.247145 17893 exec.cpp:218] Executor::registered took 22614ns I1124 19:50:16.247328 17893 exec.cpp:293] Executor asked to run task '0' I1124 19:50:16.247413 17893 exec.cpp:302] Executor::launchTask took 68899ns I1124 19:50:16.249007 17893 exec.cpp:525] Executor sending status update TASK_RUNNING (UUID: 016ab62b-adcc-42ac-8c36-df6ab997efa2) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.249248 17893 slave.cpp:2230] Handling status update TASK_RUNNING (UUID: 016ab62b-adcc-42ac-8c36-df6ab997efa2) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 from executor(57)@67.195.81.186:49443 I1124 19:50:16.249469 17881 status_update_manager.cpp:317] Received status update TASK_RUNNING (UUID: 016ab62b-adcc-42ac-8c36-df6ab997efa2) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.249538 17881 status_update_manager.cpp:494] Creating StatusUpdate stream for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.249747 17881 status_update_manager.cpp:371] Forwarding update TASK_RUNNING (UUID: 016ab62b-adcc-42ac-8c36-df6ab997efa2) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 to the slave I1124 19:50:16.250054 17888 slave.cpp:2473] Forwarding the update TASK_RUNNING (UUID: 016ab62b-adcc-42ac-8c36-df6ab997efa2) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 to [email protected]:49443 I1124 19:50:16.250211 17888 slave.cpp:2400] Status update manager successfully handled status update TASK_RUNNING (UUID: 016ab62b-adcc-42ac-8c36-df6ab997efa2) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.250242 17888 slave.cpp:2406] Sending acknowledgement for status update TASK_RUNNING (UUID: 016ab62b-adcc-42ac-8c36-df6ab997efa2) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 to executor(57)@67.195.81.186:49443 I1124 19:50:16.250370 17881 master.cpp:3409] Forwarding status update TASK_RUNNING (UUID: 016ab62b-adcc-42ac-8c36-df6ab997efa2) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.250392 17892 exec.cpp:339] Executor received status update acknowledgement 016ab62b-adcc-42ac-8c36-df6ab997efa2 for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.250536 17881 master.cpp:3381] Status update TASK_RUNNING (UUID: 016ab62b-adcc-42ac-8c36-df6ab997efa2) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 from slave 20141124-195015-3125920579-49443-17865-S0 at slave(185)@67.195.81.186:49443 (penates.apache.org) I1124 19:50:16.250589 17881 master.cpp:4666] Updating the latest state of task 0 of framework 20141124-195015-3125920579-49443-17865-0000 to TASK_RUNNING I1124 19:50:16.250754 17889 sched.cpp:693] Scheduler::statusUpdate took 65830ns I1124 19:50:16.251075 17894 master.cpp:2881] Forwarding status update acknowledgement 016ab62b-adcc-42ac-8c36-df6ab997efa2 for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 to slave 20141124-195015-3125920579-49443-17865-S0 at slave(185)@67.195.81.186:49443 (penates.apache.org) I1124 19:50:16.251427 17887 status_update_manager.cpp:389] Received status update acknowledgement (UUID: 016ab62b-adcc-42ac-8c36-df6ab997efa2) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.251471 17891 slave.cpp:2913] Executor 'default' of framework 20141124-195015-3125920579-49443-17865-0000 exited with status 0 I1124 19:50:16.253871 17891 slave.cpp:2230] Handling status update TASK_LOST (UUID: 8ddb1511-af80-4f0d-8292-fe4555ee19cf) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 from @0.0.0.0:0 I1124 19:50:16.253954 17891 slave.cpp:4172] Terminating task 0 I1124 19:50:16.254303 17891 slave.cpp:1815] Status update manager successfully handled status update acknowledgement (UUID: 016ab62b-adcc-42ac-8c36-df6ab997efa2) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.254482 17893 master.cpp:3461] Executor default of framework 20141124-195015-3125920579-49443-17865-0000 on slave 20141124-195015-3125920579-49443-17865-S0 at slave(185)@67.195.81.186:49443 (penates.apache.org) exited with status 0 I1124 19:50:16.254578 17892 status_update_manager.cpp:317] Received status update TASK_LOST (UUID: 8ddb1511-af80-4f0d-8292-fe4555ee19cf) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.254647 17893 master.cpp:4754] Removing executor 'default' with resources of framework 20141124-195015-3125920579-49443-17865-0000 on slave 20141124-195015-3125920579-49443-17865-S0 at slave(185)@67.195.81.186:49443 (penates.apache.org) I1124 19:50:16.254685 17892 status_update_manager.cpp:371] Forwarding update TASK_LOST (UUID: 8ddb1511-af80-4f0d-8292-fe4555ee19cf) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 to the slave I1124 19:50:16.254935 17880 slave.cpp:2473] Forwarding the update TASK_LOST (UUID: 8ddb1511-af80-4f0d-8292-fe4555ee19cf) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 to [email protected]:49443 I1124 19:50:16.255084 17880 slave.cpp:2400] Status update manager successfully handled status update TASK_LOST (UUID: 8ddb1511-af80-4f0d-8292-fe4555ee19cf) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.255215 17886 master.cpp:3409] Forwarding status update TASK_LOST (UUID: 8ddb1511-af80-4f0d-8292-fe4555ee19cf) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.255362 17886 master.cpp:3381] Status update TASK_LOST (UUID: 8ddb1511-af80-4f0d-8292-fe4555ee19cf) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 from slave 20141124-195015-3125920579-49443-17865-S0 at slave(185)@67.195.81.186:49443 (penates.apache.org) I1124 19:50:16.255411 17886 master.cpp:4666] Updating the latest state of task 0 of framework 20141124-195015-3125920579-49443-17865-0000 to TASK_LOST I1124 19:50:16.255450 17889 sched.cpp:693] Scheduler::statusUpdate took 17562ns I1124 19:50:16.255645 17893 hierarchical_allocator_process.hpp:563] Recovered cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave 20141124-195015-3125920579-49443-17865-S0 from framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.255806 17886 master.cpp:4725] Removing task 0 with resources cpus(*):2; mem(*):1024 of framework 20141124-195015-3125920579-49443-17865-0000 on slave 20141124-195015-3125920579-49443-17865-S0 at slave(185)@67.195.81.186:49443 (penates.apache.org) I1124 19:50:16.255950 17886 master.cpp:2881] Forwarding status update acknowledgement 8ddb1511-af80-4f0d-8292-fe4555ee19cf for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 to slave 20141124-195015-3125920579-49443-17865-S0 at slave(185)@67.195.81.186:49443 (penates.apache.org) I1124 19:50:16.256209 17887 status_update_manager.cpp:389] Received status update acknowledgement (UUID: 8ddb1511-af80-4f0d-8292-fe4555ee19cf) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.256299 17887 status_update_manager.cpp:525] Cleaning up status update stream for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:16.256499 17887 slave.cpp:1815] Status update manager successfully handled status update acknowledgement (UUID: 8ddb1511-af80-4f0d-8292-fe4555ee19cf) for task 0 of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:18.050047 17887 slave.cpp:4211] Completing task 0 I1124 19:50:18.050117 17887 slave.cpp:3022] Cleaning up executor 'default' of framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:18.050462 17887 slave.cpp:3099] Cleaning up framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:18.050451 17886 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Pu3ksq/slaves/20141124-195015-3125920579-49443-17865-S0/frameworks/20141124-195015-3125920579-49443-17865-0000/executors/default/runs/5329c51d-9513-44b1-840a-c236d031e176' for gc 1.00000289183069weeks in the future I1124 19:50:18.050568 17884 status_update_manager.cpp:279] Closing status update streams for framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:18.050669 17886 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Pu3ksq/slaves/20141124-195015-3125920579-49443-17865-S0/frameworks/20141124-195015-3125920579-49443-17865-0000/executors/default' for gc 1.00000289183069weeks in the future I1124 19:50:18.050793 17886 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Pu3ksq/slaves/20141124-195015-3125920579-49443-17865-S0/frameworks/20141124-195015-3125920579-49443-17865-0000' for gc 1.00000289183069weeks in the future I1124 19:50:18.063159 17880 slave.cpp:3336] Current usage 90.00%. Max allowed age: 0ns I1124 19:50:18.063493 17888 hierarchical_allocator_process.hpp:734] Offering disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 20141124-195015-3125920579-49443-17865-S0 to framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:18.063776 17888 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 515890ns I1124 19:50:18.064116 17885 master.cpp:3816] Sending 1 offers to framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 I1124 19:50:18.064589 17886 sched.cpp:602] Scheduler::resourceOffers took 34649ns tests/gc_tests.cpp:675: Failure Value of: os::exists(executorDir) Actual: true Expected: false I1124 19:50:18.083794 17879 master.cpp:789] Framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 disconnected I1124 19:50:18.083828 17879 master.cpp:1752] Disconnecting framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 I1124 19:50:18.083858 17879 master.cpp:1768] Deactivating framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 I1124 19:50:18.084046 17893 hierarchical_allocator_process.hpp:405] Deactivated framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:18.084364 17879 master.cpp:811] Giving framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 0ns to failover I1124 19:50:18.084377 17893 hierarchical_allocator_process.hpp:563] Recovered disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave 20141124-195015-3125920579-49443-17865-S0 from framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:18.084705 17888 master.cpp:3686] Framework failover timeout, removing framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 I1124 19:50:18.084724 17888 master.cpp:4244] Removing framework 20141124-195015-3125920579-49443-17865-0000 (default) at [email protected]:49443 I1124 19:50:18.084825 17893 slave.cpp:1548] Asked to shut down framework 20141124-195015-3125920579-49443-17865-0000 by [email protected]:49443 W1124 19:50:18.084851 17893 slave.cpp:1563] Cannot shut down unknown framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:18.085283 17888 master.cpp:698] Master terminating I1124 19:50:18.085305 17886 hierarchical_allocator_process.hpp:360] Removed framework 20141124-195015-3125920579-49443-17865-0000 I1124 19:50:18.085757 17882 slave.cpp:2638] [email protected]:49443 exited W1124 19:50:18.085777 17882 slave.cpp:2641] Master disconnected! Waiting for a new master to be elected F1124 19:50:18.085777 17865 logging.cpp:57] RAW: Pure virtual method called @ 0x2b258e443a24 google::LogMessage::Fail() @ 0x2b258e449118 google::RawLog__() @ 0x2b258db2770e __cxa_pure_virtual @ 0x8e06db mesos::internal::tests::Cluster::Slaves::shutdown() @ 0xdd9eee mesos::internal::tests::MesosTest::ShutdownSlaves() @ 0xdd9eb2 mesos::internal::tests::MesosTest::Shutdown() @ 0xdd76b9 mesos::internal::tests::MesosTest::TearDown() @ 0x10970ae testing::internal::HandleSehExceptionsInMethodIfSupported<>() @ 0x1092204 testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x107a55e testing::Test::Run() @ 0x107ac38 testing::TestInfo::Run() @ 0x107b1c0 testing::TestCase::Run() @ 0x107fe8a testing::internal::UnitTestImpl::RunAllTests() @ 0x1097f1f testing::internal::HandleSehExceptionsInMethodIfSupported<>() @ 0x1092ef5 testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x107ed96 testing::UnitTest::Run() @ 0xd0529f main @ 0x2b2590936ec5 (unknown) @ 0x8b8b69 (unknown) make[3]: *** [check-local] Aborted make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'> make[2]: *** [check-am] Error 2 make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'> make[1]: *** [check] Error 2 make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'> make: *** [check-recursive] Error 1 Test finished Exit status: 2 Build step 'Execute shell' marked build as failure Recording test results
