See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2488/changes>
Changes: [yujie.jay] PortMappingIsolator: Swap TX/RX in statistic collection in usage ------------------------------------------ [...truncated 21400 lines...] I1026 05:37:40.692209 1944 master.cpp:1242] The newly elected leader is [email protected]:48044 with id 20141026-053740-3142697795-48044-1919 I1026 05:37:40.692231 1944 master.cpp:1255] Elected as the leading master! I1026 05:37:40.692258 1944 master.cpp:1073] Recovering from registrar I1026 05:37:40.692318 1938 recover.cpp:188] Received a recover response from a replica in STARTING status I1026 05:37:40.692419 1947 registrar.cpp:313] Recovering registrar I1026 05:37:40.692847 1936 recover.cpp:554] Updating replica status to VOTING I1026 05:37:40.717001 1939 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 763823ns I1026 05:37:40.717027 1939 replica.cpp:320] Persisted replica status to VOTING I1026 05:37:40.717118 1948 recover.cpp:568] Successfully joined the Paxos group I1026 05:37:40.717316 1948 recover.cpp:452] Recover process terminated I1026 05:37:40.717768 1934 log.cpp:656] Attempting to start the writer I1026 05:37:40.719187 1935 replica.cpp:474] Replica received implicit promise request with proposal 1 I1026 05:37:40.719761 1935 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 553560ns I1026 05:37:40.719779 1935 replica.cpp:342] Persisted promised to 1 I1026 05:37:40.720424 1945 coordinator.cpp:230] Coordinator attemping to fill missing position I1026 05:37:40.721951 1933 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2 I1026 05:37:40.722365 1933 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 385625ns I1026 05:37:40.722385 1933 replica.cpp:676] Persisted action at 0 I1026 05:37:40.723311 1939 replica.cpp:508] Replica received write request for position 0 I1026 05:37:40.723372 1939 leveldb.cpp:438] Reading position from leveldb took 35296ns I1026 05:37:40.723793 1939 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 387051ns I1026 05:37:40.723814 1939 replica.cpp:676] Persisted action at 0 I1026 05:37:40.724311 1942 replica.cpp:655] Replica received learned notice for position 0 I1026 05:37:40.724762 1942 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 424112ns I1026 05:37:40.724787 1942 replica.cpp:676] Persisted action at 0 I1026 05:37:40.724809 1942 replica.cpp:661] Replica learned NOP action at position 0 I1026 05:37:40.725275 1936 log.cpp:672] Writer started with ending position 0 I1026 05:37:40.726511 1945 leveldb.cpp:438] Reading position from leveldb took 33201ns I1026 05:37:40.729558 1947 registrar.cpp:346] Successfully fetched the registry (0B) in 37.101056ms I1026 05:37:40.729665 1947 registrar.cpp:445] Applied 1 operations in 19075ns; attempting to update the 'registry' I1026 05:37:40.732529 1937 log.cpp:680] Attempting to append 138 bytes to the log I1026 05:37:40.732743 1943 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1 I1026 05:37:40.733597 1940 replica.cpp:508] Replica received write request for position 1 I1026 05:37:40.734328 1940 leveldb.cpp:343] Persisting action (157 bytes) to leveldb took 702340ns I1026 05:37:40.734354 1940 replica.cpp:676] Persisted action at 1 I1026 05:37:40.734871 1939 replica.cpp:655] Replica received learned notice for position 1 I1026 05:37:40.735640 1939 leveldb.cpp:343] Persisting action (159 bytes) to leveldb took 743999ns I1026 05:37:40.735673 1939 replica.cpp:676] Persisted action at 1 I1026 05:37:40.735704 1939 replica.cpp:661] Replica learned APPEND action at position 1 I1026 05:37:40.736652 1940 registrar.cpp:490] Successfully updated the 'registry' in 6.947072ms I1026 05:37:40.736780 1940 registrar.cpp:376] Successfully recovered registrar I1026 05:37:40.737062 1936 master.cpp:1100] Recovered 0 slaves from the Registry (100B) ; allowing 10mins for slaves to re-register I1026 05:37:40.737082 1940 log.cpp:699] Attempting to truncate the log to 1 I1026 05:37:40.737210 1934 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2 I1026 05:37:40.737901 1941 replica.cpp:508] Replica received write request for position 2 I1026 05:37:40.738412 1941 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 484781ns I1026 05:37:40.738432 1941 replica.cpp:676] Persisted action at 2 I1026 05:37:40.738870 1941 replica.cpp:655] Replica received learned notice for position 2 I1026 05:37:40.739341 1941 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 451900ns I1026 05:37:40.739384 1941 leveldb.cpp:401] Deleting ~1 keys from leveldb took 28203ns I1026 05:37:40.739397 1941 replica.cpp:676] Persisted action at 2 I1026 05:37:40.739411 1941 replica.cpp:661] Replica learned TRUNCATE action at position 2 I1026 05:37:40.751147 1935 slave.cpp:169] Slave started on 71)@67.195.81.187:48044 I1026 05:37:40.751179 1935 credentials.hpp:84] Loading credential for authentication from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_xuy4QG/credential' I1026 05:37:40.751363 1935 slave.cpp:276] Slave using credential for: test-principal I1026 05:37:40.751664 1935 slave.cpp:289] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1026 05:37:40.751751 1935 slave.cpp:318] Slave hostname: pomona.apache.org I1026 05:37:40.751765 1935 slave.cpp:319] Slave checkpoint: false W1026 05:37:40.751775 1935 slave.cpp:321] Disabling checkpointing is deprecated and the --checkpoint flag will be removed in a future release. Please avoid using this flag I1026 05:37:40.752568 1945 state.cpp:33] Recovering state from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_xuy4QG/meta' I1026 05:37:40.752869 1945 status_update_manager.cpp:197] Recovering status update manager I1026 05:37:40.753314 1940 slave.cpp:3442] Finished recovery I1026 05:37:40.753865 1935 slave.cpp:602] New master detected at [email protected]:48044 I1026 05:37:40.753885 1935 slave.cpp:665] Authenticating with master [email protected]:48044 I1026 05:37:40.753962 1935 slave.cpp:638] Detecting new master I1026 05:37:40.753981 1943 status_update_manager.cpp:171] Pausing sending status updates I1026 05:37:40.754030 1939 authenticatee.hpp:133] Creating new client SASL connection I1026 05:37:40.754212 1944 master.cpp:3853] Authenticating slave(71)@67.195.81.187:48044 I1026 05:37:40.754413 1937 authenticator.hpp:161] Creating new server SASL connection I1026 05:37:40.754632 1948 authenticatee.hpp:224] Received SASL authentication mechanisms: CRAM-MD5 I1026 05:37:40.754653 1948 authenticatee.hpp:250] Attempting to authenticate with mechanism 'CRAM-MD5' I1026 05:37:40.754703 1948 authenticator.hpp:267] Received SASL authentication start I1026 05:37:40.754739 1948 authenticator.hpp:389] Authentication requires more steps I1026 05:37:40.754792 1948 authenticatee.hpp:270] Received SASL authentication step I1026 05:37:40.754848 1948 authenticator.hpp:295] Received SASL authentication step I1026 05:37:40.754866 1948 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 I1026 05:37:40.754874 1948 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1026 05:37:40.754927 1948 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1026 05:37:40.754945 1948 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 I1026 05:37:40.754951 1948 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1026 05:37:40.754956 1948 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1026 05:37:40.754966 1948 authenticator.hpp:381] Authentication success I1026 05:37:40.755040 1948 authenticatee.hpp:310] Authentication success I1026 05:37:40.755082 1936 master.cpp:3893] Successfully authenticated principal 'test-principal' at slave(71)@67.195.81.187:48044 I1026 05:37:40.755187 1937 slave.cpp:722] Successfully authenticated with master [email protected]:48044 I1026 05:37:40.755321 1937 slave.cpp:1050] Will retry registration in 8.911789ms if necessary I1026 05:37:40.755475 1945 master.cpp:3032] Registering slave at slave(71)@67.195.81.187:48044 (pomona.apache.org) with id 20141026-053740-3142697795-48044-1919-S0 I1026 05:37:40.755848 1945 registrar.cpp:445] Applied 1 operations in 47887ns; attempting to update the 'registry' I1026 05:37:40.758046 1937 log.cpp:680] Attempting to append 314 bytes to the log I1026 05:37:40.764782 1933 slave.cpp:1050] Will retry registration in 17.226691ms if necessary I1026 05:37:40.764904 1944 master.cpp:3020] Ignoring register slave message from slave(71)@67.195.81.187:48044 (pomona.apache.org) as admission is already in progress I1026 05:37:40.820008 1938 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3 I1026 05:37:40.820843 1941 replica.cpp:508] Replica received write request for position 3 I1026 05:37:40.821717 1941 leveldb.cpp:343] Persisting action (333 bytes) to leveldb took 846259ns I1026 05:37:40.821735 1941 replica.cpp:676] Persisted action at 3 I1026 05:37:40.822347 1934 replica.cpp:655] Replica received learned notice for position 3 I1026 05:37:40.823001 1934 leveldb.cpp:343] Persisting action (335 bytes) to leveldb took 628489ns I1026 05:37:40.823026 1934 replica.cpp:676] Persisted action at 3 I1026 05:37:40.823048 1934 replica.cpp:661] Replica learned APPEND action at position 3 I1026 05:37:40.824146 1935 registrar.cpp:490] Successfully updated the 'registry' in 68.205056ms I1026 05:37:40.824504 1936 log.cpp:699] Attempting to truncate the log to 3 I1026 05:37:40.824625 1935 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4 I1026 05:37:40.824702 1936 slave.cpp:2522] Received ping from slave-observer(56)@67.195.81.187:48044 I1026 05:37:40.824784 1942 master.cpp:3086] Registered slave 20141026-053740-3142697795-48044-1919-S0 at slave(71)@67.195.81.187:48044 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1026 05:37:40.824972 1936 slave.cpp:756] Registered with master [email protected]:48044; given slave ID 20141026-053740-3142697795-48044-1919-S0 I1026 05:37:40.825006 1948 hierarchical_allocator_process.hpp:442] Added slave 20141026-053740-3142697795-48044-1919-S0 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I1026 05:37:40.825063 1941 status_update_manager.cpp:178] Resuming sending status updates I1026 05:37:40.825163 1948 hierarchical_allocator_process.hpp:679] Performed allocation for slave 20141026-053740-3142697795-48044-1919-S0 in 57286ns I1026 05:37:40.825516 1943 replica.cpp:508] Replica received write request for position 4 I1026 05:37:40.826031 1943 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 487705ns I1026 05:37:40.826053 1943 replica.cpp:676] Persisted action at 4 I1026 05:37:40.826514 1941 replica.cpp:655] Replica received learned notice for position 4 I1026 05:37:40.826992 1941 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 457616ns I1026 05:37:40.827054 1941 leveldb.cpp:401] Deleting ~2 keys from leveldb took 41154ns I1026 05:37:40.827070 1941 replica.cpp:676] Persisted action at 4 I1026 05:37:40.827090 1941 replica.cpp:661] Replica learned TRUNCATE action at position 4 I1026 05:37:40.829262 1919 sched.cpp:137] Version: 0.21.0 I1026 05:37:40.829761 1939 sched.cpp:233] New master detected at [email protected]:48044 I1026 05:37:40.829787 1939 sched.cpp:283] Authenticating with master [email protected]:48044 I1026 05:37:40.829941 1936 authenticatee.hpp:133] Creating new client SASL connection I1026 05:37:40.830123 1943 master.cpp:3853] Authenticating [email protected]:48044 I1026 05:37:40.830319 1938 authenticator.hpp:161] Creating new server SASL connection I1026 05:37:40.830438 1942 authenticatee.hpp:224] Received SASL authentication mechanisms: CRAM-MD5 I1026 05:37:40.830461 1942 authenticatee.hpp:250] Attempting to authenticate with mechanism 'CRAM-MD5' I1026 05:37:40.830538 1946 authenticator.hpp:267] Received SASL authentication start I1026 05:37:40.830588 1946 authenticator.hpp:389] Authentication requires more steps I1026 05:37:40.830651 1946 authenticatee.hpp:270] Received SASL authentication step I1026 05:37:40.830736 1936 authenticator.hpp:295] Received SASL authentication step I1026 05:37:40.830762 1936 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 I1026 05:37:40.830773 1936 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1026 05:37:40.830808 1936 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1026 05:37:40.830829 1936 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 I1026 05:37:40.830838 1936 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1026 05:37:40.830844 1936 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1026 05:37:40.830858 1936 authenticator.hpp:381] Authentication success I1026 05:37:40.830924 1942 authenticatee.hpp:310] Authentication success I1026 05:37:40.830951 1934 master.cpp:3893] Successfully authenticated principal 'test-principal' at [email protected]:48044 I1026 05:37:40.831087 1948 sched.cpp:357] Successfully authenticated with master [email protected]:48044 I1026 05:37:40.831109 1948 sched.cpp:476] Sending registration request to [email protected]:48044 I1026 05:37:40.831220 1946 master.cpp:1362] Received registration request for framework 'default' at [email protected]:48044 I1026 05:37:40.831306 1946 master.cpp:1321] Authorizing framework principal 'test-principal' to receive offers for role '*' I1026 05:37:40.831666 1946 master.cpp:1426] Registering framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 I1026 05:37:40.831886 1948 hierarchical_allocator_process.hpp:329] Added framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.831992 1943 sched.cpp:407] Framework registered with 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.832056 1943 sched.cpp:421] Scheduler::registered took 39567ns I1026 05:37:40.832061 1948 hierarchical_allocator_process.hpp:734] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141026-053740-3142697795-48044-1919-S0 to framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.832465 1948 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 557029ns I1026 05:37:40.832742 1947 master.cpp:3795] Sending 1 offers to framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 I1026 05:37:40.833416 1938 sched.cpp:544] Scheduler::resourceOffers took 413267ns I1026 05:37:40.834154 1944 master.cpp:2321] Processing reply for offers: [ 20141026-053740-3142697795-48044-1919-O0 ] on slave 20141026-053740-3142697795-48044-1919-S0 at slave(71)@67.195.81.187:48044 (pomona.apache.org) for framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 W1026 05:37:40.834249 1944 master.cpp:1969] 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. W1026 05:37:40.834276 1944 master.cpp:1980] 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. I1026 05:37:40.834388 1944 master.cpp:2417] Authorizing framework principal 'test-principal' to launch task 0 as user 'jenkins' I1026 05:37:40.835225 1935 master.hpp:877] Adding task 0 with resources cpus(*):2; mem(*):1024 on slave 20141026-053740-3142697795-48044-1919-S0 (pomona.apache.org) I1026 05:37:40.835311 1935 master.cpp:2480] Launching task 0 of framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 with resources cpus(*):2; mem(*):1024 on slave 20141026-053740-3142697795-48044-1919-S0 at slave(71)@67.195.81.187:48044 (pomona.apache.org) I1026 05:37:40.985780 1940 slave.cpp:1081] Got assigned task 0 for framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.986291 1941 hierarchical_allocator_process.hpp:563] Recovered disk(*):1024; ports(*):[31000-32000] (total allocatable: disk(*):1024; ports(*):[31000-32000]) on slave 20141026-053740-3142697795-48044-1919-S0 from framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.986400 1941 hierarchical_allocator_process.hpp:599] Framework 20141026-053740-3142697795-48044-1919-0000 filtered slave 20141026-053740-3142697795-48044-1919-S0 for 5secs I1026 05:37:40.986466 1940 slave.cpp:1191] Launching task 0 for framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.989169 1940 slave.cpp:3857] Launching executor default of framework 20141026-053740-3142697795-48044-1919-0000 in work directory '/tmp/GarbageCollectorIntegrationTest_DiskUsage_xuy4QG/slaves/20141026-053740-3142697795-48044-1919-S0/frameworks/20141026-053740-3142697795-48044-1919-0000/executors/default/runs/51de1be1-00e4-45be-ba30-b017c1067a91' I1026 05:37:40.991880 1940 exec.cpp:132] Version: 0.21.0 I1026 05:37:40.992161 1939 exec.cpp:182] Executor started at: executor(12)@67.195.81.187:48044 with pid 1919 I1026 05:37:40.992316 1940 slave.cpp:1317] Queuing task '0' for executor default of framework '20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.992468 1940 slave.cpp:555] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_DiskUsage_xuy4QG/slaves/20141026-053740-3142697795-48044-1919-S0/frameworks/20141026-053740-3142697795-48044-1919-0000/executors/default/runs/51de1be1-00e4-45be-ba30-b017c1067a91' I1026 05:37:40.992540 1940 slave.cpp:1849] Got registration for executor 'default' of framework 20141026-053740-3142697795-48044-1919-0000 from executor(12)@67.195.81.187:48044 I1026 05:37:40.992796 1940 slave.cpp:1968] Flushing queued task 0 for executor 'default' of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.992856 1933 exec.cpp:206] Executor registered on slave 20141026-053740-3142697795-48044-1919-S0 I1026 05:37:40.992960 1940 slave.cpp:2788] Monitoring executor 'default' of framework '20141026-053740-3142697795-48044-1919-0000' in container '51de1be1-00e4-45be-ba30-b017c1067a91' I1026 05:37:40.994954 1933 exec.cpp:218] Executor::registered took 26527ns I1026 05:37:40.995110 1933 exec.cpp:293] Executor asked to run task '0' I1026 05:37:40.995173 1933 exec.cpp:302] Executor::launchTask took 47056ns I1026 05:37:40.997432 1933 exec.cpp:525] Executor sending status update TASK_RUNNING (UUID: 26f54ad4-b9bc-4d89-894e-f29a708f5a4d) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.997653 1933 slave.cpp:2202] Handling status update TASK_RUNNING (UUID: 26f54ad4-b9bc-4d89-894e-f29a708f5a4d) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 from executor(12)@67.195.81.187:48044 I1026 05:37:40.997896 1947 status_update_manager.cpp:317] Received status update TASK_RUNNING (UUID: 26f54ad4-b9bc-4d89-894e-f29a708f5a4d) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.997936 1947 status_update_manager.cpp:494] Creating StatusUpdate stream for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.998147 1947 status_update_manager.cpp:371] Forwarding update TASK_RUNNING (UUID: 26f54ad4-b9bc-4d89-894e-f29a708f5a4d) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 to the slave I1026 05:37:40.998363 1934 slave.cpp:2442] Forwarding the update TASK_RUNNING (UUID: 26f54ad4-b9bc-4d89-894e-f29a708f5a4d) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 to [email protected]:48044 I1026 05:37:40.998481 1934 slave.cpp:2369] Status update manager successfully handled status update TASK_RUNNING (UUID: 26f54ad4-b9bc-4d89-894e-f29a708f5a4d) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.998504 1934 slave.cpp:2375] Sending acknowledgement for status update TASK_RUNNING (UUID: 26f54ad4-b9bc-4d89-894e-f29a708f5a4d) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 to executor(12)@67.195.81.187:48044 I1026 05:37:40.998644 1940 exec.cpp:339] Executor received status update acknowledgement 26f54ad4-b9bc-4d89-894e-f29a708f5a4d for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.998677 1944 master.cpp:3410] Forwarding status update TASK_RUNNING (UUID: 26f54ad4-b9bc-4d89-894e-f29a708f5a4d) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.998766 1944 master.cpp:3382] Status update TASK_RUNNING (UUID: 26f54ad4-b9bc-4d89-894e-f29a708f5a4d) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 from slave 20141026-053740-3142697795-48044-1919-S0 at slave(71)@67.195.81.187:48044 (pomona.apache.org) I1026 05:37:40.998797 1944 master.cpp:4617] Updating the latest state of task 0 of framework 20141026-053740-3142697795-48044-1919-0000 to TASK_RUNNING I1026 05:37:40.998863 1948 sched.cpp:635] Scheduler::statusUpdate took 41522ns I1026 05:37:40.999078 1938 master.cpp:2882] Forwarding status update acknowledgement 26f54ad4-b9bc-4d89-894e-f29a708f5a4d for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 to slave 20141026-053740-3142697795-48044-1919-S0 at slave(71)@67.195.81.187:48044 (pomona.apache.org) I1026 05:37:40.999328 1938 status_update_manager.cpp:389] Received status update acknowledgement (UUID: 26f54ad4-b9bc-4d89-894e-f29a708f5a4d) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:40.999362 1941 slave.cpp:2846] Executor 'default' of framework 20141026-053740-3142697795-48044-1919-0000 exited with status 0 I1026 05:37:41.001579 1941 slave.cpp:2202] Handling status update TASK_LOST (UUID: d749f825-9535-42e9-aac0-a5384af9269f) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 from @0.0.0.0:0 I1026 05:37:41.001646 1941 slave.cpp:4165] Terminating task 0 I1026 05:37:41.001994 1941 slave.cpp:1789] Status update manager successfully handled status update acknowledgement (UUID: 26f54ad4-b9bc-4d89-894e-f29a708f5a4d) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:41.002087 1944 master.cpp:3462] Executor default of framework 20141026-053740-3142697795-48044-1919-0000 on slave 20141026-053740-3142697795-48044-1919-S0 at slave(71)@67.195.81.187:48044 (pomona.apache.org) exited with status 0 I1026 05:37:41.002166 1944 master.cpp:4705] Removing executor 'default' with resources of framework 20141026-053740-3142697795-48044-1919-0000 on slave 20141026-053740-3142697795-48044-1919-S0 at slave(71)@67.195.81.187:48044 (pomona.apache.org) I1026 05:37:41.002255 1933 status_update_manager.cpp:317] Received status update TASK_LOST (UUID: d749f825-9535-42e9-aac0-a5384af9269f) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:41.002393 1933 status_update_manager.cpp:371] Forwarding update TASK_LOST (UUID: d749f825-9535-42e9-aac0-a5384af9269f) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 to the slave I1026 05:37:41.002594 1935 slave.cpp:2442] Forwarding the update TASK_LOST (UUID: d749f825-9535-42e9-aac0-a5384af9269f) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 to [email protected]:48044 I1026 05:37:41.002760 1935 slave.cpp:2369] Status update manager successfully handled status update TASK_LOST (UUID: d749f825-9535-42e9-aac0-a5384af9269f) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:41.002810 1934 master.cpp:3410] Forwarding status update TASK_LOST (UUID: d749f825-9535-42e9-aac0-a5384af9269f) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.157433 1934 master.cpp:3382] Status update TASK_LOST (UUID: d749f825-9535-42e9-aac0-a5384af9269f) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 from slave 20141026-053740-3142697795-48044-1919-S0 at slave(71)@67.195.81.187:48044 (pomona.apache.org) I1026 05:37:43.157491 1934 master.cpp:4617] Updating the latest state of task 0 of framework 20141026-053740-3142697795-48044-1919-0000 to TASK_LOST I1026 05:37:43.157644 1940 sched.cpp:635] Scheduler::statusUpdate took 20710ns I1026 05:37:43.157738 1946 hierarchical_allocator_process.hpp:563] Recovered cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave 20141026-053740-3142697795-48044-1919-S0 from framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.157824 1940 master.cpp:4676] Removing task 0 with resources cpus(*):2; mem(*):1024 of framework 20141026-053740-3142697795-48044-1919-0000 on slave 20141026-053740-3142697795-48044-1919-S0 at slave(71)@67.195.81.187:48044 (pomona.apache.org) I1026 05:37:43.157938 1940 master.cpp:2882] Forwarding status update acknowledgement d749f825-9535-42e9-aac0-a5384af9269f for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 to slave 20141026-053740-3142697795-48044-1919-S0 at slave(71)@67.195.81.187:48044 (pomona.apache.org) I1026 05:37:43.158191 1948 status_update_manager.cpp:389] Received status update acknowledgement (UUID: d749f825-9535-42e9-aac0-a5384af9269f) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.158341 1948 status_update_manager.cpp:525] Cleaning up status update stream for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.158565 1941 slave.cpp:1789] Status update manager successfully handled status update acknowledgement (UUID: d749f825-9535-42e9-aac0-a5384af9269f) for task 0 of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.158627 1941 slave.cpp:4204] Completing task 0 I1026 05:37:43.158670 1941 slave.cpp:2983] Cleaning up executor 'default' of framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.158879 1947 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_xuy4QG/slaves/20141026-053740-3142697795-48044-1919-S0/frameworks/20141026-053740-3142697795-48044-1919-0000/executors/default/runs/51de1be1-00e4-45be-ba30-b017c1067a91' for gc 1.00000330839619weeks in the future I1026 05:37:43.159008 1941 slave.cpp:3060] Cleaning up framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.159097 1947 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_xuy4QG/slaves/20141026-053740-3142697795-48044-1919-S0/frameworks/20141026-053740-3142697795-48044-1919-0000/executors/default' for gc 1.00000330839619weeks in the future I1026 05:37:43.159159 1941 status_update_manager.cpp:279] Closing status update streams for framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.159184 1947 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_xuy4QG/slaves/20141026-053740-3142697795-48044-1919-S0/frameworks/20141026-053740-3142697795-48044-1919-0000' for gc 1.00000330839619weeks in the future I1026 05:37:43.171516 1947 slave.cpp:3297] Current usage 90.00%. Max allowed age: 0ns I1026 05:37:43.171716 1943 hierarchical_allocator_process.hpp:734] Offering disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 20141026-053740-3142697795-48044-1919-S0 to framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.171942 1943 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 414547ns I1026 05:37:43.172202 1943 master.cpp:3795] Sending 1 offers to framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 I1026 05:37:43.172498 1947 sched.cpp:544] Scheduler::resourceOffers took 21756ns ../../src/tests/gc_tests.cpp:675: Failure Value of: os::exists(executorDir) Actual: true Expected: false I1026 05:37:43.191849 1944 master.cpp:768] Framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 disconnected I1026 05:37:43.191870 1944 master.cpp:1731] Disconnecting framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 I1026 05:37:43.191889 1944 master.cpp:1747] Deactivating framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 I1026 05:37:43.191998 1946 hierarchical_allocator_process.hpp:405] Deactivated framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.192348 1944 master.cpp:790] Giving framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 0ns to failover I1026 05:37:43.192411 1943 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 20141026-053740-3142697795-48044-1919-S0 from framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.192466 1944 master.cpp:3665] Framework failover timeout, removing framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 I1026 05:37:43.192481 1944 master.cpp:4201] Removing framework 20141026-053740-3142697795-48044-1919-0000 (default) at [email protected]:48044 I1026 05:37:43.192610 1945 slave.cpp:1522] Asked to shut down framework 20141026-053740-3142697795-48044-1919-0000 by [email protected]:48044 W1026 05:37:43.192631 1945 slave.cpp:1537] Cannot shut down unknown framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.192734 1944 hierarchical_allocator_process.hpp:360] Removed framework 20141026-053740-3142697795-48044-1919-0000 I1026 05:37:43.193313 1945 master.cpp:677] Master terminating I1026 05:37:43.193547 1945 slave.cpp:2607] [email protected]:48044 exited W1026 05:37:43.193560 1945 slave.cpp:2610] Master disconnected! Waiting for a new master to be elected *** Aborted at 1414301863 (unix time) try "date -d @1414301863" if you are using GNU date *** PC: @ 0x211 (unknown) make[3]: *** [check-local] Segmentation fault 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
