Vinod Kone created MESOS-1007:
---------------------------------
Summary: Python framework unable to parse framework messages
Key: MESOS-1007
URL: https://issues.apache.org/jira/browse/MESOS-1007
Project: Mesos
Issue Type: Bug
Environment: Fedora 20. Cxx11
Reporter: Vinod Kone
Fix For: 0.19.0
[ RUN ] ExamplesTest.PythonFramework
Using temporary directory '/tmp/ExamplesTest_PythonFramework_bk0KRb'
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0213 22:15:39.954318 17373 process.cpp:1591] libprocess is initialized on
192.168.122.164:47130 for 8 cpus
I0213 22:15:39.955761 17373 logging.cpp:140] Logging to STDERR
I0213 22:15:39.959444 17373 master.cpp:240] Master ID:
2014-02-13-22:15:39-2759502016-47130-17373 Hostname: fedora-20
I0213 22:15:39.960225 17383 master.cpp:322] Master started on
192.168.122.164:47130
I0213 22:15:39.960244 17383 master.cpp:325] Master only allowing authenticated
frameworks to register!
I0213 22:15:39.961699 17387 master.cpp:86] No whitelist given. Advertising
offers for all slaves
I0213 22:15:39.962286 17382 hierarchical_allocator_process.hpp:302]
Initializing hierarchical allocator process with master :
[email protected]:47130
I0213 22:15:39.963912 17373 containerizer.cpp:180] Using isolation:
posix/cpu,posix/mem
I0213 22:15:39.965071 17373 containerizer.cpp:180] Using isolation:
posix/cpu,posix/mem
I0213 22:15:39.965754 17384 slave.cpp:112] Slave started on
1)@192.168.122.164:47130
I0213 22:15:39.966032 17387 master.cpp:760] The newly elected leader is
[email protected]:47130 with id 2014-02-13-22:15:39-2759502016-47130-17373
I0213 22:15:39.966341 17387 master.cpp:770] Elected as the leading master!
I0213 22:15:39.966227 17384 slave.cpp:122] Slave resources: cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000]
I0213 22:15:39.967811 17384 slave.cpp:150] Slave hostname: fedora-20
I0213 22:15:39.967828 17384 slave.cpp:151] Slave checkpoint: true
I0213 22:15:39.968070 17384 state.cpp:33] Recovering state from
'/tmp/mesos-KG9dIs/0/meta'
I0213 22:15:39.968147 17384 status_update_manager.cpp:188] Recovering status
update manager
I0213 22:15:39.968200 17384 mesos_containerizer.cpp:137] Recovering
containerizer
I0213 22:15:39.969071 17384 slave.cpp:2670] Finished recovery
I0213 22:15:39.969290 17384 slave.cpp:397] New master detected at
[email protected]:47130
I0213 22:15:39.970041 17384 slave.cpp:422] Detecting new master
I0213 22:15:39.970067 17384 status_update_manager.cpp:162] New master detected
at [email protected]:47130
I0213 22:15:39.970116 17384 master.cpp:1840] Attempting to register slave on
fedora-20 at slave(1)@192.168.122.164:47130
I0213 22:15:39.970130 17384 master.cpp:2810] Adding slave
2014-02-13-22:15:39-2759502016-47130-17373-0 at fedora-20 with cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000]
I0213 22:15:39.970213 17384 slave.cpp:440] Registered with master
[email protected]:47130; given slave ID
2014-02-13-22:15:39-2759502016-47130-17373-0
I0213 22:15:39.970365 17384 slave.cpp:453] Checkpointing SlaveInfo to
'/tmp/mesos-KG9dIs/0/meta/slaves/2014-02-13-22:15:39-2759502016-47130-17373-0/slave.info'
I0213 22:15:39.971178 17382 hierarchical_allocator_process.hpp:445] Added slave
2014-02-13-22:15:39-2759502016-47130-17373-0 (fedora-20) with cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000] (and cpus(*):1; mem(*):979;
disk(*):1001; ports(*):[31000-32000] available)
I0213 22:15:39.971231 17382 hierarchical_allocator_process.hpp:708] Performed
allocation for slave 2014-02-13-22:15:39-2759502016-47130-17373-0 in 9023ns
I0213 22:15:39.972479 17373 containerizer.cpp:180] Using isolation:
posix/cpu,posix/mem
I0213 22:15:39.973124 17381 slave.cpp:112] Slave started on
2)@192.168.122.164:47130
I0213 22:15:39.973276 17381 slave.cpp:122] Slave resources: cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000]
I0213 22:15:39.974185 17381 slave.cpp:150] Slave hostname: fedora-20
I0213 22:15:39.974202 17381 slave.cpp:151] Slave checkpoint: true
I0213 22:15:39.975014 17381 state.cpp:33] Recovering state from
'/tmp/mesos-KG9dIs/1/meta'
I0213 22:15:39.975071 17381 status_update_manager.cpp:188] Recovering status
update manager
I0213 22:15:39.975098 17381 mesos_containerizer.cpp:137] Recovering
containerizer
I0213 22:15:39.975219 17381 slave.cpp:2670] Finished recovery
I0213 22:15:39.976111 17381 slave.cpp:397] New master detected at
[email protected]:47130
I0213 22:15:39.976758 17381 slave.cpp:422] Detecting new master
I0213 22:15:39.976796 17381 status_update_manager.cpp:162] New master detected
at [email protected]:47130
I0213 22:15:39.976830 17381 master.cpp:1840] Attempting to register slave on
fedora-20 at slave(2)@192.168.122.164:47130
I0213 22:15:39.976840 17381 master.cpp:2810] Adding slave
2014-02-13-22:15:39-2759502016-47130-17373-1 at fedora-20 with cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000]
I0213 22:15:39.976904 17381 slave.cpp:440] Registered with master
[email protected]:47130; given slave ID
2014-02-13-22:15:39-2759502016-47130-17373-1
I0213 22:15:39.977027 17381 slave.cpp:453] Checkpointing SlaveInfo to
'/tmp/mesos-KG9dIs/1/meta/slaves/2014-02-13-22:15:39-2759502016-47130-17373-1/slave.info'
I0213 22:15:39.977148 17381 hierarchical_allocator_process.hpp:445] Added slave
2014-02-13-22:15:39-2759502016-47130-17373-1 (fedora-20) with cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000] (and cpus(*):1; mem(*):979;
disk(*):1001; ports(*):[31000-32000] available)
I0213 22:15:39.978591 17387 slave.cpp:112] Slave started on
3)@192.168.122.164:47130
I0213 22:15:39.978715 17387 slave.cpp:122] Slave resources: cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000]
I0213 22:15:39.979027 17387 slave.cpp:150] Slave hostname: fedora-20
I0213 22:15:39.979040 17387 slave.cpp:151] Slave checkpoint: true
I0213 22:15:39.979228 17387 state.cpp:33] Recovering state from
'/tmp/mesos-KG9dIs/2/meta'
I0213 22:15:39.979279 17387 status_update_manager.cpp:188] Recovering status
update manager
I0213 22:15:39.979313 17387 mesos_containerizer.cpp:137] Recovering
containerizer
I0213 22:15:39.979580 17387 slave.cpp:2670] Finished recovery
I0213 22:15:39.979766 17387 slave.cpp:397] New master detected at
[email protected]:47130
I0213 22:15:39.979806 17387 slave.cpp:422] Detecting new master
I0213 22:15:39.979826 17387 status_update_manager.cpp:162] New master detected
at [email protected]:47130
I0213 22:15:39.979856 17387 master.cpp:1840] Attempting to register slave on
fedora-20 at slave(3)@192.168.122.164:47130
I0213 22:15:39.979866 17387 master.cpp:2810] Adding slave
2014-02-13-22:15:39-2759502016-47130-17373-2 at fedora-20 with cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000]
I0213 22:15:39.979929 17387 slave.cpp:440] Registered with master
[email protected]:47130; given slave ID
2014-02-13-22:15:39-2759502016-47130-17373-2
I0213 22:15:39.980051 17387 slave.cpp:453] Checkpointing SlaveInfo to
'/tmp/mesos-KG9dIs/2/meta/slaves/2014-02-13-22:15:39-2759502016-47130-17373-2/slave.info'
I0213 22:15:39.977181 17381 hierarchical_allocator_process.hpp:708] Performed
allocation for slave 2014-02-13-22:15:39-2759502016-47130-17373-1 in 3790ns
I0213 22:15:39.981469 17381 hierarchical_allocator_process.hpp:445] Added slave
2014-02-13-22:15:39-2759502016-47130-17373-2 (fedora-20) with cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000] (and cpus(*):1; mem(*):979;
disk(*):1001; ports(*):[31000-32000] available)
I0213 22:15:39.981503 17381 hierarchical_allocator_process.hpp:708] Performed
allocation for slave 2014-02-13-22:15:39-2759502016-47130-17373-2 in 4086ns
I0213 22:15:39.983192 17373 sched.cpp:121] Version: 0.19.0
I0213 22:15:39.983958 17382 sched.cpp:217] New master detected at
[email protected]:47130
I0213 22:15:39.983981 17382 sched.cpp:267] Authenticating with master
[email protected]:47130
I0213 22:15:39.984061 17382 authenticatee.hpp:100] Initializing client SASL
I0213 22:15:39.986805 17382 authenticatee.hpp:124] Creating new client SASL
connection
I0213 22:15:39.988211 17385 master.cpp:2323] Authenticating framework at
scheduler(1)@192.168.122.164:47130
I0213 22:15:39.988309 17385 authenticator.hpp:83] Initializing server SASL
I0213 22:15:39.988519 17385 auxprop.cpp:45] Initialized in-memory auxiliary
property plugin
I0213 22:15:39.988531 17385 authenticator.hpp:140] Creating new server SASL
connection
I0213 22:15:39.990200 17382 authenticatee.hpp:212] Received SASL authentication
mechanisms: CRAM-MD5
I0213 22:15:39.990803 17382 authenticatee.hpp:238] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0213 22:15:39.991400 17385 authenticator.hpp:243] Received SASL authentication
start
I0213 22:15:39.991436 17385 authenticator.hpp:325] Authentication requires more
steps
I0213 22:15:39.992053 17382 authenticatee.hpp:258] Received SASL authentication
step
I0213 22:15:39.992799 17386 authenticator.hpp:271] Received SASL authentication
step
I0213 22:15:39.992828 17386 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'fedora-20' server FQDN: 'fedora-20'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0213 22:15:39.992836 17386 auxprop.cpp:153] Looking up auxiliary property
'*userPassword'
I0213 22:15:39.992846 17386 auxprop.cpp:153] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0213 22:15:39.992856 17386 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'fedora-20' server FQDN: 'fedora-20'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0213 22:15:39.992862 17386 auxprop.cpp:103] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0213 22:15:39.992866 17386 auxprop.cpp:103] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0213 22:15:39.992877 17386 authenticator.hpp:317] Authentication success
I0213 22:15:39.992966 17386 master.cpp:2363] Successfully authenticated
framework at scheduler(1)@192.168.122.164:47130
I0213 22:15:39.999557 17382 authenticatee.hpp:298] Authentication success
I0213 22:15:40.000488 17382 sched.cpp:341] Successfully authenticated with
master [email protected]:47130
I0213 22:15:40.000509 17382 sched.cpp:460] Sending registration request to
[email protected]:47130
I0213 22:15:40.001138 17386 master.cpp:818] Received registration request from
scheduler(1)@192.168.122.164:47130
I0213 22:15:40.001785 17386 master.cpp:836] Registering framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 at
scheduler(1)@192.168.122.164:47130
I0213 22:15:40.002450 17387 sched.cpp:391] Framework registered with
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.002812 17387 sched.cpp:405] Scheduler::registered took 342468ns
I0213 22:15:40.003443 17384 hierarchical_allocator_process.hpp:332] Added
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.003486 17384 hierarchical_allocator_process.hpp:752] Offering
cpus(*):1; mem(*):979; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-0 to framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.003568 17384 hierarchical_allocator_process.hpp:752] Offering
cpus(*):1; mem(*):979; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-1 to framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.003624 17384 hierarchical_allocator_process.hpp:752] Offering
cpus(*):1; mem(*):979; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 to framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.003711 17384 hierarchical_allocator_process.hpp:688] Performed
allocation for 3 slaves in 250585ns
I0213 22:15:40.003845 17386 master.hpp:439] Adding offer
2014-02-13-22:15:39-2759502016-47130-17373-0 with resources cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 (fedora-20)
I0213 22:15:40.003919 17386 master.hpp:439] Adding offer
2014-02-13-22:15:39-2759502016-47130-17373-1 with resources cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-1 (fedora-20)
I0213 22:15:40.003979 17386 master.hpp:439] Adding offer
2014-02-13-22:15:39-2759502016-47130-17373-2 with resources cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-0 (fedora-20)
I0213 22:15:40.004010 17386 master.cpp:2278] Sending 3 offers to framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.008587 17385 sched.cpp:528] Scheduler::resourceOffers took
4.435927ms
I0213 22:15:40.009693 17382 master.hpp:449] Removing offer
2014-02-13-22:15:39-2759502016-47130-17373-0 with resources cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 (fedora-20)
I0213 22:15:40.009745 17382 master.cpp:1574] Processing reply for offers: [
2014-02-13-22:15:39-2759502016-47130-17373-0 ] on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 (fedora-20) for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.009810 17382 master.hpp:411] Adding task 0 with resources
cpus(*):1; mem(*):32 on slave 2014-02-13-22:15:39-2759502016-47130-17373-2
(fedora-20)
I0213 22:15:40.009838 17382 master.cpp:2447] Launching task 0 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 with resources cpus(*):1;
mem(*):32 on slave 2014-02-13-22:15:39-2759502016-47130-17373-2 (fedora-20)
I0213 22:15:40.009943 17382 slave.cpp:625] Got assigned task 0 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.010087 17382 slave.cpp:734] Launching task 0 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.010593 17387 hierarchical_allocator_process.hpp:547] Framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 left mem(*):947; disk(*):1001;
ports(*):[31000-32000] unused on slave
2014-02-13-22:15:39-2759502016-47130-17373-2
I0213 22:15:40.010656 17387 hierarchical_allocator_process.hpp:590] Framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 filtered slave
2014-02-13-22:15:39-2759502016-47130-17373-2 for 5secs
I0213 22:15:40.012295 17380 mesos_containerizer.cpp:363] Starting container
'5c917cb7-a0f7-46db-a8ce-d0213552cde8' for executor 'default' of framework
'2014-02-13-22:15:39-2759502016-47130-17373-0000'
I0213 22:15:40.012648 17380 mesos_containerizer.cpp:504] Fetching URIs for
container '5c917cb7-a0f7-46db-a8ce-d0213552cde8' using command '/usr/bin/env
MESOS_EXECUTOR_URIS=
MESOS_WORK_DIRECTORY=/tmp/mesos-KG9dIs/2/slaves/2014-02-13-22:15:39-2759502016-47130-17373-2/frameworks/2014-02-13-22:15:39-2759502016-47130-17373-0000/executors/default/runs/5c917cb7-a0f7-46db-a8ce-d0213552cde8
MESOS_USER=jenkins MESOS_FRAMEWORKS_HOME= HADOOP_HOME=
/var/jenkins/workspace/mesos-fedora-20-gcc-cxx11/src/mesos-fetcher'
I0213 22:15:40.016403 17382 slave.cpp:844] Queuing task '0' for executor
default of framework '2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.017197 17382 slave.cpp:358] Successfully attached file
'/tmp/mesos-KG9dIs/2/slaves/2014-02-13-22:15:39-2759502016-47130-17373-2/frameworks/2014-02-13-22:15:39-2759502016-47130-17373-0000/executors/default/runs/5c917cb7-a0f7-46db-a8ce-d0213552cde8'
I0213 22:15:40.019753 17381 master.hpp:449] Removing offer
2014-02-13-22:15:39-2759502016-47130-17373-1 with resources cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-1 (fedora-20)
I0213 22:15:40.019851 17381 master.cpp:1574] Processing reply for offers: [
2014-02-13-22:15:39-2759502016-47130-17373-1 ] on slave
2014-02-13-22:15:39-2759502016-47130-17373-1 (fedora-20) for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.019920 17381 master.hpp:411] Adding task 1 with resources
cpus(*):1; mem(*):32 on slave 2014-02-13-22:15:39-2759502016-47130-17373-1
(fedora-20)
I0213 22:15:40.019942 17381 master.cpp:2447] Launching task 1 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 with resources cpus(*):1;
mem(*):32 on slave 2014-02-13-22:15:39-2759502016-47130-17373-1 (fedora-20)
I0213 22:15:40.020867 17384 slave.cpp:625] Got assigned task 1 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.021042 17384 slave.cpp:734] Launching task 1 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.022826 17381 hierarchical_allocator_process.hpp:547] Framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 left mem(*):947; disk(*):1001;
ports(*):[31000-32000] unused on slave
2014-02-13-22:15:39-2759502016-47130-17373-1
I0213 22:15:40.022894 17381 hierarchical_allocator_process.hpp:590] Framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 filtered slave
2014-02-13-22:15:39-2759502016-47130-17373-1 for 5secs
I0213 22:15:40.023960 17384 slave.cpp:844] Queuing task '1' for executor
default of framework '2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.024056 17384 mesos_containerizer.cpp:363] Starting container
'61fd0991-dfe6-43f3-aebf-c3582897a5c3' for executor 'default' of framework
'2014-02-13-22:15:39-2759502016-47130-17373-0000'
I0213 22:15:40.024253 17384 slave.cpp:358] Successfully attached file
'/tmp/mesos-KG9dIs/1/slaves/2014-02-13-22:15:39-2759502016-47130-17373-1/frameworks/2014-02-13-22:15:39-2759502016-47130-17373-0000/executors/default/runs/61fd0991-dfe6-43f3-aebf-c3582897a5c3'
I0213 22:15:40.024360 17384 mesos_containerizer.cpp:504] Fetching URIs for
container '61fd0991-dfe6-43f3-aebf-c3582897a5c3' using command '/usr/bin/env
MESOS_EXECUTOR_URIS=
MESOS_WORK_DIRECTORY=/tmp/mesos-KG9dIs/1/slaves/2014-02-13-22:15:39-2759502016-47130-17373-1/frameworks/2014-02-13-22:15:39-2759502016-47130-17373-0000/executors/default/runs/61fd0991-dfe6-43f3-aebf-c3582897a5c3
MESOS_USER=jenkins MESOS_FRAMEWORKS_HOME= HADOOP_HOME=
/var/jenkins/workspace/mesos-fedora-20-gcc-cxx11/src/mesos-fetcher'
I0213 22:15:40.026907 17382 master.hpp:449] Removing offer
2014-02-13-22:15:39-2759502016-47130-17373-2 with resources cpus(*):1;
mem(*):979; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-0 (fedora-20)
I0213 22:15:40.026996 17382 master.cpp:1574] Processing reply for offers: [
2014-02-13-22:15:39-2759502016-47130-17373-2 ] on slave
2014-02-13-22:15:39-2759502016-47130-17373-0 (fedora-20) for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.027055 17382 master.hpp:411] Adding task 2 with resources
cpus(*):1; mem(*):32 on slave 2014-02-13-22:15:39-2759502016-47130-17373-0
(fedora-20)
I0213 22:15:40.027076 17382 master.cpp:2447] Launching task 2 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 with resources cpus(*):1;
mem(*):32 on slave 2014-02-13-22:15:39-2759502016-47130-17373-0 (fedora-20)
I0213 22:15:40.027211 17382 slave.cpp:625] Got assigned task 2 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.027346 17382 slave.cpp:734] Launching task 2 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.028373 17387 hierarchical_allocator_process.hpp:547] Framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 left mem(*):947; disk(*):1001;
ports(*):[31000-32000] unused on slave
2014-02-13-22:15:39-2759502016-47130-17373-0
I0213 22:15:40.028476 17387 hierarchical_allocator_process.hpp:590] Framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 filtered slave
2014-02-13-22:15:39-2759502016-47130-17373-0 for 5secs
I0213 22:15:40.031975 17382 slave.cpp:844] Queuing task '2' for executor
default of framework '2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.033087 17382 slave.cpp:358] Successfully attached file
'/tmp/mesos-KG9dIs/0/slaves/2014-02-13-22:15:39-2759502016-47130-17373-0/frameworks/2014-02-13-22:15:39-2759502016-47130-17373-0000/executors/default/runs/920c402a-d794-415d-b140-14c48e5185df'
I0213 22:15:40.032888 17385 mesos_containerizer.cpp:363] Starting container
'920c402a-d794-415d-b140-14c48e5185df' for executor 'default' of framework
'2014-02-13-22:15:39-2759502016-47130-17373-0000'
I0213 22:15:40.034847 17385 mesos_containerizer.cpp:504] Fetching URIs for
container '920c402a-d794-415d-b140-14c48e5185df' using command '/usr/bin/env
MESOS_EXECUTOR_URIS=
MESOS_WORK_DIRECTORY=/tmp/mesos-KG9dIs/0/slaves/2014-02-13-22:15:39-2759502016-47130-17373-0/frameworks/2014-02-13-22:15:39-2759502016-47130-17373-0000/executors/default/runs/920c402a-d794-415d-b140-14c48e5185df
MESOS_USER=jenkins MESOS_FRAMEWORKS_HOME= HADOOP_HOME=
/var/jenkins/workspace/mesos-fedora-20-gcc-cxx11/src/mesos-fetcher'
I0213 22:15:40.963394 17387 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-0 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.963486 17387 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-1 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.963523 17387 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:40.963564 17387 hierarchical_allocator_process.hpp:688] Performed
allocation for 3 slaves in 246441ns
I0213 22:15:41.018864 17383 launcher.cpp:120] Forked child with pid '17439' for
container '920c402a-d794-415d-b140-14c48e5185df'
I0213 22:15:41.020393 17386 launcher.cpp:120] Forked child with pid '17440' for
container '61fd0991-dfe6-43f3-aebf-c3582897a5c3'
I0213 22:15:41.021778 17386 slave.cpp:1989] Monitoring executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000' in container
'61fd0991-dfe6-43f3-aebf-c3582897a5c3'
I0213 22:15:41.022833 17383 slave.cpp:1989] Monitoring executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000' in container
'920c402a-d794-415d-b140-14c48e5185df'
I0213 22:15:41.023444 17387 launcher.cpp:120] Forked child with pid '17438' for
container '5c917cb7-a0f7-46db-a8ce-d0213552cde8'
I0213 22:15:41.025220 17387 slave.cpp:1989] Monitoring executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000' in container
'5c917cb7-a0f7-46db-a8ce-d0213552cde8'
I0213 22:15:41.963726 17387 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-0 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:41.963807 17387 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-1 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:41.963841 17387 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:41.963857 17387 hierarchical_allocator_process.hpp:688] Performed
allocation for 3 slaves in 208844ns
I0213 22:15:42.022104 17387 monitor.cpp:140] Failed to collect resource usage
for container '61fd0991-dfe6-43f3-aebf-c3582897a5c3' for executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000': Unknown container:
61fd0991-dfe6-43f3-aebf-c3582897a5c3
I0213 22:15:42.028655 17384 monitor.cpp:140] Failed to collect resource usage
for container '5c917cb7-a0f7-46db-a8ce-d0213552cde8' for executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000': Unknown container:
5c917cb7-a0f7-46db-a8ce-d0213552cde8
I0213 22:15:42.565881 17314 exec.cpp:85] Committing suicide by killing the
process group
I0213 22:15:42.566293 17330 exec.cpp:85] Committing suicide by killing the
process group
I0213 22:15:42.569000 17320 exec.cpp:85] Committing suicide by killing the
process group
I0213 22:15:42.964812 17386 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-0 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:42.964902 17386 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-1 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:42.964932 17386 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:42.964964 17386 hierarchical_allocator_process.hpp:688] Performed
allocation for 3 slaves in 210746ns
I0213 22:15:43.023181 17386 monitor.cpp:140] Failed to collect resource usage
for container '61fd0991-dfe6-43f3-aebf-c3582897a5c3' for executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000': Unknown container:
61fd0991-dfe6-43f3-aebf-c3582897a5c3
I0213 22:15:43.029309 17386 monitor.cpp:140] Failed to collect resource usage
for container '5c917cb7-a0f7-46db-a8ce-d0213552cde8' for executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000': Unknown container:
5c917cb7-a0f7-46db-a8ce-d0213552cde8
I0213 22:15:43.965808 17384 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-0 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:43.965888 17384 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-1 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:43.965917 17384 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:43.965934 17384 hierarchical_allocator_process.hpp:688] Performed
allocation for 3 slaves in 206572ns
I0213 22:15:44.024154 17384 monitor.cpp:140] Failed to collect resource usage
for container '61fd0991-dfe6-43f3-aebf-c3582897a5c3' for executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000': Unknown container:
61fd0991-dfe6-43f3-aebf-c3582897a5c3
I0213 22:15:44.030320 17385 monitor.cpp:140] Failed to collect resource usage
for container '5c917cb7-a0f7-46db-a8ce-d0213552cde8' for executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000': Unknown container:
5c917cb7-a0f7-46db-a8ce-d0213552cde8
I0213 22:15:44.962515 17383 master.cpp:86] No whitelist given. Advertising
offers for all slaves
I0213 22:15:44.966637 17383 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-0 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:44.966691 17383 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-1 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:44.966718 17383 hierarchical_allocator_process.hpp:835] Filtered
mem(*):947; disk(*):1001; ports(*):[31000-32000] on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:44.966734 17383 hierarchical_allocator_process.hpp:688] Performed
allocation for 3 slaves in 148762ns
I0213 22:15:45.024610 17383 monitor.cpp:140] Failed to collect resource usage
for container '61fd0991-dfe6-43f3-aebf-c3582897a5c3' for executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000': Unknown container:
61fd0991-dfe6-43f3-aebf-c3582897a5c3
I0213 22:15:45.030858 17383 monitor.cpp:140] Failed to collect resource usage
for container '5c917cb7-a0f7-46db-a8ce-d0213552cde8' for executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000': Unknown container:
5c917cb7-a0f7-46db-a8ce-d0213552cde8
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0213 22:15:45.436172 17438 process.cpp:1591] libprocess is initialized on
192.168.122.164:47089 for 8 cpus
I0213 22:15:45.437582 17438 exec.cpp:131] Version: 0.19.0
I0213 22:15:45.439138 17449 exec.cpp:181] Executor started at:
executor(1)@192.168.122.164:47089 with pid 17438
I0213 22:15:45.440340 17385 slave.cpp:1316] Got registration for executor
'default' of framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.440734 17385 slave.cpp:1434] Flushing queued task 0 for executor
'default' of framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.441625 17448 exec.cpp:205] Executor registered on slave
2014-02-13-22:15:39-2759502016-47130-17373-2
I0213 22:15:45.443183 17448 exec.cpp:217] Executor::registered took 555300ns
I0213 22:15:45.443704 17449 exec.cpp:292] Executor asked to run task '0'
I0213 22:15:45.444715 17452 process.cpp:1010] Socket closed while receiving
I0213 22:15:45.445168 17449 exec.cpp:301] Executor::launchTask took 1.091928ms
Starting executor
Running task 0
I0213 22:15:45.447093 17451 exec.cpp:524] Executor sending status update
TASK_RUNNING (UUID: 5d7e0bbe-2bca-46f6-99b9-789d0cc656a3) for task 0 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.447760 17385 slave.cpp:1643] Handling status update TASK_RUNNING
(UUID: 5d7e0bbe-2bca-46f6-99b9-789d0cc656a3) for task 0 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 from
executor(1)@192.168.122.164:47089
I0213 22:15:45.447860 17385 status_update_manager.cpp:315] Received status
update TASK_RUNNING (UUID: 5d7e0bbe-2bca-46f6-99b9-789d0cc656a3) for task 0 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.447873 17385 status_update_manager.cpp:494] Creating
StatusUpdate stream for task 0 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.447940 17385 status_update_manager.cpp:368] Forwarding status
update TASK_RUNNING (UUID: 5d7e0bbe-2bca-46f6-99b9-789d0cc656a3) for task 0 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000 to
[email protected]:47130
I0213 22:15:45.448047 17385 master.cpp:2026] Status update TASK_RUNNING (UUID:
5d7e0bbe-2bca-46f6-99b9-789d0cc656a3) for task 0 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 from
slave(3)@192.168.122.164:47130
I0213 22:15:45.448071 17385 slave.cpp:1763] Status update manager successfully
handled status update TASK_RUNNING (UUID: 5d7e0bbe-2bca-46f6-99b9-789d0cc656a3)
for task 0 of framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.448079 17385 slave.cpp:1769] Sending acknowledgement for status
update TASK_RUNNING (UUID: 5d7e0bbe-2bca-46f6-99b9-789d0cc656a3) for task 0 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000 to
executor(1)@192.168.122.164:47089
I0213 22:15:45.449355 17385 sched.cpp:619] Scheduler::statusUpdate took
1.069957ms
I0213 22:15:45.450139 17381 status_update_manager.cpp:393] Received status
update acknowledgement (UUID: 5d7e0bbe-2bca-46f6-99b9-789d0cc656a3) for task 0
of framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.450202 17381 slave.cpp:1256] Status update manager successfully
handled status update acknowledgement (UUID:
5d7e0bbe-2bca-46f6-99b9-789d0cc656a3) for task 0 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.450896 17452 process.cpp:1010] Socket closed while receiving
I0213 22:15:45.451138 17445 exec.cpp:338] Executor received status update
acknowledgement 5d7e0bbe-2bca-46f6-99b9-789d0cc656a3 for task 0 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
Sending status update...
I0213 22:15:45.452801 17450 exec.cpp:524] Executor sending status update
TASK_FINISHED (UUID: 844af297-36ca-4354-844c-f6a0205bfbc4) for task 0 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.453207 17381 slave.cpp:1643] Handling status update
TASK_FINISHED (UUID: 844af297-36ca-4354-844c-f6a0205bfbc4) for task 0 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000 from
executor(1)@192.168.122.164:47089
I0213 22:15:45.453235 17381 slave.cpp:3142] Terminating task 0
I0213 22:15:45.453320 17381 status_update_manager.cpp:315] Received status
update TASK_FINISHED (UUID: 844af297-36ca-4354-844c-f6a0205bfbc4) for task 0 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.453341 17381 status_update_manager.cpp:368] Forwarding status
update TASK_FINISHED (UUID: 844af297-36ca-4354-844c-f6a0205bfbc4) for task 0 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000 to
[email protected]:47130
I0213 22:15:45.453455 17381 master.cpp:2026] Status update TASK_FINISHED (UUID:
844af297-36ca-4354-844c-f6a0205bfbc4) for task 0 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 from
slave(3)@192.168.122.164:47130
I0213 22:15:45.453496 17381 master.hpp:429] Removing task 0 with resources
cpus(*):1; mem(*):32 on slave 2014-02-13-22:15:39-2759502016-47130-17373-2
(fedora-20)
I0213 22:15:45.453630 17381 slave.cpp:1763] Status update manager successfully
handled status update TASK_FINISHED (UUID:
844af297-36ca-4354-844c-f6a0205bfbc4) for task 0 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.453646 17381 slave.cpp:1769] Sending acknowledgement for status
update TASK_FINISHED (UUID: 844af297-36ca-4354-844c-f6a0205bfbc4) for task 0 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000 to
executor(1)@192.168.122.164:47089
I0213 22:15:45.454188 17381 sched.cpp:619] Scheduler::statusUpdate took 327761ns
I0213 22:15:45.454274 17381 hierarchical_allocator_process.hpp:637] Recovered
cpus(*):1; mem(*):32 (total allocatable: mem(*):979; disk(*):1001;
ports(*):[31000-32000]; cpus(*):1) on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 from framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.454340 17381 status_update_manager.cpp:393] Received status
update acknowledgement (UUID: 844af297-36ca-4354-844c-f6a0205bfbc4) for task 0
of framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.454361 17381 status_update_manager.cpp:525] Cleaning up status
update stream for task 0 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.454395 17381 slave.cpp:1256] Status update manager successfully
handled status update acknowledgement (UUID:
844af297-36ca-4354-844c-f6a0205bfbc4) for task 0 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.454406 17381 slave.cpp:3165] Completing task 0
I0213 22:15:45.454776 17452 process.cpp:1010] Socket closed while receiving
I0213 22:15:45.454874 17447 exec.cpp:338] Executor received status update
acknowledgement 844af297-36ca-4354-844c-f6a0205bfbc4 for task 0 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.454907 17447 exec.cpp:359] Executor received framework message
I0213 22:15:45.454982 17447 exec.cpp:368] Executor::frameworkMessage took
65255ns
Sent status update
I0213 22:15:45.455256 17381 slave.cpp:1822] Sending message for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 to
scheduler(1)@192.168.122.164:47130
I0213 22:15:45.455405 17381 sched.cpp:704] Scheduler::frameworkMessage took
106466ns
Traceback (most recent call last):
File
"/var/jenkins/workspace/mesos-fedora-20-gcc-cxx11/src/examples/python/test_executor.py",
line 23, in <module>
import mesos
File "build/bdist.linux-x86_64/egg/mesos.py", line 26, in <module>
File "build/bdist.linux-x86_64/egg/_mesos.py", line 7, in <module>
File "build/bdist.linux-x86_64/egg/_mesos.py", line 6, in __bootstrap__
ImportError:
/home/jenkins/.python-eggs/mesos-0.19.0-py2.7-linux-x86_64.egg-tmp/_mesos.so:
ELF load command past end of file
I0213 22:15:45.967828 17387 hierarchical_allocator_process.hpp:752] Offering
mem(*):979; disk(*):1001; ports(*):[31000-32000]; cpus(*):1 on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 to framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.967947 17387 hierarchical_allocator_process.hpp:688] Performed
allocation for 3 slaves in 238715ns
I0213 22:15:45.968009 17387 master.hpp:439] Adding offer
2014-02-13-22:15:39-2759502016-47130-17373-3 with resources mem(*):979;
disk(*):1001; ports(*):[31000-32000]; cpus(*):1 on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 (fedora-20)
I0213 22:15:45.968050 17387 master.cpp:2278] Sending 1 offers to framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.969501 17387 sched.cpp:528] Scheduler::resourceOffers took
1.366302ms
I0213 22:15:45.969679 17387 master.hpp:449] Removing offer
2014-02-13-22:15:39-2759502016-47130-17373-3 with resources mem(*):979;
disk(*):1001; ports(*):[31000-32000]; cpus(*):1 on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 (fedora-20)
I0213 22:15:45.969725 17387 master.cpp:1574] Processing reply for offers: [
2014-02-13-22:15:39-2759502016-47130-17373-3 ] on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 (fedora-20) for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.969782 17387 master.hpp:411] Adding task 3 with resources
cpus(*):1; mem(*):32 on slave 2014-02-13-22:15:39-2759502016-47130-17373-2
(fedora-20)
I0213 22:15:45.969805 17387 master.cpp:2447] Launching task 3 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 with resources cpus(*):1;
mem(*):32 on slave 2014-02-13-22:15:39-2759502016-47130-17373-2 (fedora-20)
I0213 22:15:45.969898 17387 slave.cpp:625] Got assigned task 3 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.969964 17387 slave.cpp:734] Launching task 3 for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.970001 17387 slave.cpp:866] Sending task '3' to executor
'default' of framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.971524 17448 exec.cpp:292] Executor asked to run task '3'
I0213 22:15:45.972405 17448 exec.cpp:301] Executor::launchTask took 825129ns
Running task 3
I0213 22:15:45.973731 17446 exec.cpp:524] Executor sending status update
TASK_RUNNING (UUID: 79775756-776f-4265-a66b-0dcda4e0f0ff) for task 3 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
Sending status update...
I0213 22:15:45.978966 17451 exec.cpp:524] Executor sending status update
TASK_FINISHED (UUID: c0c48bf6-8f81-4ef4-93c8-810097c57d1a) for task 3 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
Sent status update
I0213 22:15:45.980880 17452 process.cpp:1010] Socket closed while receiving
I0213 22:15:45.982945 17387 slave.cpp:1643] Handling status update TASK_RUNNING
(UUID: 79775756-776f-4265-a66b-0dcda4e0f0ff) for task 3 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 from
executor(1)@192.168.122.164:47089
I0213 22:15:45.983031 17387 slave.cpp:1643] Handling status update
TASK_FINISHED (UUID: c0c48bf6-8f81-4ef4-93c8-810097c57d1a) for task 3 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000 from
executor(1)@192.168.122.164:47089
I0213 22:15:45.983047 17387 slave.cpp:3142] Terminating task 3
I0213 22:15:45.983105 17387 hierarchical_allocator_process.hpp:547] Framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 left mem(*):947; disk(*):1001;
ports(*):[31000-32000] unused on slave
2014-02-13-22:15:39-2759502016-47130-17373-2
I0213 22:15:45.983171 17387 hierarchical_allocator_process.hpp:590] Framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 filtered slave
2014-02-13-22:15:39-2759502016-47130-17373-2 for 5secs
I0213 22:15:45.985877 17382 status_update_manager.cpp:315] Received status
update TASK_RUNNING (UUID: 79775756-776f-4265-a66b-0dcda4e0f0ff) for task 3 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.985905 17382 status_update_manager.cpp:494] Creating
StatusUpdate stream for task 3 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.987220 17382 status_update_manager.cpp:368] Forwarding status
update TASK_RUNNING (UUID: 79775756-776f-4265-a66b-0dcda4e0f0ff) for task 3 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000 to
[email protected]:47130
I0213 22:15:45.987316 17382 status_update_manager.cpp:315] Received status
update TASK_FINISHED (UUID: c0c48bf6-8f81-4ef4-93c8-810097c57d1a) for task 3 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.987392 17382 master.cpp:2026] Status update TASK_RUNNING (UUID:
79775756-776f-4265-a66b-0dcda4e0f0ff) for task 3 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 from
slave(3)@192.168.122.164:47130
I0213 22:15:45.987414 17382 slave.cpp:1763] Status update manager successfully
handled status update TASK_RUNNING (UUID: 79775756-776f-4265-a66b-0dcda4e0f0ff)
for task 3 of framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.987422 17382 slave.cpp:1769] Sending acknowledgement for status
update TASK_RUNNING (UUID: 79775756-776f-4265-a66b-0dcda4e0f0ff) for task 3 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000 to
executor(1)@192.168.122.164:47089
I0213 22:15:45.989044 17387 sched.cpp:619] Scheduler::statusUpdate took 176389ns
I0213 22:15:45.991576 17444 exec.cpp:338] Executor received status update
acknowledgement 79775756-776f-4265-a66b-0dcda4e0f0ff for task 3 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.993021 17452 process.cpp:1010] Socket closed while receiving
I0213 22:15:45.993955 17382 slave.cpp:1763] Status update manager successfully
handled status update TASK_FINISHED (UUID:
c0c48bf6-8f81-4ef4-93c8-810097c57d1a) for task 3 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.993996 17382 slave.cpp:1769] Sending acknowledgement for status
update TASK_FINISHED (UUID: c0c48bf6-8f81-4ef4-93c8-810097c57d1a) for task 3 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000 to
executor(1)@192.168.122.164:47089
I0213 22:15:45.995705 17444 exec.cpp:338] Executor received status update
acknowledgement c0c48bf6-8f81-4ef4-93c8-810097c57d1a for task 3 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.996507 17452 process.cpp:1010] Socket closed while receiving
I0213 22:15:45.997968 17386 status_update_manager.cpp:393] Received status
update acknowledgement (UUID: 79775756-776f-4265-a66b-0dcda4e0f0ff) for task 3
of framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:45.998059 17386 status_update_manager.cpp:368] Forwarding status
update TASK_FINISHED (UUID: c0c48bf6-8f81-4ef4-93c8-810097c57d1a) for task 3 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000 to
[email protected]:47130
I0213 22:15:45.998200 17386 master.cpp:2026] Status update TASK_FINISHED (UUID:
c0c48bf6-8f81-4ef4-93c8-810097c57d1a) for task 3 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 from
slave(3)@192.168.122.164:47130
I0213 22:15:45.998375 17386 master.hpp:429] Removing task 3 with resources
cpus(*):1; mem(*):32 on slave 2014-02-13-22:15:39-2759502016-47130-17373-2
(fedora-20)
I0213 22:15:45.999208 17386 sched.cpp:619] Scheduler::statusUpdate took 760887ns
I0213 22:15:45.999285 17386 hierarchical_allocator_process.hpp:637] Recovered
cpus(*):1; mem(*):32 (total allocatable: mem(*):979; disk(*):1001;
ports(*):[31000-32000]; cpus(*):1) on slave
2014-02-13-22:15:39-2759502016-47130-17373-2 from framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:46.001346 17444 exec.cpp:359] Executor received framework message
I0213 22:15:46.001395 17444 exec.cpp:368] Executor::frameworkMessage took
30730ns
I0213 22:15:46.002631 17452 process.cpp:1010] Socket closed while receiving
I0213 22:15:46.003365 17381 status_update_manager.cpp:393] Received status
update acknowledgement (UUID: c0c48bf6-8f81-4ef4-93c8-810097c57d1a) for task 3
of framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:46.003394 17381 status_update_manager.cpp:525] Cleaning up status
update stream for task 3 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:46.003514 17382 slave.cpp:1256] Status update manager successfully
handled status update acknowledgement (UUID:
79775756-776f-4265-a66b-0dcda4e0f0ff) for task 3 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:46.004482 17382 slave.cpp:1822] Sending message for framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 to
scheduler(1)@192.168.122.164:47130
I0213 22:15:46.005331 17380 sched.cpp:704] Scheduler::frameworkMessage took
147661ns
I0213 22:15:46.005781 17382 slave.cpp:1256] Status update manager successfully
handled status update acknowledgement (UUID:
c0c48bf6-8f81-4ef4-93c8-810097c57d1a) for task 3 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:46.006345 17382 slave.cpp:3165] Completing task 3
I0213 22:15:46.021203 17386 mesos_containerizer.cpp:874] Executor for container
'61fd0991-dfe6-43f3-aebf-c3582897a5c3' has exited
I0213 22:15:46.021222 17386 mesos_containerizer.cpp:791] Destroying container
'61fd0991-dfe6-43f3-aebf-c3582897a5c3'
I0213 22:15:46.025365 17381 monitor.cpp:140] Failed to collect resource usage
for container '61fd0991-dfe6-43f3-aebf-c3582897a5c3' for executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000': Unknown container:
61fd0991-dfe6-43f3-aebf-c3582897a5c3
I0213 22:15:46.032027 17381 monitor.cpp:140] Failed to collect resource usage
for container '5c917cb7-a0f7-46db-a8ce-d0213552cde8' for executor 'default' of
framework '2014-02-13-22:15:39-2759502016-47130-17373-0000': Unknown container:
5c917cb7-a0f7-46db-a8ce-d0213552cde8
I0213 22:15:46.035960 17381 slave.cpp:2047] Executor 'default' of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 has exited with status 1
I0213 22:15:46.038244 17381 slave.cpp:1643] Handling status update TASK_LOST
(UUID: 754186b9-569c-456b-940d-967d6c38f790) for task 1 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 from @0.0.0.0:0
I0213 22:15:46.038270 17381 slave.cpp:3142] Terminating task 1
I0213 22:15:46.038370 17381 status_update_manager.cpp:315] Received status
update TASK_LOST (UUID: 754186b9-569c-456b-940d-967d6c38f790) for task 1 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:46.038383 17381 status_update_manager.cpp:494] Creating
StatusUpdate stream for task 1 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:46.038445 17381 status_update_manager.cpp:368] Forwarding status
update TASK_LOST (UUID: 754186b9-569c-456b-940d-967d6c38f790) for task 1 of
framework 2014-02-13-22:15:39-2759502016-47130-17373-0000 to
[email protected]:47130
I0213 22:15:46.038585 17385 slave.cpp:1763] Status update manager successfully
handled status update TASK_LOST (UUID: 754186b9-569c-456b-940d-967d6c38f790)
for task 1 of framework 2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:46.039693 17381 master.cpp:2083] Executor default of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 on slave
2014-02-13-22:15:39-2759502016-47130-17373-1 (fedora-20) has exited with status
1
Enabling authentication for the framework
Registered with framework ID 2014-02-13-22:15:39-2759502016-47130-17373-0000
Got 3 resource offers
Got resource offer 2014-02-13-22:15:39-2759502016-47130-17373-0
Accepting offer on fedora-20 to start task 0
Got resource offer 2014-02-13-22:15:39-2759502016-47130-17373-1
Accepting offer on fedora-20 to start task 1
Got resource offer 2014-02-13-22:15:39-2759502016-47130-17373-2
Accepting offer on fedora-20 to start task 2
Task 0 is in state 1
Task 0 is in state 2
Received message: 'data with a \x00 byte'
Got 1 resource offers
Got resource offer 2014-02-13-22:15:39-2759502016-47130-17373-3
Accepting offer on fedora-20 to start task 3
Task 3 is in state 1
Task 3 is in state 2
Received message: 'data with a \x00 byte'
Task 1 is in state 5
The update data did not match!
Expected: 'data with a \x00 byte'
Actual: ''
Failed to call scheduler's statusUpdate
I0213 22:15:46.045435 17381 master.cpp:2026] Status update TASK_LOST (UUID:
754186b9-569c-456b-940d-967d6c38f790) for task 1 of framework
2014-02-13-22:15:39-2759502016-47130-17373-0000 from
slave(2)@192.168.122.164:47130
I0213 22:15:46.045485 17381 master.hpp:429] Removing task 1 with resources
cpus(*):1; mem(*):32 on slave 2014-02-13-22:15:39-2759502016-47130-17373-1
(fedora-20)
I0213 22:15:46.049846 17385 hierarchical_allocator_process.hpp:637] Recovered
cpus(*):1; mem(*):32 (total allocatable: mem(*):979; disk(*):1001;
ports(*):[31000-32000]; cpus(*):1) on slave
2014-02-13-22:15:39-2759502016-47130-17373-1 from framework
2014-02-13-22:15:39-2759502016-47130-17373-0000
I0213 22:15:46.099185 17452 process.cpp:1010] Socket closed while receiving
I0213 22:15:46.099313 17444 exec.cpp:458] Slave exited ... shutting down
I0213 22:15:46.099385 17444 exec.cpp:475] Executor::shutdown took 35477ns
I0213 22:15:46.099403 17444 exec.cpp:77] Scheduling shutdown of the executor
tests/script.cpp:78: Failure
Failed
python_framework_test.sh exited with status 1
[ FAILED ] ExamplesTest.PythonFramework (8325 ms)
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)
