mesos-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject Build failed in Jenkins: Mesos-Ubuntu-distcheck #79
Date Wed, 07 May 2014 04:37:57 GMT
See <https://builds.apache.org/job/Mesos-Ubuntu-distcheck/79/changes>

Changes:

[benjamin.hindman] Enabled unbundled usage of http-parser.

------------------------------------------
[...truncated 19388 lines...]
I0507 03:27:38.676010  5798 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_ExitedFramework_fAc62M/slaves/20140507-032738-453759884-58462-5758-0/frameworks/20140507-032738-453759884-58462-5758-0000'
for gc 6.99999254958222days in the future
I0507 03:27:38.704622  5786 hierarchical_allocator_process.hpp:687] Performed allocation for
1 slaves in 11228ns
I0507 03:27:38.704907  5791 slave.cpp:2717] Framework 20140507-032738-453759884-58462-5758-0000
seems to have exited. Ignoring registration timeout for executor 'default'
I0507 03:27:38.704932  5794 master.cpp:104] No whitelist given. Advertising offers for all
slaves
I0507 03:27:38.705431  5791 slave.cpp:2801] Current usage 67.66%. Max allowed age: 1.563618673822245days
I0507 03:27:38.705549  5780 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_ExitedFramework_fAc62M/slaves/20140507-032738-453759884-58462-5758-0/frameworks/20140507-032738-453759884-58462-5758-0000/executors/default/runs/4879ef58-5529-4ba8-9f96-2ed505d57e17
I0507 03:27:38.705714  5780 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_ExitedFramework_fAc62M/slaves/20140507-032738-453759884-58462-5758-0/frameworks/20140507-032738-453759884-58462-5758-0000/executors/default/runs/4879ef58-5529-4ba8-9f96-2ed505d57e17'
I0507 03:27:38.705773  5780 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_ExitedFramework_fAc62M/slaves/20140507-032738-453759884-58462-5758-0/frameworks/20140507-032738-453759884-58462-5758-0000/executors/default
I0507 03:27:38.705937  5780 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_ExitedFramework_fAc62M/slaves/20140507-032738-453759884-58462-5758-0/frameworks/20140507-032738-453759884-58462-5758-0000/executors/default'
I0507 03:27:38.705953  5780 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_ExitedFramework_fAc62M/slaves/20140507-032738-453759884-58462-5758-0/frameworks/20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.706040  5780 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_ExitedFramework_fAc62M/slaves/20140507-032738-453759884-58462-5758-0/frameworks/20140507-032738-453759884-58462-5758-0000'
I0507 03:27:38.714886  5782 process.cpp:3335] Handling HTTP event for process 'files' with
path: '/files/browse.json'
I0507 03:27:38.715406  5801 process.cpp:1037] Socket closed while receiving
I0507 03:27:38.724931  5758 master.cpp:552] Master terminating
I0507 03:27:38.725226  5782 slave.cpp:2152] master@140.211.11.27:58462 exited
W0507 03:27:38.725289  5782 slave.cpp:2155] Master disconnected! Waiting for a new master
to be elected
I0507 03:27:38.727746  5758 slave.cpp:415] Slave terminating
[       OK ] GarbageCollectorIntegrationTest.ExitedFramework (371 ms)
[ RUN      ] GarbageCollectorIntegrationTest.DiskUsage
Using temporary directory '/tmp/GarbageCollectorIntegrationTest_DiskUsage_pU3Ym7'
I0507 03:27:38.775058  5758 leveldb.cpp:174] Opened db in 44.343989ms
I0507 03:27:38.787498  5758 leveldb.cpp:181] Compacted db in 12.411065ms
I0507 03:27:38.787533  5758 leveldb.cpp:196] Created db iterator in 4008ns
I0507 03:27:38.787545  5758 leveldb.cpp:202] Seeked to beginning of db in 598ns
I0507 03:27:38.787552  5758 leveldb.cpp:271] Iterated through 0 keys in the db in 173ns
I0507 03:27:38.787564  5758 replica.cpp:741] Replica recovered with log positions 0 ->
0 with 1 holes and 0 unlearned
I0507 03:27:38.787858  5777 recover.cpp:425] Starting replica recovery
I0507 03:27:38.788352  5793 master.cpp:267] Master 20140507-032738-453759884-58462-5758 (hemera.apache.org)
started on 140.211.11.27:58462
I0507 03:27:38.788377  5793 master.cpp:304] Master only allowing authenticated frameworks
to register
I0507 03:27:38.788383  5793 master.cpp:309] Master only allowing authenticated slaves to register
I0507 03:27:38.788389  5793 credentials.hpp:35] Loading credentials for authentication
I0507 03:27:38.789064  5779 recover.cpp:451] Replica is in EMPTY status
W0507 03:27:38.789115  5793 credentials.hpp:48] Failed to stat credentials file 'file:///tmp/GarbageCollectorIntegrationTest_DiskUsage_pU3Ym7/credentials':
No such file or directory
I0507 03:27:38.789489  5779 master.cpp:104] No whitelist given. Advertising offers for all
slaves
I0507 03:27:38.789531  5778 hierarchical_allocator_process.hpp:301] Initializing hierarchical
allocator process with master : master@140.211.11.27:58462
I0507 03:27:38.791007  5788 replica.cpp:638] Replica in EMPTY status received a broadcasted
recover request
I0507 03:27:38.791177  5780 master.cpp:921] The newly elected leader is master@140.211.11.27:58462
with id 20140507-032738-453759884-58462-5758
I0507 03:27:38.791198  5780 master.cpp:931] Elected as the leading master!
I0507 03:27:38.791205  5780 master.cpp:752] Recovering from registrar
I0507 03:27:38.791251  5796 recover.cpp:188] Received a recover response from a replica in
EMPTY status
I0507 03:27:38.791323  5797 registrar.cpp:313] Recovering registrar
I0507 03:27:38.792137  5795 recover.cpp:542] Updating replica status to STARTING
I0507 03:27:38.807531  5781 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took
15.124092ms
I0507 03:27:38.807559  5781 replica.cpp:320] Persisted replica status to STARTING
I0507 03:27:38.807621  5781 recover.cpp:451] Replica is in STARTING status
I0507 03:27:38.809319  5799 replica.cpp:638] Replica in STARTING status received a broadcasted
recover request
I0507 03:27:38.809983  5795 recover.cpp:188] Received a recover response from a replica in
STARTING status
I0507 03:27:38.811204  5778 recover.cpp:542] Updating replica status to VOTING
I0507 03:27:38.827595  5795 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took
16.011355ms
I0507 03:27:38.827627  5795 replica.cpp:320] Persisted replica status to VOTING
I0507 03:27:38.827683  5795 recover.cpp:556] Successfully joined the Paxos group
I0507 03:27:38.827775  5795 recover.cpp:440] Recover process terminated
I0507 03:27:38.828966  5780 log.cpp:656] Attempting to start the writer
I0507 03:27:38.831114  5782 replica.cpp:474] Replica received implicit promise request with
proposal 1
I0507 03:27:38.847708  5782 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took
16.573137ms
I0507 03:27:38.847739  5782 replica.cpp:342] Persisted promised to 1
I0507 03:27:38.848141  5797 coordinator.cpp:230] Coordinator attemping to fill missing position
I0507 03:27:38.849684  5790 replica.cpp:375] Replica received explicit promise request for
position 0 with proposal 2
I0507 03:27:38.863777  5790 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 14.076775ms
I0507 03:27:38.863801  5790 replica.cpp:676] Persisted action at 0
I0507 03:27:38.864915  5798 replica.cpp:508] Replica received write request for position 0
I0507 03:27:38.864949  5798 leveldb.cpp:436] Reading position from leveldb took 11807ns
I0507 03:27:38.879945  5798 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took
14.978446ms
I0507 03:27:38.879976  5798 replica.cpp:676] Persisted action at 0
I0507 03:27:38.880491  5797 replica.cpp:655] Replica received learned notice for position
0
I0507 03:27:38.895969  5797 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took
15.459949ms
I0507 03:27:38.895992  5797 replica.cpp:676] Persisted action at 0
I0507 03:27:38.896003  5797 replica.cpp:661] Replica learned NOP action at position 0
I0507 03:27:38.896411  5783 log.cpp:672] Writer started with ending position 0
I0507 03:27:38.898058  5798 leveldb.cpp:436] Reading position from leveldb took 11910ns
I0507 03:27:38.899749  5777 registrar.cpp:346] Successfully fetched the registry (0B)
I0507 03:27:38.899766  5777 registrar.cpp:422] Attempting to update the 'registry'
I0507 03:27:38.901458  5791 log.cpp:680] Attempting to append 137 bytes to the log
I0507 03:27:38.901666  5780 coordinator.cpp:340] Coordinator attempting to write APPEND action
at position 1
I0507 03:27:38.902773  5783 replica.cpp:508] Replica received write request for position 1
I0507 03:27:38.916127  5783 leveldb.cpp:341] Persisting action (156 bytes) to leveldb took
13.225715ms
I0507 03:27:38.916152  5783 replica.cpp:676] Persisted action at 1
I0507 03:27:38.916534  5790 replica.cpp:655] Replica received learned notice for position
1
I0507 03:27:38.928203  5790 leveldb.cpp:341] Persisting action (158 bytes) to leveldb took
11.652434ms
I0507 03:27:38.928225  5790 replica.cpp:676] Persisted action at 1
I0507 03:27:38.928236  5790 replica.cpp:661] Replica learned APPEND action at position 1
I0507 03:27:38.928546  5790 registrar.cpp:479] Successfully updated 'registry'
I0507 03:27:38.928642  5790 registrar.cpp:372] Successfully recovered registrar
I0507 03:27:38.929044  5783 master.cpp:779] Recovered 0 slaves from the Registry (99B) ; allowing
10mins for slaves to re-register
I0507 03:27:38.929502  5799 log.cpp:699] Attempting to truncate the log to 1
I0507 03:27:38.929888  5797 coordinator.cpp:340] Coordinator attempting to write TRUNCATE
action at position 2
I0507 03:27:38.930161  5781 replica.cpp:508] Replica received write request for position 2
I0507 03:27:38.932977  5789 slave.cpp:140] Slave started on 56)@140.211.11.27:58462
I0507 03:27:38.932991  5789 credentials.hpp:35] Loading credentials for authentication
W0507 03:27:38.933567  5789 credentials.hpp:48] Failed to stat credentials file 'file:///tmp/GarbageCollectorIntegrationTest_DiskUsage_A9Pxks/credential':
No such file or directory
I0507 03:27:38.933585  5789 slave.cpp:230] Slave using credential for: test-principal
I0507 03:27:38.933765  5789 slave.cpp:243] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000]
I0507 03:27:38.933854  5789 slave.cpp:271] Slave hostname: hemera.apache.org
I0507 03:27:38.933863  5789 slave.cpp:272] Slave checkpoint: false
I0507 03:27:38.934239  5778 state.cpp:33] Recovering state from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_A9Pxks/meta'
I0507 03:27:38.934960  5792 status_update_manager.cpp:193] Recovering status update manager
I0507 03:27:38.935123  5779 slave.cpp:2945] Finished recovery
I0507 03:27:38.936998  5779 slave.cpp:526] New master detected at master@140.211.11.27:58462
I0507 03:27:38.937021  5779 slave.cpp:586] Authenticating with master master@140.211.11.27:58462
I0507 03:27:38.937077  5798 status_update_manager.cpp:167] New master detected at master@140.211.11.27:58462
I0507 03:27:38.937306  5779 slave.cpp:559] Detecting new master
I0507 03:27:38.937335  5800 authenticatee.hpp:128] Creating new client SASL connection
I0507 03:27:38.938030  5778 master.cpp:2798] Authenticating slave(56)@140.211.11.27:58462
I0507 03:27:38.938742  5783 authenticator.hpp:148] Creating new server SASL connection
I0507 03:27:38.939312  5786 authenticatee.hpp:219] Received SASL authentication mechanisms:
CRAM-MD5
I0507 03:27:38.939340  5786 authenticatee.hpp:245] Attempting to authenticate with mechanism
'CRAM-MD5'
I0507 03:27:38.939390  5786 authenticator.hpp:254] Received SASL authentication start
I0507 03:27:38.939553  5786 authenticator.hpp:342] Authentication requires more steps
I0507 03:27:38.939592  5786 authenticatee.hpp:265] Received SASL authentication step
I0507 03:27:38.939715  5786 authenticator.hpp:282] Received SASL authentication step
I0507 03:27:38.939803  5786 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0507 03:27:38.939821  5786 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0507 03:27:38.939831  5786 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0507 03:27:38.939841  5786 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0507 03:27:38.939851  5786 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since
SASL_AUXPROP_AUTHZID == true
I0507 03:27:38.939857  5786 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
I0507 03:27:38.939870  5786 authenticator.hpp:334] Authentication success
I0507 03:27:38.939937  5786 authenticatee.hpp:305] Authentication success
I0507 03:27:38.940016  5778 master.cpp:2838] Successfully authenticated slave(56)@140.211.11.27:58462
I0507 03:27:38.940449  5799 slave.cpp:643] Successfully authenticated with master master@140.211.11.27:58462
I0507 03:27:38.940513  5799 slave.cpp:872] Will retry registration in 5.176207635secs if necessary
I0507 03:27:38.940625  5794 master.cpp:2134] Registering slave at slave(56)@140.211.11.27:58462
(hemera.apache.org) with id 20140507-032738-453759884-58462-5758-0
I0507 03:27:38.940800  5796 registrar.cpp:422] Attempting to update the 'registry'
I0507 03:27:38.940850  5781 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took
10.659152ms
I0507 03:27:38.940871  5781 replica.cpp:676] Persisted action at 2
I0507 03:27:38.941843  5788 replica.cpp:655] Replica received learned notice for position
2
I0507 03:27:38.953193  5788 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took
11.291343ms
I0507 03:27:38.953258  5788 leveldb.cpp:399] Deleting ~1 keys from leveldb took 33725ns
I0507 03:27:38.953274  5788 replica.cpp:676] Persisted action at 2
I0507 03:27:38.953282  5788 replica.cpp:661] Replica learned TRUNCATE action at position 2
I0507 03:27:38.953541  5797 log.cpp:680] Attempting to append 330 bytes to the log
I0507 03:27:38.953614  5797 coordinator.cpp:340] Coordinator attempting to write APPEND action
at position 3
I0507 03:27:38.954731  5789 replica.cpp:508] Replica received write request for position 3
I0507 03:27:38.965240  5789 leveldb.cpp:341] Persisting action (349 bytes) to leveldb took
10.489719ms
I0507 03:27:38.965261  5789 replica.cpp:676] Persisted action at 3
I0507 03:27:38.966253  5780 replica.cpp:655] Replica received learned notice for position
3
I0507 03:27:38.977375  5780 leveldb.cpp:341] Persisting action (351 bytes) to leveldb took
11.098798ms
I0507 03:27:38.977408  5780 replica.cpp:676] Persisted action at 3
I0507 03:27:38.977421  5780 replica.cpp:661] Replica learned APPEND action at position 3
I0507 03:27:38.977859  5792 registrar.cpp:479] Successfully updated 'registry'
I0507 03:27:38.977926  5780 log.cpp:699] Attempting to truncate the log to 3
I0507 03:27:38.978060  5792 master.cpp:2174] Registered slave 20140507-032738-453759884-58462-5758-0
at slave(56)@140.211.11.27:58462 (hemera.apache.org)
I0507 03:27:38.978112  5792 master.cpp:3283] Adding slave 20140507-032738-453759884-58462-5758-0
at slave(56)@140.211.11.27:58462 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000]
I0507 03:27:38.978134  5784 coordinator.cpp:340] Coordinator attempting to write TRUNCATE
action at position 4
I0507 03:27:38.978508  5785 slave.cpp:676] Registered with master master@140.211.11.27:58462;
given slave ID 20140507-032738-453759884-58462-5758-0
I0507 03:27:38.978631  5786 hierarchical_allocator_process.hpp:444] Added slave 20140507-032738-453759884-58462-5758-0
(hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and
cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I0507 03:27:38.978677  5786 hierarchical_allocator_process.hpp:707] Performed allocation for
slave 20140507-032738-453759884-58462-5758-0 in 5421ns
I0507 03:27:38.979872  5796 replica.cpp:508] Replica received write request for position 4
I0507 03:27:38.982084  5758 sched.cpp:121] Version: 0.19.0
I0507 03:27:38.982213  5789 sched.cpp:217] New master detected at master@140.211.11.27:58462
I0507 03:27:38.982228  5789 sched.cpp:268] Authenticating with master master@140.211.11.27:58462
I0507 03:27:38.982347  5788 authenticatee.hpp:128] Creating new client SASL connection
I0507 03:27:38.982676  5788 master.cpp:2798] Authenticating scheduler(59)@140.211.11.27:58462
I0507 03:27:38.983100  5788 authenticator.hpp:148] Creating new server SASL connection
I0507 03:27:38.983294  5788 authenticatee.hpp:219] Received SASL authentication mechanisms:
CRAM-MD5
I0507 03:27:38.983312  5788 authenticatee.hpp:245] Attempting to authenticate with mechanism
'CRAM-MD5'
I0507 03:27:38.983360  5788 authenticator.hpp:254] Received SASL authentication start
I0507 03:27:38.983505  5788 authenticator.hpp:342] Authentication requires more steps
I0507 03:27:38.984220  5782 authenticatee.hpp:265] Received SASL authentication step
I0507 03:27:38.984275  5782 authenticator.hpp:282] Received SASL authentication step
I0507 03:27:38.984315  5782 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0507 03:27:38.984347  5782 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0507 03:27:38.984359  5782 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0507 03:27:38.984370  5782 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0507 03:27:38.984377  5782 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since
SASL_AUXPROP_AUTHZID == true
I0507 03:27:38.984383  5782 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
I0507 03:27:38.984397  5782 authenticator.hpp:334] Authentication success
I0507 03:27:38.984429  5782 authenticatee.hpp:305] Authentication success
I0507 03:27:38.984469  5795 master.cpp:2838] Successfully authenticated scheduler(59)@140.211.11.27:58462
I0507 03:27:38.985110  5782 sched.cpp:342] Successfully authenticated with master master@140.211.11.27:58462
I0507 03:27:38.985133  5782 sched.cpp:461] Sending registration request to master@140.211.11.27:58462
I0507 03:27:38.985326  5795 master.cpp:980] Received registration request from scheduler(59)@140.211.11.27:58462
I0507 03:27:38.985357  5795 master.cpp:998] Registering framework 20140507-032738-453759884-58462-5758-0000
at scheduler(59)@140.211.11.27:58462
I0507 03:27:38.985424  5795 sched.cpp:392] Framework registered with 20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.985471  5792 hierarchical_allocator_process.hpp:331] Added framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.985610  5795 sched.cpp:406] Scheduler::registered took 36702ns
I0507 03:27:38.985646  5792 hierarchical_allocator_process.hpp:751] Offering cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave 20140507-032738-453759884-58462-5758-0 to framework
20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.985954  5792 hierarchical_allocator_process.hpp:687] Performed allocation for
1 slaves in 330895ns
I0507 03:27:38.986001  5789 master.hpp:612] Adding offer 20140507-032738-453759884-58462-5758-0
with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140507-032738-453759884-58462-5758-0
(hemera.apache.org)
I0507 03:27:38.986090  5789 master.cpp:2747] Sending 1 offers to framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.986548  5792 sched.cpp:529] Scheduler::resourceOffers took 162873ns
I0507 03:27:38.986721  5792 master.hpp:622] Removing offer 20140507-032738-453759884-58462-5758-0
with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140507-032738-453759884-58462-5758-0
(hemera.apache.org)
I0507 03:27:38.986781  5792 master.cpp:1812] Processing reply for offers: [ 20140507-032738-453759884-58462-5758-0
] on slave 20140507-032738-453759884-58462-5758-0 at slave(56)@140.211.11.27:58462 (hemera.apache.org)
for framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.986843  5792 master.hpp:584] Adding task 0 with resources cpus(*):2; mem(*):1024
on slave 20140507-032738-453759884-58462-5758-0 (hemera.apache.org)
I0507 03:27:38.986876  5792 master.cpp:2922] Launching task 0 of framework 20140507-032738-453759884-58462-5758-0000
with resources cpus(*):2; mem(*):1024 on slave 20140507-032738-453759884-58462-5758-0 at slave(56)@140.211.11.27:58462
(hemera.apache.org)
I0507 03:27:38.986981  5795 slave.cpp:906] Got assigned task 0 for framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.987180  5795 slave.cpp:1016] Launching task 0 for framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.987203  5787 hierarchical_allocator_process.hpp:546] Framework 20140507-032738-453759884-58462-5758-0000
left disk(*):1024; ports(*):[31000-32000] unused on slave 20140507-032738-453759884-58462-5758-0
I0507 03:27:38.987287  5787 hierarchical_allocator_process.hpp:589] Framework 20140507-032738-453759884-58462-5758-0000
filtered slave 20140507-032738-453759884-58462-5758-0 for 5secs
I0507 03:27:38.991395  5795 exec.cpp:131] Version: 0.19.0
I0507 03:27:38.991497  5779 exec.cpp:181] Executor started at: executor(27)@140.211.11.27:58462
with pid 5758
I0507 03:27:38.991510  5795 slave.cpp:1126] Queuing task '0' for executor default of framework
'20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.991566  5795 slave.cpp:487] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_DiskUsage_A9Pxks/slaves/20140507-032738-453759884-58462-5758-0/frameworks/20140507-032738-453759884-58462-5758-0000/executors/default/runs/de776bec-2822-4bbc-befc-eec40eb5f674'
I0507 03:27:38.991595  5795 slave.cpp:2283] Monitoring executor 'default' of framework '20140507-032738-453759884-58462-5758-0000'
in container 'de776bec-2822-4bbc-befc-eec40eb5f674'
I0507 03:27:38.991778  5795 slave.cpp:1599] Got registration for executor 'default' of framework
20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.991874  5795 slave.cpp:1718] Flushing queued task 0 for executor 'default'
of framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.991935  5780 exec.cpp:205] Executor registered on slave 20140507-032738-453759884-58462-5758-0
I0507 03:27:38.993419  5796 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took
13.489998ms
I0507 03:27:38.993449  5796 replica.cpp:676] Persisted action at 4
I0507 03:27:38.994510  5777 replica.cpp:655] Replica received learned notice for position
4
I0507 03:27:38.994753  5780 exec.cpp:217] Executor::registered took 14516ns
I0507 03:27:38.994818  5780 exec.cpp:292] Executor asked to run task '0'
I0507 03:27:38.994849  5780 exec.cpp:301] Executor::launchTask took 18872ns
I0507 03:27:38.996703  5780 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID:
be7346ad-e198-4b38-9252-421ff759fdee) for task 0 of framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.996793  5780 slave.cpp:1954] Handling status update TASK_RUNNING (UUID: be7346ad-e198-4b38-9252-421ff759fdee)
for task 0 of framework 20140507-032738-453759884-58462-5758-0000 from executor(27)@140.211.11.27:58462
I0507 03:27:38.996888  5780 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: be7346ad-e198-4b38-9252-421ff759fdee) for task 0 of framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.996920  5780 status_update_manager.cpp:499] Creating StatusUpdate stream for
task 0 of framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.996968  5780 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING
(UUID: be7346ad-e198-4b38-9252-421ff759fdee) for task 0 of framework 20140507-032738-453759884-58462-5758-0000
to master@140.211.11.27:58462
I0507 03:27:38.997189  5790 master.cpp:2450] Status update TASK_RUNNING (UUID: be7346ad-e198-4b38-9252-421ff759fdee)
for task 0 of framework 20140507-032738-453759884-58462-5758-0000 from slave 20140507-032738-453759884-58462-5758-0
at slave(56)@140.211.11.27:58462 (hemera.apache.org)
I0507 03:27:38.997268  5780 slave.cpp:2071] Status update manager successfully handled status
update TASK_RUNNING (UUID: be7346ad-e198-4b38-9252-421ff759fdee) for task 0 of framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:38.997321  5797 sched.cpp:620] Scheduler::statusUpdate took 77906ns
I0507 03:27:38.997336  5780 slave.cpp:2077] Sending acknowledgement for status update TASK_RUNNING
(UUID: be7346ad-e198-4b38-9252-421ff759fdee) for task 0 of framework 20140507-032738-453759884-58462-5758-0000
to executor(27)@140.211.11.27:58462
I0507 03:27:38.998700  5797 slave.cpp:2341] Executor 'default' of framework 20140507-032738-453759884-58462-5758-0000
has exited with status 0
I0507 03:27:38.998814  5793 exec.cpp:338] Executor received status update acknowledgement
be7346ad-e198-4b38-9252-421ff759fdee for task 0 of framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:39.000041  5797 slave.cpp:1954] Handling status update TASK_LOST (UUID: 4c8e572c-3fa7-43f3-aaf8-f82e77a70c1b)
for task 0 of framework 20140507-032738-453759884-58462-5758-0000 from @0.0.0.0:0
I0507 03:27:39.000063  5797 slave.cpp:3446] Terminating task 0
I0507 03:27:39.000190  5797 status_update_manager.cpp:320] Received status update TASK_LOST
(UUID: 4c8e572c-3fa7-43f3-aaf8-f82e77a70c1b) for task 0 of framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:39.000229  5779 master.cpp:2523] Executor default of framework 20140507-032738-453759884-58462-5758-0000
on slave 20140507-032738-453759884-58462-5758-0 at slave(56)@140.211.11.27:58462 (hemera.apache.org)
has exited with status 0
I0507 03:27:39.000341  5797 status_update_manager.cpp:398] Received status update acknowledgement
(UUID: be7346ad-e198-4b38-9252-421ff759fdee) for task 0 of framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:39.000385  5797 status_update_manager.cpp:373] Forwarding status update TASK_LOST
(UUID: 4c8e572c-3fa7-43f3-aaf8-f82e77a70c1b) for task 0 of framework 20140507-032738-453759884-58462-5758-0000
to master@140.211.11.27:58462
I0507 03:27:39.000516  5791 slave.cpp:2071] Status update manager successfully handled status
update TASK_LOST (UUID: 4c8e572c-3fa7-43f3-aaf8-f82e77a70c1b) for task 0 of framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:39.000686  5791 slave.cpp:1539] Status update manager successfully handled status
update acknowledgement (UUID: be7346ad-e198-4b38-9252-421ff759fdee) for task 0 of framework
20140507-032738-453759884-58462-5758-0000
I0507 03:27:39.000759  5795 master.cpp:2450] Status update TASK_LOST (UUID: 4c8e572c-3fa7-43f3-aaf8-f82e77a70c1b)
for task 0 of framework 20140507-032738-453759884-58462-5758-0000 from slave 20140507-032738-453759884-58462-5758-0
at slave(56)@140.211.11.27:58462 (hemera.apache.org)
I0507 03:27:39.000841  5784 sched.cpp:620] Scheduler::statusUpdate took 11418ns
I0507 03:27:39.000849  5795 master.hpp:602] Removing task 0 with resources cpus(*):2; mem(*):1024
on slave 20140507-032738-453759884-58462-5758-0 (hemera.apache.org)
I0507 03:27:39.001313  5799 hierarchical_allocator_process.hpp:636] Recovered cpus(*):2; mem(*):1024
(total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave
20140507-032738-453759884-58462-5758-0 from framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:39.002792  5778 status_update_manager.cpp:398] Received status update acknowledgement
(UUID: 4c8e572c-3fa7-43f3-aaf8-f82e77a70c1b) for task 0 of framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:39.002831  5778 status_update_manager.cpp:530] Cleaning up status update stream
for task 0 of framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:39.002903  5778 slave.cpp:1539] Status update manager successfully handled status
update acknowledgement (UUID: 4c8e572c-3fa7-43f3-aaf8-f82e77a70c1b) for task 0 of framework
20140507-032738-453759884-58462-5758-0000
I0507 03:27:39.002976  5778 slave.cpp:3470] Completing task 0
I0507 03:27:39.002991  5778 slave.cpp:2480] Cleaning up executor 'default' of framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:39.006098  5778 slave.cpp:2555] Cleaning up framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:39.006105  5800 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_A9Pxks/slaves/20140507-032738-453759884-58462-5758-0/frameworks/20140507-032738-453759884-58462-5758-0000/executors/default/runs/de776bec-2822-4bbc-befc-eec40eb5f674'
for gc 1.00000000231788weeks in the future
I0507 03:27:39.006146  5800 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_A9Pxks/slaves/20140507-032738-453759884-58462-5758-0/frameworks/20140507-032738-453759884-58462-5758-0000/executors/default'
for gc 1.00000000231788weeks in the future
I0507 03:27:39.006211  5786 status_update_manager.cpp:282] Closing status update streams for
framework 20140507-032738-453759884-58462-5758-0000
I0507 03:27:39.006299  5786 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_A9Pxks/slaves/20140507-032738-453759884-58462-5758-0/frameworks/20140507-032738-453759884-58462-5758-0000'
for gc 1.00000000231788weeks in the future
I0507 03:27:39.010058  5777 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took
15.533184ms
I0507 03:27:39.010144  5777 leveldb.cpp:399] Deleting ~2 keys from leveldb took 64787ns
I0507 03:27:39.010154  5777 replica.cpp:676] Persisted action at 4
I0507 03:27:39.010160  5777 replica.cpp:661] Replica learned TRUNCATE action at position 4
I0507 03:27:39.029413  5789 slave.cpp:2801] Current usage 90.00%. Max allowed age: 0ns
../../src/tests/gc_tests.cpp:658: Failure
Value of: os::exists(executorDir)
  Actual: true
Expected: false
Build timed out (after 120 minutes). Marking the build as failed.
Build was aborted
make[1]: *** [check-recursive] Terminated
make: *** [distcheck] Terminated

Mime
View raw message