[
https://issues.apache.org/jira/browse/MESOS-2144?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14289792#comment-14289792
]
Yan Xu commented on MESOS-2144:
-------------------------------
{noformat:title=verbose log}
[ RUN ] ExamplesTest.LowLevelSchedulerPthread
Using temporary directory '/tmp/ExamplesTest_LowLevelSchedulerPthread_2syI5e'
I0122 20:08:39.492336 10532 logging.cpp:177] Logging to STDERR
Enabling authentication for the scheduler
I0122 20:08:39.500661 10532 process.cpp:958] libprocess is initialized on
192.168.122.135:42248 for 8 cpus
I0122 20:08:39.510413 10532 scheduler.cpp:146] Version: 0.22.0
I0122 20:08:39.522413 10532 leveldb.cpp:176] Opened db in 1.637054ms
I0122 20:08:39.523161 10532 leveldb.cpp:183] Compacted db in 574825ns
I0122 20:08:39.523373 10532 leveldb.cpp:198] Created db iterator in 58461ns
I0122 20:08:39.523664 10532 leveldb.cpp:204] Seeked to beginning of db in 8708ns
I0122 20:08:39.523814 10532 leveldb.cpp:273] Iterated through 0 keys in the db
in 4594ns
I0122 20:08:39.524168 10532 replica.cpp:744] Replica recovered with log
positions 0 -> 0 with 1 holes and 0 unlearned
I0122 20:08:39.526536 10558 recover.cpp:449] Starting replica recovery
I0122 20:08:39.527796 10558 recover.cpp:475] Replica is in EMPTY status
I0122 20:08:39.532749 10557 replica.cpp:641] Replica in EMPTY status received a
broadcasted recover request
I0122 20:08:39.540638 10563 recover.cpp:195] Received a recover response from a
replica in EMPTY status
I0122 20:08:39.541692 10563 recover.cpp:566] Updating replica status to STARTING
I0122 20:08:39.549593 10562 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 113474ns
I0122 20:08:39.549753 10562 replica.cpp:323] Persisted replica status to
STARTING
I0122 20:08:39.557155 10563 recover.cpp:475] Replica is in STARTING status
I0122 20:08:39.565675 10563 replica.cpp:641] Replica in STARTING status
received a broadcasted recover request
I0122 20:08:39.573648 10563 recover.cpp:195] Received a recover response from a
replica in STARTING status
I0122 20:08:39.576818 10563 recover.cpp:566] Updating replica status to VOTING
I0122 20:08:39.580477 10563 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 45725ns
I0122 20:08:39.580647 10563 replica.cpp:323] Persisted replica status to VOTING
I0122 20:08:39.580970 10557 recover.cpp:580] Successfully joined the Paxos group
I0122 20:08:39.581374 10558 recover.cpp:464] Recover process terminated
I0122 20:08:39.591231 10558 master.cpp:262] Master
20150122-200839-2272962752-42248-10532 (fedora-19) started on
192.168.122.135:42248
I0122 20:08:39.591495 10558 master.cpp:308] Master only allowing authenticated
frameworks to register
I0122 20:08:39.593546 10558 master.cpp:315] Master allowing unauthenticated
slaves to register
I0122 20:08:39.593855 10558 credentials.hpp:36] Loading credentials for
authentication from
'/tmp/ExamplesTest_LowLevelSchedulerPthread_2syI5e/credentials'
W0122 20:08:39.594051 10558 credentials.hpp:51] Permissions on credentials file
'/tmp/ExamplesTest_LowLevelSchedulerPthread_2syI5e/credentials' are too open.
It is recommended that your credentials file is NOT accessible by others.
I0122 20:08:39.594580 10558 master.cpp:357] Authorization enabled
I0122 20:08:39.596122 10557 hierarchical_allocator_process.hpp:285] Initialized
hierarchical allocator process
I0122 20:08:39.597481 10560 whitelist_watcher.cpp:65] No whitelist given
I0122 20:08:39.600026 10532 containerizer.cpp:103] Using isolation:
posix/cpu,posix/mem
I0122 20:08:39.637444 10562 slave.cpp:173] Slave started on
1)@192.168.122.135:42248
I0122 20:08:39.638299 10562 slave.cpp:300] Slave resources: cpus(*):2;
mem(*):10240; disk(*):752; ports(*):[31000-32000]
I0122 20:08:39.639659 10562 slave.cpp:329] Slave hostname: fedora-19
I0122 20:08:39.639822 10562 slave.cpp:330] Slave checkpoint: true
I0122 20:08:39.642604 10558 master.cpp:1219] The newly elected leader is
[email protected]:42248 with id 20150122-200839-2272962752-42248-10532
I0122 20:08:39.645637 10558 master.cpp:1232] Elected as the leading master!
I0122 20:08:39.645807 10558 master.cpp:1050] Recovering from registrar
I0122 20:08:39.645594 10532 containerizer.cpp:103] Using isolation:
posix/cpu,posix/mem
I0122 20:08:39.646863 10561 registrar.cpp:313] Recovering registrar
I0122 20:08:39.649919 10557 log.cpp:660] Attempting to start the writer
I0122 20:08:39.659095 10561 replica.cpp:477] Replica received implicit promise
request with proposal 1
I0122 20:08:39.659322 10561 leveldb.cpp:306] Persisting metadata (8 bytes) to
leveldb took 65595ns
I0122 20:08:39.659595 10561 replica.cpp:345] Persisted promised to 1
I0122 20:08:39.661293 10561 coordinator.cpp:230] Coordinator attemping to fill
missing position
I0122 20:08:39.667981 10559 replica.cpp:378] Replica received explicit promise
request for position 0 with proposal 2
I0122 20:08:39.668236 10559 leveldb.cpp:343] Persisting action (8 bytes) to
leveldb took 68276ns
I0122 20:08:39.668509 10559 replica.cpp:679] Persisted action at 0
I0122 20:08:39.675886 10563 replica.cpp:511] Replica received write request for
position 0
I0122 20:08:39.676527 10563 leveldb.cpp:438] Reading position from leveldb took
57476ns
I0122 20:08:39.676946 10563 leveldb.cpp:343] Persisting action (14 bytes) to
leveldb took 44435ns
I0122 20:08:39.677175 10563 replica.cpp:679] Persisted action at 0
I0122 20:08:39.676426 10558 state.cpp:33] Recovering state from
'/tmp/mesos-xY0d15/0/meta'
I0122 20:08:39.678335 10558 status_update_manager.cpp:197] Recovering status
update manager
I0122 20:08:39.678937 10559 containerizer.cpp:300] Recovering containerizer
I0122 20:08:39.681118 10563 replica.cpp:658] Replica received learned notice
for position 0
I0122 20:08:39.681784 10563 leveldb.cpp:343] Persisting action (16 bytes) to
leveldb took 49802ns
I0122 20:08:39.682178 10563 replica.cpp:679] Persisted action at 0
I0122 20:08:39.682526 10563 replica.cpp:664] Replica learned NOP action at
position 0
I0122 20:08:39.684800 10562 slave.cpp:173] Slave started on
2)@192.168.122.135:42248
I0122 20:08:39.685456 10562 slave.cpp:300] Slave resources: cpus(*):2;
mem(*):10240; disk(*):752; ports(*):[31000-32000]
I0122 20:08:39.686591 10562 slave.cpp:329] Slave hostname: fedora-19
I0122 20:08:39.686748 10562 slave.cpp:330] Slave checkpoint: true
I0122 20:08:39.687547 10560 log.cpp:676] Writer started with ending position 0
I0122 20:08:39.691155 10562 state.cpp:33] Recovering state from
'/tmp/mesos-xY0d15/1/meta'
I0122 20:08:39.692009 10559 slave.cpp:3519] Finished recovery
I0122 20:08:39.693778 10557 leveldb.cpp:438] Reading position from leveldb took
33607ns
I0122 20:08:39.694455 10564 status_update_manager.cpp:197] Recovering status
update manager
I0122 20:08:39.694815 10559 slave.cpp:613] New master detected at
[email protected]:42248
I0122 20:08:39.695754 10559 slave.cpp:638] No credentials provided. Attempting
to register without authentication
I0122 20:08:39.694857 10563 status_update_manager.cpp:171] Pausing sending
status updates
I0122 20:08:39.698586 10561 containerizer.cpp:300] Recovering containerizer
I0122 20:08:39.700152 10561 slave.cpp:3519] Finished recovery
I0122 20:08:39.700755 10559 slave.cpp:649] Detecting new master
I0122 20:08:39.701057 10532 containerizer.cpp:103] Using isolation:
posix/cpu,posix/mem
I0122 20:08:39.707221 10564 status_update_manager.cpp:171] Pausing sending
status updates
I0122 20:08:39.707435 10559 slave.cpp:613] New master detected at
[email protected]:42248
I0122 20:08:39.707795 10559 slave.cpp:638] No credentials provided. Attempting
to register without authentication
I0122 20:08:39.708272 10559 slave.cpp:649] Detecting new master
I0122 20:08:39.713948 10560 registrar.cpp:346] Successfully fetched the
registry (0B) in 66.91328ms
I0122 20:08:39.714581 10560 registrar.cpp:445] Applied 1 operations in 83530ns;
attempting to update the 'registry'
I0122 20:08:39.727648 10559 slave.cpp:173] Slave started on
3)@192.168.122.135:42248
I0122 20:08:39.728307 10559 slave.cpp:300] Slave resources: cpus(*):2;
mem(*):10240; disk(*):752; ports(*):[31000-32000]
I0122 20:08:39.729104 10559 slave.cpp:329] Slave hostname: fedora-19
I0122 20:08:39.729257 10559 slave.cpp:330] Slave checkpoint: true
I0122 20:08:39.730301 10559 state.cpp:33] Recovering state from
'/tmp/mesos-xY0d15/2/meta'
I0122 20:08:39.730885 10564 status_update_manager.cpp:197] Recovering status
update manager
I0122 20:08:39.731420 10564 containerizer.cpp:300] Recovering containerizer
I0122 20:08:39.733012 10559 slave.cpp:3519] Finished recovery
I0122 20:08:39.733803 10563 status_update_manager.cpp:171] Pausing sending
status updates
I0122 20:08:39.733993 10559 slave.cpp:613] New master detected at
[email protected]:42248
I0122 20:08:39.734305 10559 slave.cpp:638] No credentials provided. Attempting
to register without authentication
I0122 20:08:39.734509 10559 slave.cpp:649] Detecting new master
I0122 20:08:39.736112 10563 log.cpp:684] Attempting to append 131 bytes to the
log
I0122 20:08:39.736632 10558 coordinator.cpp:340] Coordinator attempting to
write APPEND action at position 1
I0122 20:08:39.738078 10558 replica.cpp:511] Replica received write request for
position 1
I0122 20:08:39.738556 10558 leveldb.cpp:343] Persisting action (150 bytes) to
leveldb took 60142ns
I0122 20:08:39.738713 10558 replica.cpp:679] Persisted action at 1
I0122 20:08:39.740087 10558 replica.cpp:658] Replica received learned notice
for position 1
I0122 20:08:39.740684 10558 leveldb.cpp:343] Persisting action (152 bytes) to
leveldb took 55048ns
I0122 20:08:39.741070 10558 replica.cpp:679] Persisted action at 1
I0122 20:08:39.741372 10558 replica.cpp:664] Replica learned APPEND action at
position 1
I0122 20:08:39.745448 10560 registrar.cpp:490] Successfully updated the
'registry' in 30.595072ms
I0122 20:08:39.746182 10563 log.cpp:703] Attempting to truncate the log to 1
I0122 20:08:39.747153 10561 scheduler.cpp:417] New master detected at
[email protected]:42248
I0122 20:08:39.747684 10561 scheduler.cpp:466] Authenticating with master
[email protected]:42248
I0122 20:08:39.748791 10561 authenticatee.hpp:114] Initializing client SASL
I0122 20:08:39.750627 10561 authenticatee.hpp:138] Creating new client SASL
connection
I0122 20:08:39.751426 10560 registrar.cpp:376] Successfully recovered registrar
I0122 20:08:39.751652 10562 coordinator.cpp:340] Coordinator attempting to
write TRUNCATE action at position 2
I0122 20:08:39.753128 10557 replica.cpp:511] Replica received write request for
position 2
I0122 20:08:39.753334 10557 leveldb.cpp:343] Persisting action (16 bytes) to
leveldb took 52619ns
I0122 20:08:39.753643 10557 replica.cpp:679] Persisted action at 2
I0122 20:08:39.754601 10564 master.cpp:1077] Recovered 0 slaves from the
Registry (95B) ; allowing 10mins for slaves to re-register
I0122 20:08:39.755134 10564 master.cpp:4129] Authenticating
scheduler(1)@192.168.122.135:42248
I0122 20:08:39.755300 10564 master.cpp:4140] Using default CRAM-MD5
authenticator
I0122 20:08:39.756546 10564 authenticator.hpp:108] Initializing server SASL
I0122 20:08:39.757117 10564 auxprop.cpp:63] Initialized in-memory auxiliary
property plugin
I0122 20:08:39.757277 10564 authenticator.hpp:170] Creating new server SASL
connection
I0122 20:08:39.758543 10564 authenticatee.hpp:229] Received SASL authentication
mechanisms: CRAM-MD5
I0122 20:08:39.758924 10564 authenticatee.hpp:255] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0122 20:08:39.759263 10564 authenticator.hpp:276] Received SASL authentication
start
I0122 20:08:39.759459 10564 authenticator.hpp:398] Authentication requires more
steps
I0122 20:08:39.759955 10558 authenticatee.hpp:275] Received SASL authentication
step
I0122 20:08:39.760273 10564 authenticator.hpp:304] Received SASL authentication
step
I0122 20:08:39.760464 10564 auxprop.cpp:99] Request to lookup properties for
user: 'test-principal' realm: 'fedora-19' server FQDN: 'fedora-19'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0122 20:08:39.760723 10564 auxprop.cpp:171] Looking up auxiliary property
'*userPassword'
I0122 20:08:39.761003 10564 auxprop.cpp:171] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0122 20:08:39.761193 10564 auxprop.cpp:99] Request to lookup properties for
user: 'test-principal' realm: 'fedora-19' server FQDN: 'fedora-19'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0122 20:08:39.761343 10564 auxprop.cpp:121] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0122 20:08:39.761610 10564 auxprop.cpp:121] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0122 20:08:39.761780 10564 authenticator.hpp:390] Authentication success
I0122 20:08:39.762049 10563 replica.cpp:658] Replica received learned notice
for position 2
I0122 20:08:39.762279 10563 leveldb.cpp:343] Persisting action (18 bytes) to
leveldb took 57676ns
I0122 20:08:39.762539 10563 leveldb.cpp:401] Deleting ~1 keys from leveldb took
40307ns
I0122 20:08:39.762689 10563 replica.cpp:679] Persisted action at 2
I0122 20:08:39.762969 10563 replica.cpp:664] Replica learned TRUNCATE action at
position 2
I0122 20:08:39.763530 10559 authenticatee.hpp:315] Authentication success
I0122 20:08:39.769049 10563 scheduler.cpp:537] Successfully authenticated with
master [email protected]:42248
I0122 20:08:39.769552 10564 master.cpp:4187] Successfully authenticated
principal 'test-principal' at scheduler(1)@192.168.122.135:42248
I0122 20:08:39.773854 10564 master.cpp:1420] Received registration request for
framework 'Low-Level Scheduler using pthread (C++)' at
scheduler(1)@192.168.122.135:42248
I0122 20:08:39.774281 10564 master.cpp:1298] Authorizing framework principal
'test-principal' to receive offers for role '*'
I0122 20:08:39.775631 10563 master.cpp:1484] Registering framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248
I0122 20:08:39.777061 10563 hierarchical_allocator_process.hpp:319] Added
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:39.777854 10558 scheduler.cpp:586] Enqueuing event 1 from
[email protected]:42248
Received a REGISTERED event
Framework '20150122-200839-2272962752-42248-10532-0000' registered with Master
'20150122-200839-2272962752-42248-10532'
I0122 20:08:39.779561 10563 hierarchical_allocator_process.hpp:839] No
resources available to allocate!
I0122 20:08:39.779737 10563 hierarchical_allocator_process.hpp:746] Performed
allocation for 0 slaves in 302066ns
I0122 20:08:40.002131 10558 slave.cpp:1075] Will retry registration in
445.955946ms if necessary
I0122 20:08:40.002552 10560 master.cpp:3275] Registering slave at
slave(2)@192.168.122.135:42248 (fedora-19) with id
20150122-200839-2272962752-42248-10532-S0
I0122 20:08:40.003609 10560 registrar.cpp:445] Applied 1 operations in
121919ns; attempting to update the 'registry'
I0122 20:08:40.006961 10563 log.cpp:684] Attempting to append 302 bytes to the
log
I0122 20:08:40.007282 10563 coordinator.cpp:340] Coordinator attempting to
write APPEND action at position 3
I0122 20:08:40.008296 10559 replica.cpp:511] Replica received write request for
position 3
I0122 20:08:40.008713 10559 leveldb.cpp:343] Persisting action (321 bytes) to
leveldb took 215643ns
I0122 20:08:40.008862 10559 replica.cpp:679] Persisted action at 3
I0122 20:08:40.010185 10563 replica.cpp:658] Replica received learned notice
for position 3
I0122 20:08:40.010670 10563 leveldb.cpp:343] Persisting action (323 bytes) to
leveldb took 52858ns
I0122 20:08:40.010821 10563 replica.cpp:679] Persisted action at 3
I0122 20:08:40.011059 10563 replica.cpp:664] Replica learned APPEND action at
position 3
I0122 20:08:40.012128 10558 log.cpp:703] Attempting to truncate the log to 3
I0122 20:08:40.012542 10561 coordinator.cpp:340] Coordinator attempting to
write TRUNCATE action at position 4
I0122 20:08:40.013661 10561 replica.cpp:511] Replica received write request for
position 4
I0122 20:08:40.014096 10561 leveldb.cpp:343] Persisting action (16 bytes) to
leveldb took 54567ns
I0122 20:08:40.014245 10561 replica.cpp:679] Persisted action at 4
I0122 20:08:40.018638 10564 replica.cpp:658] Replica received learned notice
for position 4
I0122 20:08:40.018841 10564 leveldb.cpp:343] Persisting action (18 bytes) to
leveldb took 52691ns
I0122 20:08:40.019147 10564 leveldb.cpp:401] Deleting ~2 keys from leveldb took
39729ns
I0122 20:08:40.019284 10564 replica.cpp:679] Persisted action at 4
I0122 20:08:40.019479 10564 replica.cpp:664] Replica learned TRUNCATE action at
position 4
I0122 20:08:40.024982 10560 registrar.cpp:490] Successfully updated the
'registry' in 21.148928ms
I0122 20:08:40.026402 10563 master.cpp:3329] Registered slave
20150122-200839-2272962752-42248-10532-S0 at slave(2)@192.168.122.135:42248
(fedora-19) with cpus(*):2; mem(*):10240; disk(*):752; ports(*):[31000-32000]
I0122 20:08:40.027078 10557 hierarchical_allocator_process.hpp:453] Added slave
20150122-200839-2272962752-42248-10532-S0 (fedora-19) with cpus(*):2;
mem(*):10240; disk(*):752; ports(*):[31000-32000] (and cpus(*):2; mem(*):10240;
disk(*):752; ports(*):[31000-32000] available)
I0122 20:08:40.027191 10562 slave.cpp:781] Registered with master
[email protected]:42248; given slave ID
20150122-200839-2272962752-42248-10532-S0
I0122 20:08:40.028743 10558 status_update_manager.cpp:178] Resuming sending
status updates
I0122 20:08:40.029157 10562 slave.cpp:797] Checkpointing SlaveInfo to
'/tmp/mesos-xY0d15/1/meta/slaves/20150122-200839-2272962752-42248-10532-S0/slave.info'
I0122 20:08:40.029721 10562 slave.cpp:2588] Received ping from
slave-observer(1)@192.168.122.135:42248
I0122 20:08:40.030551 10561 master.cpp:4071] Sending 1 offers to framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248
I0122 20:08:40.030634 10557 hierarchical_allocator_process.hpp:764] Performed
allocation for slave 20150122-200839-2272962752-42248-10532-S0 in 3.2566ms
I0122 20:08:40.031625 10558 scheduler.cpp:586] Enqueuing event 3 from
[email protected]:42248
Received an OFFERS event
Received offer 20150122-200839-2272962752-42248-10532-O0 with cpus(*):2;
mem(*):10240; disk(*):752; ports(*):[31000-32000]
Launching task 0 using offer 20150122-200839-2272962752-42248-10532-O0
Launching task 1 using offer 20150122-200839-2272962752-42248-10532-O0
I0122 20:08:40.036274 10560 master.cpp:2677] Processing ACCEPT call for offers:
[ 20150122-200839-2272962752-42248-10532-O0 ] on slave
20150122-200839-2272962752-42248-10532-S0 at slave(2)@192.168.122.135:42248
(fedora-19) for framework 20150122-200839-2272962752-42248-10532-0000
(Low-Level Scheduler using pthread (C++)) at scheduler(1)@192.168.122.135:42248
I0122 20:08:40.036737 10560 master.cpp:2513] Authorizing framework principal
'test-principal' to launch task 0 as user 'jenkins'
I0122 20:08:40.037303 10560 master.cpp:2513] Authorizing framework principal
'test-principal' to launch task 1 as user 'jenkins'
W0122 20:08:40.039355 10560 master.cpp:2130] Executor default for task 0 uses
less CPUs (None) than the minimum required (0.01). Please update your executor,
as this will be mandatory in future releases.
W0122 20:08:40.039556 10560 master.cpp:2142] Executor default for task 0 uses
less memory (None) than the minimum required (32MB). Please update your
executor, as this will be mandatory in future releases.
I0122 20:08:40.040520 10560 master.hpp:782] Adding task 0 with resources
cpus(*):1; mem(*):128 on slave 20150122-200839-2272962752-42248-10532-S0
(fedora-19)
I0122 20:08:40.040915 10560 master.cpp:2885] Launching task 0 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 with resources cpus(*):1;
mem(*):128 on slave 20150122-200839-2272962752-42248-10532-S0 at
slave(2)@192.168.122.135:42248 (fedora-19)
I0122 20:08:40.041509 10561 slave.cpp:1130] Got assigned task 0 for framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.042819 10561 slave.cpp:1245] Launching task 0 for framework
20150122-200839-2272962752-42248-10532-0000
W0122 20:08:40.045670 10560 master.cpp:2130] 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.
W0122 20:08:40.045845 10560 master.cpp:2142] 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.
I0122 20:08:40.046263 10560 master.hpp:782] Adding task 1 with resources
cpus(*):1; mem(*):128 on slave 20150122-200839-2272962752-42248-10532-S0
(fedora-19)
I0122 20:08:40.046706 10560 master.cpp:2885] Launching task 1 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 with resources cpus(*):1;
mem(*):128 on slave 20150122-200839-2272962752-42248-10532-S0 at
slave(2)@192.168.122.135:42248 (fedora-19)
I0122 20:08:40.046531 10561 slave.cpp:3921] Launching executor default of
framework 20150122-200839-2272962752-42248-10532-0000 in work directory
'/tmp/mesos-xY0d15/1/slaves/20150122-200839-2272962752-42248-10532-S0/frameworks/20150122-200839-2272962752-42248-10532-0000/executors/default/runs/5102171c-7b8d-4b49-8a94-dacf1c3e98dc'
I0122 20:08:40.048109 10564 hierarchical_allocator_process.hpp:653] Recovered
mem(*):9984; disk(*):752; ports(*):[31000-32000] (total allocatable:
mem(*):9984; disk(*):752; ports(*):[31000-32000]) on slave
20150122-200839-2272962752-42248-10532-S0 from framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.048302 10564 hierarchical_allocator_process.hpp:689] Framework
20150122-200839-2272962752-42248-10532-0000 filtered slave
20150122-200839-2272962752-42248-10532-S0 for 5secs
I0122 20:08:40.049228 10559 containerizer.cpp:445] Starting container
'5102171c-7b8d-4b49-8a94-dacf1c3e98dc' for executor 'default' of framework
'20150122-200839-2272962752-42248-10532-0000'
I0122 20:08:40.055325 10561 slave.cpp:1368] Queuing task '0' for executor
default of framework '20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.056138 10561 slave.cpp:1130] Got assigned task 1 for framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.056833 10561 slave.cpp:566] Successfully attached file
'/tmp/mesos-xY0d15/1/slaves/20150122-200839-2272962752-42248-10532-S0/frameworks/20150122-200839-2272962752-42248-10532-0000/executors/default/runs/5102171c-7b8d-4b49-8a94-dacf1c3e98dc'
I0122 20:08:40.057253 10561 slave.cpp:1245] Launching task 1 for framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.057955 10561 slave.cpp:1368] Queuing task '1' for executor
default of framework '20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.059038 10559 launcher.cpp:137] Forked child with pid '10567' for
container '5102171c-7b8d-4b49-8a94-dacf1c3e98dc'
I0122 20:08:40.085119 10557 slave.cpp:2890] Monitoring executor 'default' of
framework '20150122-200839-2272962752-42248-10532-0000' in container
'5102171c-7b8d-4b49-8a94-dacf1c3e98dc'
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0122 20:08:40.226256 10567 process.cpp:958] libprocess is initialized on
192.168.122.135:34800 for 8 cpus
I0122 20:08:40.227149 10567 logging.cpp:177] Logging to STDERR
I0122 20:08:40.230245 10567 exec.cpp:147] Version: 0.22.0
I0122 20:08:40.239662 10598 exec.cpp:197] Executor started at:
executor(1)@192.168.122.135:34800 with pid 10567
I0122 20:08:40.244689 10564 slave.cpp:1912] Got registration for executor
'default' of framework 20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:34800
I0122 20:08:40.247730 10564 slave.cpp:2031] Flushing queued task 0 for executor
'default' of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.249625 10564 slave.cpp:2031] Flushing queued task 1 for executor
'default' of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.252501 10596 exec.cpp:221] Executor registered on slave
20150122-200839-2272962752-42248-10532-S0
Registered executor on fedora-19
I0122 20:08:40.258982 10596 exec.cpp:233] Executor::registered took 2.770466ms
I0122 20:08:40.261250 10596 exec.cpp:308] Executor asked to run task '0'
Starting task 0
Finishing task 0
I0122 20:08:40.268803 10596 exec.cpp:317] Executor::launchTask took 786179ns
I0122 20:08:40.270768 10596 exec.cpp:308] Executor asked to run task '1'
Starting task 1
Finishing task 1
I0122 20:08:40.272456 10596 exec.cpp:317] Executor::launchTask took 1.273463ms
I0122 20:08:40.274494 10596 exec.cpp:540] Executor sending status update
TASK_RUNNING (UUID: fc2e7968-1c86-46fd-bb95-7ea1b657f8b2) for task 0 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.276442 10563 slave.cpp:2265] Handling status update TASK_RUNNING
(UUID: fc2e7968-1c86-46fd-bb95-7ea1b657f8b2) for task 0 of framework
20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:34800
I0122 20:08:40.277344 10563 status_update_manager.cpp:317] Received status
update TASK_RUNNING (UUID: fc2e7968-1c86-46fd-bb95-7ea1b657f8b2) for task 0 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.277601 10563 status_update_manager.cpp:494] Creating
StatusUpdate stream for task 0 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.278669 10563 status_update_manager.cpp:371] Forwarding update
TASK_RUNNING (UUID: fc2e7968-1c86-46fd-bb95-7ea1b657f8b2) for task 0 of
framework 20150122-200839-2272962752-42248-10532-0000 to the slave
I0122 20:08:40.279330 10560 slave.cpp:2508] Forwarding the update TASK_RUNNING
(UUID: fc2e7968-1c86-46fd-bb95-7ea1b657f8b2) for task 0 of framework
20150122-200839-2272962752-42248-10532-0000 to [email protected]:42248
II0122 20:08:40.281968 10560 master.cpp:3652] Forwarding status update
TASK_RUNNING (UUID: fc2e7968-1c86-46fd-bb95-7ea1b657f8b2) for task 0 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.282456 10560 master.cpp:3624] Status update TASK_RUNNING (UUID:
fc2e7968-1c86-46fd-bb95-7ea1b657f8b2) for task 0 of framework
20150122-200839-2272962752-42248-10532-0000 from slave
20150122-200839-2272962752-42248-10532-S0 at slave(2)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.282989 10560 master.cpp:4934] Updating the latest state of task
0 of framework 20150122-200839-2272962752-42248-10532-0000 to TASK_RUNNING
I0122 20:08:40.282920 10561 scheduler.cpp:586] Enqueuing event 5 from
[email protected]:42248
0122 20:08:40.281280 10596 exec.cpp:540] Executor sending status update
TASK_FINISHED (UUID: 3f241a80-a50d-43b9-8f5c-e15cc403bbfc) for task 0 of
framework 20150122-200839-2272962752-42248-10532-0000
Received an UPDATE event
Task 0 is in state TASK_RUNNING
I0122 20:08:40.287866 10557 slave.cpp:2265] Handling status update
TASK_FINISHED (UUID: 3f241a80-a50d-43b9-8f5c-e15cc403bbfc) for task 0 of
framework 20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:34800
I0122 20:08:40.288283 10557 slave.cpp:4229] Terminating task 0
I0122 20:08:40.289058 10561 master.cpp:3125] Forwarding status update
acknowledgement fc2e7968-1c86-46fd-bb95-7ea1b657f8b2 for task 0 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 to slave
20150122-200839-2272962752-42248-10532-S0 at slave(2)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.290421 10596 exec.cpp:540] Executor sending status update
TASK_RUNNING (UUID: 5858b2f8-57dc-4349-94bf-6c40fadc4298) for task 1 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.293179 10557 slave.cpp:2265] Handling status update TASK_RUNNING
(UUID: 5858b2f8-57dc-4349-94bf-6c40fadc4298) for task 1 of framework
20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:34800
II0122 20:08:40.295326 10562 slave.cpp:2435] Status update manager successfully
handled status update TASK_RUNNING (UUID: fc2e7968-1c86-46fd-bb95-7ea1b657f8b2)
for task 0 of framework 20150122-200839-2272962752-42248-10532-0000
0122 20:08:40.294106 10596 exec.cpp:540] Executor sending status update
TASK_FINISHED (UUID: 1e6c6032-dd25-4449-beff-4dc7d25fa859) for task 1 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.296205 10562 slave.cpp:2441] Sending acknowledgement for status
update TASK_RUNNING (UUID: fc2e7968-1c86-46fd-bb95-7ea1b657f8b2) for task 0 of
framework 20150122-200839-2272962752-42248-10532-0000 to
executor(1)@192.168.122.135:34800
I0122 20:08:40.297919 10558 slave.cpp:2265] Handling status update
TASK_FINISHED (UUID: 1e6c6032-dd25-4449-beff-4dc7d25fa859) for task 1 of
framework 20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:34800
I0122 20:08:40.298166 10558 slave.cpp:4229] Terminating task 1
I0122 20:08:40.301353 10600 exec.cpp:354] Executor received status update
acknowledgement fc2e7968-1c86-46fd-bb95-7ea1b657f8b2 for task 0 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.302722 10563 status_update_manager.cpp:317] Received status
update TASK_RUNNING (UUID: 5858b2f8-57dc-4349-94bf-6c40fadc4298) for task 1 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.302939 10563 status_update_manager.cpp:494] Creating
StatusUpdate stream for task 1 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.303791 10563 status_update_manager.cpp:371] Forwarding update
TASK_RUNNING (UUID: 5858b2f8-57dc-4349-94bf-6c40fadc4298) for task 1 of
framework 20150122-200839-2272962752-42248-10532-0000 to the slave
I0122 20:08:40.304713 10564 slave.cpp:2508] Forwarding the update TASK_RUNNING
(UUID: 5858b2f8-57dc-4349-94bf-6c40fadc4298) for task 1 of framework
20150122-200839-2272962752-42248-10532-0000 to [email protected]:42248
I0122 20:08:40.305222 10564 master.cpp:3652] Forwarding status update
TASK_RUNNING (UUID: 5858b2f8-57dc-4349-94bf-6c40fadc4298) for task 1 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.305651 10564 master.cpp:3624] Status update TASK_RUNNING (UUID:
5858b2f8-57dc-4349-94bf-6c40fadc4298) for task 1 of framework
20150122-200839-2272962752-42248-10532-0000 from slave
20150122-200839-2272962752-42248-10532-S0 at slave(2)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.305866 10564 master.cpp:4934] Updating the latest state of task
1 of framework 20150122-200839-2272962752-42248-10532-0000 to TASK_FINISHED
(status update state: TASK_RUNNING)
I0122 20:08:40.306493 10564 scheduler.cpp:586] Enqueuing event 5 from
[email protected]:42248
I0122 20:08:40.307680 10560 hierarchical_allocator_process.hpp:653] Recovered
cpus(*):1; mem(*):128 (total allocatable: mem(*):10112; disk(*):752;
ports(*):[31000-32000]; cpus(*):1) on slave
20150122-200839-2272962752-42248-10532-S0 from framework
20150122-200839-2272962752-42248-10532-0000
Received an UPDATE event
Task 1 is in state TASK_RUNNING
I0122 20:08:40.308845 10564 master.cpp:3125] Forwarding status update
acknowledgement 5858b2f8-57dc-4349-94bf-6c40fadc4298 for task 1 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 to slave
20150122-200839-2272962752-42248-10532-S0 at slave(2)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.309620 10561 slave.cpp:2435] Status update manager successfully
handled status update TASK_RUNNING (UUID: 5858b2f8-57dc-4349-94bf-6c40fadc4298)
for task 1 of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.309809 10561 slave.cpp:2441] Sending acknowledgement for status
update TASK_RUNNING (UUID: 5858b2f8-57dc-4349-94bf-6c40fadc4298) for task 1 of
framework 20150122-200839-2272962752-42248-10532-0000 to
executor(1)@192.168.122.135:34800
I0122 20:08:40.311774 10600 exec.cpp:354] Executor received status update
acknowledgement 5858b2f8-57dc-4349-94bf-6c40fadc4298 for task 1 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.312751 10558 slave.cpp:1075] Will retry registration in
322.705631ms if necessary
I0122 20:08:40.313252 10558 master.cpp:3275] Registering slave at
slave(3)@192.168.122.135:42248 (fedora-19) with id
20150122-200839-2272962752-42248-10532-S1
I0122 20:08:40.314151 10558 registrar.cpp:445] Applied 1 operations in
132237ns; attempting to update the 'registry'
I0122 20:08:40.316995 10563 status_update_manager.cpp:317] Received status
update TASK_FINISHED (UUID: 3f241a80-a50d-43b9-8f5c-e15cc403bbfc) for task 0 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.319458 10561 slave.cpp:2435] Status update manager successfully
handled status update TASK_FINISHED (UUID:
3f241a80-a50d-43b9-8f5c-e15cc403bbfc) for task 0 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.319638 10561 slave.cpp:2441] Sending acknowledgement for status
update TASK_FINISHED (UUID: 3f241a80-a50d-43b9-8f5c-e15cc403bbfc) for task 0 of
framework 20150122-200839-2272962752-42248-10532-0000 to
executor(1)@192.168.122.135:34800
I0122 20:08:40.321369 10599 exec.cpp:354] Executor received status update
acknowledgement 3f241a80-a50d-43b9-8f5c-e15cc403bbfc for task 0 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.322038 10563 status_update_manager.cpp:389] Received status
update acknowledgement (UUID: fc2e7968-1c86-46fd-bb95-7ea1b657f8b2) for task 0
of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.322793 10563 status_update_manager.cpp:371] Forwarding update
TASK_FINISHED (UUID: 3f241a80-a50d-43b9-8f5c-e15cc403bbfc) for task 0 of
framework 20150122-200839-2272962752-42248-10532-0000 to the slave
I0122 20:08:40.327605 10557 slave.cpp:2508] Forwarding the update TASK_FINISHED
(UUID: 3f241a80-a50d-43b9-8f5c-e15cc403bbfc) for task 0 of framework
20150122-200839-2272962752-42248-10532-0000 to [email protected]:42248
I0122 20:08:40.328116 10557 master.cpp:3652] Forwarding status update
TASK_FINISHED (UUID: 3f241a80-a50d-43b9-8f5c-e15cc403bbfc) for task 0 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.328625 10561 scheduler.cpp:586] Enqueuing event 5 from
[email protected]:42248
I0122 20:08:40.329550 10557 master.cpp:3624] Status update TASK_FINISHED (UUID:
3f241a80-a50d-43b9-8f5c-e15cc403bbfc) for task 0 of framework
20150122-200839-2272962752-42248-10532-0000 from slave
20150122-200839-2272962752-42248-10532-S0 at slave(2)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.329864 10557 master.cpp:4934] Updating the latest state of task
0 of framework 20150122-200839-2272962752-42248-10532-0000 to TASK_FINISHED
Received an UPDATE event
Task 0 is in state TASK_FINISHED
I0122 20:08:40.331504 10557 hierarchical_allocator_process.hpp:653] Recovered
cpus(*):1; mem(*):128 (total allocatable: mem(*):10240; disk(*):752;
ports(*):[31000-32000]; cpus(*):2) on slave
20150122-200839-2272962752-42248-10532-S0 from framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.331965 10561 master.cpp:4993] Removing task 0 with resources
cpus(*):1; mem(*):128 of framework 20150122-200839-2272962752-42248-10532-0000
on slave 20150122-200839-2272962752-42248-10532-S0 at
slave(2)@192.168.122.135:42248 (fedora-19)
I0122 20:08:40.332584 10561 master.cpp:3125] Forwarding status update
acknowledgement 3f241a80-a50d-43b9-8f5c-e15cc403bbfc for task 0 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 to slave
20150122-200839-2272962752-42248-10532-S0 at slave(2)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.333081 10564 slave.cpp:1852] Status update manager successfully
handled status update acknowledgement (UUID:
fc2e7968-1c86-46fd-bb95-7ea1b657f8b2) for task 0 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.333164 10563 status_update_manager.cpp:317] Received status
update TASK_FINISHED (UUID: 1e6c6032-dd25-4449-beff-4dc7d25fa859) for task 1 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.334703 10562 log.cpp:684] Attempting to append 467 bytes to the
log
I0122 20:08:40.335224 10562 coordinator.cpp:340] Coordinator attempting to
write APPEND action at position 5
I0122 20:08:40.336733 10562 replica.cpp:511] Replica received write request for
position 5
I0122 20:08:40.337149 10562 leveldb.cpp:343] Persisting action (486 bytes) to
leveldb took 231675ns
I0122 20:08:40.337303 10562 replica.cpp:679] Persisted action at 5
I0122 20:08:40.338551 10562 replica.cpp:658] Replica received learned notice
for position 5
I0122 20:08:40.339457 10560 slave.cpp:2435] Status update manager successfully
handled status update TASK_FINISHED (UUID:
1e6c6032-dd25-4449-beff-4dc7d25fa859) for task 1 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.340095 10560 slave.cpp:2441] Sending acknowledgement for status
update TASK_FINISHED (UUID: 1e6c6032-dd25-4449-beff-4dc7d25fa859) for task 1 of
framework 20150122-200839-2272962752-42248-10532-0000 to
executor(1)@192.168.122.135:34800
I0122 20:08:40.341928 10597 exec.cpp:354] Executor received status update
acknowledgement 1e6c6032-dd25-4449-beff-4dc7d25fa859 for task 1 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.339537 10563 status_update_manager.cpp:389] Received status
update acknowledgement (UUID: 5858b2f8-57dc-4349-94bf-6c40fadc4298) for task 1
of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.345861 10563 status_update_manager.cpp:371] Forwarding update
TASK_FINISHED (UUID: 1e6c6032-dd25-4449-beff-4dc7d25fa859) for task 1 of
framework 20150122-200839-2272962752-42248-10532-0000 to the slave
I0122 20:08:40.346510 10563 status_update_manager.cpp:389] Received status
update acknowledgement (UUID: 3f241a80-a50d-43b9-8f5c-e15cc403bbfc) for task 0
of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.346947 10563 status_update_manager.cpp:525] Cleaning up status
update stream for task 0 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.347085 10562 leveldb.cpp:343] Persisting action (488 bytes) to
leveldb took 66488ns
I0122 20:08:40.347264 10557 slave.cpp:2508] Forwarding the update TASK_FINISHED
(UUID: 1e6c6032-dd25-4449-beff-4dc7d25fa859) for task 1 of framework
20150122-200839-2272962752-42248-10532-0000 to [email protected]:42248
I0122 20:08:40.350143 10557 slave.cpp:1852] Status update manager successfully
handled status update acknowledgement (UUID:
5858b2f8-57dc-4349-94bf-6c40fadc4298) for task 1 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.350641 10557 slave.cpp:1852] Status update manager successfully
handled status update acknowledgement (UUID:
3f241a80-a50d-43b9-8f5c-e15cc403bbfc) for task 0 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.350833 10557 slave.cpp:4268] Completing task 0
I0122 20:08:40.350466 10564 master.cpp:3652] Forwarding status update
TASK_FINISHED (UUID: 1e6c6032-dd25-4449-beff-4dc7d25fa859) for task 1 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.351483 10564 master.cpp:3624] Status update TASK_FINISHED (UUID:
1e6c6032-dd25-4449-beff-4dc7d25fa859) for task 1 of framework
20150122-200839-2272962752-42248-10532-0000 from slave
20150122-200839-2272962752-42248-10532-S0 at slave(2)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.351804 10564 master.cpp:4934] Updating the latest state of task
1 of framework 20150122-200839-2272962752-42248-10532-0000 to TASK_FINISHED
I0122 20:08:40.351753 10559 scheduler.cpp:586] Enqueuing event 5 from
[email protected]:42248
Received an UPDATE event
Task 1 is in state TASK_FINISHED
I0122 20:08:40.353961 10559 master.cpp:4993] Removing task 1 with resources
cpus(*):1; mem(*):128 of framework 20150122-200839-2272962752-42248-10532-0000
on slave 20150122-200839-2272962752-42248-10532-S0 at
slave(2)@192.168.122.135:42248 (fedora-19)
I0122 20:08:40.354480 10559 master.cpp:3125] Forwarding status update
acknowledgement 1e6c6032-dd25-4449-beff-4dc7d25fa859 for task 1 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 to slave
20150122-200839-2272962752-42248-10532-S0 at slave(2)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.354969 10564 status_update_manager.cpp:389] Received status
update acknowledgement (UUID: 1e6c6032-dd25-4449-beff-4dc7d25fa859) for task 1
of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.355335 10564 status_update_manager.cpp:525] Cleaning up status
update stream for task 1 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.355859 10564 slave.cpp:1852] Status update manager successfully
handled status update acknowledgement (UUID:
1e6c6032-dd25-4449-beff-4dc7d25fa859) for task 1 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.356041 10564 slave.cpp:4268] Completing task 1
I0122 20:08:40.356495 10562 replica.cpp:679] Persisted action at 5
I0122 20:08:40.356811 10562 replica.cpp:664] Replica learned APPEND action at
position 5
I0122 20:08:40.358880 10562 registrar.cpp:490] Successfully updated the
'registry' in 44.509952ms
I0122 20:08:40.359055 10559 log.cpp:703] Attempting to truncate the log to 5
I0122 20:08:40.359797 10559 coordinator.cpp:340] Coordinator attempting to
write TRUNCATE action at position 6
I0122 20:08:40.361030 10557 replica.cpp:511] Replica received write request for
position 6
I0122 20:08:40.361729 10557 leveldb.cpp:343] Persisting action (16 bytes) to
leveldb took 58391ns
I0122 20:08:40.361884 10557 replica.cpp:679] Persisted action at 6
I0122 20:08:40.363170 10559 replica.cpp:658] Replica received learned notice
for position 6
I0122 20:08:40.363654 10559 leveldb.cpp:343] Persisting action (18 bytes) to
leveldb took 53013ns
I0122 20:08:40.363848 10559 leveldb.cpp:401] Deleting ~2 keys from leveldb took
42777ns
I0122 20:08:40.364101 10559 replica.cpp:679] Persisted action at 6
I0122 20:08:40.364305 10559 replica.cpp:664] Replica learned TRUNCATE action at
position 6
I0122 20:08:40.365901 10561 master.cpp:3329] Registered slave
20150122-200839-2272962752-42248-10532-S1 at slave(3)@192.168.122.135:42248
(fedora-19) with cpus(*):2; mem(*):10240; disk(*):752; ports(*):[31000-32000]
I0122 20:08:40.366505 10560 hierarchical_allocator_process.hpp:453] Added slave
20150122-200839-2272962752-42248-10532-S1 (fedora-19) with cpus(*):2;
mem(*):10240; disk(*):752; ports(*):[31000-32000] (and cpus(*):2; mem(*):10240;
disk(*):752; ports(*):[31000-32000] available)
I0122 20:08:40.366591 10564 slave.cpp:781] Registered with master
[email protected]:42248; given slave ID
20150122-200839-2272962752-42248-10532-S1
I0122 20:08:40.367792 10560 hierarchical_allocator_process.hpp:764] Performed
allocation for slave 20150122-200839-2272962752-42248-10532-S1 in 1.021954ms
I0122 20:08:40.368551 10560 status_update_manager.cpp:178] Resuming sending
status updates
I0122 20:08:40.368489 10564 slave.cpp:797] Checkpointing SlaveInfo to
'/tmp/mesos-xY0d15/2/meta/slaves/20150122-200839-2272962752-42248-10532-S1/slave.info'
I0122 20:08:40.369320 10564 slave.cpp:2588] Received ping from
slave-observer(2)@192.168.122.135:42248
I0122 20:08:40.369823 10560 master.cpp:4071] Sending 1 offers to framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248
I0122 20:08:40.370368 10560 scheduler.cpp:586] Enqueuing event 3 from
[email protected]:42248
Received an OFFERS event
Received offer 20150122-200839-2272962752-42248-10532-O1 with cpus(*):2;
mem(*):10240; disk(*):752; ports(*):[31000-32000]
Launching task 2 using offer 20150122-200839-2272962752-42248-10532-O1
Launching task 3 using offer 20150122-200839-2272962752-42248-10532-O1
I0122 20:08:40.375704 10558 master.cpp:2677] Processing ACCEPT call for offers:
[ 20150122-200839-2272962752-42248-10532-O1 ] on slave
20150122-200839-2272962752-42248-10532-S1 at slave(3)@192.168.122.135:42248
(fedora-19) for framework 20150122-200839-2272962752-42248-10532-0000
(Low-Level Scheduler using pthread (C++)) at scheduler(1)@192.168.122.135:42248
I0122 20:08:40.375888 10558 master.cpp:2513] Authorizing framework principal
'test-principal' to launch task 2 as user 'jenkins'
I0122 20:08:40.376291 10558 master.cpp:2513] Authorizing framework principal
'test-principal' to launch task 3 as user 'jenkins'
W0122 20:08:40.377882 10558 master.cpp:2130] Executor default for task 2 uses
less CPUs (None) than the minimum required (0.01). Please update your executor,
as this will be mandatory in future releases.
W0122 20:08:40.378118 10558 master.cpp:2142] Executor default for task 2 uses
less memory (None) than the minimum required (32MB). Please update your
executor, as this will be mandatory in future releases.
I0122 20:08:40.379070 10558 master.hpp:782] Adding task 2 with resources
cpus(*):1; mem(*):128 on slave 20150122-200839-2272962752-42248-10532-S1
(fedora-19)
I0122 20:08:40.379295 10558 master.cpp:2885] Launching task 2 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 with resources cpus(*):1;
mem(*):128 on slave 20150122-200839-2272962752-42248-10532-S1 at
slave(3)@192.168.122.135:42248 (fedora-19)
I0122 20:08:40.379976 10564 slave.cpp:1130] Got assigned task 2 for framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.380890 10564 slave.cpp:1245] Launching task 2 for framework
20150122-200839-2272962752-42248-10532-0000
W0122 20:08:40.383601 10558 master.cpp:2130] Executor default for task 3 uses
less CPUs (None) than the minimum required (0.01). Please update your executor,
as this will be mandatory in future releases.
W0122 20:08:40.386440 10558 master.cpp:2142] Executor default for task 3 uses
less memory (None) than the minimum required (32MB). Please update your
executor, as this will be mandatory in future releases.
I0122 20:08:40.386993 10558 master.hpp:782] Adding task 3 with resources
cpus(*):1; mem(*):128 on slave 20150122-200839-2272962752-42248-10532-S1
(fedora-19)
I0122 20:08:40.387166 10564 slave.cpp:3921] Launching executor default of
framework 20150122-200839-2272962752-42248-10532-0000 in work directory
'/tmp/mesos-xY0d15/2/slaves/20150122-200839-2272962752-42248-10532-S1/frameworks/20150122-200839-2272962752-42248-10532-0000/executors/default/runs/9ff27ea5-f18f-433f-bdba-58cdcb2b31f5'
I0122 20:08:40.387878 10558 master.cpp:2885] Launching task 3 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 with resources cpus(*):1;
mem(*):128 on slave 20150122-200839-2272962752-42248-10532-S1 at
slave(3)@192.168.122.135:42248 (fedora-19)
I0122 20:08:40.388492 10563 containerizer.cpp:445] Starting container
'9ff27ea5-f18f-433f-bdba-58cdcb2b31f5' for executor 'default' of framework
'20150122-200839-2272962752-42248-10532-0000'
I0122 20:08:40.393259 10564 slave.cpp:1368] Queuing task '2' for executor
default of framework '20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.394104 10564 slave.cpp:566] Successfully attached file
'/tmp/mesos-xY0d15/2/slaves/20150122-200839-2272962752-42248-10532-S1/frameworks/20150122-200839-2272962752-42248-10532-0000/executors/default/runs/9ff27ea5-f18f-433f-bdba-58cdcb2b31f5'
I0122 20:08:40.394556 10564 slave.cpp:1130] Got assigned task 3 for framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.395155 10564 slave.cpp:1245] Launching task 3 for framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.395787 10559 hierarchical_allocator_process.hpp:653] Recovered
mem(*):9984; disk(*):752; ports(*):[31000-32000] (total allocatable:
mem(*):9984; disk(*):752; ports(*):[31000-32000]) on slave
20150122-200839-2272962752-42248-10532-S1 from framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.396286 10559 hierarchical_allocator_process.hpp:689] Framework
20150122-200839-2272962752-42248-10532-0000 filtered slave
20150122-200839-2272962752-42248-10532-S1 for 5secs
I0122 20:08:40.396797 10564 slave.cpp:1368] Queuing task '3' for executor
default of framework '20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.400925 10563 launcher.cpp:137] Forked child with pid '10603' for
container '9ff27ea5-f18f-433f-bdba-58cdcb2b31f5'
I0122 20:08:40.418807 10559 slave.cpp:2890] Monitoring executor 'default' of
framework '20150122-200839-2272962752-42248-10532-0000' in container
'9ff27ea5-f18f-433f-bdba-58cdcb2b31f5'
I0122 20:08:40.541836 10561 slave.cpp:1075] Will retry registration in
805.728481ms if necessary
I0122 20:08:40.542330 10559 master.cpp:3275] Registering slave at
slave(1)@192.168.122.135:42248 (fedora-19) with id
20150122-200839-2272962752-42248-10532-S2
I0122 20:08:40.543189 10559 registrar.cpp:445] Applied 1 operations in
126376ns; attempting to update the 'registry'
I0122 20:08:40.549960 10557 log.cpp:684] Attempting to append 632 bytes to the
log
I0122 20:08:40.550444 10558 coordinator.cpp:340] Coordinator attempting to
write APPEND action at position 7
I0122 20:08:40.551933 10558 replica.cpp:511] Replica received write request for
position 7
I0122 20:08:40.556540 10558 leveldb.cpp:343] Persisting action (651 bytes) to
leveldb took 87788ns
I0122 20:08:40.556716 10558 replica.cpp:679] Persisted action at 7
I0122 20:08:40.560170 10562 replica.cpp:658] Replica received learned notice
for position 7
I0122 20:08:40.560578 10562 leveldb.cpp:343] Persisting action (653 bytes) to
leveldb took 262269ns
I0122 20:08:40.560833 10562 replica.cpp:679] Persisted action at 7
I0122 20:08:40.560984 10562 replica.cpp:664] Replica learned APPEND action at
position 7
I0122 20:08:40.566922 10562 log.cpp:703] Attempting to truncate the log to 7
I0122 20:08:40.567323 10557 coordinator.cpp:340] Coordinator attempting to
write TRUNCATE action at position 8
I0122 20:08:40.568490 10561 replica.cpp:511] Replica received write request for
position 8
I0122 20:08:40.568707 10561 leveldb.cpp:343] Persisting action (16 bytes) to
leveldb took 49961ns
I0122 20:08:40.568933 10561 replica.cpp:679] Persisted action at 8
I0122 20:08:40.570076 10563 replica.cpp:658] Replica received learned notice
for position 8
I0122 20:08:40.570283 10563 leveldb.cpp:343] Persisting action (18 bytes) to
leveldb took 55166ns
I0122 20:08:40.570623 10563 leveldb.cpp:401] Deleting ~2 keys from leveldb took
41766ns
I0122 20:08:40.570855 10563 replica.cpp:679] Persisted action at 8
I0122 20:08:40.571092 10563 replica.cpp:664] Replica learned TRUNCATE action at
position 8
I0122 20:08:40.573290 10559 registrar.cpp:490] Successfully updated the
'registry' in 25.792768ms
I0122 20:08:40.578714 10558 master.cpp:3329] Registered slave
20150122-200839-2272962752-42248-10532-S2 at slave(1)@192.168.122.135:42248
(fedora-19) with cpus(*):2; mem(*):10240; disk(*):752; ports(*):[31000-32000]
I0122 20:08:40.579231 10560 slave.cpp:781] Registered with master
[email protected]:42248; given slave ID
20150122-200839-2272962752-42248-10532-S2
I0122 20:08:40.579784 10561 status_update_manager.cpp:178] Resuming sending
status updates
I0122 20:08:40.580266 10560 slave.cpp:797] Checkpointing SlaveInfo to
'/tmp/mesos-xY0d15/0/meta/slaves/20150122-200839-2272962752-42248-10532-S2/slave.info'
I0122 20:08:40.579411 10563 hierarchical_allocator_process.hpp:453] Added slave
20150122-200839-2272962752-42248-10532-S2 (fedora-19) with cpus(*):2;
mem(*):10240; disk(*):752; ports(*):[31000-32000] (and cpus(*):2; mem(*):10240;
disk(*):752; ports(*):[31000-32000] available)
I0122 20:08:40.582334 10560 slave.cpp:2588] Received ping from
slave-observer(3)@192.168.122.135:42248
I0122 20:08:40.583549 10563 hierarchical_allocator_process.hpp:764] Performed
allocation for slave 20150122-200839-2272962752-42248-10532-S2 in 2.608018ms
I0122 20:08:40.584131 10558 master.cpp:4071] Sending 1 offers to framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248
I0122 20:08:40.586567 10561 scheduler.cpp:586] Enqueuing event 3 from
[email protected]:42248
Received an OFFERS event
Received offer 20150122-200839-2272962752-42248-10532-O2 with cpus(*):2;
mem(*):10240; disk(*):752; ports(*):[31000-32000]
Launching task 4 using offer 20150122-200839-2272962752-42248-10532-O2
I0122 20:08:40.592905 10558 master.cpp:2677] Processing ACCEPT call for offers:
[ 20150122-200839-2272962752-42248-10532-O2 ] on slave
20150122-200839-2272962752-42248-10532-S2 at slave(1)@192.168.122.135:42248
(fedora-19) for framework 20150122-200839-2272962752-42248-10532-0000
(Low-Level Scheduler using pthread (C++)) at scheduler(1)@192.168.122.135:42248
I0122 20:08:40.593096 10558 master.cpp:2513] Authorizing framework principal
'test-principal' to launch task 4 as user 'jenkins'
W0122 20:08:40.595840 10557 master.cpp:2130] Executor default for task 4 uses
less CPUs (None) than the minimum required (0.01). Please update your executor,
as this will be mandatory in future releases.
W0122 20:08:40.599565 10557 master.cpp:2142] Executor default for task 4 uses
less memory (None) than the minimum required (32MB). Please update your
executor, as this will be mandatory in future releases.
I0122 20:08:40.600139 10557 master.hpp:782] Adding task 4 with resources
cpus(*):1; mem(*):128 on slave 20150122-200839-2272962752-42248-10532-S2
(fedora-19)
I0122 20:08:40.600373 10557 master.cpp:2885] Launching task 4 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 with resources cpus(*):1;
mem(*):128 on slave 20150122-200839-2272962752-42248-10532-S2 at
slave(1)@192.168.122.135:42248 (fedora-19)
I0122 20:08:40.602550 10561 hierarchical_allocator_process.hpp:903] Filtered
mem(*):9984; disk(*):752; ports(*):[31000-32000] on slave
20150122-200839-2272962752-42248-10532-S1 for framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.603024 10562 slave.cpp:1130] Got assigned task 4 for framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.605978 10562 slave.cpp:1245] Launching task 4 for framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.607987 10561 hierarchical_allocator_process.hpp:746] Performed
allocation for 3 slaves in 5.825759ms
I0122 20:08:40.611176 10561 hierarchical_allocator_process.hpp:653] Recovered
cpus(*):1; mem(*):10112; disk(*):752; ports(*):[31000-32000] (total
allocatable: cpus(*):1; mem(*):10112; disk(*):752; ports(*):[31000-32000]) on
slave 20150122-200839-2272962752-42248-10532-S2 from framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.611373 10561 hierarchical_allocator_process.hpp:689] Framework
20150122-200839-2272962752-42248-10532-0000 filtered slave
20150122-200839-2272962752-42248-10532-S2 for 5secs
I0122 20:08:40.610733 10560 master.cpp:4071] Sending 1 offers to framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0122 20:08:40.615535 10564 scheduler.cpp:586] Enqueuing event 3 from
[email protected]:42248
Received an OFFERS event
Received offer 20150122-200839-2272962752-42248-10532-O3 with mem(*):10240;
disk(*):752; ports(*):[31000-32000]; cpus(*):2
I0122 20:08:40.618844 10560 master.cpp:2677] Processing ACCEPT call for offers:
[ 20150122-200839-2272962752-42248-10532-O3 ] on slave
20150122-200839-2272962752-42248-10532-S0 at slave(2)@192.168.122.135:42248
(fedora-19) for framework 20150122-200839-2272962752-42248-10532-0000
(Low-Level Scheduler using pthread (C++)) at scheduler(1)@192.168.122.135:42248
I0122 20:08:40.614884 10603 process.cpp:958] libprocess is initialized on
192.168.122.135:60215 for 8 cpus
I0122 20:08:40.623142 10563 hierarchical_allocator_process.hpp:653] Recovered
mem(*):10240; disk(*):752; ports(*):[31000-32000]; cpus(*):2 (total
allocatable: mem(*):10240; disk(*):752; ports(*):[31000-32000]; cpus(*):2) on
slave 20150122-200839-2272962752-42248-10532-S0 from framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.623333 10563 hierarchical_allocator_process.hpp:689] Framework
20150122-200839-2272962752-42248-10532-0000 filtered slave
20150122-200839-2272962752-42248-10532-S0 for 5secs
I0122 20:08:40.623661 10603 logging.cpp:177] Logging to STDERR
I0122 20:08:40.628443 10603 exec.cpp:147] Version: 0.22.0
I0122 20:08:40.629503 10562 slave.cpp:3921] Launching executor default of
framework 20150122-200839-2272962752-42248-10532-0000 in work directory
'/tmp/mesos-xY0d15/0/slaves/20150122-200839-2272962752-42248-10532-S2/frameworks/20150122-200839-2272962752-42248-10532-0000/executors/default/runs/45415118-19bf-41bf-a6cb-2d9a822ecde4'
I0122 20:08:40.632686 10561 containerizer.cpp:445] Starting container
'45415118-19bf-41bf-a6cb-2d9a822ecde4' for executor 'default' of framework
'20150122-200839-2272962752-42248-10532-0000'
I0122 20:08:40.642963 10562 slave.cpp:1368] Queuing task '4' for executor
default of framework '20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.644832 10562 slave.cpp:566] Successfully attached file
'/tmp/mesos-xY0d15/0/slaves/20150122-200839-2272962752-42248-10532-S2/frameworks/20150122-200839-2272962752-42248-10532-0000/executors/default/runs/45415118-19bf-41bf-a6cb-2d9a822ecde4'
I0122 20:08:40.649799 10635 exec.cpp:197] Executor started at:
executor(1)@192.168.122.135:60215 with pid 10603
I0122 20:08:40.665899 10559 slave.cpp:1912] Got registration for executor
'default' of framework 20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:60215
I0122 20:08:40.669504 10559 slave.cpp:2031] Flushing queued task 2 for executor
'default' of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.679615 10633 exec.cpp:221] Executor registered on slave
20150122-200839-2272962752-42248-10532-S1
Registered executor on fedora-19
I0122 20:08:40.681521 10633 exec.cpp:233] Executor::registered took 213348ns
I0122 20:08:40.685662 10559 slave.cpp:2031] Flushing queued task 3 for executor
'default' of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.688174 10636 exec.cpp:308] Executor asked to run task '2'
Starting task 2
Finishing task 2
I0122 20:08:40.689067 10636 exec.cpp:317] Executor::launchTask took 410277ns
I0122 20:08:40.690079 10561 launcher.cpp:137] Forked child with pid '10639' for
container '45415118-19bf-41bf-a6cb-2d9a822ecde4'
I0122 20:08:40.695547 10636 exec.cpp:540] Executor sending status update
TASK_RUNNING (UUID: ccc94cc2-232e-4899-a087-e2dc2b461e65) for task 2 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.699674 10564 slave.cpp:2890] Monitoring executor 'default' of
framework '20150122-200839-2272962752-42248-10532-0000' in container
'45415118-19bf-41bf-a6cb-2d9a822ecde4'
I0122 20:08:40.717429 10636 exec.cpp:540] Executor sending status update
TASK_FINISHED (UUID: 2b20b099-7128-451a-919d-adb649411d4e) for task 2 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.718463 10636 exec.cpp:308] Executor asked to run task '3'
Starting task 3
Finishing task 3
I0122 20:08:40.719969 10636 exec.cpp:317] Executor::launchTask took 1.114264ms
I0122 20:08:40.721158 10564 slave.cpp:2265] Handling status update TASK_RUNNING
(UUID: ccc94cc2-232e-4899-a087-e2dc2b461e65) for task 2 of framework
20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:60215
II0122 20:08:40.726655 10564 slave.cpp:2265] Handling status update
TASK_FINISHED (UUID: 2b20b099-7128-451a-919d-adb649411d4e) for task 2 of
framework 20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:60215
I0122 20:08:40.726865 10562 status_update_manager.cpp:317] Received status
update TASK_RUNNING (UUID: ccc94cc2-232e-4899-a087-e2dc2b461e65) for task 2 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.727193 10562 status_update_manager.cpp:494] Creating
StatusUpdate stream for task 2 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.727747 10562 status_update_manager.cpp:371] Forwarding update
TASK_RUNNING (UUID: ccc94cc2-232e-4899-a087-e2dc2b461e65) for task 2 of
framework 20150122-200839-2272962752-42248-10532-0000 to the slave
I0122 20:08:40.728168 10564 slave.cpp:4229] Terminating task 2
0122 20:08:40.722985 10636 exec.cpp:540] Executor sending status update
TASK_RUNNING (UUID: dd34b260-176e-499e-998b-24bf9ec7bcef) for task 3 of
framework 20150122-200839-2272962752-42248-10532-0000
II0122 20:08:40.731721 10564 slave.cpp:2508] Forwarding the update TASK_RUNNING
(UUID: ccc94cc2-232e-4899-a087-e2dc2b461e65) for task 2 of framework
20150122-200839-2272962752-42248-10532-0000 to [email protected]:42248
I0122 20:08:40.733245 10564 slave.cpp:2265] Handling status update TASK_RUNNING
(UUID: dd34b260-176e-499e-998b-24bf9ec7bcef) for task 3 of framework
20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:60215
0122 20:08:40.730630 10636 exec.cpp:540] Executor sending status update
TASK_FINISHED (UUID: 70c2a9a5-decb-4b85-ae32-dceb75dbdaca) for task 3 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.734875 10563 master.cpp:3652] Forwarding status update
TASK_RUNNING (UUID: ccc94cc2-232e-4899-a087-e2dc2b461e65) for task 2 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.736168 10563 master.cpp:3624] Status update TASK_RUNNING (UUID:
ccc94cc2-232e-4899-a087-e2dc2b461e65) for task 2 of framework
20150122-200839-2272962752-42248-10532-0000 from slave
20150122-200839-2272962752-42248-10532-S1 at slave(3)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.740586 10563 master.cpp:4934] Updating the latest state of task
2 of framework 20150122-200839-2272962752-42248-10532-0000 to TASK_FINISHED
(status update state: TASK_RUNNING)
I0122 20:08:40.740514 10561 scheduler.cpp:586] Enqueuing event 5 from
[email protected]:42248
Received an UPDATE event
Task 2 is in state TASK_RUNNING
I0122 20:08:40.741619 10563 hierarchical_allocator_process.hpp:653] Recovered
cpus(*):1; mem(*):128 (total allocatable: mem(*):10112; disk(*):752;
ports(*):[31000-32000]; cpus(*):1) on slave
20150122-200839-2272962752-42248-10532-S1 from framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.743125 10561 master.cpp:3125] Forwarding status update
acknowledgement ccc94cc2-232e-4899-a087-e2dc2b461e65 for task 2 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 to slave
20150122-200839-2272962752-42248-10532-S1 at slave(3)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.743201 10557 status_update_manager.cpp:317] Received status
update TASK_RUNNING (UUID: dd34b260-176e-499e-998b-24bf9ec7bcef) for task 3 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.743988 10557 status_update_manager.cpp:494] Creating
StatusUpdate stream for task 3 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.744329 10557 status_update_manager.cpp:371] Forwarding update
TASK_RUNNING (UUID: dd34b260-176e-499e-998b-24bf9ec7bcef) for task 3 of
framework 20150122-200839-2272962752-42248-10532-0000 to the slave
I0122 20:08:40.744786 10557 status_update_manager.cpp:317] Received status
update TASK_FINISHED (UUID: 2b20b099-7128-451a-919d-adb649411d4e) for task 2 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.745403 10564 slave.cpp:2435] Status update manager successfully
handled status update TASK_RUNNING (UUID: ccc94cc2-232e-4899-a087-e2dc2b461e65)
for task 2 of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.745568 10564 slave.cpp:2441] Sending acknowledgement for status
update TASK_RUNNING (UUID: ccc94cc2-232e-4899-a087-e2dc2b461e65) for task 2 of
framework 20150122-200839-2272962752-42248-10532-0000 to
executor(1)@192.168.122.135:60215
I0122 20:08:40.747900 10637 exec.cpp:354] Executor received status update
acknowledgement ccc94cc2-232e-4899-a087-e2dc2b461e65 for task 2 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.751119 10564 slave.cpp:2265] Handling status update
TASK_FINISHED (UUID: 70c2a9a5-decb-4b85-ae32-dceb75dbdaca) for task 3 of
framework 20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:60215
I0122 20:08:40.751344 10564 slave.cpp:4229] Terminating task 3
I0122 20:08:40.753001 10564 slave.cpp:2508] Forwarding the update TASK_RUNNING
(UUID: dd34b260-176e-499e-998b-24bf9ec7bcef) for task 3 of framework
20150122-200839-2272962752-42248-10532-0000 to [email protected]:42248
I0122 20:08:40.758657 10558 master.cpp:3652] Forwarding status update
TASK_RUNNING (UUID: dd34b260-176e-499e-998b-24bf9ec7bcef) for task 3 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.759134 10562 scheduler.cpp:586] Enqueuing event 5 from
[email protected]:42248
I0122 20:08:40.763401 10558 master.cpp:3624] Status update TASK_RUNNING (UUID:
dd34b260-176e-499e-998b-24bf9ec7bcef) for task 3 of framework
20150122-200839-2272962752-42248-10532-0000 from slave
20150122-200839-2272962752-42248-10532-S1 at slave(3)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.763607 10558 master.cpp:4934] Updating the latest state of task
3 of framework 20150122-200839-2272962752-42248-10532-0000 to TASK_FINISHED
(status update state: TASK_RUNNING)
I0122 20:08:40.764101 10558 hierarchical_allocator_process.hpp:653] Recovered
cpus(*):1; mem(*):128 (total allocatable: mem(*):10240; disk(*):752;
ports(*):[31000-32000]; cpus(*):2) on slave
20150122-200839-2272962752-42248-10532-S1 from framework
20150122-200839-2272962752-42248-10532-0000
Received an UPDATE event
Task 3 is in state TASK_RUNNING
I0122 20:08:40.765974 10562 master.cpp:3125] Forwarding status update
acknowledgement dd34b260-176e-499e-998b-24bf9ec7bcef for task 3 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 to slave
20150122-200839-2272962752-42248-10532-S1 at slave(3)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.766343 10564 slave.cpp:2435] Status update manager successfully
handled status update TASK_RUNNING (UUID: dd34b260-176e-499e-998b-24bf9ec7bcef)
for task 3 of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.766548 10564 slave.cpp:2441] Sending acknowledgement for status
update TASK_RUNNING (UUID: dd34b260-176e-499e-998b-24bf9ec7bcef) for task 3 of
framework 20150122-200839-2272962752-42248-10532-0000 to
executor(1)@192.168.122.135:60215
I0122 20:08:40.768641 10637 exec.cpp:354] Executor received status update
acknowledgement dd34b260-176e-499e-998b-24bf9ec7bcef for task 3 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.773669 10563 status_update_manager.cpp:389] Received status
update acknowledgement (UUID: ccc94cc2-232e-4899-a087-e2dc2b461e65) for task 2
of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.773919 10563 status_update_manager.cpp:371] Forwarding update
TASK_FINISHED (UUID: 2b20b099-7128-451a-919d-adb649411d4e) for task 2 of
framework 20150122-200839-2272962752-42248-10532-0000 to the slave
I0122 20:08:40.774297 10564 slave.cpp:2435] Status update manager successfully
handled status update TASK_FINISHED (UUID:
2b20b099-7128-451a-919d-adb649411d4e) for task 2 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.774417 10564 slave.cpp:2441] Sending acknowledgement for status
update TASK_FINISHED (UUID: 2b20b099-7128-451a-919d-adb649411d4e) for task 2 of
framework 20150122-200839-2272962752-42248-10532-0000 to
executor(1)@192.168.122.135:60215
I0122 20:08:40.776123 10630 exec.cpp:354] Executor received status update
acknowledgement 2b20b099-7128-451a-919d-adb649411d4e for task 2 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.780586 10559 status_update_manager.cpp:317] Received status
update TASK_FINISHED (UUID: 70c2a9a5-decb-4b85-ae32-dceb75dbdaca) for task 3 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.784471 10560 status_update_manager.cpp:389] Received status
update acknowledgement (UUID: dd34b260-176e-499e-998b-24bf9ec7bcef) for task 3
of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.784726 10560 status_update_manager.cpp:371] Forwarding update
TASK_FINISHED (UUID: 70c2a9a5-decb-4b85-ae32-dceb75dbdaca) for task 3 of
framework 20150122-200839-2272962752-42248-10532-0000 to the slave
I0122 20:08:40.785308 10564 slave.cpp:2508] Forwarding the update TASK_FINISHED
(UUID: 2b20b099-7128-451a-919d-adb649411d4e) for task 2 of framework
20150122-200839-2272962752-42248-10532-0000 to [email protected]:42248
I0122 20:08:40.785856 10558 master.cpp:3652] Forwarding status update
TASK_FINISHED (UUID: 2b20b099-7128-451a-919d-adb649411d4e) for task 2 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.786310 10558 master.cpp:3624] Status update TASK_FINISHED (UUID:
2b20b099-7128-451a-919d-adb649411d4e) for task 2 of framework
20150122-200839-2272962752-42248-10532-0000 from slave
20150122-200839-2272962752-42248-10532-S1 at slave(3)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.787513 10558 master.cpp:4934] Updating the latest state of task
2 of framework 20150122-200839-2272962752-42248-10532-0000 to TASK_FINISHED
I0122 20:08:40.787453 10557 scheduler.cpp:586] Enqueuing event 5 from
[email protected]:42248
Received an UPDATE event
Task 2 is in state TASK_FINISHED
I0122 20:08:40.792043 10557 master.cpp:4993] Removing task 2 with resources
cpus(*):1; mem(*):128 of framework 20150122-200839-2272962752-42248-10532-0000
on slave 20150122-200839-2272962752-42248-10532-S1 at
slave(3)@192.168.122.135:42248 (fedora-19)
I0122 20:08:40.792562 10557 master.cpp:3125] Forwarding status update
acknowledgement 2b20b099-7128-451a-919d-adb649411d4e for task 2 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 to slave
20150122-200839-2272962752-42248-10532-S1 at slave(3)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.792922 10564 slave.cpp:1852] Status update manager successfully
handled status update acknowledgement (UUID:
ccc94cc2-232e-4899-a087-e2dc2b461e65) for task 2 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.793135 10564 slave.cpp:2435] Status update manager successfully
handled status update TASK_FINISHED (UUID:
70c2a9a5-decb-4b85-ae32-dceb75dbdaca) for task 3 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.796571 10564 slave.cpp:2441] Sending acknowledgement for status
update TASK_FINISHED (UUID: 70c2a9a5-decb-4b85-ae32-dceb75dbdaca) for task 3 of
framework 20150122-200839-2272962752-42248-10532-0000 to
executor(1)@192.168.122.135:60215
I0122 20:08:40.801857 10634 exec.cpp:354] Executor received status update
acknowledgement 70c2a9a5-decb-4b85-ae32-dceb75dbdaca for task 3 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.806483 10564 slave.cpp:2508] Forwarding the update TASK_FINISHED
(UUID: 70c2a9a5-decb-4b85-ae32-dceb75dbdaca) for task 3 of framework
20150122-200839-2272962752-42248-10532-0000 to [email protected]:42248
I0122 20:08:40.806995 10561 master.cpp:3652] Forwarding status update
TASK_FINISHED (UUID: 70c2a9a5-decb-4b85-ae32-dceb75dbdaca) for task 3 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.807569 10561 master.cpp:3624] Status update TASK_FINISHED (UUID:
70c2a9a5-decb-4b85-ae32-dceb75dbdaca) for task 3 of framework
20150122-200839-2272962752-42248-10532-0000 from slave
20150122-200839-2272962752-42248-10532-S1 at slave(3)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.808123 10561 master.cpp:4934] Updating the latest state of task
3 of framework 20150122-200839-2272962752-42248-10532-0000 to TASK_FINISHED
I0122 20:08:40.808059 10560 scheduler.cpp:586] Enqueuing event 5 from
[email protected]:42248
Received an UPDATE event
Task 3 is in state TASK_FINISHED
I0122 20:08:40.811568 10560 master.cpp:4993] Removing task 3 with resources
cpus(*):1; mem(*):128 of framework 20150122-200839-2272962752-42248-10532-0000
on slave 20150122-200839-2272962752-42248-10532-S1 at
slave(3)@192.168.122.135:42248 (fedora-19)
I0122 20:08:40.812093 10560 master.cpp:3125] Forwarding status update
acknowledgement 70c2a9a5-decb-4b85-ae32-dceb75dbdaca for task 3 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 to slave
20150122-200839-2272962752-42248-10532-S1 at slave(3)@192.168.122.135:42248
(fedora-19)
I0122 20:08:40.813508 10564 slave.cpp:1852] Status update manager successfully
handled status update acknowledgement (UUID:
dd34b260-176e-499e-998b-24bf9ec7bcef) for task 3 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.813998 10563 status_update_manager.cpp:389] Received status
update acknowledgement (UUID: 2b20b099-7128-451a-919d-adb649411d4e) for task 2
of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.814224 10563 status_update_manager.cpp:525] Cleaning up status
update stream for task 2 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.814972 10557 status_update_manager.cpp:389] Received status
update acknowledgement (UUID: 70c2a9a5-decb-4b85-ae32-dceb75dbdaca) for task 3
of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.816488 10557 status_update_manager.cpp:525] Cleaning up status
update stream for task 3 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.816992 10564 slave.cpp:1852] Status update manager successfully
handled status update acknowledgement (UUID:
2b20b099-7128-451a-919d-adb649411d4e) for task 2 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.817180 10564 slave.cpp:4268] Completing task 2
I0122 20:08:40.817477 10564 slave.cpp:1852] Status update manager successfully
handled status update acknowledgement (UUID:
70c2a9a5-decb-4b85-ae32-dceb75dbdaca) for task 3 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.817654 10564 slave.cpp:4268] Completing task 3
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0122 20:08:40.931277 10639 process.cpp:958] libprocess is initialized on
192.168.122.135:39321 for 8 cpus
I0122 20:08:40.931936 10639 logging.cpp:177] Logging to STDERR
I0122 20:08:40.935899 10639 exec.cpp:147] Version: 0.22.0
I0122 20:08:40.955930 10666 exec.cpp:197] Executor started at:
executor(1)@192.168.122.135:39321 with pid 10639
I0122 20:08:40.964131 10559 slave.cpp:1912] Got registration for executor
'default' of framework 20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:39321
I0122 20:08:40.967190 10559 slave.cpp:2031] Flushing queued task 4 for executor
'default' of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.969008 10673 exec.cpp:221] Executor registered on slave
20150122-200839-2272962752-42248-10532-S2
Registered executor on fedora-19
I0122 20:08:40.971034 10673 exec.cpp:233] Executor::registered took 167974ns
I0122 20:08:40.975049 10668 exec.cpp:308] Executor asked to run task '4'
Starting task 4
Finishing task 4
I0122 20:08:40.975874 10668 exec.cpp:317] Executor::launchTask took 578851ns
I0122 20:08:40.977870 10668 exec.cpp:540] Executor sending status update
TASK_RUNNING (UUID: 739d2179-3242-4353-8c4d-a2cb296c1076) for task 4 of
framework 20150122-200839-2272962752-42248-10532-0000
II0122 20:08:40.991987 10560 slave.cpp:2265] Handling status update
TASK_RUNNING (UUID: 739d2179-3242-4353-8c4d-a2cb296c1076) for task 4 of
framework 20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:39321
0122 20:08:40.991050 10668 exec.cpp:540] Executor sending status update
TASK_FINISHED (UUID: 77224e59-26f3-4c18-b7c4-f8073fbe3d19) for task 4 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.993120 10560 status_update_manager.cpp:317] Received status
update TASK_RUNNING (UUID: 739d2179-3242-4353-8c4d-a2cb296c1076) for task 4 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.993940 10560 status_update_manager.cpp:494] Creating
StatusUpdate stream for task 4 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.993860 10563 slave.cpp:2265] Handling status update
TASK_FINISHED (UUID: 77224e59-26f3-4c18-b7c4-f8073fbe3d19) for task 4 of
framework 20150122-200839-2272962752-42248-10532-0000 from
executor(1)@192.168.122.135:39321
I0122 20:08:40.994536 10563 slave.cpp:4229] Terminating task 4
I0122 20:08:40.996110 10560 status_update_manager.cpp:371] Forwarding update
TASK_RUNNING (UUID: 739d2179-3242-4353-8c4d-a2cb296c1076) for task 4 of
framework 20150122-200839-2272962752-42248-10532-0000 to the slave
I0122 20:08:40.996731 10560 status_update_manager.cpp:317] Received status
update TASK_FINISHED (UUID: 77224e59-26f3-4c18-b7c4-f8073fbe3d19) for task 4 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.997251 10558 slave.cpp:2508] Forwarding the update TASK_RUNNING
(UUID: 739d2179-3242-4353-8c4d-a2cb296c1076) for task 4 of framework
20150122-200839-2272962752-42248-10532-0000 to [email protected]:42248
I0122 20:08:40.997838 10557 master.cpp:3652] Forwarding status update
TASK_RUNNING (UUID: 739d2179-3242-4353-8c4d-a2cb296c1076) for task 4 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.998352 10564 scheduler.cpp:586] Enqueuing event 5 from
[email protected]:42248
I0122 20:08:40.997568 10558 slave.cpp:2435] Status update manager successfully
handled status update TASK_RUNNING (UUID: 739d2179-3242-4353-8c4d-a2cb296c1076)
for task 4 of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:40.999615 10558 slave.cpp:2441] Sending acknowledgement for status
update TASK_RUNNING (UUID: 739d2179-3242-4353-8c4d-a2cb296c1076) for task 4 of
framework 20150122-200839-2272962752-42248-10532-0000 to
executor(1)@192.168.122.135:39321
I0122 20:08:40.999567 10557 master.cpp:3624] Status update TASK_RUNNING (UUID:
739d2179-3242-4353-8c4d-a2cb296c1076) for task 4 of framework
20150122-200839-2272962752-42248-10532-0000 from slave
20150122-200839-2272962752-42248-10532-S2 at slave(1)@192.168.122.135:42248
(fedora-19)
I0122 20:08:41.000540 10557 master.cpp:4934] Updating the latest state of task
4 of framework 20150122-200839-2272962752-42248-10532-0000 to TASK_FINISHED
(status update state: TASK_RUNNING)
I0122 20:08:41.001199 10557 hierarchical_allocator_process.hpp:653] Recovered
cpus(*):1; mem(*):128 (total allocatable: cpus(*):2; mem(*):10240; disk(*):752;
ports(*):[31000-32000]) on slave 20150122-200839-2272962752-42248-10532-S2 from
framework 20150122-200839-2272962752-42248-10532-0000
Received an UPDATE event
Task 4 is in state TASK_RUNNING
I0122 20:08:41.003185 10671 exec.cpp:354] Executor received status update
acknowledgement 739d2179-3242-4353-8c4d-a2cb296c1076 for task 4 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.003861 10558 slave.cpp:2435] Status update manager successfully
handled status update TASK_FINISHED (UUID:
77224e59-26f3-4c18-b7c4-f8073fbe3d19) for task 4 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.004186 10558 slave.cpp:2441] Sending acknowledgement for status
update TASK_FINISHED (UUID: 77224e59-26f3-4c18-b7c4-f8073fbe3d19) for task 4 of
framework 20150122-200839-2272962752-42248-10532-0000 to
executor(1)@192.168.122.135:39321
I0122 20:08:41.004698 10561 master.cpp:3125] Forwarding status update
acknowledgement 739d2179-3242-4353-8c4d-a2cb296c1076 for task 4 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 to slave
20150122-200839-2272962752-42248-10532-S2 at slave(1)@192.168.122.135:42248
(fedora-19)
I0122 20:08:41.005631 10667 exec.cpp:354] Executor received status update
acknowledgement 77224e59-26f3-4c18-b7c4-f8073fbe3d19 for task 4 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.009431 10560 status_update_manager.cpp:389] Received status
update acknowledgement (UUID: 739d2179-3242-4353-8c4d-a2cb296c1076) for task 4
of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.009832 10560 status_update_manager.cpp:371] Forwarding update
TASK_FINISHED (UUID: 77224e59-26f3-4c18-b7c4-f8073fbe3d19) for task 4 of
framework 20150122-200839-2272962752-42248-10532-0000 to the slave
I0122 20:08:41.010289 10559 slave.cpp:2508] Forwarding the update TASK_FINISHED
(UUID: 77224e59-26f3-4c18-b7c4-f8073fbe3d19) for task 4 of framework
20150122-200839-2272962752-42248-10532-0000 to [email protected]:42248
I0122 20:08:41.011001 10559 master.cpp:3652] Forwarding status update
TASK_FINISHED (UUID: 77224e59-26f3-4c18-b7c4-f8073fbe3d19) for task 4 of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.011409 10559 master.cpp:3624] Status update TASK_FINISHED (UUID:
77224e59-26f3-4c18-b7c4-f8073fbe3d19) for task 4 of framework
20150122-200839-2272962752-42248-10532-0000 from slave
20150122-200839-2272962752-42248-10532-S2 at slave(1)@192.168.122.135:42248
(fedora-19)
I0122 20:08:41.011595 10559 master.cpp:4934] Updating the latest state of task
4 of framework 20150122-200839-2272962752-42248-10532-0000 to TASK_FINISHED
I0122 20:08:41.012003 10559 scheduler.cpp:586] Enqueuing event 5 from
[email protected]:42248
Received an UPDATE event
Task 4 is in state TASK_FINISHED
I0122 20:08:41.017364 10557 master.cpp:4993] Removing task 4 with resources
cpus(*):1; mem(*):128 of framework 20150122-200839-2272962752-42248-10532-0000
on slave 20150122-200839-2272962752-42248-10532-S2 at
slave(1)@192.168.122.135:42248 (fedora-19)
I0122 20:08:41.017693 10557 master.cpp:3125] Forwarding status update
acknowledgement 77224e59-26f3-4c18-b7c4-f8073fbe3d19 for task 4 of framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248 to slave
20150122-200839-2272962752-42248-10532-S2 at slave(1)@192.168.122.135:42248
(fedora-19)
I0122 20:08:41.017989 10557 master.cpp:1744] Asked to unregister framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.020586 10557 master.cpp:4499] Removing framework
20150122-200839-2272962752-42248-10532-0000 (Low-Level Scheduler using pthread
(C++)) at scheduler(1)@192.168.122.135:42248
I0122 20:08:41.021868 10562 hierarchical_allocator_process.hpp:398] Deactivated
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.022279 10562 slave.cpp:1585] Asked to shut down framework
20150122-200839-2272962752-42248-10532-0000 by [email protected]:42248
I0122 20:08:41.022485 10562 slave.cpp:1610] Shutting down framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.023097 10562 slave.cpp:3198] Shutting down executor 'default' of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.022202 10561 slave.cpp:1585] Asked to shut down framework
20150122-200839-2272962752-42248-10532-0000 by [email protected]:42248
I0122 20:08:41.024669 10561 slave.cpp:1610] Shutting down framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.025168 10561 slave.cpp:3198] Shutting down executor 'default' of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.026361 10558 slave.cpp:1585] Asked to shut down framework
20150122-200839-2272962752-42248-10532-0000 by [email protected]:42248
I0122 20:08:41.026558 10558 slave.cpp:1610] Shutting down framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.026912 10558 slave.cpp:3198] Shutting down executor 'default' of
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.030810 10595 exec.cpp:394] Executor asked to shutdown
I0122 20:08:41.030952 10595 exec.cpp:409] Executor::shutdown took 10847ns
I0122 20:08:41.031111 10595 exec.cpp:90] Scheduling shutdown of the executor
I0122 20:08:41.033154 10560 status_update_manager.cpp:389] Received status
update acknowledgement (UUID: 77224e59-26f3-4c18-b7c4-f8073fbe3d19) for task 4
of framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.033664 10560 status_update_manager.cpp:525] Cleaning up status
update stream for task 4 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.033541 10557 master.cpp:5022] Removing executor 'default' with
resources of framework 20150122-200839-2272962752-42248-10532-0000 on slave
20150122-200839-2272962752-42248-10532-S2 at slave(1)@192.168.122.135:42248
(fedora-19)
I0122 20:08:41.033350 10559 slave.cpp:1852] Status update manager successfully
handled status update acknowledgement (UUID:
739d2179-3242-4353-8c4d-a2cb296c1076) for task 4 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.034914 10557 master.cpp:5022] Removing executor 'default' with
resources of framework 20150122-200839-2272962752-42248-10532-0000 on slave
20150122-200839-2272962752-42248-10532-S1 at slave(3)@192.168.122.135:42248
(fedora-19)
I0122 20:08:41.035495 10563 slave.cpp:1852] Status update manager successfully
handled status update acknowledgement (UUID:
77224e59-26f3-4c18-b7c4-f8073fbe3d19) for task 4 of framework
20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.035691 10563 slave.cpp:4268] Completing task 4
I0122 20:08:41.036345 10557 master.cpp:5022] Removing executor 'default' with
resources of framework 20150122-200839-2272962752-42248-10532-0000 on slave
20150122-200839-2272962752-42248-10532-S0 at slave(2)@192.168.122.135:42248
(fedora-19)
I0122 20:08:41.037884 10637 exec.cpp:394] Executor asked to shutdown
I0122 20:08:41.038007 10637 exec.cpp:409] Executor::shutdown took 3314ns
I0122 20:08:41.038141 10637 exec.cpp:90] Scheduling shutdown of the executor
I0122 20:08:41.040258 10667 exec.cpp:394] Executor asked to shutdown
I0122 20:08:41.040402 10667 exec.cpp:409] Executor::shutdown took 3200ns
I0122 20:08:41.040537 10667 exec.cpp:90] Scheduling shutdown of the executor
I0122 20:08:41.045760 10557 master.cpp:654] Master terminating
I0122 20:08:41.046711 10562 hierarchical_allocator_process.hpp:352] Removed
framework 20150122-200839-2272962752-42248-10532-0000
I0122 20:08:41.071681 10562 slave.cpp:2673] [email protected]:42248 exited
W0122 20:08:41.071836 10562 slave.cpp:2676] Master disconnected! Waiting for a
new master to be elected
I0122 20:08:41.072162 10564 slave.cpp:2673] [email protected]:42248 exited
W0122 20:08:41.072310 10564 slave.cpp:2676] Master disconnected! Waiting for a
new master to be elected
I0122 20:08:41.072582 10561 slave.cpp:2673] [email protected]:42248 exited
W0122 20:08:41.072751 10561 slave.cpp:2676] Master disconnected! Waiting for a
new master to be elected
I0122 20:08:41.096324 10558 monitor.cpp:142] Failed to collect resource usage
for container '5102171c-7b8d-4b49-8a94-dacf1c3e98dc' for executor 'default' of
framework '20150122-200839-2272962752-42248-10532-0000': Unknown container:
5102171c-7b8d-4b49-8a94-dacf1c3e98dc
I0122 20:08:41.099726 10563 slave.cpp:495] Slave terminating
I0122 20:08:41.100277 10563 slave.cpp:1585] Asked to shut down framework
20150122-200839-2272962752-42248-10532-0000 by @0.0.0.0:0
W0122 20:08:41.100471 10563 slave.cpp:1606] Ignoring shutdown framework
20150122-200839-2272962752-42248-10532-0000 because it is terminating
I0122 20:08:41.114271 10532 slave.cpp:495] Slave terminating
I0122 20:08:41.120193 10532 slave.cpp:1585] Asked to shut down framework
20150122-200839-2272962752-42248-10532-0000 by @0.0.0.0:0
W0122 20:08:41.120553 10532 slave.cpp:1606] Ignoring shutdown framework
20150122-200839-2272962752-42248-10532-0000 because it is terminating
I0122 20:08:41.144495 10557 slave.cpp:495] Slave terminating
I0122 20:08:41.144713 10557 slave.cpp:1585] Asked to shut down framework
20150122-200839-2272962752-42248-10532-0000 by @0.0.0.0:0
W0122 20:08:41.145010 10557 slave.cpp:1606] Ignoring shutdown framework
20150122-200839-2272962752-42248-10532-0000 because it is terminating
*** Aborted at 1421986121 (unix time) try "date -d @1421986121" if you are
using GNU date ***
PC: @ 0x110ccb0 (unknown)
*** SIGSEGV (@0x110ccb0) received by PID 10532 (TID 0x7f6d45dd8700) from PID
17878192; stack trace: ***
@ 0x3aa2a0efa0 (unknown)
@ 0x110ccb0 (unknown)
I0122 20:08:41.746435 10601 exec.cpp:455] Ignoring exited event because the
driver is aborted!
I0122 20:08:41.748462 10666 exec.cpp:455] Ignoring exited event because the
driver is aborted!
I0122 20:08:41.749724 10637 exec.cpp:455] Ignoring exited event because the
driver is aborted!
tests/script.cpp:83: Failure
Failed
low_level_scheduler_pthread_test.sh terminated with signal Segmentation fault
[ FAILED ] ExamplesTest.LowLevelSchedulerPthread (3836 ms)
{noformat}
> Segmentation Fault in ExamplesTest.LowLevelSchedulerPthread
> -----------------------------------------------------------
>
> Key: MESOS-2144
> URL: https://issues.apache.org/jira/browse/MESOS-2144
> Project: Mesos
> Issue Type: Bug
> Components: test
> Affects Versions: 0.21.0
> Reporter: Cody Maloney
> Priority: Minor
> Labels: flaky
>
> Occured on review bot review of:
> https://reviews.apache.org/r/28262/#review62333
> The review doesn't touch code related to the test (And doesn't break
> libprocess in general)
> [ RUN ] ExamplesTest.LowLevelSchedulerPthread
> ../../src/tests/script.cpp:83: Failure
> Failed
> low_level_scheduler_pthread_test.sh terminated with signal Segmentation fault
> [ FAILED ] ExamplesTest.LowLevelSchedulerPthread (7561 ms)
> The test
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
