You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/10/26 07:42:33 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2489
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2489/changes>
Changes:
[yujie.jay] Added a check in routing library due to a bug in libnl.
[yujie.jay] Added documentation for egress rate limit control.
[yujie.jay] Reordered functions in type_utils and added an equal comparator for
------------------------------------------
[...truncated 27165 lines...]
I1026 06:41:46.457535 25758 recover.cpp:188] Received a recover response from a replica in STARTING status
I1026 06:41:46.457991 25750 recover.cpp:554] Updating replica status to VOTING
I1026 06:41:46.458199 25752 master.cpp:1242] The newly elected leader is master@67.195.81.187:43097 with id 20141026-064146-3142697795-43097-25733
I1026 06:41:46.458217 25752 master.cpp:1255] Elected as the leading master!
I1026 06:41:46.458232 25752 master.cpp:1073] Recovering from registrar
I1026 06:41:46.458415 25751 registrar.cpp:313] Recovering registrar
I1026 06:41:46.458650 25760 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 573727ns
I1026 06:41:46.458668 25760 replica.cpp:320] Persisted replica status to VOTING
I1026 06:41:46.458760 25749 recover.cpp:568] Successfully joined the Paxos group
I1026 06:41:46.459080 25749 recover.cpp:452] Recover process terminated
I1026 06:41:46.459432 25759 log.cpp:656] Attempting to start the writer
I1026 06:41:46.460531 25748 replica.cpp:474] Replica received implicit promise request with proposal 1
I1026 06:41:46.461136 25748 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 580573ns
I1026 06:41:46.461159 25748 replica.cpp:342] Persisted promised to 1
I1026 06:41:46.461663 25759 coordinator.cpp:230] Coordinator attemping to fill missing position
I1026 06:41:46.462652 25754 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I1026 06:41:46.462955 25754 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 277799ns
I1026 06:41:46.462973 25754 replica.cpp:676] Persisted action at 0
I1026 06:41:46.463737 25762 replica.cpp:508] Replica received write request for position 0
I1026 06:41:46.463778 25762 leveldb.cpp:438] Reading position from leveldb took 21076ns
I1026 06:41:46.464140 25762 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 338716ns
I1026 06:41:46.464161 25762 replica.cpp:676] Persisted action at 0
I1026 06:41:46.464614 25748 replica.cpp:655] Replica received learned notice for position 0
I1026 06:41:46.718680 25748 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 795695ns
I1026 06:41:46.718708 25748 replica.cpp:676] Persisted action at 0
I1026 06:41:46.718729 25748 replica.cpp:661] Replica learned NOP action at position 0
I1026 06:41:46.719110 25759 log.cpp:672] Writer started with ending position 0
I1026 06:41:46.720623 25749 leveldb.cpp:438] Reading position from leveldb took 28527ns
I1026 06:41:46.723644 25751 registrar.cpp:346] Successfully fetched the registry (0B) in 265.200896ms
I1026 06:41:46.723754 25751 registrar.cpp:445] Applied 1 operations in 17532ns; attempting to update the 'registry'
I1026 06:41:46.726586 25759 log.cpp:680] Attempting to append 139 bytes to the log
I1026 06:41:46.726748 25752 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1
I1026 06:41:46.727654 25755 replica.cpp:508] Replica received write request for position 1
I1026 06:41:46.728191 25755 leveldb.cpp:343] Persisting action (158 bytes) to leveldb took 508773ns
I1026 06:41:46.728211 25755 replica.cpp:676] Persisted action at 1
I1026 06:41:46.728724 25753 replica.cpp:655] Replica received learned notice for position 1
I1026 06:41:46.729320 25753 leveldb.cpp:343] Persisting action (160 bytes) to leveldb took 569027ns
I1026 06:41:46.729344 25753 replica.cpp:676] Persisted action at 1
I1026 06:41:46.729362 25753 replica.cpp:661] Replica learned APPEND action at position 1
I1026 06:41:46.730180 25748 registrar.cpp:490] Successfully updated the 'registry' in 6.381824ms
I1026 06:41:46.730314 25748 registrar.cpp:376] Successfully recovered registrar
I1026 06:41:46.730535 25748 log.cpp:699] Attempting to truncate the log to 1
I1026 06:41:46.730551 25753 master.cpp:1100] Recovered 0 slaves from the Registry (101B) ; allowing 10mins for slaves to re-register
I1026 06:41:46.730693 25751 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2
I1026 06:41:46.731369 25755 replica.cpp:508] Replica received write request for position 2
I1026 06:41:46.731914 25755 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 518190ns
I1026 06:41:46.731933 25755 replica.cpp:676] Persisted action at 2
I1026 06:41:46.732419 25747 replica.cpp:655] Replica received learned notice for position 2
I1026 06:41:46.732816 25747 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 370032ns
I1026 06:41:46.732863 25747 leveldb.cpp:401] Deleting ~1 keys from leveldb took 27192ns
I1026 06:41:46.732877 25747 replica.cpp:676] Persisted action at 2
I1026 06:41:46.732900 25747 replica.cpp:661] Replica learned TRUNCATE action at position 2
I1026 06:41:46.745275 25757 slave.cpp:169] Slave started on 97)@67.195.81.187:43097
I1026 06:41:46.745347 25757 credentials.hpp:84] Loading credential for authentication from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_ht3BFs/credential'
I1026 06:41:46.745471 25757 slave.cpp:276] Slave using credential for: test-principal
I1026 06:41:46.745676 25757 slave.cpp:289] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1026 06:41:46.745760 25757 slave.cpp:318] Slave hostname: pomona.apache.org
I1026 06:41:46.745774 25757 slave.cpp:319] Slave checkpoint: false
W1026 06:41:46.745779 25757 slave.cpp:321] Disabling checkpointing is deprecated and the --checkpoint flag will be removed in a future release. Please avoid using this flag
I1026 06:41:46.746373 25752 state.cpp:33] Recovering state from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_ht3BFs/meta'
I1026 06:41:46.746532 25761 status_update_manager.cpp:197] Recovering status update manager
I1026 06:41:46.746846 25762 slave.cpp:3442] Finished recovery
I1026 06:41:46.747267 25751 status_update_manager.cpp:171] Pausing sending status updates
I1026 06:41:46.747267 25749 slave.cpp:602] New master detected at master@67.195.81.187:43097
I1026 06:41:46.747344 25749 slave.cpp:665] Authenticating with master master@67.195.81.187:43097
I1026 06:41:46.747414 25749 slave.cpp:638] Detecting new master
I1026 06:41:46.747441 25761 authenticatee.hpp:133] Creating new client SASL connection
I1026 06:41:46.747570 25761 master.cpp:3853] Authenticating slave(97)@67.195.81.187:43097
I1026 06:41:46.747745 25754 authenticator.hpp:161] Creating new server SASL connection
I1026 06:41:46.747874 25748 authenticatee.hpp:224] Received SASL authentication mechanisms: CRAM-MD5
I1026 06:41:46.747900 25748 authenticatee.hpp:250] Attempting to authenticate with mechanism 'CRAM-MD5'
I1026 06:41:46.747982 25757 authenticator.hpp:267] Received SASL authentication start
I1026 06:41:46.748023 25757 authenticator.hpp:389] Authentication requires more steps
I1026 06:41:46.748107 25758 authenticatee.hpp:270] Received SASL authentication step
I1026 06:41:46.748181 25757 authenticator.hpp:295] Received SASL authentication step
I1026 06:41:46.748204 25757 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 06:41:46.748214 25757 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I1026 06:41:46.748250 25757 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1026 06:41:46.748277 25757 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 06:41:46.748314 25757 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1026 06:41:46.748325 25757 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1026 06:41:46.748347 25757 authenticator.hpp:381] Authentication success
I1026 06:41:46.748428 25757 authenticatee.hpp:310] Authentication success
I1026 06:41:46.748456 25758 master.cpp:3893] Successfully authenticated principal 'test-principal' at slave(97)@67.195.81.187:43097
I1026 06:41:46.748574 25751 slave.cpp:722] Successfully authenticated with master master@67.195.81.187:43097
I1026 06:41:46.748672 25751 slave.cpp:1050] Will retry registration in 1.631964ms if necessary
I1026 06:41:46.748816 25757 master.cpp:3032] Registering slave at slave(97)@67.195.81.187:43097 (pomona.apache.org) with id 20141026-064146-3142697795-43097-25733-S0
I1026 06:41:46.749179 25760 registrar.cpp:445] Applied 1 operations in 56021ns; attempting to update the 'registry'
I1026 06:41:46.751027 25751 slave.cpp:1050] Will retry registration in 24.736363ms if necessary
I1026 06:41:46.751168 25752 master.cpp:3020] Ignoring register slave message from slave(97)@67.195.81.187:43097 (pomona.apache.org) as admission is already in progress
I1026 06:41:46.751997 25754 log.cpp:680] Attempting to append 316 bytes to the log
I1026 06:41:46.752126 25749 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3
I1026 06:41:46.752656 25757 replica.cpp:508] Replica received write request for position 3
I1026 06:41:46.752861 25757 leveldb.cpp:343] Persisting action (335 bytes) to leveldb took 184127ns
I1026 06:41:46.752876 25757 replica.cpp:676] Persisted action at 3
I1026 06:41:46.753203 25749 replica.cpp:655] Replica received learned notice for position 3
I1026 06:41:46.753525 25749 leveldb.cpp:343] Persisting action (337 bytes) to leveldb took 303871ns
I1026 06:41:46.753541 25749 replica.cpp:676] Persisted action at 3
I1026 06:41:46.753553 25749 replica.cpp:661] Replica learned APPEND action at position 3
I1026 06:41:46.754174 25756 registrar.cpp:490] Successfully updated the 'registry' in 4.947968ms
I1026 06:41:46.754426 25756 log.cpp:699] Attempting to truncate the log to 3
I1026 06:41:46.754539 25750 slave.cpp:2522] Received ping from slave-observer(99)@67.195.81.187:43097
I1026 06:41:46.754572 25754 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4
I1026 06:41:46.754669 25762 master.cpp:3086] Registered slave 20141026-064146-3142697795-43097-25733-S0 at slave(97)@67.195.81.187:43097 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1026 06:41:46.754787 25755 slave.cpp:756] Registered with master master@67.195.81.187:43097; given slave ID 20141026-064146-3142697795-43097-25733-S0
I1026 06:41:46.754802 25756 hierarchical_allocator_process.hpp:442] Added slave 20141026-064146-3142697795-43097-25733-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 06:41:46.755051 25751 replica.cpp:508] Replica received write request for position 4
I1026 06:41:46.758406 25733 sched.cpp:137] Version: 0.21.0
I1026 06:41:46.870838 25755 status_update_manager.cpp:178] Resuming sending status updates
I1026 06:41:46.870841 25756 hierarchical_allocator_process.hpp:679] Performed allocation for slave 20141026-064146-3142697795-43097-25733-S0 in 52614ns
I1026 06:41:46.871240 25755 sched.cpp:233] New master detected at master@67.195.81.187:43097
I1026 06:41:46.871265 25755 sched.cpp:283] Authenticating with master master@67.195.81.187:43097
I1026 06:41:46.871430 25750 authenticatee.hpp:133] Creating new client SASL connection
I1026 06:41:46.871518 25751 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 669981ns
I1026 06:41:46.871548 25751 replica.cpp:676] Persisted action at 4
I1026 06:41:46.871724 25761 master.cpp:3853] Authenticating scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097
I1026 06:41:46.871932 25762 authenticator.hpp:161] Creating new server SASL connection
I1026 06:41:46.872071 25757 authenticatee.hpp:224] Received SASL authentication mechanisms: CRAM-MD5
I1026 06:41:46.872081 25762 replica.cpp:655] Replica received learned notice for position 4
I1026 06:41:46.872092 25757 authenticatee.hpp:250] Attempting to authenticate with mechanism 'CRAM-MD5'
I1026 06:41:46.872167 25757 authenticator.hpp:267] Received SASL authentication start
I1026 06:41:46.872228 25757 authenticator.hpp:389] Authentication requires more steps
I1026 06:41:46.872275 25757 authenticatee.hpp:270] Received SASL authentication step
I1026 06:41:46.872398 25757 authenticator.hpp:295] Received SASL authentication step
I1026 06:41:46.872414 25757 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 06:41:46.872422 25757 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I1026 06:41:46.872462 25757 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1026 06:41:46.872475 25757 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 06:41:46.872481 25757 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1026 06:41:46.872485 25757 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1026 06:41:46.872494 25757 authenticator.hpp:381] Authentication success
I1026 06:41:46.872555 25758 authenticatee.hpp:310] Authentication success
I1026 06:41:46.872586 25754 master.cpp:3893] Successfully authenticated principal 'test-principal' at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097
I1026 06:41:46.872618 25762 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 515681ns
I1026 06:41:46.872690 25762 leveldb.cpp:401] Deleting ~2 keys from leveldb took 47776ns
I1026 06:41:46.872711 25762 replica.cpp:676] Persisted action at 4
I1026 06:41:46.872716 25751 sched.cpp:357] Successfully authenticated with master master@67.195.81.187:43097
I1026 06:41:46.872735 25751 sched.cpp:476] Sending registration request to master@67.195.81.187:43097
I1026 06:41:46.872733 25762 replica.cpp:661] Replica learned TRUNCATE action at position 4
I1026 06:41:46.872853 25756 master.cpp:1362] Received registration request for framework 'default' at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097
I1026 06:41:46.872918 25756 master.cpp:1321] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1026 06:41:46.873502 25760 master.cpp:1426] Registering framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097
I1026 06:41:46.873715 25750 hierarchical_allocator_process.hpp:329] Added framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:46.873859 25749 sched.cpp:407] Framework registered with 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:46.873858 25750 hierarchical_allocator_process.hpp:734] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141026-064146-3142697795-43097-25733-S0 to framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:46.873914 25749 sched.cpp:421] Scheduler::registered took 37389ns
I1026 06:41:46.874214 25750 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 476028ns
I1026 06:41:46.874563 25748 master.cpp:3795] Sending 1 offers to framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097
I1026 06:41:46.875187 25753 sched.cpp:544] Scheduler::resourceOffers took 312078ns
I1026 06:41:46.875845 25748 master.cpp:2321] Processing reply for offers: [ 20141026-064146-3142697795-43097-25733-O0 ] on slave 20141026-064146-3142697795-43097-25733-S0 at slave(97)@67.195.81.187:43097 (pomona.apache.org) for framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097
W1026 06:41:46.875929 25748 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 06:41:46.875949 25748 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 06:41:46.876027 25748 master.cpp:2417] Authorizing framework principal 'test-principal' to launch task 0 as user 'jenkins'
I1026 06:41:46.876816 25748 master.hpp:877] Adding task 0 with resources cpus(*):2; mem(*):1024 on slave 20141026-064146-3142697795-43097-25733-S0 (pomona.apache.org)
I1026 06:41:46.876862 25748 master.cpp:2480] Launching task 0 of framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097 with resources cpus(*):2; mem(*):1024 on slave 20141026-064146-3142697795-43097-25733-S0 at slave(97)@67.195.81.187:43097 (pomona.apache.org)
I1026 06:41:46.877115 25750 slave.cpp:1081] Got assigned task 0 for framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:46.877193 25748 hierarchical_allocator_process.hpp:563] Recovered disk(*):1024; ports(*):[31000-32000] (total allocatable: disk(*):1024; ports(*):[31000-32000]) on slave 20141026-064146-3142697795-43097-25733-S0 from framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:46.877224 25748 hierarchical_allocator_process.hpp:599] Framework 20141026-064146-3142697795-43097-25733-0000 filtered slave 20141026-064146-3142697795-43097-25733-S0 for 5secs
I1026 06:41:46.877611 25750 slave.cpp:1191] Launching task 0 for framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:46.880142 25750 slave.cpp:3857] Launching executor default of framework 20141026-064146-3142697795-43097-25733-0000 in work directory '/tmp/GarbageCollectorIntegrationTest_DiskUsage_ht3BFs/slaves/20141026-064146-3142697795-43097-25733-S0/frameworks/20141026-064146-3142697795-43097-25733-0000/executors/default/runs/58a24d23-fcee-4ccd-9b55-b166de2edab4'
I1026 06:41:46.882810 25750 exec.cpp:132] Version: 0.21.0
I1026 06:41:46.883015 25758 exec.cpp:182] Executor started at: executor(43)@67.195.81.187:43097 with pid 25733
I1026 06:41:46.883136 25750 slave.cpp:1317] Queuing task '0' for executor default of framework '20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.017436 25750 slave.cpp:555] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_DiskUsage_ht3BFs/slaves/20141026-064146-3142697795-43097-25733-S0/frameworks/20141026-064146-3142697795-43097-25733-0000/executors/default/runs/58a24d23-fcee-4ccd-9b55-b166de2edab4'
I1026 06:41:47.017570 25750 slave.cpp:2788] Monitoring executor 'default' of framework '20141026-064146-3142697795-43097-25733-0000' in container '58a24d23-fcee-4ccd-9b55-b166de2edab4'
I1026 06:41:47.017729 25750 slave.cpp:1849] Got registration for executor 'default' of framework 20141026-064146-3142697795-43097-25733-0000 from executor(43)@67.195.81.187:43097
I1026 06:41:47.018019 25750 slave.cpp:1968] Flushing queued task 0 for executor 'default' of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.018118 25751 exec.cpp:206] Executor registered on slave 20141026-064146-3142697795-43097-25733-S0
I1026 06:41:47.019531 25751 exec.cpp:218] Executor::registered took 19682ns
I1026 06:41:47.019644 25751 exec.cpp:293] Executor asked to run task '0'
I1026 06:41:47.019692 25751 exec.cpp:302] Executor::launchTask took 36998ns
I1026 06:41:47.020967 25751 exec.cpp:525] Executor sending status update TASK_RUNNING (UUID: 4044d259-9bee-4958-b63a-8e22c1fd5772) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.021155 25751 slave.cpp:2202] Handling status update TASK_RUNNING (UUID: 4044d259-9bee-4958-b63a-8e22c1fd5772) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000 from executor(43)@67.195.81.187:43097
I1026 06:41:47.021420 25753 status_update_manager.cpp:317] Received status update TASK_RUNNING (UUID: 4044d259-9bee-4958-b63a-8e22c1fd5772) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.021450 25753 status_update_manager.cpp:494] Creating StatusUpdate stream for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.021644 25753 status_update_manager.cpp:371] Forwarding update TASK_RUNNING (UUID: 4044d259-9bee-4958-b63a-8e22c1fd5772) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000 to the slave
I1026 06:41:47.021826 25757 slave.cpp:2442] Forwarding the update TASK_RUNNING (UUID: 4044d259-9bee-4958-b63a-8e22c1fd5772) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000 to master@67.195.81.187:43097
I1026 06:41:47.021947 25757 slave.cpp:2369] Status update manager successfully handled status update TASK_RUNNING (UUID: 4044d259-9bee-4958-b63a-8e22c1fd5772) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.021970 25757 slave.cpp:2375] Sending acknowledgement for status update TASK_RUNNING (UUID: 4044d259-9bee-4958-b63a-8e22c1fd5772) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000 to executor(43)@67.195.81.187:43097
I1026 06:41:47.022037 25748 master.cpp:3410] Forwarding status update TASK_RUNNING (UUID: 4044d259-9bee-4958-b63a-8e22c1fd5772) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.022085 25754 exec.cpp:339] Executor received status update acknowledgement 4044d259-9bee-4958-b63a-8e22c1fd5772 for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.022125 25748 master.cpp:3382] Status update TASK_RUNNING (UUID: 4044d259-9bee-4958-b63a-8e22c1fd5772) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000 from slave 20141026-064146-3142697795-43097-25733-S0 at slave(97)@67.195.81.187:43097 (pomona.apache.org)
I1026 06:41:47.022162 25748 master.cpp:4617] Updating the latest state of task 0 of framework 20141026-064146-3142697795-43097-25733-0000 to TASK_RUNNING
I1026 06:41:47.022233 25762 sched.cpp:635] Scheduler::statusUpdate took 35780ns
I1026 06:41:47.022446 25750 master.cpp:2882] Forwarding status update acknowledgement 4044d259-9bee-4958-b63a-8e22c1fd5772 for task 0 of framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097 to slave 20141026-064146-3142697795-43097-25733-S0 at slave(97)@67.195.81.187:43097 (pomona.apache.org)
I1026 06:41:47.022650 25756 status_update_manager.cpp:389] Received status update acknowledgement (UUID: 4044d259-9bee-4958-b63a-8e22c1fd5772) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.022794 25755 slave.cpp:2846] Executor 'default' of framework 20141026-064146-3142697795-43097-25733-0000 exited with status 0
I1026 06:41:47.025022 25755 slave.cpp:2202] Handling status update TASK_LOST (UUID: 6236c6e5-6c17-4ba1-a5b0-02dc3db33c32) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000 from @0.0.0.0:0
I1026 06:41:47.025094 25755 slave.cpp:4165] Terminating task 0
I1026 06:41:47.025454 25755 slave.cpp:1789] Status update manager successfully handled status update acknowledgement (UUID: 4044d259-9bee-4958-b63a-8e22c1fd5772) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.025532 25749 master.cpp:3462] Executor default of framework 20141026-064146-3142697795-43097-25733-0000 on slave 20141026-064146-3142697795-43097-25733-S0 at slave(97)@67.195.81.187:43097 (pomona.apache.org) exited with status 0
I1026 06:41:47.025600 25749 master.cpp:4705] Removing executor 'default' with resources of framework 20141026-064146-3142697795-43097-25733-0000 on slave 20141026-064146-3142697795-43097-25733-S0 at slave(97)@67.195.81.187:43097 (pomona.apache.org)
I1026 06:41:47.025724 25754 status_update_manager.cpp:317] Received status update TASK_LOST (UUID: 6236c6e5-6c17-4ba1-a5b0-02dc3db33c32) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.025782 25754 status_update_manager.cpp:371] Forwarding update TASK_LOST (UUID: 6236c6e5-6c17-4ba1-a5b0-02dc3db33c32) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000 to the slave
I1026 06:41:47.026013 25751 slave.cpp:2442] Forwarding the update TASK_LOST (UUID: 6236c6e5-6c17-4ba1-a5b0-02dc3db33c32) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000 to master@67.195.81.187:43097
I1026 06:41:47.026139 25751 slave.cpp:2369] Status update manager successfully handled status update TASK_LOST (UUID: 6236c6e5-6c17-4ba1-a5b0-02dc3db33c32) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.026262 25748 master.cpp:3410] Forwarding status update TASK_LOST (UUID: 6236c6e5-6c17-4ba1-a5b0-02dc3db33c32) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.026356 25748 master.cpp:3382] Status update TASK_LOST (UUID: 6236c6e5-6c17-4ba1-a5b0-02dc3db33c32) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000 from slave 20141026-064146-3142697795-43097-25733-S0 at slave(97)@67.195.81.187:43097 (pomona.apache.org)
I1026 06:41:47.026384 25748 master.cpp:4617] Updating the latest state of task 0 of framework 20141026-064146-3142697795-43097-25733-0000 to TASK_LOST
I1026 06:41:47.026463 25762 sched.cpp:635] Scheduler::statusUpdate took 17045ns
I1026 06:41:47.026646 25748 master.cpp:4676] Removing task 0 with resources cpus(*):2; mem(*):1024 of framework 20141026-064146-3142697795-43097-25733-0000 on slave 20141026-064146-3142697795-43097-25733-S0 at slave(97)@67.195.81.187:43097 (pomona.apache.org)
I1026 06:41:47.026696 25749 hierarchical_allocator_process.hpp:563] Recovered cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave 20141026-064146-3142697795-43097-25733-S0 from framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:47.026762 25748 master.cpp:2882] Forwarding status update acknowledgement 6236c6e5-6c17-4ba1-a5b0-02dc3db33c32 for task 0 of framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097 to slave 20141026-064146-3142697795-43097-25733-S0 at slave(97)@67.195.81.187:43097 (pomona.apache.org)
I1026 06:41:49.050568 25752 status_update_manager.cpp:389] Received status update acknowledgement (UUID: 6236c6e5-6c17-4ba1-a5b0-02dc3db33c32) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:49.050704 25752 status_update_manager.cpp:525] Cleaning up status update stream for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:49.050910 25751 slave.cpp:1789] Status update manager successfully handled status update acknowledgement (UUID: 6236c6e5-6c17-4ba1-a5b0-02dc3db33c32) for task 0 of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:49.050966 25751 slave.cpp:4204] Completing task 0
I1026 06:41:49.050999 25751 slave.cpp:2983] Cleaning up executor 'default' of framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:49.051177 25757 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_ht3BFs/slaves/20141026-064146-3142697795-43097-25733-S0/frameworks/20141026-064146-3142697795-43097-25733-0000/executors/default/runs/58a24d23-fcee-4ccd-9b55-b166de2edab4' for gc 1.00000326966095weeks in the future
I1026 06:41:49.051319 25751 slave.cpp:3060] Cleaning up framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:49.051378 25752 status_update_manager.cpp:279] Closing status update streams for framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:49.051398 25757 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_ht3BFs/slaves/20141026-064146-3142697795-43097-25733-S0/frameworks/20141026-064146-3142697795-43097-25733-0000/executors/default' for gc 1.00000326966095weeks in the future
I1026 06:41:49.051498 25757 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_ht3BFs/slaves/20141026-064146-3142697795-43097-25733-S0/frameworks/20141026-064146-3142697795-43097-25733-0000' for gc 1.00000326966095weeks in the future
I1026 06:41:49.067361 25758 slave.cpp:3297] Current usage 90.00%. Max allowed age: 0ns
I1026 06:41:49.067641 25749 hierarchical_allocator_process.hpp:734] Offering disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 20141026-064146-3142697795-43097-25733-S0 to framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:49.067864 25749 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 405014ns
I1026 06:41:49.068156 25756 master.cpp:3795] Sending 1 offers to framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097
I1026 06:41:49.068528 25749 sched.cpp:544] Scheduler::resourceOffers took 21762ns
../../src/tests/gc_tests.cpp:675: Failure
Value of: os::exists(executorDir)
Actual: true
Expected: false
I1026 06:41:49.087713 25757 master.cpp:768] Framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097 disconnected
I1026 06:41:49.087738 25757 master.cpp:1731] Disconnecting framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097
I1026 06:41:49.087756 25757 master.cpp:1747] Deactivating framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097
I1026 06:41:49.087870 25762 hierarchical_allocator_process.hpp:405] Deactivated framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:49.088148 25757 master.cpp:790] Giving framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097 0ns to failover
I1026 06:41:49.088464 25761 master.cpp:3665] Framework failover timeout, removing framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097
I1026 06:41:49.088486 25761 master.cpp:4201] Removing framework 20141026-064146-3142697795-43097-25733-0000 (default) at scheduler-0bb4a588-c204-4a22-b57d-c2cfa5f3760c@67.195.81.187:43097
I1026 06:41:49.088531 25751 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-064146-3142697795-43097-25733-S0 from framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:49.088618 25748 slave.cpp:1522] Asked to shut down framework 20141026-064146-3142697795-43097-25733-0000 by master@67.195.81.187:43097
W1026 06:41:49.088646 25748 slave.cpp:1537] Cannot shut down unknown framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:49.088754 25761 master.cpp:677] Master terminating
I1026 06:41:49.088845 25755 hierarchical_allocator_process.hpp:360] Removed framework 20141026-064146-3142697795-43097-25733-0000
I1026 06:41:49.089078 25751 slave.cpp:2607] master@67.195.81.187:43097 exited
W1026 06:41:49.089097 25751 slave.cpp:2610] Master disconnected! Waiting for a new master to be elected
*** Aborted at 1414305709 (unix time) try "date -d @1414305709" if you are using GNU date ***
PC: @ 0x1 (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
Jenkins build is back to normal :
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2490
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2490/changes>