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/14 09:45:55 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2439
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2439/changes>
Changes:
[adam] NOLINT a few operator overloads, to enable whitespace/operators
[adam] Enabled whitespace/operators rule for cpplint.
[benjamin.hindman] Modify configure.ac to fix --with-sasl.
------------------------------------------
[...truncated 60828 lines...]
I1014 07:45:16.772703 29155 gc.cpp:56] Scheduling '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_Ptf7B0/meta/slaves/20141014-074516-3142697795-60149-29137-0/frameworks/20141014-074516-3142697795-60149-29137-0000' for gc 6.99999105812444days in the future
[ OK ] StatusUpdateManagerTest.DuplicateTerminalUpdateAfterAck (743 ms)
[ RUN ] StatusUpdateManagerTest.CheckpointStatusUpdate
Using temporary directory '/tmp/StatusUpdateManagerTest_CheckpointStatusUpdate_CBiQ2x'
I1014 07:45:16.871641 29137 leveldb.cpp:176] Opened db in 2.303204ms
I1014 07:45:16.872565 29137 leveldb.cpp:183] Compacted db in 896783ns
I1014 07:45:16.872586 29137 leveldb.cpp:198] Created db iterator in 4827ns
I1014 07:45:16.872596 29137 leveldb.cpp:204] Seeked to beginning of db in 610ns
I1014 07:45:16.872609 29137 leveldb.cpp:273] Iterated through 0 keys in the db in 362ns
I1014 07:45:16.872632 29137 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1014 07:45:16.872802 29158 recover.cpp:425] Starting replica recovery
I1014 07:45:16.872874 29158 recover.cpp:451] Replica is in EMPTY status
I1014 07:45:16.873253 29160 replica.cpp:638] Replica in EMPTY status received a broadcasted recover request
I1014 07:45:16.873345 29152 recover.cpp:188] Received a recover response from a replica in EMPTY status
I1014 07:45:16.873622 29163 recover.cpp:542] Updating replica status to STARTING
I1014 07:45:16.874006 29152 master.cpp:312] Master 20141014-074516-3142697795-60149-29137 (pomona.apache.org) started on 67.195.81.187:60149
I1014 07:45:16.874037 29152 master.cpp:358] Master only allowing authenticated frameworks to register
I1014 07:45:16.874044 29152 master.cpp:363] Master only allowing authenticated slaves to register
I1014 07:45:16.874055 29152 credentials.hpp:36] Loading credentials for authentication from '/tmp/StatusUpdateManagerTest_CheckpointStatusUpdate_CBiQ2x/credentials'
I1014 07:45:16.874155 29154 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 452350ns
I1014 07:45:16.874168 29154 replica.cpp:320] Persisted replica status to STARTING
I1014 07:45:16.874172 29152 master.cpp:392] Authorization enabled
I1014 07:45:16.874248 29156 recover.cpp:451] Replica is in STARTING status
I1014 07:45:16.874403 29156 master.cpp:120] No whitelist given. Advertising offers for all slaves
I1014 07:45:16.874400 29154 hierarchical_allocator_process.hpp:299] Initializing hierarchical allocator process with master : master@67.195.81.187:60149
I1014 07:45:16.874639 29164 replica.cpp:638] Replica in STARTING status received a broadcasted recover request
I1014 07:45:16.874743 29152 master.cpp:1242] The newly elected leader is master@67.195.81.187:60149 with id 20141014-074516-3142697795-60149-29137
I1014 07:45:16.874761 29152 master.cpp:1255] Elected as the leading master!
I1014 07:45:16.874770 29152 master.cpp:1073] Recovering from registrar
I1014 07:45:16.874790 29161 recover.cpp:188] Received a recover response from a replica in STARTING status
I1014 07:45:16.874898 29152 recover.cpp:542] Updating replica status to VOTING
I1014 07:45:16.874954 29160 registrar.cpp:313] Recovering registrar
I1014 07:45:16.875218 29153 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 235769ns
I1014 07:45:16.875231 29153 replica.cpp:320] Persisted replica status to VOTING
I1014 07:45:16.875267 29164 recover.cpp:556] Successfully joined the Paxos group
I1014 07:45:16.875347 29164 recover.cpp:440] Recover process terminated
I1014 07:45:16.875480 29166 log.cpp:656] Attempting to start the writer
I1014 07:45:16.875936 29161 replica.cpp:474] Replica received implicit promise request with proposal 1
I1014 07:45:16.876178 29161 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 228853ns
I1014 07:45:16.876191 29161 replica.cpp:342] Persisted promised to 1
I1014 07:45:16.876405 29160 coordinator.cpp:230] Coordinator attemping to fill missing position
I1014 07:45:16.876824 29152 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I1014 07:45:16.877068 29152 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 226122ns
I1014 07:45:16.877080 29152 replica.cpp:676] Persisted action at 0
I1014 07:45:16.877507 29161 replica.cpp:508] Replica received write request for position 0
I1014 07:45:16.877531 29161 leveldb.cpp:438] Reading position from leveldb took 10921ns
I1014 07:45:16.877768 29161 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 222715ns
I1014 07:45:16.877779 29161 replica.cpp:676] Persisted action at 0
I1014 07:45:16.877989 29165 replica.cpp:655] Replica received learned notice for position 0
I1014 07:45:16.878095 29165 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 90495ns
I1014 07:45:16.878108 29165 replica.cpp:676] Persisted action at 0
I1014 07:45:16.878113 29165 replica.cpp:661] Replica learned NOP action at position 0
I1014 07:45:16.878293 29157 log.cpp:672] Writer started with ending position 0
I1014 07:45:16.878598 29154 leveldb.cpp:438] Reading position from leveldb took 10922ns
I1014 07:45:16.879518 29151 registrar.cpp:346] Successfully fetched the registry (0B) in 4.525056ms
I1014 07:45:16.879556 29151 registrar.cpp:445] Applied 1 operations in 2533ns; attempting to update the 'registry'
I1014 07:45:16.880435 29163 log.cpp:680] Attempting to append 139 bytes to the log
I1014 07:45:16.880506 29162 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1
I1014 07:45:16.880759 29161 replica.cpp:508] Replica received write request for position 1
I1014 07:45:16.881000 29161 leveldb.cpp:343] Persisting action (158 bytes) to leveldb took 226553ns
I1014 07:45:16.881012 29161 replica.cpp:676] Persisted action at 1
I1014 07:45:16.881219 29154 replica.cpp:655] Replica received learned notice for position 1
I1014 07:45:16.881321 29154 leveldb.cpp:343] Persisting action (160 bytes) to leveldb took 86086ns
I1014 07:45:16.881333 29154 replica.cpp:676] Persisted action at 1
I1014 07:45:16.881338 29154 replica.cpp:661] Replica learned APPEND action at position 1
I1014 07:45:16.881577 29165 registrar.cpp:490] Successfully updated the 'registry' in 2.003968ms
I1014 07:45:16.881623 29165 registrar.cpp:376] Successfully recovered registrar
I1014 07:45:16.881636 29154 log.cpp:699] Attempting to truncate the log to 1
I1014 07:45:16.881711 29165 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2
I1014 07:45:16.881713 29158 master.cpp:1100] Recovered 0 slaves from the Registry (101B) ; allowing 10mins for slaves to re-register
I1014 07:45:16.881963 29166 replica.cpp:508] Replica received write request for position 2
I1014 07:45:16.882211 29166 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 231219ns
I1014 07:45:16.882225 29166 replica.cpp:676] Persisted action at 2
I1014 07:45:16.882433 29164 replica.cpp:655] Replica received learned notice for position 2
I1014 07:45:16.882669 29164 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 221635ns
I1014 07:45:16.882693 29164 leveldb.cpp:401] Deleting ~1 keys from leveldb took 10955ns
I1014 07:45:16.882699 29164 replica.cpp:676] Persisted action at 2
I1014 07:45:16.882705 29164 replica.cpp:661] Replica learned TRUNCATE action at position 2
I1014 07:45:16.893728 29156 slave.cpp:169] Slave started on 213)@67.195.81.187:60149
I1014 07:45:16.893754 29156 credentials.hpp:84] Loading credential for authentication from '/tmp/StatusUpdateManagerTest_CheckpointStatusUpdate_Dy3lx5/credential'
I1014 07:45:16.893831 29156 slave.cpp:276] Slave using credential for: test-principal
I1014 07:45:16.893920 29156 slave.cpp:289] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1014 07:45:16.893970 29156 slave.cpp:318] Slave hostname: pomona.apache.org
I1014 07:45:16.893977 29156 slave.cpp:319] Slave checkpoint: true
I1014 07:45:16.894261 29159 state.cpp:33] Recovering state from '/tmp/StatusUpdateManagerTest_CheckpointStatusUpdate_Dy3lx5/meta'
I1014 07:45:16.894410 29159 status_update_manager.cpp:193] Recovering status update manager
I1014 07:45:16.894520 29162 slave.cpp:3329] Finished recovery
I1014 07:45:16.894758 29162 slave.cpp:600] New master detected at master@67.195.81.187:60149
I1014 07:45:16.894783 29162 slave.cpp:674] Authenticating with master master@67.195.81.187:60149
I1014 07:45:16.894803 29159 status_update_manager.cpp:167] New master detected at master@67.195.81.187:60149
I1014 07:45:16.894839 29162 slave.cpp:647] Detecting new master
I1014 07:45:16.894860 29164 authenticatee.hpp:133] Creating new client SASL connection
I1014 07:45:16.895792 29137 sched.cpp:137] Version: 0.21.0
I1014 07:45:17.039440 29151 sched.cpp:233] New master detected at master@67.195.81.187:60149
I1014 07:45:17.039440 29162 master.cpp:3787] Authenticating slave(213)@67.195.81.187:60149
I1014 07:45:17.039477 29151 sched.cpp:283] Authenticating with master master@67.195.81.187:60149
I1014 07:45:17.039579 29161 authenticatee.hpp:133] Creating new client SASL connection
I1014 07:45:17.039595 29158 authenticator.hpp:161] Creating new server SASL connection
I1014 07:45:17.039763 29158 authenticatee.hpp:224] Received SASL authentication mechanisms: CRAM-MD5
I1014 07:45:17.039783 29158 authenticatee.hpp:250] Attempting to authenticate with mechanism 'CRAM-MD5'
I1014 07:45:17.039787 29161 master.cpp:3787] Authenticating scheduler-4d3d40bd-4ca3-4998-8479-c86e0f9ba9d2@67.195.81.187:60149
I1014 07:45:17.039821 29158 authenticator.hpp:267] Received SASL authentication start
I1014 07:45:17.039876 29158 authenticator.hpp:389] Authentication requires more steps
I1014 07:45:17.039894 29155 authenticator.hpp:161] Creating new server SASL connection
I1014 07:45:17.039968 29152 authenticatee.hpp:270] Received SASL authentication step
I1014 07:45:17.040444 29154 authenticatee.hpp:224] Received SASL authentication mechanisms: CRAM-MD5
I1014 07:45:17.040465 29154 authenticatee.hpp:250] Attempting to authenticate with mechanism 'CRAM-MD5'
I1014 07:45:17.040499 29154 authenticator.hpp:267] Received SASL authentication start
I1014 07:45:17.040542 29154 authenticator.hpp:389] Authentication requires more steps
I1014 07:45:17.040573 29154 authenticatee.hpp:270] Received SASL authentication step
I1014 07:45:17.040614 29154 authenticator.hpp:295] Received SASL authentication step
I1014 07:45:17.040633 29154 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
I1014 07:45:17.040644 29154 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I1014 07:45:17.040645 29151 authenticator.hpp:295] Received SASL authentication step
I1014 07:45:17.040654 29154 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1014 07:45:17.040662 29154 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
I1014 07:45:17.040665 29154 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1014 07:45:17.040666 29151 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
I1014 07:45:17.040669 29154 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1014 07:45:17.040673 29151 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I1014 07:45:17.040679 29151 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1014 07:45:17.040679 29154 authenticator.hpp:381] Authentication success
I1014 07:45:17.040691 29151 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
I1014 07:45:17.040696 29151 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1014 07:45:17.040700 29151 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1014 07:45:17.040709 29151 authenticator.hpp:381] Authentication success
I1014 07:45:17.040783 29166 authenticatee.hpp:310] Authentication success
I1014 07:45:17.040810 29159 authenticatee.hpp:310] Authentication success
I1014 07:45:17.040895 29157 master.cpp:3827] Successfully authenticated principal 'test-principal' at scheduler-4d3d40bd-4ca3-4998-8479-c86e0f9ba9d2@67.195.81.187:60149
I1014 07:45:17.041152 29152 sched.cpp:357] Successfully authenticated with master master@67.195.81.187:60149
I1014 07:45:17.041170 29152 sched.cpp:476] Sending registration request to master@67.195.81.187:60149
I1014 07:45:17.041275 29157 master.cpp:3827] Successfully authenticated principal 'test-principal' at slave(213)@67.195.81.187:60149
I1014 07:45:17.041369 29164 slave.cpp:731] Successfully authenticated with master master@67.195.81.187:60149
I1014 07:45:17.041460 29164 slave.cpp:1048] Will retry registration in 17.703809ms if necessary
I1014 07:45:17.041486 29157 master.cpp:1362] Received registration request for framework 'default' at scheduler-4d3d40bd-4ca3-4998-8479-c86e0f9ba9d2@67.195.81.187:60149
I1014 07:45:17.041509 29157 master.cpp:1321] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1014 07:45:17.041620 29157 master.cpp:2968] Registering slave at slave(213)@67.195.81.187:60149 (pomona.apache.org) with id 20141014-074516-3142697795-60149-29137-0
I1014 07:45:17.041731 29157 master.cpp:1426] Registering framework 20141014-074516-3142697795-60149-29137-0000 (default) at scheduler-4d3d40bd-4ca3-4998-8479-c86e0f9ba9d2@67.195.81.187:60149
I1014 07:45:17.041753 29161 registrar.cpp:445] Applied 1 operations in 22521ns; attempting to update the 'registry'
I1014 07:45:17.041836 29159 hierarchical_allocator_process.hpp:329] Added framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:17.041847 29159 hierarchical_allocator_process.hpp:697] No resources available to allocate!
I1014 07:45:17.041854 29159 hierarchical_allocator_process.hpp:659] Performed allocation for 0 slaves in 6747ns
I1014 07:45:17.041872 29162 sched.cpp:407] Framework registered with 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:17.041898 29162 sched.cpp:421] Scheduler::registered took 10477ns
I1014 07:45:17.042734 29166 log.cpp:680] Attempting to append 315 bytes to the log
I1014 07:45:17.042796 29164 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3
I1014 07:45:17.043186 29156 replica.cpp:508] Replica received write request for position 3
I1014 07:45:17.043416 29156 leveldb.cpp:343] Persisting action (334 bytes) to leveldb took 209976ns
I1014 07:45:17.043431 29156 replica.cpp:676] Persisted action at 3
I1014 07:45:17.043629 29159 replica.cpp:655] Replica received learned notice for position 3
I1014 07:45:17.044214 29159 leveldb.cpp:343] Persisting action (336 bytes) to leveldb took 568375ns
I1014 07:45:17.044229 29159 replica.cpp:676] Persisted action at 3
I1014 07:45:17.044235 29159 replica.cpp:661] Replica learned APPEND action at position 3
I1014 07:45:17.044677 29166 registrar.cpp:490] Successfully updated the 'registry' in 2.898176ms
I1014 07:45:17.044767 29152 log.cpp:699] Attempting to truncate the log to 3
I1014 07:45:17.044868 29157 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4
I1014 07:45:17.044870 29159 master.cpp:3022] Registered slave 20141014-074516-3142697795-60149-29137-0 at slave(213)@67.195.81.187:60149 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1014 07:45:17.044914 29152 slave.cpp:2403] Received ping from slave-observer(188)@67.195.81.187:60149
I1014 07:45:17.044972 29152 slave.cpp:765] Registered with master master@67.195.81.187:60149; given slave ID 20141014-074516-3142697795-60149-29137-0
I1014 07:45:17.044939 29165 hierarchical_allocator_process.hpp:442] Added slave 20141014-074516-3142697795-60149-29137-0 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I1014 07:45:17.045037 29165 hierarchical_allocator_process.hpp:734] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141014-074516-3142697795-60149-29137-0 to framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:17.045192 29152 slave.cpp:778] Checkpointing SlaveInfo to '/tmp/StatusUpdateManagerTest_CheckpointStatusUpdate_Dy3lx5/meta/slaves/20141014-074516-3142697795-60149-29137-0/slave.info'
I1014 07:45:17.045233 29162 replica.cpp:508] Replica received write request for position 4
I1014 07:45:18.970877 29165 hierarchical_allocator_process.hpp:679] Performed allocation for slave 20141014-074516-3142697795-60149-29137-0 in 1.925862903secs
I1014 07:45:18.970960 29165 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 18833ns
I1014 07:45:18.971019 29161 master.cpp:3729] Sending 1 offers to framework 20141014-074516-3142697795-60149-29137-0000 (default) at scheduler-4d3d40bd-4ca3-4998-8479-c86e0f9ba9d2@67.195.81.187:60149
I1014 07:45:18.971176 29152 sched.cpp:544] Scheduler::resourceOffers took 26290ns
I1014 07:45:18.971711 29162 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 863451ns
I1014 07:45:18.971730 29162 replica.cpp:676] Persisted action at 4
I1014 07:45:18.971740 29152 master.cpp:2315] Processing reply for offers: [ 20141014-074516-3142697795-60149-29137-0 ] on slave 20141014-074516-3142697795-60149-29137-0 at slave(213)@67.195.81.187:60149 (pomona.apache.org) for framework 20141014-074516-3142697795-60149-29137-0000 (default) at scheduler-4d3d40bd-4ca3-4998-8479-c86e0f9ba9d2@67.195.81.187:60149
W1014 07:45:18.971781 29152 master.cpp:1969] Executor default for task 1 uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W1014 07:45:18.971796 29152 master.cpp:1980] Executor default for task 1 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I1014 07:45:18.971806 29152 master.cpp:2397] Authorizing framework principal 'test-principal' to launch task 1 as user 'jenkins'
I1014 07:45:18.972033 29160 replica.cpp:655] Replica received learned notice for position 4
I1014 07:45:18.972189 29156 master.hpp:869] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141014-074516-3142697795-60149-29137-0 (pomona.apache.org)
I1014 07:45:18.972229 29156 master.cpp:2463] Launching task 1 of framework 20141014-074516-3142697795-60149-29137-0000 (default) at scheduler-4d3d40bd-4ca3-4998-8479-c86e0f9ba9d2@67.195.81.187:60149 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141014-074516-3142697795-60149-29137-0 at slave(213)@67.195.81.187:60149 (pomona.apache.org)
I1014 07:45:18.972517 29166 slave.cpp:1079] Got assigned task 1 for framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:18.972591 29160 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 543871ns
I1014 07:45:18.972625 29160 leveldb.cpp:401] Deleting ~2 keys from leveldb took 19616ns
I1014 07:45:18.972631 29160 replica.cpp:676] Persisted action at 4
I1014 07:45:18.972638 29160 replica.cpp:661] Replica learned TRUNCATE action at position 4
I1014 07:45:18.972647 29166 slave.cpp:3678] Checkpointing FrameworkInfo to '/tmp/StatusUpdateManagerTest_CheckpointStatusUpdate_Dy3lx5/meta/slaves/20141014-074516-3142697795-60149-29137-0/frameworks/20141014-074516-3142697795-60149-29137-0000/framework.info'
I1014 07:45:18.972839 29166 slave.cpp:3685] Checkpointing framework pid 'scheduler-4d3d40bd-4ca3-4998-8479-c86e0f9ba9d2@67.195.81.187:60149' to '/tmp/StatusUpdateManagerTest_CheckpointStatusUpdate_Dy3lx5/meta/slaves/20141014-074516-3142697795-60149-29137-0/frameworks/20141014-074516-3142697795-60149-29137-0000/framework.pid'
I1014 07:45:18.973106 29166 slave.cpp:1189] Launching task 1 for framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:18.974549 29166 slave.cpp:4101] Checkpointing ExecutorInfo to '/tmp/StatusUpdateManagerTest_CheckpointStatusUpdate_Dy3lx5/meta/slaves/20141014-074516-3142697795-60149-29137-0/frameworks/20141014-074516-3142697795-60149-29137-0000/executors/default/executor.info'
I1014 07:45:18.974838 29166 slave.cpp:3733] Launching executor default of framework 20141014-074516-3142697795-60149-29137-0000 in work directory '/tmp/StatusUpdateManagerTest_CheckpointStatusUpdate_Dy3lx5/slaves/20141014-074516-3142697795-60149-29137-0/frameworks/20141014-074516-3142697795-60149-29137-0000/executors/default/runs/ba380460-a662-4c44-88d4-94ea91224c08'
I1014 07:45:18.976243 29166 exec.cpp:132] Version: 0.21.0
I1014 07:45:18.976409 29164 exec.cpp:182] Executor started at: executor(69)@67.195.81.187:60149 with pid 29137
I1014 07:45:18.976445 29166 slave.cpp:4124] Checkpointing TaskInfo to '/tmp/StatusUpdateManagerTest_CheckpointStatusUpdate_Dy3lx5/meta/slaves/20141014-074516-3142697795-60149-29137-0/frameworks/20141014-074516-3142697795-60149-29137-0000/executors/default/runs/ba380460-a662-4c44-88d4-94ea91224c08/tasks/1/task.info'
I1014 07:45:18.976619 29166 slave.cpp:1303] Queuing task '1' for executor default of framework '20141014-074516-3142697795-60149-29137-0000
I1014 07:45:18.976672 29166 slave.cpp:556] Successfully attached file '/tmp/StatusUpdateManagerTest_CheckpointStatusUpdate_Dy3lx5/slaves/20141014-074516-3142697795-60149-29137-0/frameworks/20141014-074516-3142697795-60149-29137-0000/executors/default/runs/ba380460-a662-4c44-88d4-94ea91224c08'
I1014 07:45:18.976716 29166 slave.cpp:2669] Monitoring executor 'default' of framework '20141014-074516-3142697795-60149-29137-0000' in container 'ba380460-a662-4c44-88d4-94ea91224c08'
I1014 07:45:18.976780 29166 slave.cpp:1814] Got registration for executor 'default' of framework 20141014-074516-3142697795-60149-29137-0000 from executor(69)@67.195.81.187:60149
I1014 07:45:18.976809 29166 slave.cpp:1900] Checkpointing executor pid 'executor(69)@67.195.81.187:60149' to '/tmp/StatusUpdateManagerTest_CheckpointStatusUpdate_Dy3lx5/meta/slaves/20141014-074516-3142697795-60149-29137-0/frameworks/20141014-074516-3142697795-60149-29137-0000/executors/default/runs/ba380460-a662-4c44-88d4-94ea91224c08/pids/libprocess.pid'
I1014 07:45:18.977041 29166 slave.cpp:1933] Flushing queued task 1 for executor 'default' of framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:18.977093 29165 exec.cpp:206] Executor registered on slave 20141014-074516-3142697795-60149-29137-0
I1014 07:45:18.978142 29165 exec.cpp:218] Executor::registered took 16202ns
I1014 07:45:18.978210 29165 exec.cpp:293] Executor asked to run task '1'
I1014 07:45:18.978245 29165 exec.cpp:302] Executor::launchTask took 23057ns
I1014 07:45:18.979346 29165 exec.cpp:525] Executor sending status update TASK_RUNNING (UUID: 288a1c44-4565-46f5-99f0-530842074af1) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:18.979435 29165 slave.cpp:2167] Handling status update TASK_RUNNING (UUID: 288a1c44-4565-46f5-99f0-530842074af1) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000 from executor(69)@67.195.81.187:60149
I1014 07:45:18.979537 29163 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 288a1c44-4565-46f5-99f0-530842074af1) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:18.979557 29163 status_update_manager.cpp:499] Creating StatusUpdate stream for task 1 of framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:18.979703 29163 status_update_manager.hpp:342] Checkpointing UPDATE for status update TASK_RUNNING (UUID: 288a1c44-4565-46f5-99f0-530842074af1) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:18.981128 29163 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: 288a1c44-4565-46f5-99f0-530842074af1) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000 to master@67.195.81.187:60149
I1014 07:45:18.981235 29163 master.cpp:3352] Forwarding status update TASK_RUNNING (UUID: 288a1c44-4565-46f5-99f0-530842074af1) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:18.981307 29165 slave.cpp:2324] Status update manager successfully handled status update TASK_RUNNING (UUID: 288a1c44-4565-46f5-99f0-530842074af1) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:19.015609 29165 slave.cpp:2330] Sending acknowledgement for status update TASK_RUNNING (UUID: 288a1c44-4565-46f5-99f0-530842074af1) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000 to executor(69)@67.195.81.187:60149
I1014 07:45:19.015719 29163 master.cpp:3324] Status update TASK_RUNNING (UUID: 288a1c44-4565-46f5-99f0-530842074af1) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000 from slave 20141014-074516-3142697795-60149-29137-0 at slave(213)@67.195.81.187:60149 (pomona.apache.org)
I1014 07:45:19.015794 29160 exec.cpp:339] Executor received status update acknowledgement 288a1c44-4565-46f5-99f0-530842074af1 for task 1 of framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:19.015823 29165 sched.cpp:635] Scheduler::statusUpdate took 41347ns
I1014 07:45:19.016036 29151 master.cpp:2813] Forwarding status update acknowledgement 288a1c44-4565-46f5-99f0-530842074af1 for task 1 of framework 20141014-074516-3142697795-60149-29137-0000 (default) at scheduler-4d3d40bd-4ca3-4998-8479-c86e0f9ba9d2@67.195.81.187:60149 to slave 20141014-074516-3142697795-60149-29137-0 at slave(213)@67.195.81.187:60149 (pomona.apache.org)
I1014 07:45:19.016397 29160 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 288a1c44-4565-46f5-99f0-530842074af1) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:19.016427 29160 status_update_manager.hpp:342] Checkpointing ACK for status update TASK_RUNNING (UUID: 288a1c44-4565-46f5-99f0-530842074af1) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:19.017277 29160 slave.cpp:1754] Status update manager successfully handled status update acknowledgement (UUID: 288a1c44-4565-46f5-99f0-530842074af1) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:19.018054 29163 sched.cpp:745] Stopping framework '20141014-074516-3142697795-60149-29137-0000'
I1014 07:45:19.018056 29137 master.cpp:677] Master terminating
W1014 07:45:19.018091 29137 master.cpp:4528] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework 20141014-074516-3142697795-60149-29137-0000 on slave 20141014-074516-3142697795-60149-29137-0 at slave(213)@67.195.81.187:60149 (pomona.apache.org) in non-terminal state TASK_RUNNING
I1014 07:45:19.018272 29137 master.cpp:4571] Removing executor 'default' with resources of framework 20141014-074516-3142697795-60149-29137-0000 on slave 20141014-074516-3142697795-60149-29137-0 at slave(213)@67.195.81.187:60149 (pomona.apache.org)
I1014 07:45:19.018374 29157 hierarchical_allocator_process.hpp:563] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 20141014-074516-3142697795-60149-29137-0 from framework 20141014-074516-3142697795-60149-29137-0000
I1014 07:45:19.018481 29160 slave.cpp:2488] master@67.195.81.187:60149 exited
W1014 07:45:19.018496 29160 slave.cpp:2491] Master disconnected! Waiting for a new master to be elected
I1014 07:45:19.020192 29159 slave.cpp:2727] Executor 'default' of framework 20141014-074516-3142697795-60149-29137-0000 exited with status 0
I1014 07:45:19.021337 29159 slave.cpp:2167] Handling status update TASK_LOST (UUID: 34fe4d01-bcfe-42b7-b748-d5aeeb3db86f) for task 1 of framework 20141014-074516-3142697795-60149-29137-0000 from @0.0.0.0:0
I1014 07:45:19.021364 29159 slave.cpp:4041] Terminating task 1
I1014 07:45:19.021495 29159 slave.cpp:479] Slave terminating
[ OK ] StatusUpdateManagerTest.CheckpointStatusUpdate (2154 ms)
[----------] 7 tests from StatusUpdateManagerTest (8239 ms total)
[----------] Global test environment tear-down
[==========] 388 tests from 62 test cases ran. (194235 ms total)
[ PASSED ] 387 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] SlaveRecoveryTest/0.RemoveNonCheckpointingFramework, where TypeParam = mesos::internal::slave::MesosContainerizer
1 FAILED TEST
YOU HAVE 5 DISABLED TESTS
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
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
#2440
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/2440/changes>