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/04/24 07:38:11 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2082
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2082/changes>
Changes:
[vinod] Introduced exponential backoff for slave registration retries.
[bmahler] Fixed a compiler warning in Statistics.
------------------------------------------
[...truncated 35598 lines...]
I0424 05:38:11.419913 19967 slave.cpp:731] Will retry registration in 9.94340938secs if necessary
I0424 05:38:11.419935 19967 slave.cpp:522] Detecting new master
I0424 05:38:11.419945 19966 status_update_manager.cpp:167] New master detected at master@67.195.138.61:47555
I0424 05:38:11.425075 19969 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 7.688313ms
I0424 05:38:11.425103 19969 leveldb.cpp:399] Deleting ~1 keys from leveldb took 13605ns
I0424 05:38:11.425113 19969 replica.cpp:664] Persisted action at 2
I0424 05:38:11.425123 19969 replica.cpp:649] Replica learned TRUNCATE action at position 2
I0424 05:38:11.425451 19966 log.cpp:680] Attempting to append 344 bytes to the log
I0424 05:38:11.425524 19965 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 3
I0424 05:38:11.425849 19966 replica.cpp:508] Replica received write request for position 3
I0424 05:38:11.433406 19966 leveldb.cpp:341] Persisting action (363 bytes) to leveldb took 7.534047ms
I0424 05:38:11.433423 19966 replica.cpp:664] Persisted action at 3
I0424 05:38:11.433735 19967 replica.cpp:643] Replica received learned notice for position 3
I0424 05:38:11.441730 19967 leveldb.cpp:341] Persisting action (365 bytes) to leveldb took 7.978187ms
I0424 05:38:11.441746 19967 replica.cpp:664] Persisted action at 3
I0424 05:38:11.441756 19967 replica.cpp:649] Replica learned APPEND action at position 3
I0424 05:38:11.442138 19969 registrar.cpp:436] Successfully updated 'registry'
I0424 05:38:11.442210 19969 registrar.cpp:388] Attempting to update the 'registry'
I0424 05:38:11.442247 19965 master.cpp:2150] Admitted slave on juno.apache.org at slave(138)@67.195.138.61:47555
I0424 05:38:11.442263 19965 master.cpp:3204] Adding slave 20140424-053811-1032504131-47555-19839-0 at juno.apache.org with cpus(role1):2; mem(role1):1024; disk(role1):0; ports(role1):[31000-32000]
I0424 05:38:11.442289 19968 log.cpp:699] Attempting to truncate the log to 3
I0424 05:38:11.442358 19967 slave.cpp:540] Registered with master master@67.195.138.61:47555; given slave ID 20140424-053811-1032504131-47555-19839-0
I0424 05:38:11.442363 19968 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 4
I0424 05:38:11.442575 19965 hierarchical_allocator_process.hpp:445] Added slave 20140424-053811-1032504131-47555-19839-0 (juno.apache.org) with cpus(role1):2; mem(role1):1024; disk(role1):0; ports(role1):[31000-32000] (and cpus(role1):2; mem(role1):1024; disk(role1):0; ports(role1):[31000-32000] available)
I0424 05:38:11.442622 19965 hierarchical_allocator_process.hpp:708] Performed allocation for slave 20140424-053811-1032504131-47555-19839-0 in 13784ns
I0424 05:38:11.442688 19971 replica.cpp:508] Replica received write request for position 4
I0424 05:38:11.450081 19971 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 7.363288ms
I0424 05:38:11.450101 19971 replica.cpp:664] Persisted action at 4
I0424 05:38:11.450361 19966 replica.cpp:643] Replica received learned notice for position 4
I0424 05:38:11.458402 19966 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 8.020306ms
I0424 05:38:11.458443 19966 leveldb.cpp:399] Deleting ~2 keys from leveldb took 20603ns
I0424 05:38:11.458454 19966 replica.cpp:664] Persisted action at 4
I0424 05:38:11.458463 19966 replica.cpp:649] Replica learned TRUNCATE action at position 4
I0424 05:38:11.458749 19966 log.cpp:680] Attempting to append 992 bytes to the log
I0424 05:38:11.458801 19966 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 5
I0424 05:38:11.459033 19966 replica.cpp:508] Replica received write request for position 5
I0424 05:38:11.466732 19966 leveldb.cpp:341] Persisting action (1011 bytes) to leveldb took 7.684193ms
I0424 05:38:11.466750 19966 replica.cpp:664] Persisted action at 5
I0424 05:38:11.466948 19966 replica.cpp:643] Replica received learned notice for position 5
I0424 05:38:11.475059 19966 leveldb.cpp:341] Persisting action (1013 bytes) to leveldb took 8.091616ms
I0424 05:38:11.475077 19966 replica.cpp:664] Persisted action at 5
I0424 05:38:11.475086 19966 replica.cpp:649] Replica learned APPEND action at position 5
I0424 05:38:11.475510 19968 registrar.cpp:436] Successfully updated 'registry'
I0424 05:38:11.475630 19971 log.cpp:699] Attempting to truncate the log to 5
I0424 05:38:11.475709 19970 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 6
I0424 05:38:11.475764 19969 master.cpp:2150] Admitted slave on juno.apache.org at slave(139)@67.195.138.61:47555
I0424 05:38:11.475782 19969 master.cpp:3204] Adding slave 20140424-053811-1032504131-47555-19839-1 at juno.apache.org with cpus(role2):2; mem(role2):1024; cpus(*):1; mem(*):1024; disk(*):0; ports(*):[31000-32000]
I0424 05:38:11.475848 19970 slave.cpp:540] Registered with master master@67.195.138.61:47555; given slave ID 20140424-053811-1032504131-47555-19839-1
I0424 05:38:11.475949 19969 master.cpp:2150] Admitted slave on juno.apache.org at slave(140)@67.195.138.61:47555
I0424 05:38:11.475960 19969 master.cpp:3204] Adding slave 20140424-053811-1032504131-47555-19839-2 at juno.apache.org with cpus(role3):4; mem(role3):4096; disk(role3):0; ports(role3):[31000-32000]
I0424 05:38:11.476105 19967 replica.cpp:508] Replica received write request for position 6
I0424 05:38:11.476110 19968 slave.cpp:540] Registered with master master@67.195.138.61:47555; given slave ID 20140424-053811-1032504131-47555-19839-2
I0424 05:38:11.476122 19969 master.cpp:2150] Admitted slave on juno.apache.org at slave(141)@67.195.138.61:47555
I0424 05:38:11.476140 19969 master.cpp:3204] Adding slave 20140424-053811-1032504131-47555-19839-3 at juno.apache.org with cpus(role4):1; mem(role4):1024; disk(role4):0; ports(role4):[31000-32000]
I0424 05:38:11.476217 19965 slave.cpp:540] Registered with master master@67.195.138.61:47555; given slave ID 20140424-053811-1032504131-47555-19839-3
I0424 05:38:11.476372 19969 hierarchical_allocator_process.hpp:445] Added slave 20140424-053811-1032504131-47555-19839-1 (juno.apache.org) with cpus(role2):2; mem(role2):1024; cpus(*):1; mem(*):1024; disk(*):0; ports(*):[31000-32000] (and cpus(role2):2; mem(role2):1024; cpus(*):1; mem(*):1024; disk(*):0; ports(*):[31000-32000] available)
I0424 05:38:11.476431 19969 hierarchical_allocator_process.hpp:708] Performed allocation for slave 20140424-053811-1032504131-47555-19839-1 in 20423ns
I0424 05:38:11.476598 19969 hierarchical_allocator_process.hpp:445] Added slave 20140424-053811-1032504131-47555-19839-2 (juno.apache.org) with cpus(role3):4; mem(role3):4096; disk(role3):0; ports(role3):[31000-32000] (and cpus(role3):4; mem(role3):4096; disk(role3):0; ports(role3):[31000-32000] available)
I0424 05:38:11.476644 19969 hierarchical_allocator_process.hpp:708] Performed allocation for slave 20140424-053811-1032504131-47555-19839-2 in 14115ns
I0424 05:38:11.476790 19969 hierarchical_allocator_process.hpp:445] Added slave 20140424-053811-1032504131-47555-19839-3 (juno.apache.org) with cpus(role4):1; mem(role4):1024; disk(role4):0; ports(role4):[31000-32000] (and cpus(role4):1; mem(role4):1024; disk(role4):0; ports(role4):[31000-32000] available)
I0424 05:38:11.476835 19969 hierarchical_allocator_process.hpp:708] Performed allocation for slave 20140424-053811-1032504131-47555-19839-3 in 12966ns
I0424 05:38:11.477823 19839 sched.cpp:121] Version: 0.19.0
I0424 05:38:11.477984 19965 sched.cpp:217] New master detected at master@67.195.138.61:47555
I0424 05:38:11.478003 19965 sched.cpp:268] Authenticating with master master@67.195.138.61:47555
I0424 05:38:11.478063 19971 authenticatee.hpp:128] Creating new client SASL connection
I0424 05:38:11.478183 19965 master.cpp:2715] Authenticating framework at scheduler(132)@67.195.138.61:47555
I0424 05:38:11.478245 19971 authenticator.hpp:148] Creating new server SASL connection
I0424 05:38:11.478346 19965 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0424 05:38:11.478364 19965 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0424 05:38:11.478396 19965 authenticator.hpp:254] Received SASL authentication start
I0424 05:38:11.478425 19965 authenticator.hpp:342] Authentication requires more steps
I0424 05:38:11.478456 19965 authenticatee.hpp:265] Received SASL authentication step
I0424 05:38:11.478498 19965 authenticator.hpp:282] Received SASL authentication step
I0424 05:38:11.478518 19965 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0424 05:38:11.478526 19965 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0424 05:38:11.478538 19965 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0424 05:38:11.478549 19965 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0424 05:38:11.478555 19965 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0424 05:38:11.478562 19965 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0424 05:38:11.478575 19965 authenticator.hpp:334] Authentication success
I0424 05:38:11.478608 19971 authenticatee.hpp:305] Authentication success
I0424 05:38:11.478622 19965 master.cpp:2755] Successfully authenticated framework at scheduler(132)@67.195.138.61:47555
I0424 05:38:11.478744 19971 sched.cpp:342] Successfully authenticated with master master@67.195.138.61:47555
I0424 05:38:11.478759 19971 sched.cpp:461] Sending registration request to master@67.195.138.61:47555
I0424 05:38:11.478832 19966 master.cpp:997] Received registration request from scheduler(132)@67.195.138.61:47555
I0424 05:38:11.478864 19966 master.cpp:1015] Registering framework 20140424-053811-1032504131-47555-19839-0000 at scheduler(132)@67.195.138.61:47555
I0424 05:38:11.478924 19971 sched.cpp:392] Framework registered with 20140424-053811-1032504131-47555-19839-0000
I0424 05:38:11.478957 19971 sched.cpp:406] Scheduler::registered took 21315ns
I0424 05:38:11.479013 19971 hierarchical_allocator_process.hpp:332] Added framework 20140424-053811-1032504131-47555-19839-0000
I0424 05:38:11.479089 19971 hierarchical_allocator_process.hpp:752] Offering cpus(role1):2; mem(role1):1024; disk(role1):0; ports(role1):[31000-32000] on slave 20140424-053811-1032504131-47555-19839-0 to framework 20140424-053811-1032504131-47555-19839-0000
I0424 05:38:11.479157 19971 hierarchical_allocator_process.hpp:752] Offering cpus(*):1; mem(*):1024; disk(*):0; ports(*):[31000-32000] on slave 20140424-053811-1032504131-47555-19839-1 to framework 20140424-053811-1032504131-47555-19839-0000
I0424 05:38:11.479334 19971 hierarchical_allocator_process.hpp:688] Performed allocation for 4 slaves in 303552ns
I0424 05:38:11.479380 19966 master.hpp:524] Adding offer 20140424-053811-1032504131-47555-19839-0 with resources cpus(*):1; mem(*):1024; disk(*):0; ports(*):[31000-32000] on slave 20140424-053811-1032504131-47555-19839-1 (juno.apache.org)
I0424 05:38:11.479487 19966 master.hpp:524] Adding offer 20140424-053811-1032504131-47555-19839-1 with resources cpus(role1):2; mem(role1):1024; disk(role1):0; ports(role1):[31000-32000] on slave 20140424-053811-1032504131-47555-19839-0 (juno.apache.org)
I0424 05:38:11.479537 19966 master.cpp:2676] Sending 2 offers to framework 20140424-053811-1032504131-47555-19839-0000
I0424 05:38:11.479764 19972 sched.cpp:529] Scheduler::resourceOffers took 24914ns
I0424 05:38:11.481042 19839 sched.cpp:121] Version: 0.19.0
I0424 05:38:11.481204 19971 sched.cpp:217] New master detected at master@67.195.138.61:47555
I0424 05:38:11.481222 19971 sched.cpp:268] Authenticating with master master@67.195.138.61:47555
I0424 05:38:11.481271 19965 authenticatee.hpp:128] Creating new client SASL connection
I0424 05:38:11.481413 19972 master.cpp:2715] Authenticating framework at scheduler(133)@67.195.138.61:47555
I0424 05:38:11.481509 19968 authenticator.hpp:148] Creating new server SASL connection
I0424 05:38:11.481611 19965 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0424 05:38:11.481627 19965 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0424 05:38:11.481657 19965 authenticator.hpp:254] Received SASL authentication start
I0424 05:38:11.481683 19965 authenticator.hpp:342] Authentication requires more steps
I0424 05:38:11.481720 19965 authenticatee.hpp:265] Received SASL authentication step
I0424 05:38:11.481757 19965 authenticator.hpp:282] Received SASL authentication step
I0424 05:38:11.481773 19965 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0424 05:38:11.481781 19965 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0424 05:38:11.481791 19965 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0424 05:38:11.481801 19965 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0424 05:38:11.481807 19965 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0424 05:38:11.481813 19965 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0424 05:38:11.481824 19965 authenticator.hpp:334] Authentication success
I0424 05:38:11.481875 19970 authenticatee.hpp:305] Authentication success
I0424 05:38:11.481883 19965 master.cpp:2755] Successfully authenticated framework at scheduler(133)@67.195.138.61:47555
I0424 05:38:11.481992 19970 sched.cpp:342] Successfully authenticated with master master@67.195.138.61:47555
I0424 05:38:11.482009 19970 sched.cpp:461] Sending registration request to master@67.195.138.61:47555
I0424 05:38:11.482072 19971 master.cpp:997] Received registration request from scheduler(133)@67.195.138.61:47555
I0424 05:38:11.482120 19971 master.cpp:1015] Registering framework 20140424-053811-1032504131-47555-19839-0001 at scheduler(133)@67.195.138.61:47555
I0424 05:38:11.482188 19970 sched.cpp:392] Framework registered with 20140424-053811-1032504131-47555-19839-0001
I0424 05:38:11.482214 19970 sched.cpp:406] Scheduler::registered took 10509ns
I0424 05:38:11.482239 19968 hierarchical_allocator_process.hpp:332] Added framework 20140424-053811-1032504131-47555-19839-0001
I0424 05:38:11.482290 19968 hierarchical_allocator_process.hpp:752] Offering cpus(role2):2; mem(role2):1024 on slave 20140424-053811-1032504131-47555-19839-1 to framework 20140424-053811-1032504131-47555-19839-0001
I0424 05:38:11.482365 19968 hierarchical_allocator_process.hpp:688] Performed allocation for 4 slaves in 109643ns
I0424 05:38:11.482386 19971 master.hpp:524] Adding offer 20140424-053811-1032504131-47555-19839-2 with resources cpus(role2):2; mem(role2):1024 on slave 20140424-053811-1032504131-47555-19839-1 (juno.apache.org)
I0424 05:38:11.482432 19971 master.cpp:2676] Sending 1 offers to framework 20140424-053811-1032504131-47555-19839-0001
I0424 05:38:11.482529 19971 sched.cpp:529] Scheduler::resourceOffers took 18740ns
I0424 05:38:11.483383 19967 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 7.260898ms
I0424 05:38:11.483402 19967 replica.cpp:664] Persisted action at 6
I0424 05:38:11.483660 19972 replica.cpp:643] Replica received learned notice for position 6
I0424 05:38:11.483906 19839 sched.cpp:121] Version: 0.19.0
I0424 05:38:11.484030 19967 sched.cpp:217] New master detected at master@67.195.138.61:47555
I0424 05:38:11.484050 19967 sched.cpp:268] Authenticating with master master@67.195.138.61:47555
I0424 05:38:11.484122 19971 authenticatee.hpp:128] Creating new client SASL connection
I0424 05:38:11.484249 19968 master.cpp:2715] Authenticating framework at scheduler(134)@67.195.138.61:47555
I0424 05:38:11.484315 19971 authenticator.hpp:148] Creating new server SASL connection
I0424 05:38:11.484441 19971 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0424 05:38:11.484459 19971 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0424 05:38:11.484489 19971 authenticator.hpp:254] Received SASL authentication start
I0424 05:38:11.484516 19971 authenticator.hpp:342] Authentication requires more steps
I0424 05:38:11.484546 19971 authenticatee.hpp:265] Received SASL authentication step
I0424 05:38:11.484587 19971 authenticator.hpp:282] Received SASL authentication step
I0424 05:38:11.484606 19971 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0424 05:38:11.484614 19971 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0424 05:38:11.484623 19971 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0424 05:38:11.484634 19971 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0424 05:38:11.484642 19971 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0424 05:38:11.484648 19971 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0424 05:38:11.484660 19971 authenticator.hpp:334] Authentication success
I0424 05:38:11.484696 19971 authenticatee.hpp:305] Authentication success
I0424 05:38:11.484733 19970 master.cpp:2755] Successfully authenticated framework at scheduler(134)@67.195.138.61:47555
I0424 05:38:11.484794 19971 sched.cpp:342] Successfully authenticated with master master@67.195.138.61:47555
I0424 05:38:11.484829 19971 sched.cpp:461] Sending registration request to master@67.195.138.61:47555
I0424 05:38:11.484871 19970 master.cpp:997] Received registration request from scheduler(134)@67.195.138.61:47555
I0424 05:38:11.484902 19970 master.cpp:1015] Registering framework 20140424-053811-1032504131-47555-19839-0002 at scheduler(134)@67.195.138.61:47555
I0424 05:38:11.484972 19966 sched.cpp:392] Framework registered with 20140424-053811-1032504131-47555-19839-0002
I0424 05:38:11.485014 19970 hierarchical_allocator_process.hpp:332] Added framework 20140424-053811-1032504131-47555-19839-0002
I0424 05:38:11.485054 19966 sched.cpp:406] Scheduler::registered took 68586ns
I0424 05:38:11.485090 19970 hierarchical_allocator_process.hpp:752] Offering cpus(role3):4; mem(role3):4096; disk(role3):0; ports(role3):[31000-32000] on slave 20140424-053811-1032504131-47555-19839-2 to framework 20140424-053811-1032504131-47555-19839-0002
I0424 05:38:11.485206 19970 hierarchical_allocator_process.hpp:688] Performed allocation for 4 slaves in 179246ns
I0424 05:38:11.485229 19966 master.hpp:524] Adding offer 20140424-053811-1032504131-47555-19839-3 with resources cpus(role3):4; mem(role3):4096; disk(role3):0; ports(role3):[31000-32000] on slave 20140424-053811-1032504131-47555-19839-2 (juno.apache.org)
I0424 05:38:11.485281 19966 master.cpp:2676] Sending 1 offers to framework 20140424-053811-1032504131-47555-19839-0002
I0424 05:38:11.485378 19970 sched.cpp:529] Scheduler::resourceOffers took 17642ns
I0424 05:38:11.487298 19969 slave.cpp:130] Slave started on 142)@67.195.138.61:47555
I0424 05:38:11.487408 19969 slave.cpp:218] Slave resources: cpus(role1):1; mem(role1):512; disk(role1):0; ports(role1):[31000-32000]
I0424 05:38:11.487478 19969 slave.cpp:246] Slave hostname: juno.apache.org
I0424 05:38:11.487489 19969 slave.cpp:247] Slave checkpoint: false
I0424 05:38:11.487939 19966 state.cpp:33] Recovering state from '/tmp/ReservationAllocatorTest_ReservedResources_yiwJGU/meta'
I0424 05:38:11.488044 19971 status_update_manager.cpp:193] Recovering status update manager
I0424 05:38:11.488164 19971 slave.cpp:2802] Finished recovery
I0424 05:38:11.488396 19971 slave.cpp:497] New master detected at master@67.195.138.61:47555
I0424 05:38:11.488441 19971 slave.cpp:731] Will retry registration in 6.38259785secs if necessary
I0424 05:38:11.488463 19971 slave.cpp:522] Detecting new master
I0424 05:38:11.488499 19971 status_update_manager.cpp:167] New master detected at master@67.195.138.61:47555
I0424 05:38:11.488662 19971 registrar.cpp:388] Attempting to update the 'registry'
I0424 05:38:11.491710 19972 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 8.036935ms
I0424 05:38:11.491747 19972 leveldb.cpp:399] Deleting ~2 keys from leveldb took 17606ns
I0424 05:38:11.491757 19972 replica.cpp:664] Persisted action at 6
I0424 05:38:11.491766 19972 replica.cpp:649] Replica learned TRUNCATE action at position 6
I0424 05:38:11.492063 19965 log.cpp:680] Attempting to append 1195 bytes to the log
I0424 05:38:11.492133 19967 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 7
I0424 05:38:11.492475 19967 replica.cpp:508] Replica received write request for position 7
I0424 05:38:11.560897 19967 leveldb.cpp:341] Persisting action (1214 bytes) to leveldb took 68.40271ms
I0424 05:38:11.560919 19967 replica.cpp:664] Persisted action at 7
I0424 05:38:11.561200 19965 replica.cpp:643] Replica received learned notice for position 7
I0424 05:38:11.570550 19965 leveldb.cpp:341] Persisting action (1216 bytes) to leveldb took 9.325538ms
I0424 05:38:11.570572 19965 replica.cpp:664] Persisted action at 7
I0424 05:38:11.570581 19965 replica.cpp:649] Replica learned APPEND action at position 7
I0424 05:38:11.571058 19965 registrar.cpp:436] Successfully updated 'registry'
I0424 05:38:11.571228 19972 master.cpp:2150] Admitted slave on juno.apache.org at slave(142)@67.195.138.61:47555
I0424 05:38:11.571241 19971 log.cpp:699] Attempting to truncate the log to 7
I0424 05:38:11.571246 19972 master.cpp:3204] Adding slave 20140424-053811-1032504131-47555-19839-4 at juno.apache.org with cpus(role1):1; mem(role1):512; disk(role1):0; ports(role1):[31000-32000]
I0424 05:38:11.571338 19967 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 8
I0424 05:38:11.571379 19968 slave.cpp:540] Registered with master master@67.195.138.61:47555; given slave ID 20140424-053811-1032504131-47555-19839-4
I0424 05:38:11.571570 19965 hierarchical_allocator_process.hpp:445] Added slave 20140424-053811-1032504131-47555-19839-4 (juno.apache.org) with cpus(role1):1; mem(role1):512; disk(role1):0; ports(role1):[31000-32000] (and cpus(role1):1; mem(role1):512; disk(role1):0; ports(role1):[31000-32000] available)
I0424 05:38:11.571660 19970 replica.cpp:508] Replica received write request for position 8
I0424 05:38:11.571670 19965 hierarchical_allocator_process.hpp:752] Offering cpus(role1):1; mem(role1):512; disk(role1):0; ports(role1):[31000-32000] on slave 20140424-053811-1032504131-47555-19839-4 to framework 20140424-053811-1032504131-47555-19839-0000
I0424 05:38:11.571753 19965 hierarchical_allocator_process.hpp:708] Performed allocation for slave 20140424-053811-1032504131-47555-19839-4 in 146001ns
I0424 05:38:11.571854 19968 master.hpp:524] Adding offer 20140424-053811-1032504131-47555-19839-4 with resources cpus(role1):1; mem(role1):512; disk(role1):0; ports(role1):[31000-32000] on slave 20140424-053811-1032504131-47555-19839-4 (juno.apache.org)
I0424 05:38:11.571909 19968 master.cpp:2676] Sending 1 offers to framework 20140424-053811-1032504131-47555-19839-0000
I0424 05:38:11.572064 19966 sched.cpp:529] Scheduler::resourceOffers took 21329ns
I0424 05:38:11.572268 19972 sched.cpp:731] Stopping framework '20140424-053811-1032504131-47555-19839-0002'
I0424 05:38:11.572295 19968 sched.cpp:731] Stopping framework '20140424-053811-1032504131-47555-19839-0000'
I0424 05:38:11.572314 19967 sched.cpp:731] Stopping framework '20140424-053811-1032504131-47555-19839-0001'
I0424 05:38:11.572336 19965 master.cpp:573] Master terminating
I0424 05:38:11.572414 19965 master.hpp:534] Removing offer 20140424-053811-1032504131-47555-19839-3 with resources cpus(role3):4; mem(role3):4096; disk(role3):0; ports(role3):[31000-32000] on slave 20140424-053811-1032504131-47555-19839-2 (juno.apache.org)
I0424 05:38:11.572491 19965 master.hpp:534] Removing offer 20140424-053811-1032504131-47555-19839-2 with resources cpus(role2):2; mem(role2):1024 on slave 20140424-053811-1032504131-47555-19839-1 (juno.apache.org)
I0424 05:38:11.572588 19965 master.hpp:534] Removing offer 20140424-053811-1032504131-47555-19839-4 with resources cpus(role1):1; mem(role1):512; disk(role1):0; ports(role1):[31000-32000] on slave 20140424-053811-1032504131-47555-19839-4 (juno.apache.org)
I0424 05:38:11.572669 19965 master.hpp:534] Removing offer 20140424-053811-1032504131-47555-19839-1 with resources cpus(role1):2; mem(role1):1024; disk(role1):0; ports(role1):[31000-32000] on slave 20140424-053811-1032504131-47555-19839-0 (juno.apache.org)
I0424 05:38:11.572738 19965 master.hpp:534] Removing offer 20140424-053811-1032504131-47555-19839-0 with resources cpus(*):1; mem(*):1024; disk(*):0; ports(*):[31000-32000] on slave 20140424-053811-1032504131-47555-19839-1 (juno.apache.org)
I0424 05:38:11.573129 19965 slave.cpp:2010] master@67.195.138.61:47555 exited
W0424 05:38:11.573151 19965 slave.cpp:2013] Master disconnected! Waiting for a new master to be elected
I0424 05:38:11.573160 19972 slave.cpp:2010] master@67.195.138.61:47555 exited
W0424 05:38:11.573176 19972 slave.cpp:2013] Master disconnected! Waiting for a new master to be elected
I0424 05:38:11.573201 19969 slave.cpp:2010] master@67.195.138.61:47555 exited
I0424 05:38:11.573133 19966 slave.cpp:2010] master@67.195.138.61:47555 exited
I0424 05:38:11.573215 19968 slave.cpp:2010] master@67.195.138.61:47555 exited
W0424 05:38:11.573230 19968 slave.cpp:2013] Master disconnected! Waiting for a new master to be elected
W0424 05:38:11.573231 19966 slave.cpp:2013] Master disconnected! Waiting for a new master to be elected
W0424 05:38:11.573215 19969 slave.cpp:2013] Master disconnected! Waiting for a new master to be elected
I0424 05:38:11.578887 19970 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 7.203859ms
I0424 05:38:11.578907 19970 replica.cpp:664] Persisted action at 8
I0424 05:38:11.579386 19839 slave.cpp:387] Slave terminating
I0424 05:38:11.579692 19839 slave.cpp:387] Slave terminating
I0424 05:38:11.579974 19839 slave.cpp:387] Slave terminating
I0424 05:38:11.580167 19839 slave.cpp:387] Slave terminating
I0424 05:38:11.580375 19839 slave.cpp:387] Slave terminating
[ OK ] ReservationAllocatorTest.ReservedResources (569 ms)
[----------] 2 tests from ReservationAllocatorTest (1013 ms total)
[----------] Global test environment tear-down
[==========] 258 tests from 43 test cases ran. (185455 ms total)
[ PASSED ] 257 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] MasterTest.MetricsInStatsEndpoint
1 FAILED TEST
YOU HAVE 1 DISABLED TEST
make[3]: *** [check-local] Error 1
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
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal :
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2084
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/2084/changes>
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2083
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/2083/changes>
Changes:
[benjamin.hindman] Cleanups in configure.ac for libjvm detection.
------------------------------------------
[...truncated 35459 lines...]
I0424 17:53:59.611883 15029 status_update_manager.cpp:167] New master detected at master@67.195.138.61:42677
I0424 17:53:59.612136 15029 registrar.cpp:388] Attempting to update the 'registry'
I0424 17:53:59.612213 14944 sched.cpp:121] Version: 0.19.0
I0424 17:53:59.612607 15032 sched.cpp:217] New master detected at master@67.195.138.61:42677
I0424 17:53:59.612628 15032 sched.cpp:268] Authenticating with master master@67.195.138.61:42677
I0424 17:53:59.612747 15030 authenticatee.hpp:128] Creating new client SASL connection
I0424 17:53:59.613092 15032 master.cpp:2715] Authenticating framework at scheduler(134)@67.195.138.61:42677
I0424 17:53:59.613188 15033 authenticator.hpp:148] Creating new server SASL connection
I0424 17:53:59.613333 15032 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0424 17:53:59.613361 15032 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0424 17:53:59.613421 15032 authenticator.hpp:254] Received SASL authentication start
I0424 17:53:59.613466 15032 authenticator.hpp:342] Authentication requires more steps
I0424 17:53:59.613531 15033 authenticatee.hpp:265] Received SASL authentication step
I0424 17:53:59.613629 15029 authenticator.hpp:282] Received SASL authentication step
I0424 17:53:59.613662 15029 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0424 17:53:59.613670 15029 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0424 17:53:59.613682 15029 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0424 17:53:59.613693 15029 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0424 17:53:59.613700 15029 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0424 17:53:59.613705 15029 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0424 17:53:59.613723 15029 authenticator.hpp:334] Authentication success
I0424 17:53:59.613770 15032 authenticatee.hpp:305] Authentication success
I0424 17:53:59.613795 15029 master.cpp:2755] Successfully authenticated framework at scheduler(134)@67.195.138.61:42677
I0424 17:53:59.613919 15032 sched.cpp:342] Successfully authenticated with master master@67.195.138.61:42677
I0424 17:53:59.613940 15032 sched.cpp:461] Sending registration request to master@67.195.138.61:42677
I0424 17:53:59.614038 15029 master.cpp:997] Received registration request from scheduler(134)@67.195.138.61:42677
I0424 17:53:59.614078 15029 master.cpp:1015] Registering framework 20140424-175359-1032504131-42677-14944-0000 at scheduler(134)@67.195.138.61:42677
I0424 17:53:59.614189 15026 sched.cpp:392] Framework registered with 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.614217 15026 sched.cpp:406] Scheduler::registered took 13920ns
I0424 17:53:59.614249 15027 hierarchical_allocator_process.hpp:332] Added framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.614264 15027 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I0424 17:53:59.614269 15027 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 7116ns
I0424 17:53:59.624558 15029 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I0424 17:53:59.624573 15029 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 20612ns
I0424 17:53:59.649266 15028 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.522976ms
I0424 17:53:59.649335 15028 replica.cpp:664] Persisted action at 2
I0424 17:53:59.649665 15028 replica.cpp:643] Replica received learned notice for position 2
I0424 17:53:59.659700 15028 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 10.008698ms
I0424 17:53:59.659773 15028 leveldb.cpp:399] Deleting ~1 keys from leveldb took 25421ns
I0424 17:53:59.659785 15028 replica.cpp:664] Persisted action at 2
I0424 17:53:59.659795 15028 replica.cpp:649] Replica learned TRUNCATE action at position 2
I0424 17:53:59.660099 15028 log.cpp:680] Attempting to append 328 bytes to the log
I0424 17:53:59.660140 15028 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 3
I0424 17:53:59.660415 15028 replica.cpp:508] Replica received write request for position 3
I0424 17:53:59.673882 15028 leveldb.cpp:341] Persisting action (347 bytes) to leveldb took 13.437307ms
I0424 17:53:59.673939 15028 replica.cpp:664] Persisted action at 3
I0424 17:53:59.674322 15028 replica.cpp:643] Replica received learned notice for position 3
I0424 17:53:59.674695 15030 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I0424 17:53:59.674707 15030 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 15959ns
I0424 17:53:59.715523 15028 leveldb.cpp:341] Persisting action (349 bytes) to leveldb took 41.18326ms
I0424 17:53:59.715560 15028 replica.cpp:664] Persisted action at 3
I0424 17:53:59.715570 15028 replica.cpp:649] Replica learned APPEND action at position 3
I0424 17:53:59.716306 15032 registrar.cpp:436] Successfully updated 'registry'
I0424 17:53:59.716405 15030 log.cpp:699] Attempting to truncate the log to 3
I0424 17:53:59.716456 15030 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 4
I0424 17:53:59.716724 15030 replica.cpp:508] Replica received write request for position 4
I0424 17:53:59.716930 15032 master.cpp:2150] Admitted slave on juno.apache.org at slave(142)@67.195.138.61:42677
I0424 17:53:59.716951 15032 master.cpp:3204] Adding slave 20140424-175359-1032504131-42677-14944-0 at juno.apache.org with cpus(*):3; mem(*):1024; disk(*):23038; ports(*):[31000-32000]
I0424 17:53:59.717094 15032 slave.cpp:540] Registered with master master@67.195.138.61:42677; given slave ID 20140424-175359-1032504131-42677-14944-0
I0424 17:53:59.717232 15032 hierarchical_allocator_process.hpp:445] Added slave 20140424-175359-1032504131-42677-14944-0 (juno.apache.org) with cpus(*):3; mem(*):1024; disk(*):23038; ports(*):[31000-32000] (and cpus(*):3; mem(*):1024; disk(*):23038; ports(*):[31000-32000] available)
I0424 17:53:59.717296 15032 hierarchical_allocator_process.hpp:752] Offering cpus(*):3; mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave 20140424-175359-1032504131-42677-14944-0 to framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.717422 15032 hierarchical_allocator_process.hpp:708] Performed allocation for slave 20140424-175359-1032504131-42677-14944-0 in 150789ns
I0424 17:53:59.717492 15032 master.hpp:524] Adding offer 20140424-175359-1032504131-42677-14944-0 with resources cpus(*):3; mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave 20140424-175359-1032504131-42677-14944-0 (juno.apache.org)
I0424 17:53:59.717537 15032 master.cpp:2676] Sending 1 offers to framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.717881 15032 sched.cpp:529] Scheduler::resourceOffers took 211426ns
W0424 17:53:59.717936 15032 sched.cpp:902] Attempting to launch task 1 with an unknown offer 20140424-175359-1032504131-42677-14944-0
I0424 17:53:59.718089 15032 master.hpp:534] Removing offer 20140424-175359-1032504131-42677-14944-0 with resources cpus(*):3; mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave 20140424-175359-1032504131-42677-14944-0 (juno.apache.org)
I0424 17:53:59.718142 15032 master.cpp:1815] Processing reply for offers: [ 20140424-175359-1032504131-42677-14944-0 ] on slave 20140424-175359-1032504131-42677-14944-0 (juno.apache.org) for framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.718209 15032 master.hpp:496] Adding task 0 with resources cpus(*):1; mem(*):256 on slave 20140424-175359-1032504131-42677-14944-0 (juno.apache.org)
I0424 17:53:59.718240 15032 master.cpp:2839] Launching task 0 of framework 20140424-175359-1032504131-42677-14944-0000 with resources cpus(*):1; mem(*):256 on slave 20140424-175359-1032504131-42677-14944-0 (juno.apache.org)
I0424 17:53:59.718330 15032 master.hpp:496] Adding task 1 with resources cpus(*):1; mem(*):256 on slave 20140424-175359-1032504131-42677-14944-0 (juno.apache.org)
I0424 17:53:59.718364 15032 master.cpp:2839] Launching task 1 of framework 20140424-175359-1032504131-42677-14944-0000 with resources cpus(*):1; mem(*):256 on slave 20140424-175359-1032504131-42677-14944-0 (juno.apache.org)
I0424 17:53:59.718493 15032 slave.cpp:765] Got assigned task 0 for framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.718686 15032 slave.cpp:765] Got assigned task 1 for framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.718794 15032 slave.cpp:874] Launching task 0 for framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.720613 15027 hierarchical_allocator_process.hpp:547] Framework 20140424-175359-1032504131-42677-14944-0000 left cpus(*):1; mem(*):512; disk(*):23038; ports(*):[31000-32000] unused on slave 20140424-175359-1032504131-42677-14944-0
I0424 17:53:59.720798 15027 hierarchical_allocator_process.hpp:590] Framework 20140424-175359-1032504131-42677-14944-0000 filtered slave 20140424-175359-1032504131-42677-14944-0 for 5secs
I0424 17:53:59.720924 15032 exec.cpp:131] Version: 0.19.0
I0424 17:53:59.721012 15028 exec.cpp:181] Executor started at: executor(45)@67.195.138.61:42677 with pid 14944
I0424 17:53:59.721065 15032 slave.cpp:984] Queuing task '0' for executor default of framework '20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.721106 15032 slave.cpp:874] Launching task 1 for framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.721118 15032 slave.cpp:984] Queuing task '1' for executor default of framework '20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.721143 15032 slave.cpp:458] Successfully attached file '/tmp/AllocatorTest_0_TaskFinished_wOL6c6/slaves/20140424-175359-1032504131-42677-14944-0/frameworks/20140424-175359-1032504131-42677-14944-0000/executors/default/runs/cb16b2fa-28c2-46dc-9b7c-4d6ba1371e14'
I0424 17:53:59.721165 15032 slave.cpp:2141] Monitoring executor 'default' of framework '20140424-175359-1032504131-42677-14944-0000' in container 'cb16b2fa-28c2-46dc-9b7c-4d6ba1371e14'
I0424 17:53:59.721258 15032 slave.cpp:1457] Got registration for executor 'default' of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.721436 15032 slave.cpp:1576] Flushing queued task 0 for executor 'default' of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.721472 15032 slave.cpp:1576] Flushing queued task 1 for executor 'default' of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.721477 15026 exec.cpp:205] Executor registered on slave 20140424-175359-1032504131-42677-14944-0
I0424 17:53:59.722453 15026 exec.cpp:217] Executor::registered took 13985ns
I0424 17:53:59.722533 15026 exec.cpp:292] Executor asked to run task '0'
I0424 17:53:59.722601 15026 exec.cpp:301] Executor::launchTask took 50287ns
I0424 17:53:59.722666 15026 exec.cpp:292] Executor asked to run task '1'
I0424 17:53:59.722739 15026 exec.cpp:301] Executor::launchTask took 55741ns
I0424 17:53:59.723701 15026 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 9f2fe23a-fb33-48c9-80bf-308ea4790de7) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.723832 15028 slave.cpp:1812] Handling status update TASK_RUNNING (UUID: 9f2fe23a-fb33-48c9-80bf-308ea4790de7) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000 from executor(45)@67.195.138.61:42677
I0424 17:53:59.723953 15028 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 9f2fe23a-fb33-48c9-80bf-308ea4790de7) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.723970 15028 status_update_manager.cpp:499] Creating StatusUpdate stream for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.724051 15028 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: 9f2fe23a-fb33-48c9-80bf-308ea4790de7) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000 to master@67.195.138.61:42677
I0424 17:53:59.724174 15028 master.cpp:2382] Status update TASK_RUNNING (UUID: 9f2fe23a-fb33-48c9-80bf-308ea4790de7) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000 from slave(142)@67.195.138.61:42677
I0424 17:53:59.724206 15028 slave.cpp:1929] Status update manager successfully handled status update TASK_RUNNING (UUID: 9f2fe23a-fb33-48c9-80bf-308ea4790de7) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.724215 15028 slave.cpp:1935] Sending acknowledgement for status update TASK_RUNNING (UUID: 9f2fe23a-fb33-48c9-80bf-308ea4790de7) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000 to executor(45)@67.195.138.61:42677
I0424 17:53:59.724274 15028 sched.cpp:620] Scheduler::statusUpdate took 14099ns
I0424 17:53:59.724428 15028 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 9f2fe23a-fb33-48c9-80bf-308ea4790de7) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.724479 15028 slave.cpp:1397] Status update manager successfully handled status update acknowledgement (UUID: 9f2fe23a-fb33-48c9-80bf-308ea4790de7) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.724825 15026 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: a297df10-a6e6-436a-b19c-c407689d6fe4) for task 1 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.724946 15033 slave.cpp:1812] Handling status update TASK_RUNNING (UUID: a297df10-a6e6-436a-b19c-c407689d6fe4) for task 1 of framework 20140424-175359-1032504131-42677-14944-0000 from executor(45)@67.195.138.61:42677
I0424 17:53:59.725054 15033 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: a297df10-a6e6-436a-b19c-c407689d6fe4) for task 1 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.725071 15033 status_update_manager.cpp:499] Creating StatusUpdate stream for task 1 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.725149 15033 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: a297df10-a6e6-436a-b19c-c407689d6fe4) for task 1 of framework 20140424-175359-1032504131-42677-14944-0000 to master@67.195.138.61:42677
I0424 17:53:59.725262 15027 master.cpp:2382] Status update TASK_RUNNING (UUID: a297df10-a6e6-436a-b19c-c407689d6fe4) for task 1 of framework 20140424-175359-1032504131-42677-14944-0000 from slave(142)@67.195.138.61:42677
I0424 17:53:59.725344 15027 hierarchical_allocator_process.hpp:835] Filtered cpus(*):1; mem(*):512; disk(*):23038; ports(*):[31000-32000] on slave 20140424-175359-1032504131-42677-14944-0 for framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.725371 15027 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 72985ns
I0424 17:53:59.725440 15027 sched.cpp:620] Scheduler::statusUpdate took 10269ns
I0424 17:53:59.725627 15033 status_update_manager.cpp:398] Received status update acknowledgement (UUID: a297df10-a6e6-436a-b19c-c407689d6fe4) for task 1 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.725698 15029 slave.cpp:1929] Status update manager successfully handled status update TASK_RUNNING (UUID: a297df10-a6e6-436a-b19c-c407689d6fe4) for task 1 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.725715 15029 slave.cpp:1935] Sending acknowledgement for status update TASK_RUNNING (UUID: a297df10-a6e6-436a-b19c-c407689d6fe4) for task 1 of framework 20140424-175359-1032504131-42677-14944-0000 to executor(45)@67.195.138.61:42677
I0424 17:53:59.725755 15029 slave.cpp:1397] Status update manager successfully handled status update acknowledgement (UUID: a297df10-a6e6-436a-b19c-c407689d6fe4) for task 1 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.725913 15026 exec.cpp:524] Executor sending status update TASK_FINISHED (UUID: 78334139-8992-4614-b365-0cf523d23e97) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.725970 15026 exec.cpp:338] Executor received status update acknowledgement 9f2fe23a-fb33-48c9-80bf-308ea4790de7 for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.726011 15026 exec.cpp:338] Executor received status update acknowledgement a297df10-a6e6-436a-b19c-c407689d6fe4 for task 1 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.726021 15032 slave.cpp:1812] Handling status update TASK_FINISHED (UUID: 78334139-8992-4614-b365-0cf523d23e97) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000 from executor(45)@67.195.138.61:42677
I0424 17:53:59.726038 15032 slave.cpp:3303] Terminating task 0
I0424 17:53:59.726124 15032 status_update_manager.cpp:320] Received status update TASK_FINISHED (UUID: 78334139-8992-4614-b365-0cf523d23e97) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.726141 15032 status_update_manager.cpp:373] Forwarding status update TASK_FINISHED (UUID: 78334139-8992-4614-b365-0cf523d23e97) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000 to master@67.195.138.61:42677
I0424 17:53:59.726230 15032 master.cpp:2382] Status update TASK_FINISHED (UUID: 78334139-8992-4614-b365-0cf523d23e97) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000 from slave(142)@67.195.138.61:42677
I0424 17:53:59.726265 15032 master.hpp:514] Removing task 0 with resources cpus(*):1; mem(*):256 on slave 20140424-175359-1032504131-42677-14944-0 (juno.apache.org)
I0424 17:53:59.726322 15032 slave.cpp:1929] Status update manager successfully handled status update TASK_FINISHED (UUID: 78334139-8992-4614-b365-0cf523d23e97) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.726333 15032 slave.cpp:1935] Sending acknowledgement for status update TASK_FINISHED (UUID: 78334139-8992-4614-b365-0cf523d23e97) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000 to executor(45)@67.195.138.61:42677
I0424 17:53:59.726383 15032 sched.cpp:620] Scheduler::statusUpdate took 6797ns
I0424 17:53:59.726466 15032 exec.cpp:338] Executor received status update acknowledgement 78334139-8992-4614-b365-0cf523d23e97 for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.726559 15032 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):256 (total allocatable: cpus(*):2; mem(*):768; disk(*):23038; ports(*):[31000-32000]) on slave 20140424-175359-1032504131-42677-14944-0 from framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.726588 15032 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 78334139-8992-4614-b365-0cf523d23e97) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.726603 15032 status_update_manager.cpp:530] Cleaning up status update stream for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.726656 15032 slave.cpp:1397] Status update manager successfully handled status update acknowledgement (UUID: 78334139-8992-4614-b365-0cf523d23e97) for task 0 of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.726668 15032 slave.cpp:3327] Completing task 0
I0424 17:53:59.768754 15030 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 51.988048ms
I0424 17:53:59.768823 15030 replica.cpp:664] Persisted action at 4
I0424 17:53:59.769208 15029 replica.cpp:643] Replica received learned notice for position 4
I0424 17:53:59.775812 15032 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):768; disk(*):23038; ports(*):[31000-32000] on slave 20140424-175359-1032504131-42677-14944-0 to framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.776016 15032 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 278875ns
I0424 17:53:59.776146 15031 master.hpp:524] Adding offer 20140424-175359-1032504131-42677-14944-1 with resources cpus(*):2; mem(*):768; disk(*):23038; ports(*):[31000-32000] on slave 20140424-175359-1032504131-42677-14944-0 (juno.apache.org)
I0424 17:53:59.776242 15031 master.cpp:2676] Sending 1 offers to framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.776458 15032 sched.cpp:529] Scheduler::resourceOffers took 26615ns
I0424 17:53:59.776726 14944 master.cpp:573] Master terminating
I0424 17:53:59.776754 15030 sched.cpp:731] Stopping framework '20140424-175359-1032504131-42677-14944-0000'
I0424 17:53:59.776806 14944 master.hpp:514] Removing task 1 with resources cpus(*):1; mem(*):256 on slave 20140424-175359-1032504131-42677-14944-0 (juno.apache.org)
I0424 17:53:59.776906 14944 master.hpp:534] Removing offer 20140424-175359-1032504131-42677-14944-1 with resources cpus(*):2; mem(*):768; disk(*):23038; ports(*):[31000-32000] on slave 20140424-175359-1032504131-42677-14944-0 (juno.apache.org)
I0424 17:53:59.777055 15027 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):256 (total allocatable: cpus(*):1; mem(*):256) on slave 20140424-175359-1032504131-42677-14944-0 from framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.777129 15030 slave.cpp:2010] master@67.195.138.61:42677 exited
W0424 17:53:59.777148 15030 slave.cpp:2013] Master disconnected! Waiting for a new master to be elected
I0424 17:53:59.807171 15029 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 37.925589ms
I0424 17:53:59.807286 15029 leveldb.cpp:399] Deleting ~2 keys from leveldb took 41965ns
I0424 17:53:59.807301 15029 replica.cpp:664] Persisted action at 4
I0424 17:53:59.807312 15029 replica.cpp:649] Replica learned TRUNCATE action at position 4
I0424 17:53:59.807911 14944 slave.cpp:387] Slave terminating
I0424 17:53:59.808006 14944 slave.cpp:1168] Asked to shut down framework 20140424-175359-1032504131-42677-14944-0000 by @0.0.0.0:0
I0424 17:53:59.808023 14944 slave.cpp:1193] Shutting down framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.808038 14944 slave.cpp:2484] Shutting down executor 'default' of framework 20140424-175359-1032504131-42677-14944-0000
I0424 17:53:59.808141 15028 exec.cpp:378] Executor asked to shutdown
I0424 17:53:59.808178 15028 exec.cpp:393] Executor::shutdown took 11936ns
[ OK ] AllocatorTest/0.TaskFinished (715 ms)
[----------] 10 tests from AllocatorTest/0 (6416 ms total)
[----------] 6 tests from FilesTest
[ RUN ] FilesTest.AttachTest
Using temporary directory '/tmp/FilesTest_AttachTest_YVpT4p'
[ OK ] FilesTest.AttachTest (54 ms)
[ RUN ] FilesTest.DetachTest
Using temporary directory '/tmp/FilesTest_DetachTest_qoMH5J'
[ OK ] FilesTest.DetachTest (0 ms)
[ RUN ] FilesTest.ReadTest
Using temporary directory '/tmp/FilesTest_ReadTest_r50z63'
I0424 17:53:59.863067 15028 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.863576 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.863968 15029 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.864322 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.864701 15026 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.865063 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.865610 15031 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.865993 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.866307 15026 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.866718 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.867027 15026 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.867334 15034 process.cpp:1013] Socket closed while receiving
[ OK ] FilesTest.ReadTest (5 ms)
[ RUN ] FilesTest.DownloadTest
Using temporary directory '/tmp/FilesTest_DownloadTest_oVci8n'
I0424 17:53:59.896601 15033 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/download.json'
I0424 17:53:59.896752 15033 process.cpp:1746] Sending file at '/tmp/FilesTest_DownloadTest_oVci8n/binary' with length 17
I0424 17:53:59.897016 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.897624 15030 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/download.json'
I0424 17:53:59.897739 15030 process.cpp:1746] Sending file at '/tmp/FilesTest_DownloadTest_oVci8n/black.gif' with length 42
I0424 17:53:59.897927 15034 process.cpp:1013] Socket closed while receiving
[ OK ] FilesTest.DownloadTest (31 ms)
[ RUN ] FilesTest.BrowseTest
Using temporary directory '/tmp/FilesTest_BrowseTest_IxScfI'
I0424 17:53:59.916050 15029 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0424 17:53:59.916841 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.917245 15029 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0424 17:53:59.917827 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.918242 15026 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0424 17:53:59.919463 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.919854 15033 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0424 17:53:59.920076 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.920518 15029 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0424 17:53:59.920728 15034 process.cpp:1013] Socket closed while receiving
[ OK ] FilesTest.BrowseTest (23 ms)
[ RUN ] FilesTest.ResolveTest
Using temporary directory '/tmp/FilesTest_ResolveTest_EVEYp2'
I0424 17:53:59.922188 15028 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.922535 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.922850 15029 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.923197 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.923499 15030 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.924005 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.924321 15027 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.924732 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.925042 15027 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.925395 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.925698 15029 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.926009 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.926324 15033 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.926556 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.926859 15033 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.927098 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.927459 15028 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.927698 15034 process.cpp:1013] Socket closed while receiving
I0424 17:53:59.928010 15026 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0424 17:53:59.928434 15034 process.cpp:1013] Socket closed while receiving
[ OK ] FilesTest.ResolveTest (7 ms)
[----------] 6 tests from FilesTest (120 ms total)
[----------] Global test environment tear-down
[==========] 258 tests from 43 test cases ran. (299925 ms total)
[ PASSED ] 257 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] MasterTest.MetricsInStatsEndpoint
1 FAILED TEST
YOU HAVE 1 DISABLED TEST
make[3]: *** [check-local] Error 1
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
Build step 'Execute shell' marked build as failure