See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2411/changes>
Changes: [adam] Switched path::join() to be variadic ------------------------------------------ [...truncated 48978 lines...] I1002 02:47:01.653427 16003 recover.cpp:556] Successfully joined the Paxos group I1002 02:47:01.653519 16003 recover.cpp:440] Recover process terminated I1002 02:47:01.653671 15999 log.cpp:656] Attempting to start the writer I1002 02:47:01.654139 15996 replica.cpp:474] Replica received implicit promise request with proposal 1 I1002 02:47:01.654238 15996 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 83270ns I1002 02:47:01.654253 15996 replica.cpp:342] Persisted promised to 1 I1002 02:47:01.654510 15995 coordinator.cpp:230] Coordinator attemping to fill missing position I1002 02:47:01.655135 16000 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2 I1002 02:47:01.655256 16000 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 100443ns I1002 02:47:01.655269 16000 replica.cpp:676] Persisted action at 0 I1002 02:47:01.655750 15992 replica.cpp:508] Replica received write request for position 0 I1002 02:47:01.655791 15992 leveldb.cpp:438] Reading position from leveldb took 24224ns I1002 02:47:01.655927 15992 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 117966ns I1002 02:47:01.655941 15992 replica.cpp:676] Persisted action at 0 I1002 02:47:01.656297 15991 replica.cpp:655] Replica received learned notice for position 0 I1002 02:47:01.656416 15991 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 99083ns I1002 02:47:01.656435 15991 replica.cpp:676] Persisted action at 0 I1002 02:47:01.656445 15991 replica.cpp:661] Replica learned NOP action at position 0 I1002 02:47:01.656647 15998 log.cpp:672] Writer started with ending position 0 I1002 02:47:01.657019 16003 leveldb.cpp:438] Reading position from leveldb took 12701ns I1002 02:47:01.658120 15997 registrar.cpp:345] Successfully fetched the registry (0B) I1002 02:47:01.658150 15997 registrar.cpp:421] Attempting to update the 'registry' I1002 02:47:01.659194 15997 log.cpp:680] Attempting to append 139 bytes to the log I1002 02:47:01.659256 15998 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1 I1002 02:47:01.659601 15996 replica.cpp:508] Replica received write request for position 1 I1002 02:47:01.660011 15996 leveldb.cpp:343] Persisting action (158 bytes) to leveldb took 387583ns I1002 02:47:01.660024 15996 replica.cpp:676] Persisted action at 1 I1002 02:47:01.660307 16004 replica.cpp:655] Replica received learned notice for position 1 I1002 02:47:01.660419 16004 leveldb.cpp:343] Persisting action (160 bytes) to leveldb took 93775ns I1002 02:47:01.660434 16004 replica.cpp:676] Persisted action at 1 I1002 02:47:01.660440 16004 replica.cpp:661] Replica learned APPEND action at position 1 I1002 02:47:01.660686 16000 registrar.cpp:478] Successfully updated 'registry' I1002 02:47:01.660742 16000 registrar.cpp:371] Successfully recovered registrar I1002 02:47:01.660822 15997 log.cpp:699] Attempting to truncate the log to 1 I1002 02:47:01.660979 16000 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2 I1002 02:47:01.660996 15994 master.cpp:1099] Recovered 0 slaves from the Registry (101B) ; allowing 10mins for slaves to re-register I1002 02:47:01.661290 16002 replica.cpp:508] Replica received write request for position 2 I1002 02:47:01.661568 16002 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 259619ns I1002 02:47:01.661582 16002 replica.cpp:676] Persisted action at 2 I1002 02:47:01.661831 15992 replica.cpp:655] Replica received learned notice for position 2 I1002 02:47:01.661967 15992 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 111032ns I1002 02:47:01.661993 15992 leveldb.cpp:401] Deleting ~1 keys from leveldb took 11295ns I1002 02:47:01.662001 15992 replica.cpp:676] Persisted action at 2 I1002 02:47:01.662009 15992 replica.cpp:661] Replica learned TRUNCATE action at position 2 I1002 02:47:01.673589 15997 slave.cpp:169] Slave started on 187)@67.195.81.187:35939 I1002 02:47:01.673624 15997 credentials.hpp:84] Loading credential for authentication from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_CXotBR/credential' I1002 02:47:01.673719 15997 slave.cpp:276] Slave using credential for: test-principal I1002 02:47:01.673852 15997 slave.cpp:289] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1002 02:47:01.673921 15997 slave.cpp:317] Slave hostname: pomona.apache.org I1002 02:47:01.673936 15997 slave.cpp:318] Slave checkpoint: false I1002 02:47:01.674248 16004 state.cpp:33] Recovering state from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_CXotBR/meta' I1002 02:47:01.674418 15996 status_update_manager.cpp:193] Recovering status update manager I1002 02:47:01.674634 16000 slave.cpp:3271] Finished recovery I1002 02:47:01.674911 16000 slave.cpp:598] New master detected at [email protected]:35939 I1002 02:47:01.674952 16000 slave.cpp:672] Authenticating with master [email protected]:35939 I1002 02:47:01.674974 15990 status_update_manager.cpp:167] New master detected at [email protected]:35939 I1002 02:47:01.675025 16000 slave.cpp:645] Detecting new master I1002 02:47:01.675061 15991 authenticatee.hpp:128] Creating new client SASL connection I1002 02:47:01.675143 15991 master.cpp:3737] Authenticating slave(187)@67.195.81.187:35939 I1002 02:47:01.675237 15997 authenticator.hpp:156] Creating new server SASL connection I1002 02:47:01.675349 15999 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I1002 02:47:01.675369 15999 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I1002 02:47:01.675406 15999 authenticator.hpp:262] Received SASL authentication start I1002 02:47:01.675447 15999 authenticator.hpp:384] Authentication requires more steps I1002 02:47:01.675503 15990 authenticatee.hpp:265] Received SASL authentication step I1002 02:47:01.675580 15998 authenticator.hpp:290] Received SASL authentication step I1002 02:47:01.675601 15998 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'pomona.apache.org' server FQDN: 'pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1002 02:47:01.675607 15998 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1002 02:47:01.675617 15998 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1002 02:47:01.675626 15998 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'pomona.apache.org' server FQDN: 'pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1002 02:47:01.675631 15998 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1002 02:47:01.675637 15998 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1002 02:47:01.799227 15998 authenticator.hpp:376] Authentication success I1002 02:47:01.799336 16004 authenticatee.hpp:305] Authentication success I1002 02:47:01.799350 15998 master.cpp:3777] Successfully authenticated principal 'test-principal' at slave(187)@67.195.81.187:35939 I1002 02:47:01.799533 16004 slave.cpp:729] Successfully authenticated with master [email protected]:35939 I1002 02:47:01.799592 16004 slave.cpp:992] Will retry registration in 14.110686ms if necessary I1002 02:47:01.799685 15996 master.cpp:2930] Registering slave at slave(187)@67.195.81.187:35939 (pomona.apache.org) with id 20141002-024701-3142697795-35939-15976-0 I1002 02:47:01.799839 16004 registrar.cpp:421] Attempting to update the 'registry' I1002 02:47:01.800976 16004 log.cpp:680] Attempting to append 315 bytes to the log I1002 02:47:01.801031 16004 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3 I1002 02:47:01.801441 15994 replica.cpp:508] Replica received write request for position 3 I1002 02:47:01.801659 15994 leveldb.cpp:343] Persisting action (334 bytes) to leveldb took 191860ns I1002 02:47:01.801676 15994 replica.cpp:676] Persisted action at 3 I1002 02:47:01.801920 16003 replica.cpp:655] Replica received learned notice for position 3 I1002 02:47:01.802364 16003 leveldb.cpp:343] Persisting action (336 bytes) to leveldb took 423596ns I1002 02:47:01.802379 16003 replica.cpp:676] Persisted action at 3 I1002 02:47:01.802387 16003 replica.cpp:661] Replica learned APPEND action at position 3 I1002 02:47:01.802693 15999 registrar.cpp:478] Successfully updated 'registry' I1002 02:47:01.802774 16005 log.cpp:699] Attempting to truncate the log to 3 I1002 02:47:01.802824 16002 master.cpp:2970] Registered slave 20141002-024701-3142697795-35939-15976-0 at slave(187)@67.195.81.187:35939 (pomona.apache.org) I1002 02:47:01.802834 16004 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4 I1002 02:47:01.802844 16002 master.cpp:4180] Adding slave 20141002-024701-3142697795-35939-15976-0 at slave(187)@67.195.81.187:35939 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1002 02:47:01.802966 16005 slave.cpp:763] Registered with master [email protected]:35939; given slave ID 20141002-024701-3142697795-35939-15976-0 I1002 02:47:01.803052 16003 hierarchical_allocator_process.hpp:442] Added slave 20141002-024701-3142697795-35939-15976-0 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I1002 02:47:01.803084 16005 slave.cpp:2345] Received ping from slave-observer(168)@67.195.81.187:35939 I1002 02:47:01.803105 16003 hierarchical_allocator_process.hpp:679] Performed allocation for slave 20141002-024701-3142697795-35939-15976-0 in 10420ns I1002 02:47:01.803220 15997 replica.cpp:508] Replica received write request for position 4 I1002 02:47:01.803325 15997 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 89469ns I1002 02:47:01.803339 15997 replica.cpp:676] Persisted action at 4 I1002 02:47:01.803592 15995 replica.cpp:655] Replica received learned notice for position 4 I1002 02:47:01.803695 15995 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 85992ns I1002 02:47:01.803724 15995 leveldb.cpp:401] Deleting ~2 keys from leveldb took 14241ns I1002 02:47:01.803735 15995 replica.cpp:676] Persisted action at 4 I1002 02:47:01.803743 15995 replica.cpp:661] Replica learned TRUNCATE action at position 4 I1002 02:47:01.805353 15976 sched.cpp:137] Version: 0.21.0 I1002 02:47:01.806022 16003 sched.cpp:233] New master detected at [email protected]:35939 I1002 02:47:01.806042 16003 sched.cpp:283] Authenticating with master [email protected]:35939 I1002 02:47:01.806233 15999 authenticatee.hpp:128] Creating new client SASL connection I1002 02:47:01.806419 15995 master.cpp:3737] Authenticating [email protected]:35939 I1002 02:47:01.806506 15997 authenticator.hpp:156] Creating new server SASL connection I1002 02:47:01.806607 15997 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I1002 02:47:01.806623 15997 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I1002 02:47:01.806674 15997 authenticator.hpp:262] Received SASL authentication start I1002 02:47:01.806711 15997 authenticator.hpp:384] Authentication requires more steps I1002 02:47:01.806782 15991 authenticatee.hpp:265] Received SASL authentication step I1002 02:47:01.806911 16000 authenticator.hpp:290] Received SASL authentication step I1002 02:47:01.806934 16000 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'pomona.apache.org' server FQDN: 'pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1002 02:47:01.806942 16000 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1002 02:47:01.806954 16000 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1002 02:47:01.806962 16000 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'pomona.apache.org' server FQDN: 'pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1002 02:47:01.806969 16000 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1002 02:47:01.806974 16000 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1002 02:47:01.806988 16000 authenticator.hpp:376] Authentication success I1002 02:47:01.807119 15997 authenticatee.hpp:305] Authentication success I1002 02:47:01.807134 16000 master.cpp:3777] Successfully authenticated principal 'test-principal' at [email protected]:35939 I1002 02:47:01.807276 15997 sched.cpp:357] Successfully authenticated with master [email protected]:35939 I1002 02:47:01.807291 15997 sched.cpp:476] Sending registration request to [email protected]:35939 I1002 02:47:01.807400 15997 master.cpp:1360] Received registration request from [email protected]:35939 I1002 02:47:01.807425 15997 master.cpp:1320] Authorizing framework principal 'test-principal' to receive offers for role '*' I1002 02:47:01.807741 15999 master.cpp:1419] Registering framework 20141002-024701-3142697795-35939-15976-0000 at [email protected]:35939 I1002 02:47:01.807890 15996 sched.cpp:407] Framework registered with 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.807901 15999 hierarchical_allocator_process.hpp:329] Added framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.807931 15996 sched.cpp:421] Scheduler::registered took 20972ns I1002 02:47:01.807945 15999 hierarchical_allocator_process.hpp:734] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141002-024701-3142697795-35939-15976-0 to framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.808084 15999 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 163339ns I1002 02:47:01.808148 16002 master.hpp:868] Adding offer 20141002-024701-3142697795-35939-15976-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141002-024701-3142697795-35939-15976-0 (pomona.apache.org) I1002 02:47:01.808209 16002 master.cpp:3679] Sending 1 offers to framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.808513 15999 sched.cpp:544] Scheduler::resourceOffers took 106210ns I1002 02:47:01.808814 15999 master.hpp:877] Removing offer 20141002-024701-3142697795-35939-15976-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141002-024701-3142697795-35939-15976-0 (pomona.apache.org) I1002 02:47:01.808851 15999 master.cpp:2274] Processing reply for offers: [ 20141002-024701-3142697795-35939-15976-0 ] on slave 20141002-024701-3142697795-35939-15976-0 at slave(187)@67.195.81.187:35939 (pomona.apache.org) for framework 20141002-024701-3142697795-35939-15976-0000 W1002 02:47:01.858193 15999 master.cpp:1944] 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. W1002 02:47:01.858240 15999 master.cpp:1955] 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. I1002 02:47:01.858255 15999 master.cpp:2357] Authorizing framework principal 'test-principal' to launch task 0 as user 'jenkins' I1002 02:47:01.858844 15997 master.hpp:845] Adding task 0 with resources cpus(*):2; mem(*):1024 on slave 20141002-024701-3142697795-35939-15976-0 (pomona.apache.org) I1002 02:47:01.858901 15997 master.cpp:2423] Launching task 0 of framework 20141002-024701-3142697795-35939-15976-0000 with resources cpus(*):2; mem(*):1024 on slave 20141002-024701-3142697795-35939-15976-0 at slave(187)@67.195.81.187:35939 (pomona.apache.org) I1002 02:47:01.859171 15990 slave.cpp:1023] Got assigned task 0 for framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.859176 15992 hierarchical_allocator_process.hpp:563] Recovered disk(*):1024; ports(*):[31000-32000] (total allocatable: disk(*):1024; ports(*):[31000-32000]) on slave 20141002-024701-3142697795-35939-15976-0 from framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.859221 15992 hierarchical_allocator_process.hpp:599] Framework 20141002-024701-3142697795-35939-15976-0000 filtered slave 20141002-024701-3142697795-35939-15976-0 for 5secs I1002 02:47:01.859403 15990 slave.cpp:1133] Launching task 0 for framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.861740 15990 exec.cpp:132] Version: 0.21.0 I1002 02:47:01.861816 15997 exec.cpp:182] Executor started at: executor(58)@67.195.81.187:35939 with pid 15976 I1002 02:47:01.861845 15990 slave.cpp:1246] Queuing task '0' for executor default of framework '20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.861881 15990 slave.cpp:554] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_DiskUsage_CXotBR/slaves/20141002-024701-3142697795-35939-15976-0/frameworks/20141002-024701-3142697795-35939-15976-0000/executors/default/runs/8d454563-6304-4e4e-9171-1ccd436ced72' I1002 02:47:01.861914 15990 slave.cpp:2611] Monitoring executor 'default' of framework '20141002-024701-3142697795-35939-15976-0000' in container '8d454563-6304-4e4e-9171-1ccd436ced72' I1002 02:47:01.861963 15990 slave.cpp:1756] Got registration for executor 'default' of framework 20141002-024701-3142697795-35939-15976-0000 from executor(58)@67.195.81.187:35939 I1002 02:47:01.862181 15990 slave.cpp:1875] Flushing queued task 0 for executor 'default' of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.862275 15993 exec.cpp:206] Executor registered on slave 20141002-024701-3142697795-35939-15976-0 I1002 02:47:01.864341 15993 exec.cpp:218] Executor::registered took 22939ns I1002 02:47:01.864440 15993 exec.cpp:293] Executor asked to run task '0' I1002 02:47:01.864500 15993 exec.cpp:302] Executor::launchTask took 36149ns I1002 02:47:01.865999 15993 exec.cpp:525] Executor sending status update TASK_RUNNING (UUID: 5512601e-2267-4627-91b1-f67368110eaa) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.866113 15993 slave.cpp:2109] Handling status update TASK_RUNNING (UUID: 5512601e-2267-4627-91b1-f67368110eaa) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 from executor(58)@67.195.81.187:35939 I1002 02:47:01.866224 15993 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 5512601e-2267-4627-91b1-f67368110eaa) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.866243 15993 status_update_manager.cpp:499] Creating StatusUpdate stream for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.866333 15993 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: 5512601e-2267-4627-91b1-f67368110eaa) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 to [email protected]:35939 I1002 02:47:01.866482 16004 slave.cpp:2266] Status update manager successfully handled status update TASK_RUNNING (UUID: 5512601e-2267-4627-91b1-f67368110eaa) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.866503 16004 slave.cpp:2272] Sending acknowledgement for status update TASK_RUNNING (UUID: 5512601e-2267-4627-91b1-f67368110eaa) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 to executor(58)@67.195.81.187:35939 I1002 02:47:01.866511 16005 master.cpp:3301] Forwarding status update TASK_RUNNING (UUID: 5512601e-2267-4627-91b1-f67368110eaa) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.866583 16001 exec.cpp:339] Executor received status update acknowledgement 5512601e-2267-4627-91b1-f67368110eaa for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.866600 16005 master.cpp:3273] Status update TASK_RUNNING (UUID: 5512601e-2267-4627-91b1-f67368110eaa) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 from slave 20141002-024701-3142697795-35939-15976-0 at slave(187)@67.195.81.187:35939 (pomona.apache.org) I1002 02:47:01.866868 15991 sched.cpp:635] Scheduler::statusUpdate took 203787ns I1002 02:47:01.866968 16000 master.cpp:2777] Forwarding status update acknowledgement 5512601e-2267-4627-91b1-f67368110eaa for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 to slave 20141002-024701-3142697795-35939-15976-0 at slave(187)@67.195.81.187:35939 (pomona.apache.org) I1002 02:47:01.867075 16000 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 5512601e-2267-4627-91b1-f67368110eaa) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.867141 16000 slave.cpp:1696] Status update manager successfully handled status update acknowledgement (UUID: 5512601e-2267-4627-91b1-f67368110eaa) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.867223 16004 slave.cpp:2669] Executor 'default' of framework 20141002-024701-3142697795-35939-15976-0000 exited with status 0 I1002 02:47:01.868087 16004 slave.cpp:2109] Handling status update TASK_LOST (UUID: 0c53a57d-e373-405e-9fa0-978d821971de) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 from @0.0.0.0:0 I1002 02:47:01.868111 16004 slave.cpp:3989] Terminating task 0 I1002 02:47:01.868294 15993 master.cpp:3353] Executor default of framework 20141002-024701-3142697795-35939-15976-0000 on slave 20141002-024701-3142697795-35939-15976-0 at slave(187)@67.195.81.187:35939 (pomona.apache.org) exited with status 0 I1002 02:47:01.868301 16002 status_update_manager.cpp:320] Received status update TASK_LOST (UUID: 0c53a57d-e373-405e-9fa0-978d821971de) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.868320 15993 master.cpp:4514] Removing executor 'default' with resources of framework 20141002-024701-3142697795-35939-15976-0000 on slave 20141002-024701-3142697795-35939-15976-0 at slave(187)@67.195.81.187:35939 (pomona.apache.org) I1002 02:47:01.868329 16002 status_update_manager.cpp:373] Forwarding status update TASK_LOST (UUID: 0c53a57d-e373-405e-9fa0-978d821971de) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 to [email protected]:35939 I1002 02:47:01.868407 15998 slave.cpp:2266] Status update manager successfully handled status update TASK_LOST (UUID: 0c53a57d-e373-405e-9fa0-978d821971de) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:01.868499 15993 master.cpp:3301] Forwarding status update TASK_LOST (UUID: 0c53a57d-e373-405e-9fa0-978d821971de) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.943646 15993 master.cpp:3273] Status update TASK_LOST (UUID: 0c53a57d-e373-405e-9fa0-978d821971de) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 from slave 20141002-024701-3142697795-35939-15976-0 at slave(187)@67.195.81.187:35939 (pomona.apache.org) I1002 02:47:03.943807 16002 sched.cpp:635] Scheduler::statusUpdate took 10268ns I1002 02:47:03.943819 15990 hierarchical_allocator_process.hpp:563] Recovered cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave 20141002-024701-3142697795-35939-15976-0 from framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.943902 15993 master.cpp:4485] Removing task 0 with resources cpus(*):2; mem(*):1024 of framework 20141002-024701-3142697795-35939-15976-0000 on slave 20141002-024701-3142697795-35939-15976-0 at slave(187)@67.195.81.187:35939 (pomona.apache.org) I1002 02:47:03.943953 15993 master.cpp:2777] Forwarding status update acknowledgement 0c53a57d-e373-405e-9fa0-978d821971de for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 to slave 20141002-024701-3142697795-35939-15976-0 at slave(187)@67.195.81.187:35939 (pomona.apache.org) I1002 02:47:03.944031 15993 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 0c53a57d-e373-405e-9fa0-978d821971de) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.944061 15993 status_update_manager.cpp:530] Cleaning up status update stream for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.944155 15993 slave.cpp:1696] Status update manager successfully handled status update acknowledgement (UUID: 0c53a57d-e373-405e-9fa0-978d821971de) for task 0 of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.944181 15993 slave.cpp:4028] Completing task 0 I1002 02:47:03.944198 15993 slave.cpp:2805] Cleaning up executor 'default' of framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.944303 16002 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_CXotBR/slaves/20141002-024701-3142697795-35939-15976-0/frameworks/20141002-024701-3142697795-35939-15976-0000/executors/default/runs/8d454563-6304-4e4e-9171-1ccd436ced72' for gc 1.00000187328381weeks in the future I1002 02:47:03.944325 15993 slave.cpp:2880] Cleaning up framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.944368 16002 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_CXotBR/slaves/20141002-024701-3142697795-35939-15976-0/frameworks/20141002-024701-3142697795-35939-15976-0000/executors/default' for gc 1.00000187328381weeks in the future I1002 02:47:03.944397 15996 status_update_manager.cpp:282] Closing status update streams for framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.944406 16002 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_CXotBR/slaves/20141002-024701-3142697795-35939-15976-0/frameworks/20141002-024701-3142697795-35939-15976-0000' for gc 1.00000187328381weeks in the future I1002 02:47:03.959619 15997 slave.cpp:3126] Current usage 90.00%. Max allowed age: 0ns I1002 02:47:03.959607 15992 hierarchical_allocator_process.hpp:734] Offering disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 20141002-024701-3142697795-35939-15976-0 to framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.959767 15992 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 234600ns I1002 02:47:03.959823 15995 master.hpp:868] Adding offer 20141002-024701-3142697795-35939-15976-1 with resources disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 20141002-024701-3142697795-35939-15976-0 (pomona.apache.org) I1002 02:47:03.959872 15995 master.cpp:3679] Sending 1 offers to framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.960018 15998 sched.cpp:544] Scheduler::resourceOffers took 9443ns ../../src/tests/gc_tests.cpp:675: Failure Value of: os::exists(executorDir) Actual: true Expected: false I1002 02:47:03.979867 15997 master.cpp:767] Framework 20141002-024701-3142697795-35939-15976-0000 disconnected I1002 02:47:03.979897 15997 master.cpp:1705] Disconnecting framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.979909 15997 master.cpp:1721] Deactivating framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.979987 16000 hierarchical_allocator_process.hpp:405] Deactivated framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.980011 15997 master.hpp:877] Removing offer 20141002-024701-3142697795-35939-15976-1 with resources disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 20141002-024701-3142697795-35939-15976-0 (pomona.apache.org) I1002 02:47:03.980074 15997 master.cpp:789] Giving framework 20141002-024701-3142697795-35939-15976-0000 0ns to failover I1002 02:47:03.980108 16000 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 20141002-024701-3142697795-35939-15976-0 from framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.980177 16001 master.cpp:3549] Framework failover timeout, removing framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.980188 16001 master.cpp:4041] Removing framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.980253 15998 slave.cpp:1429] Asked to shut down framework 20141002-024701-3142697795-35939-15976-0000 by [email protected]:35939 W1002 02:47:03.980273 15998 slave.cpp:1444] Cannot shut down unknown framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.980324 15998 hierarchical_allocator_process.hpp:360] Removed framework 20141002-024701-3142697795-35939-15976-0000 I1002 02:47:03.980417 15976 master.cpp:676] Master terminating I1002 02:47:03.980510 15996 slave.cpp:2430] [email protected]:35939 exited W1002 02:47:03.980530 15996 slave.cpp:2433] Master disconnected! Waiting for a new master to be elected F1002 02:47:03.980530 15976 logging.cpp:57] RAW: Pure virtual method called @ 0x2ae7635e40ad google::LogMessage::Fail() @ 0x2ae7635eb7a6 google::RawLog__() @ 0x4fe866 mesos::internal::tests::Cluster::Slaves::shutdown() @ 0x7903b4 mesos::internal::tests::MesosTest::ShutdownSlaves() @ 0x95b173 testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x952310 testing::Test::Run() @ 0x9523ee testing::TestInfo::Run() @ 0x9524f5 testing::TestCase::Run() @ 0x952798 testing::internal::UnitTestImpl::RunAllTests() @ 0x952a37 testing::UnitTest::Run() @ 0x48ca43 main @ 0x2ae7652ffec5 (unknown) @ 0x497928 (unknown) make[3]: *** [check-local] Aborted 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 Test finished Exit status: 2 Build step 'Execute shell' marked build as failure Recording test results
