You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by "Benjamin Mahler (JIRA)" <ji...@apache.org> on 2014/05/16 23:05:24 UTC

[jira] [Updated] (MESOS-988) ExamplesTest.PythonFramework is flaky

     [ https://issues.apache.org/jira/browse/MESOS-988?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Benjamin Mahler updated MESOS-988:
----------------------------------

    Fix Version/s:     (was: 0.19.0)

> ExamplesTest.PythonFramework is flaky
> -------------------------------------
>
>                 Key: MESOS-988
>                 URL: https://issues.apache.org/jira/browse/MESOS-988
>             Project: Mesos
>          Issue Type: Bug
>          Components: test
>    Affects Versions: 0.18.0
>            Reporter: Vinod Kone
>
> Looks like a SEGFAULT during shutdown.
> [ RUN      ] ExamplesTest.PythonFramework
> Using temporary directory '/tmp/ExamplesTest_PythonFramework_RZ4yaf'
> WARNING: Logging before InitGoogleLogging() is written to STDERR
> I0211 21:14:47.861803 21045 process.cpp:1591] libprocess is initialized on 67.195.138.9:53443 for 8 cpus
> I0211 21:14:47.861884 21045 logging.cpp:140] Logging to STDERR
> I0211 21:14:47.862761 21045 master.cpp:240] Master ID: 2014-02-11-21:14:47-160088899-53443-21045 Hostname: vesta.apache.org
> I0211 21:14:47.862897 21054 master.cpp:322] Master started on 67.195.138.9:53443
> I0211 21:14:47.862908 21054 master.cpp:325] Master only allowing authenticated frameworks to register!
> I0211 21:14:47.864362 21053 master.cpp:86] No whitelist given. Advertising offers for all slaves
> I0211 21:14:47.864506 21055 slave.cpp:112] Slave started on 1)@67.195.138.9:53443
> I0211 21:14:47.864522 21059 slave.cpp:112] Slave started on 2)@67.195.138.9:53443
> I0211 21:14:47.864749 21055 slave.cpp:212] Slave resources: cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000]
> I0211 21:14:47.864778 21059 slave.cpp:212] Slave resources: cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000]
> I0211 21:14:47.864819 21055 slave.cpp:240] Slave hostname: vesta.apache.org
> I0211 21:14:47.864827 21055 slave.cpp:241] Slave checkpoint: true
> I0211 21:14:47.864850 21059 slave.cpp:240] Slave hostname: vesta.apache.org
> I0211 21:14:47.864858 21059 slave.cpp:241] Slave checkpoint: true
> I0211 21:14:47.865329 21055 master.cpp:760] The newly elected leader is master@67.195.138.9:53443 with id 2014-02-11-21:14:47-160088899-53443-21045
> I0211 21:14:47.865350 21055 master.cpp:770] Elected as the leading master!
> I0211 21:14:47.865399 21055 state.cpp:33] Recovering state from '/tmp/mesos-Z8v6cu/1/meta'
> I0211 21:14:47.865407 21059 state.cpp:33] Recovering state from '/tmp/mesos-Z8v6cu/0/meta'
> I0211 21:14:47.865502 21052 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : master@67.195.138.9:53443
> I0211 21:14:47.865540 21054 status_update_manager.cpp:188] Recovering status update manager
> I0211 21:14:47.865619 21053 process_isolator.cpp:319] Recovering isolator
> I0211 21:14:47.865674 21057 status_update_manager.cpp:188] Recovering status update manager
> I0211 21:14:47.865699 21059 slave.cpp:2760] Finished recovery
> I0211 21:14:47.865733 21053 process_isolator.cpp:319] Recovering isolator
> I0211 21:14:47.865789 21053 slave.cpp:2760] Finished recovery
> I0211 21:14:47.865921 21059 slave.cpp:508] New master detected at master@67.195.138.9:53443
> I0211 21:14:47.865958 21053 status_update_manager.cpp:162] New master detected at master@67.195.138.9:53443
> I0211 21:14:47.865978 21059 slave.cpp:533] Detecting new master
> I0211 21:14:47.866019 21053 slave.cpp:508] New master detected at master@67.195.138.9:53443
> I0211 21:14:47.866063 21053 slave.cpp:533] Detecting new master
> I0211 21:14:47.866070 21055 status_update_manager.cpp:162] New master detected at master@67.195.138.9:53443
> I0211 21:14:47.866077 21059 master.cpp:1840] Attempting to register slave on vesta.apache.org at slave(2)@67.195.138.9:53443
> I0211 21:14:47.866092 21059 master.cpp:2810] Adding slave 2014-02-11-21:14:47-160088899-53443-21045-0 at vesta.apache.org with cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000]
> I0211 21:14:47.866216 21059 master.cpp:1840] Attempting to register slave on vesta.apache.org at slave(1)@67.195.138.9:53443
> I0211 21:14:47.866225 21053 slave.cpp:551] Registered with master master@67.195.138.9:53443; given slave ID 2014-02-11-21:14:47-160088899-53443-21045-0
> I0211 21:14:47.866228 21059 master.cpp:2810] Adding slave 2014-02-11-21:14:47-160088899-53443-21045-1 at vesta.apache.org with cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000]
> I0211 21:14:47.866278 21055 hierarchical_allocator_process.hpp:445] Added slave 2014-02-11-21:14:47-160088899-53443-21045-0 (vesta.apache.org) with cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] (and cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] available)
> I0211 21:14:47.866297 21059 slave.cpp:551] Registered with master master@67.195.138.9:53443; given slave ID 2014-02-11-21:14:47-160088899-53443-21045-1
> I0211 21:14:47.866327 21055 hierarchical_allocator_process.hpp:708] Performed allocation for slave 2014-02-11-21:14:47-160088899-53443-21045-0 in 11us
> I0211 21:14:47.866330 21053 slave.cpp:564] Checkpointing SlaveInfo to '/tmp/mesos-Z8v6cu/1/meta/slaves/2014-02-11-21:14:47-160088899-53443-21045-0/slave.info'
> I0211 21:14:47.866400 21059 slave.cpp:564] Checkpointing SlaveInfo to '/tmp/mesos-Z8v6cu/0/meta/slaves/2014-02-11-21:14:47-160088899-53443-21045-1/slave.info'
> I0211 21:14:47.866399 21055 hierarchical_allocator_process.hpp:445] Added slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org) with cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] (and cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] available)
> I0211 21:14:47.866423 21055 hierarchical_allocator_process.hpp:708] Performed allocation for slave 2014-02-11-21:14:47-160088899-53443-21045-1 in 2505ns
> I0211 21:14:47.866636 21059 slave.cpp:112] Slave started on 3)@67.195.138.9:53443
> I0211 21:14:47.866727 21059 slave.cpp:212] Slave resources: cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000]
> I0211 21:14:47.866766 21059 slave.cpp:240] Slave hostname: vesta.apache.org
> I0211 21:14:47.866772 21059 slave.cpp:241] Slave checkpoint: true
> I0211 21:14:47.867300 21052 state.cpp:33] Recovering state from '/tmp/mesos-Z8v6cu/2/meta'
> I0211 21:14:47.867368 21052 status_update_manager.cpp:188] Recovering status update manager
> I0211 21:14:47.867419 21055 process_isolator.cpp:319] Recovering isolator
> I0211 21:14:47.867544 21052 slave.cpp:2760] Finished recovery
> I0211 21:14:47.867729 21052 slave.cpp:508] New master detected at master@67.195.138.9:53443
> I0211 21:14:47.867770 21054 status_update_manager.cpp:162] New master detected at master@67.195.138.9:53443
> I0211 21:14:47.867777 21052 slave.cpp:533] Detecting new master
> I0211 21:14:47.867815 21055 master.cpp:1840] Attempting to register slave on vesta.apache.org at slave(3)@67.195.138.9:53443
> I0211 21:14:47.867827 21055 master.cpp:2810] Adding slave 2014-02-11-21:14:47-160088899-53443-21045-2 at vesta.apache.org with cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000]
> I0211 21:14:47.867885 21052 slave.cpp:551] Registered with master master@67.195.138.9:53443; given slave ID 2014-02-11-21:14:47-160088899-53443-21045-2
> I0211 21:14:47.867961 21055 hierarchical_allocator_process.hpp:445] Added slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org) with cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] (and cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] available)
> I0211 21:14:47.867985 21052 slave.cpp:564] Checkpointing SlaveInfo to '/tmp/mesos-Z8v6cu/2/meta/slaves/2014-02-11-21:14:47-160088899-53443-21045-2/slave.info'
> I0211 21:14:47.867987 21055 hierarchical_allocator_process.hpp:708] Performed allocation for slave 2014-02-11-21:14:47-160088899-53443-21045-2 in 3308ns
> I0211 21:14:47.868468 21045 sched.cpp:121] Version: 0.18.0
> I0211 21:14:47.868633 21055 sched.cpp:217] New master detected at master@67.195.138.9:53443
> I0211 21:14:47.868651 21055 sched.cpp:268] Authenticating with master master@67.195.138.9:53443
> I0211 21:14:47.868696 21055 sched.cpp:237] Detecting new master
> I0211 21:14:47.868708 21054 authenticatee.hpp:100] Initializing client SASL
> I0211 21:14:47.869549 21054 authenticatee.hpp:124] Creating new client SASL connection
> I0211 21:14:47.869633 21055 master.cpp:2323] Authenticating framework at scheduler(1)@67.195.138.9:53443
> I0211 21:14:47.869818 21059 authenticator.hpp:83] Initializing server SASL
> I0211 21:14:47.870029 21059 auxprop.cpp:45] Initialized in-memory auxiliary property plugin
> I0211 21:14:47.870040 21059 authenticator.hpp:140] Creating new server SASL connection
> I0211 21:14:47.870144 21057 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5
> I0211 21:14:47.870174 21057 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
> I0211 21:14:47.870203 21057 authenticator.hpp:243] Received SASL authentication start
> I0211 21:14:47.870256 21057 authenticator.hpp:325] Authentication requires more steps
> I0211 21:14:47.870282 21057 authenticatee.hpp:258] Received SASL authentication step
> I0211 21:14:47.870348 21057 authenticator.hpp:271] Received SASL authentication step
> I0211 21:14:47.870376 21057 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
> I0211 21:14:47.870384 21057 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
> I0211 21:14:47.870396 21057 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0211 21:14:47.870405 21057 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
> I0211 21:14:47.870411 21057 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0211 21:14:47.870415 21057 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0211 21:14:47.870425 21057 authenticator.hpp:317] Authentication success
> I0211 21:14:47.870445 21057 master.cpp:2363] Successfully authenticated framework at scheduler(1)@67.195.138.9:53443
> I0211 21:14:47.870448 21055 authenticatee.hpp:298] Authentication success
> I0211 21:14:47.870492 21055 sched.cpp:342] Successfully authenticated with master master@67.195.138.9:53443
> I0211 21:14:47.870538 21057 master.cpp:818] Received registration request from scheduler(1)@67.195.138.9:53443
> I0211 21:14:47.870590 21057 master.cpp:836] Registering framework 2014-02-11-21:14:47-160088899-53443-21045-0000 at scheduler(1)@67.195.138.9:53443
> I0211 21:14:47.870661 21055 sched.cpp:391] Framework registered with 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.870661 21057 hierarchical_allocator_process.hpp:332] Added framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.870707 21057 hierarchical_allocator_process.hpp:752] Offering cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-0 to framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.870798 21057 hierarchical_allocator_process.hpp:752] Offering cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-1 to framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.870869 21057 hierarchical_allocator_process.hpp:752] Offering cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-2 to framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.870894 21055 sched.cpp:405] Scheduler::registered took 222149ns
> I0211 21:14:47.871038 21057 hierarchical_allocator_process.hpp:688] Performed allocation for 3 slaves in 351098ns
> I0211 21:14:47.871106 21058 master.hpp:439] Adding offer 2014-02-11-21:14:47-160088899-53443-21045-0 with resources cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org)
> I0211 21:14:47.871215 21058 master.hpp:439] Adding offer 2014-02-11-21:14:47-160088899-53443-21045-1 with resources cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org)
> I0211 21:14:47.871296 21058 master.hpp:439] Adding offer 2014-02-11-21:14:47-160088899-53443-21045-2 with resources cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-0 (vesta.apache.org)
> I0211 21:14:47.871333 21058 master.cpp:2278] Sending 3 offers to framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.873667 21055 sched.cpp:525] Scheduler::resourceOffers took 2.150843ms
> I0211 21:14:47.873884 21053 master.hpp:449] Removing offer 2014-02-11-21:14:47-160088899-53443-21045-0 with resources cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org)
> I0211 21:14:47.873934 21053 master.cpp:1574] Processing reply for offers: [ 2014-02-11-21:14:47-160088899-53443-21045-0 ] on slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org) for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.874035 21053 master.hpp:411] Adding task 0 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org)
> I0211 21:14:47.874059 21053 master.cpp:2447] Launching task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org)
> I0211 21:14:47.874150 21059 slave.cpp:736] Got assigned task 0 for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.874200 21058 hierarchical_allocator_process.hpp:547] Framework 2014-02-11-21:14:47-160088899-53443-21045-0000 left cpus(*):7; mem(*):6929; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 2014-02-11-21:14:47-160088899-53443-21045-2
> I0211 21:14:47.874250 21053 master.hpp:449] Removing offer 2014-02-11-21:14:47-160088899-53443-21045-1 with resources cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org)
> I0211 21:14:47.874307 21053 master.cpp:1574] Processing reply for offers: [ 2014-02-11-21:14:47-160088899-53443-21045-1 ] on slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org) for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.874322 21058 hierarchical_allocator_process.hpp:590] Framework 2014-02-11-21:14:47-160088899-53443-21045-0000 filtered slave 2014-02-11-21:14:47-160088899-53443-21045-2 for 5secs
> I0211 21:14:47.874354 21059 slave.cpp:845] Launching task 0 for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.874404 21053 master.hpp:411] Adding task 1 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org)
> I0211 21:14:47.874428 21053 master.cpp:2447] Launching task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org)
> I0211 21:14:47.874479 21058 slave.cpp:736] Got assigned task 1 for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.874586 21053 master.hpp:449] Removing offer 2014-02-11-21:14:47-160088899-53443-21045-2 with resources cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-0 (vesta.apache.org)
> I0211 21:14:47.874646 21053 master.cpp:1574] Processing reply for offers: [ 2014-02-11-21:14:47-160088899-53443-21045-2 ] on slave 2014-02-11-21:14:47-160088899-53443-21045-0 (vesta.apache.org) for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.874690 21058 slave.cpp:845] Launching task 1 for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.874694 21053 master.hpp:411] Adding task 2 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-0 (vesta.apache.org)
> I0211 21:14:47.874716 21053 master.cpp:2447] Launching task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-0 (vesta.apache.org)
> I0211 21:14:47.874820 21053 hierarchical_allocator_process.hpp:547] Framework 2014-02-11-21:14:47-160088899-53443-21045-0000 left cpus(*):7; mem(*):6929; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 2014-02-11-21:14:47-160088899-53443-21045-1
> I0211 21:14:47.874892 21053 hierarchical_allocator_process.hpp:590] Framework 2014-02-11-21:14:47-160088899-53443-21045-0000 filtered slave 2014-02-11-21:14:47-160088899-53443-21045-1 for 5secs
> I0211 21:14:47.874922 21053 hierarchical_allocator_process.hpp:547] Framework 2014-02-11-21:14:47-160088899-53443-21045-0000 left cpus(*):7; mem(*):6929; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 2014-02-11-21:14:47-160088899-53443-21045-0
> I0211 21:14:47.874980 21053 hierarchical_allocator_process.hpp:590] Framework 2014-02-11-21:14:47-160088899-53443-21045-0000 filtered slave 2014-02-11-21:14:47-160088899-53443-21045-0 for 5secs
> I0211 21:14:47.875012 21053 slave.cpp:736] Got assigned task 2 for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.875151 21053 slave.cpp:845] Launching task 2 for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.875527 21059 slave.cpp:955] Queuing task '0' for executor default of framework '2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.875608 21059 process_isolator.cpp:102] Launching default (/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src/examples/python/test-executor) in /tmp/mesos-Z8v6cu/2/slaves/2014-02-11-21:14:47-160088899-53443-21045-2/frameworks/2014-02-11-21:14:47-160088899-53443-21045-0000/executors/default/runs/02cdf8bd-0757-4a40-8e77-af60bb202d71 with resources cpus(*):1; mem(*):32' for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.876787 21054 slave.cpp:469] Successfully attached file '/tmp/mesos-Z8v6cu/2/slaves/2014-02-11-21:14:47-160088899-53443-21045-2/frameworks/2014-02-11-21:14:47-160088899-53443-21045-0000/executors/default/runs/02cdf8bd-0757-4a40-8e77-af60bb202d71'
> I0211 21:14:47.876852 21059 process_isolator.cpp:165] Forked executor at 21061
> I0211 21:14:47.876940 21058 slave.cpp:955] Queuing task '1' for executor default of framework '2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.877095 21057 process_isolator.cpp:102] Launching default (/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src/examples/python/test-executor) in /tmp/mesos-Z8v6cu/0/slaves/2014-02-11-21:14:47-160088899-53443-21045-1/frameworks/2014-02-11-21:14:47-160088899-53443-21045-0000/executors/default/runs/568b657d-839d-483f-aff1-4872fbfc27dc with resources cpus(*):1; mem(*):32' for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.877102 21052 slave.cpp:469] Successfully attached file '/tmp/mesos-Z8v6cu/0/slaves/2014-02-11-21:14:47-160088899-53443-21045-1/frameworks/2014-02-11-21:14:47-160088899-53443-21045-0000/executors/default/runs/568b657d-839d-483f-aff1-4872fbfc27dc'
> I0211 21:14:47.878783 21057 process_isolator.cpp:165] Forked executor at 21062
> I0211 21:14:47.879032 21053 slave.cpp:955] Queuing task '2' for executor default of framework '2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.879192 21054 slave.cpp:2098] Monitoring executor default of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 forked at pid 21062
> I0211 21:14:47.879192 21058 slave.cpp:469] Successfully attached file '/tmp/mesos-Z8v6cu/1/slaves/2014-02-11-21:14:47-160088899-53443-21045-0/frameworks/2014-02-11-21:14:47-160088899-53443-21045-0000/executors/default/runs/a7c4170a-f40b-4493-81b3-0ea8c70e3977'
> I0211 21:14:47.879166 21052 process_isolator.cpp:102] Launching default (/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src/examples/python/test-executor) in /tmp/mesos-Z8v6cu/1/slaves/2014-02-11-21:14:47-160088899-53443-21045-0/frameworks/2014-02-11-21:14:47-160088899-53443-21045-0000/executors/default/runs/a7c4170a-f40b-4493-81b3-0ea8c70e3977 with resources cpus(*):1; mem(*):32' for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:47.880775 21057 slave.cpp:2098] Monitoring executor default of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 forked at pid 21061
> I0211 21:14:47.880959 21052 process_isolator.cpp:165] Forked executor at 21064
> E0211 21:14:47.881386 21054 slave.cpp:2124] Failed to watch executor default of framework 2014-02-11-21:14:47-160088899-53443-21045-0000: Already watched
> I0211 21:14:47.881474 21055 slave.cpp:2098] Monitoring executor default of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 forked at pid 21064
> E0211 21:14:47.881516 21055 slave.cpp:2124] Failed to watch executor default of framework 2014-02-11-21:14:47-160088899-53443-21045-0000: Already watched
> Fetching resources into '/tmp/mesos-Z8v6cu/2/slaves/2014-02-11-21:14:47-160088899-53443-21045-2/frameworks/2014-02-11-21:14:47-160088899-53443-21045-0000/executors/default/runs/02cdf8bd-0757-4a40-8e77-af60bb202d71'
> Fetching resources into '/tmp/mesos-Z8v6cu/0/slaves/2014-02-11-21:14:47-160088899-53443-21045-1/frameworks/2014-02-11-21:14:47-160088899-53443-21045-0000/executors/default/runs/568b657d-839d-483f-aff1-4872fbfc27dc'
> Fetching resources into '/tmp/mesos-Z8v6cu/1/slaves/2014-02-11-21:14:47-160088899-53443-21045-0/frameworks/2014-02-11-21:14:47-160088899-53443-21045-0000/executors/default/runs/a7c4170a-f40b-4493-81b3-0ea8c70e3977'
> WARNING: Logging before InitGoogleLogging() is written to STDERR
> I0211 21:14:48.154657 21117 process.cpp:1591] libprocess is initialized on 67.195.138.9:60148 for 8 cpus
> I0211 21:14:48.155632 21117 exec.cpp:131] Version: 0.18.0
> WARNING: Logging before InitGoogleLogging() is written to STDERR
> I0211 21:14:48.156184 21116 process.cpp:1591] libprocess is initialized on 67.195.138.9:55901 for 8 cpus
> I0211 21:14:48.157078 21119 exec.cpp:181] Executor started at: executor(1)@67.195.138.9:60148 with pid 21117
> I0211 21:14:48.157146 21116 exec.cpp:131] Version: 0.18.0
> I0211 21:14:48.157536 21052 slave.cpp:1431] Got registration for executor 'default' of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.157784 21052 slave.cpp:1552] Flushing queued task 2 for executor 'default' of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.158042 21126 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.158088 21124 exec.cpp:205] Executor registered on slave 2014-02-11-21:14:47-160088899-53443-21045-0
> WARNING: Logging before InitGoogleLogging() is written to STDERR
> I0211 21:14:48.158324 21113 process.cpp:1591] libprocess is initialized on 67.195.138.9:43514 for 8 cpus
> I0211 21:14:48.158526 21128 exec.cpp:181] Executor started at: executor(1)@67.195.138.9:55901 with pid 21116
> I0211 21:14:48.158803 21055 slave.cpp:1431] Got registration for executor 'default' of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.159018 21055 slave.cpp:1552] Flushing queued task 1 for executor 'default' of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.159241 21133 exec.cpp:205] Executor registered on slave 2014-02-11-21:14:47-160088899-53443-21045-1
> I0211 21:14:48.159246 21135 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.159283 21113 exec.cpp:131] Version: 0.18.0
> I0211 21:14:48.159543 21124 exec.cpp:217] Executor::registered took 575493ns
> I0211 21:14:48.159593 21124 exec.cpp:292] Executor asked to run task '2'
> Starting executor
> Running task 2
> I0211 21:14:48.160181 21124 exec.cpp:301] Executor::launchTask took 569794ns
> I0211 21:14:48.160450 21133 exec.cpp:217] Executor::registered took 454612ns
> I0211 21:14:48.160522 21133 exec.cpp:292] Executor asked to run task '1'
> Sending status update...
> I0211 21:14:48.160640 21137 exec.cpp:181] Executor started at: executor(1)@67.195.138.9:43514 with pid 21113
> Sent status update
> I0211 21:14:48.160894 21052 slave.cpp:1431] Got registration for executor 'default' of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> Starting executor
> Running task 1
> I0211 21:14:48.161001 21133 exec.cpp:301] Executor::launchTask took 466392ns
> I0211 21:14:48.161068 21052 slave.cpp:1552] Flushing queued task 0 for executor 'default' of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.161222 21144 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.161273 21137 exec.cpp:205] Executor registered on slave 2014-02-11-21:14:47-160088899-53443-21045-2
> ISending status update...
> 0211 21:14:48.161321 21144 process.cpp:1010] Socket closed while receiving
> Sent status update
> I0211 21:14:48.161535 21125 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: bd0018b7-0742-42bc-a0a0-1d90f87e7d3b) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.161744 21058 slave.cpp:1765] Handling status update TASK_RUNNING (UUID: bd0018b7-0742-42bc-a0a0-1d90f87e7d3b) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from executor(1)@67.195.138.9:60148
> I0211 21:14:48.161859 21058 status_update_manager.cpp:314] Received status update TASK_RUNNING (UUID: bd0018b7-0742-42bc-a0a0-1d90f87e7d3b) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.161874 21058 status_update_manager.cpp:493] Creating StatusUpdate stream for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.161938 21058 status_update_manager.cpp:367] Forwarding status update TASK_RUNNING (UUID: bd0018b7-0742-42bc-a0a0-1d90f87e7d3b) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to master@67.195.138.9:53443
> I0211 21:14:48.162057 21058 master.cpp:2026] Status update TASK_RUNNING (UUID: bd0018b7-0742-42bc-a0a0-1d90f87e7d3b) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from slave(2)@67.195.138.9:53443
> I0211 21:14:48.162080 21058 slave.cpp:1884] Status update manager successfully handled status update TASK_RUNNING (UUID: bd0018b7-0742-42bc-a0a0-1d90f87e7d3b) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.162088 21058 slave.cpp:1890] Sending acknowledgement for status update TASK_RUNNING (UUID: bd0018b7-0742-42bc-a0a0-1d90f87e7d3b) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to executor(1)@67.195.138.9:60148
> I0211 21:14:48.162555 21058 sched.cpp:616] Scheduler::statusUpdate took 351553ns
> I0211 21:14:48.162623 21058 status_update_manager.cpp:392] Received status update acknowledgement (UUID: bd0018b7-0742-42bc-a0a0-1d90f87e7d3b) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.162669 21058 slave.cpp:1371] Status update manager successfully handled status update acknowledgement (UUID: bd0018b7-0742-42bc-a0a0-1d90f87e7d3b) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.162766 21126 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.163368 21131 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: e2254a60-ebc8-4553-9ed8-e44cc4d84eb8) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.163434 21125 exec.cpp:524] Executor sending status update TASK_FINISHED (UUID: 1d57909c-8b68-45f9-9785-c4b6ad29e664) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.163486 21125 exec.cpp:338] Executor received status update acknowledgement bd0018b7-0742-42bc-a0a0-1d90f87e7d3b for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.163565 21058 slave.cpp:1765] Handling status update TASK_FINISHED (UUID: 1d57909c-8b68-45f9-9785-c4b6ad29e664) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from executor(1)@67.195.138.9:60148
> I0211 21:14:48.163583 21058 slave.cpp:3214] Terminating task 2
> I0211 21:14:48.163662 21058 slave.cpp:1765] Handling status update TASK_RUNNING (UUID: e2254a60-ebc8-4553-9ed8-e44cc4d84eb8) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from executor(1)@67.195.138.9:55901
> I0211 21:14:48.163676 21137 exec.cpp:217] Executor::registered took 548316ns
> II0211 21:14:48.163739 21058 status_update_manager.cpp:314] Received status update TASK_FINISHED (UUID: 1d57909c-8b68-45f9-9785-c4b6ad29e664) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> 0211 21:14:48.163740 21137 exec.cpp:292] Executor asked to run task '0'
> I0211 21:14:48.163756 21058 status_update_manager.cpp:367] Forwarding status update TASK_FINISHED (UUID: 1d57909c-8b68-45f9-9785-c4b6ad29e664) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to master@67.195.138.9:53443
> I0211 21:14:48.163813 21058 status_update_manager.cpp:314] Received status update TASK_RUNNING (UUID: e2254a60-ebc8-4553-9ed8-e44cc4d84eb8) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.163825 21058 status_update_manager.cpp:493] Creating StatusUpdate stream for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.163868 21058 status_update_manager.cpp:367] Forwarding status update TASK_RUNNING (UUID: e2254a60-ebc8-4553-9ed8-e44cc4d84eb8) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to master@67.195.138.9:53443
> I0211 21:14:48.163954 21058 master.cpp:2026] Status update TASK_FINISHED (UUID: 1d57909c-8b68-45f9-9785-c4b6ad29e664) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from slave(2)@67.195.138.9:53443
> I0211 21:14:48.163998 21058 master.hpp:429] Removing task 2 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-0 (vesta.apache.org)
> I0211 21:14:48.164083 21058 master.cpp:2026] Status update TASK_RUNNING (UUID: e2254a60-ebc8-4553-9ed8-e44cc4d84eb8) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from slave(1)@67.195.138.9:53443
> I0211 21:14:48.164103 21058 slave.cpp:1884] Status update manager successfully handled status update TASK_FINISHED (UUID: 1d57909c-8b68-45f9-9785-c4b6ad29e664) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.164113 21058 slave.cpp:1890] Sending acknowledgement for status update TASK_FINISHED (UUID: 1d57909c-8b68-45f9-9785-c4b6ad29e664) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to executor(1)@67.195.138.9:60148
> I0211 21:14:48.164181 21058 slave.cpp:1884] Status update manager successfully handled status update TASK_RUNNING (UUID: e2254a60-ebc8-4553-9ed8-e44cc4d84eb8) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> II0211 21:14:48.164193 21058 slave.cpp:1890] Sending acknowledgement for status update TASK_RUNNING (UUID: e2254a60-ebc8-4553-9ed8-e44cc4d84eb8) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to executor(1)@67.195.138.9:55901
> 0211 21:14:48.164191 21131 exec.cpp:524] Executor sending status update TASK_FINISHED (UUID: 37fd5f35-c3b3-4c16-b836-3cab90ed6874) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> Starting executor
> Running task 0
> I0211 21:14:48.164299 21052 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):32 (total allocatable: cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000]) on slave 2014-02-11-21:14:47-160088899-53443-21045-0 from framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.164361 21058 slave.cpp:1765] Handling status update TASK_FINISHED (UUID: 37fd5f35-c3b3-4c16-b836-3cab90ed6874) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from executor(1)@67.195.138.9:55901
> I0211 21:14:48.164392 21058 slave.cpp:3214] Terminating task 1
> I0211 21:14:48.164505 21052 status_update_manager.cpp:314] Received status update TASK_FINISHED (UUID: 37fd5f35-c3b3-4c16-b836-3cab90ed6874) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.164512 21057 sched.cpp:616] Scheduler::statusUpdate took 238156ns
> I0211 21:14:48.164559 21052 slave.cpp:1884] Status update manager successfully handled status update TASK_FINISHED (UUID: 37fd5f35-c3b3-4c16-b836-3cab90ed6874) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> II0211 21:14:48.164572 21052 slave.cpp:1890] Sending acknowledgement for status update TASK_FINISHED (UUID: 37fd5f35-c3b3-4c16-b836-3cab90ed6874) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to executor(1)@67.195.138.9:55901
> 0211 21:14:48.164571 21135 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.164600 21130 exec.cpp:338] Executor received status update acknowledgement e2254a60-ebc8-4553-9ed8-e44cc4d84eb8 for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.164635 21057 sched.cpp:616] Scheduler::statusUpdate took 76837ns
> Sending status update...
> I0211 21:14:48.164715 21135 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.164726 21057 status_update_manager.cpp:392] Received status update acknowledgement (UUID: e2254a60-ebc8-4553-9ed8-e44cc4d84eb8) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.164728 21130 exec.cpp:338] Executor received status update acknowledgement 37fd5f35-c3b3-4c16-b836-3cab90ed6874 for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.164749 21057 status_update_manager.cpp:367] Forwarding status update TASK_FINISHED (UUID: 37fd5f35-c3b3-4c16-b836-3cab90ed6874) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to master@67.195.138.9:53443
> Sent status update
> I0211 21:14:48.164818 21057 slave.cpp:1371] Status update manager successfully handled status update acknowledgement (UUID: e2254a60-ebc8-4553-9ed8-e44cc4d84eb8) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.164842 21053 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 1d57909c-8b68-45f9-9785-c4b6ad29e664) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.164829 21137 exec.cpp:301] Executor::launchTask took 1.068244ms
> I0211 21:14:48.164872 21053 status_update_manager.cpp:524] Cleaning up status update stream for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.164911 21126 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.164952 21122 exec.cpp:338] Executor received status update acknowledgement 1d57909c-8b68-45f9-9785-c4b6ad29e664 for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.164995 21126 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.165006 21122 exec.cpp:359] Executor received framework message
> I0211 21:14:48.165004 21058 master.cpp:2026] Status update TASK_FINISHED (UUID: 37fd5f35-c3b3-4c16-b836-3cab90ed6874) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from slave(1)@67.195.138.9:53443
> I0211 21:14:48.165043 21057 slave.cpp:1371] Status update manager successfully handled status update acknowledgement (UUID: 1d57909c-8b68-45f9-9785-c4b6ad29e664) for task 2 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.165052 21122 exec.cpp:368] Executor::frameworkMessage took 34533ns
> I0211 21:14:48.165058 21057 slave.cpp:3237] Completing task 2
> I0211 21:14:48.165057 21058 master.hpp:429] Removing task 1 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org)
> I0211 21:14:48.165175 21053 sched.cpp:616] Scheduler::statusUpdate took 162784ns
> I0211 21:14:48.165220 21058 slave.cpp:1943] Sending message for framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to scheduler(1)@67.195.138.9:53443
> I0211 21:14:48.165211 21055 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):32 (total allocatable: cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000]) on slave 2014-02-11-21:14:47-160088899-53443-21045-1 from framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.165316 21057 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 37fd5f35-c3b3-4c16-b836-3cab90ed6874) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.165386 21057 status_update_manager.cpp:524] Cleaning up status update stream for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.165427 21135 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.165451 21055 sched.cpp:701] Scheduler::frameworkMessage took 170832ns
> I0211 21:14:48.165462 21053 slave.cpp:1371] Status update manager successfully handled status update acknowledgement (UUID: 37fd5f35-c3b3-4c16-b836-3cab90ed6874) for task 1 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.165468 21132 exec.cpp:359] Executor received framework message
> I0211 21:14:48.165475 21053 slave.cpp:3237] Completing task 1
> I0211 21:14:48.165493 21132 exec.cpp:368] Executor::frameworkMessage took 11572ns
> I0211 21:14:48.165654 21057 slave.cpp:1943] Sending message for framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to scheduler(1)@67.195.138.9:53443
> I0211 21:14:48.165786 21057 sched.cpp:701] Scheduler::frameworkMessage took 96059ns
> I0211 21:14:48.165777 21137 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: f955480b-856b-4f79-8d92-63edea7ad97d) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.165974 21055 slave.cpp:1765] Handling status update TASK_RUNNING (UUID: f955480b-856b-4f79-8d92-63edea7ad97d) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from executor(1)@67.195.138.9:43514
> I0211 21:14:48.166085 21053 status_update_manager.cpp:314] Received status update TASK_RUNNING (UUID: f955480b-856b-4f79-8d92-63edea7ad97d) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.166113 21053 status_update_manager.cpp:493] Creating StatusUpdate stream for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.166160 21053 status_update_manager.cpp:367] Forwarding status update TASK_RUNNING (UUID: f955480b-856b-4f79-8d92-63edea7ad97d) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to master@67.195.138.9:53443
> I0211 21:14:48.166240 21052 master.cpp:2026] Status update TASK_RUNNING (UUID: f955480b-856b-4f79-8d92-63edea7ad97d) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from slave(3)@67.195.138.9:53443
> I0211 21:14:48.166244 21055 slave.cpp:1884] Status update manager successfully handled status update TASK_RUNNING (UUID: f955480b-856b-4f79-8d92-63edea7ad97d) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.166278 21055 slave.cpp:1890] Sending acknowledgement for status update TASK_RUNNING (UUID: f955480b-856b-4f79-8d92-63edea7ad97d) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to executor(1)@67.195.138.9:43514
> I0211 21:14:48.166385 21058 sched.cpp:616] Scheduler::statusUpdate took 88496ns
> I0211 21:14:48.166489 21144 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.166631 21052 status_update_manager.cpp:392] Received status update acknowledgement (UUID: f955480b-856b-4f79-8d92-63edea7ad97d) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.166653 21137 exec.cpp:524] Executor sending status update TASK_FINISHED (UUID: 9af4cdff-74ae-40ab-9788-0d5f8b7435ec) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.166679 21052 slave.cpp:1371] Status update manager successfully handled status update acknowledgement (UUID: f955480b-856b-4f79-8d92-63edea7ad97d) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.166699 21137 exec.cpp:338] Executor received status update acknowledgement f955480b-856b-4f79-8d92-63edea7ad97d for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.166836 21059 slave.cpp:1765] Handling status update TASK_FINISHED (UUID: 9af4cdff-74ae-40ab-9788-0d5f8b7435ec) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from executor(1)@67.195.138.9:43514
> I0211 21:14:48.166858 21059 slave.cpp:3214] Terminating task 0
> I0211 21:14:48.166960 21054 status_update_manager.cpp:314] Received status update TASK_FINISHED (UUID: 9af4cdff-74ae-40ab-9788-0d5f8b7435ec) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.166988 21054 status_update_manager.cpp:367] Forwarding status update TASK_FINISHED (UUID: 9af4cdff-74ae-40ab-9788-0d5f8b7435ec) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to master@67.195.138.9:53443
> I0211 21:14:48.167079 21055 slave.cpp:1884] Status update manager successfully handled status update TASK_FINISHED (UUID: 9af4cdff-74ae-40ab-9788-0d5f8b7435ec) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.167095 21055 slave.cpp:1890] Sending acknowledgement for status update TASK_FINISHED (UUID: 9af4cdff-74ae-40ab-9788-0d5f8b7435ec) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to executor(1)@67.195.138.9:43514
> I0211 21:14:48.167100 21059 master.cpp:2026] Status update TASK_FINISHED (UUID: 9af4cdff-74ae-40ab-9788-0d5f8b7435ec) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from slave(3)@67.195.138.9:53443
> I0211 21:14:48.167147 21059 master.hpp:429] Removing task 0 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org)
> I0211 21:14:48.167260 21055 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):32 (total allocatable: cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000]) on slave 2014-02-11-21:14:47-160088899-53443-21045-2 from framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.167284 21144 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.167284 21140 exec.cpp:338] Executor received status update acknowledgement 9af4cdff-74ae-40ab-9788-0d5f8b7435ec for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.167326 21054 sched.cpp:616] Scheduler::statusUpdate took 160237ns
> I0211 21:14:48.167469 21057 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 9af4cdff-74ae-40ab-9788-0d5f8b7435ec) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.167495 21057 status_update_manager.cpp:524] Cleaning up status update stream for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.167501 21144 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.167520 21141 exec.cpp:359] Executor received framework message
> I0211 21:14:48.167543 21054 slave.cpp:1371] Status update manager successfully handled status update acknowledgement (UUID: 9af4cdff-74ae-40ab-9788-0d5f8b7435ec) for task 0 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.167563 21054 slave.cpp:3237] Completing task 0
> I0211 21:14:48.167563 21141 exec.cpp:368] Executor::frameworkMessage took 29844ns
> I0211 21:14:48.167691 21057 slave.cpp:1943] Sending message for framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to scheduler(1)@67.195.138.9:53443
> I0211 21:14:48.167773 21052 sched.cpp:701] Scheduler::frameworkMessage took 46462ns
> I0211 21:14:48.866621 21057 hierarchical_allocator_process.hpp:752] Offering cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-0 to framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.866730 21057 hierarchical_allocator_process.hpp:752] Offering cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-1 to framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.866799 21057 hierarchical_allocator_process.hpp:752] Offering cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-2 to framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.866981 21057 hierarchical_allocator_process.hpp:688] Performed allocation for 3 slaves in 433438ns
> I0211 21:14:48.867055 21059 master.hpp:439] Adding offer 2014-02-11-21:14:47-160088899-53443-21045-3 with resources cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org)
> I0211 21:14:48.867164 21059 master.hpp:439] Adding offer 2014-02-11-21:14:47-160088899-53443-21045-4 with resources cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org)
> I0211 21:14:48.867241 21059 master.hpp:439] Adding offer 2014-02-11-21:14:47-160088899-53443-21045-5 with resources cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-0 (vesta.apache.org)
> I0211 21:14:48.867285 21059 master.cpp:2278] Sending 3 offers to framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.869622 21053 sched.cpp:525] Scheduler::resourceOffers took 2.155683ms
> I0211 21:14:48.869803 21059 master.hpp:449] Removing offer 2014-02-11-21:14:47-160088899-53443-21045-3 with resources cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org)
> I0211 21:14:48.869858 21059 master.cpp:1574] Processing reply for offers: [ 2014-02-11-21:14:47-160088899-53443-21045-3 ] on slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org) for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.869946 21059 master.hpp:411] Adding task 3 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org)
> I0211 21:14:48.869969 21059 master.cpp:2447] Launching task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org)
> I0211 21:14:48.870033 21053 slave.cpp:736] Got assigned task 3 for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.870142 21059 master.hpp:449] Removing offer 2014-02-11-21:14:47-160088899-53443-21045-4 with resources cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org)
> I0211 21:14:48.870169 21058 hierarchical_allocator_process.hpp:547] Framework 2014-02-11-21:14:47-160088899-53443-21045-0000 left cpus(*):7; mem(*):6929; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 2014-02-11-21:14:47-160088899-53443-21045-2
> I0211 21:14:48.870193 21059 master.cpp:1574] Processing reply for offers: [ 2014-02-11-21:14:47-160088899-53443-21045-4 ] on slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org) for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.870250 21059 master.hpp:411] Adding task 4 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org)
> I0211 21:14:48.870275 21059 master.cpp:2447] Launching task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org)
> I0211 21:14:48.870281 21058 hierarchical_allocator_process.hpp:590] Framework 2014-02-11-21:14:47-160088899-53443-21045-0000 filtered slave 2014-02-11-21:14:47-160088899-53443-21045-2 for 5secs
> I0211 21:14:48.870331 21058 slave.cpp:736] Got assigned task 4 for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.870414 21058 slave.cpp:845] Launching task 4 for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.870406 21059 master.hpp:449] Removing offer 2014-02-11-21:14:47-160088899-53443-21045-5 with resources cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:14:47-160088899-53443-21045-0 (vesta.apache.org)
> I0211 21:14:48.870468 21058 slave.cpp:980] Sending task '4' to executor 'default' of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.870475 21059 master.cpp:1574] Processing reply for offers: [ 2014-02-11-21:14:47-160088899-53443-21045-5 ] on slave 2014-02-11-21:14:47-160088899-53443-21045-0 (vesta.apache.org) for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.870528 21059 hierarchical_allocator_process.hpp:547] Framework 2014-02-11-21:14:47-160088899-53443-21045-0000 left cpus(*):7; mem(*):6929; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 2014-02-11-21:14:47-160088899-53443-21045-1
> I0211 21:14:48.870601 21059 hierarchical_allocator_process.hpp:590] Framework 2014-02-11-21:14:47-160088899-53443-21045-0000 filtered slave 2014-02-11-21:14:47-160088899-53443-21045-1 for 5secs
> I0211 21:14:48.870632 21053 slave.cpp:845] Launching task 3 for framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.870656 21059 hierarchical_allocator_process.hpp:547] Framework 2014-02-11-21:14:47-160088899-53443-21045-0000 left cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 2014-02-11-21:14:47-160088899-53443-21045-0
> I0211 21:14:48.870666 21053 slave.cpp:980] Sending task '3' to executor 'default' of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.870735 21059 hierarchical_allocator_process.hpp:590] Framework 2014-02-11-21:14:47-160088899-53443-21045-0000 filtered slave 2014-02-11-21:14:47-160088899-53443-21045-0 for 5secs
> I0211 21:14:48.870842 21135 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.870910 21133 exec.cpp:292] Executor asked to run task '4'
> I0211 21:14:48.870980 21144 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.871078 21136 exec.cpp:292] Executor asked to run task '3'
> Running task 4
> I0211 21:14:48.871618 21133 exec.cpp:301] Executor::launchTask took 669868ns
> Sending status update...
> Running task 3
> Sent status update
> Sending status update...
> Sent status update
> I0211 21:14:48.872700 21134 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 1402086c-13c6-4892-a87a-603864039b45) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.872844 21136 exec.cpp:301] Executor::launchTask took 1.735607ms
> I0211 21:14:48.872951 21057 slave.cpp:1765] Handling status update TASK_RUNNING (UUID: 1402086c-13c6-4892-a87a-603864039b45) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from executor(1)@67.195.138.9:55901
> I0211 21:14:48.873046 21055 status_update_manager.cpp:314] Received status update TASK_RUNNING (UUID: 1402086c-13c6-4892-a87a-603864039b45) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.873066 21055 status_update_manager.cpp:493] Creating StatusUpdate stream for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.873123 21055 status_update_manager.cpp:367] Forwarding status update TASK_RUNNING (UUID: 1402086c-13c6-4892-a87a-603864039b45) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to master@67.195.138.9:53443
> I0211 21:14:48.873214 21057 master.cpp:2026] Status update TASK_RUNNING (UUID: 1402086c-13c6-4892-a87a-603864039b45) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from slave(1)@67.195.138.9:53443
> I0211 21:14:48.873245 21058 slave.cpp:1884] Status update manager successfully handled status update TASK_RUNNING (UUID: 1402086c-13c6-4892-a87a-603864039b45) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.873268 21058 slave.cpp:1890] Sending acknowledgement for status update TASK_RUNNING (UUID: 1402086c-13c6-4892-a87a-603864039b45) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to executor(1)@67.195.138.9:55901
> I0211 21:14:48.873344 21055 sched.cpp:616] Scheduler::statusUpdate took 109430ns
> I0211 21:14:48.873440 21055 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 1402086c-13c6-4892-a87a-603864039b45) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.873472 21135 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.873497 21057 slave.cpp:1371] Status update manager successfully handled status update acknowledgement (UUID: 1402086c-13c6-4892-a87a-603864039b45) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.874042 21134 exec.cpp:524] Executor sending status update TASK_FINISHED (UUID: 9ef8e17e-8569-41fc-93f2-df09a42bf876) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.874084 21134 exec.cpp:338] Executor received status update acknowledgement 1402086c-13c6-4892-a87a-603864039b45 for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.874217 21055 slave.cpp:1765] Handling status update TASK_FINISHED (UUID: 9ef8e17e-8569-41fc-93f2-df09a42bf876) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from executor(1)@67.195.138.9:55901
> I0211 21:14:48.874234 21055 slave.cpp:3214] Terminating task 4
> I0211 21:14:48.874250 21136 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 14454a53-c4e5-49bd-be22-cc119dbf206e) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.874305 21055 status_update_manager.cpp:314] Received status update TASK_FINISHED (UUID: 9ef8e17e-8569-41fc-93f2-df09a42bf876) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.874326 21055 status_update_manager.cpp:367] Forwarding status update TASK_FINISHED (UUID: 9ef8e17e-8569-41fc-93f2-df09a42bf876) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to master@67.195.138.9:53443
> I0211 21:14:48.874400 21055 slave.cpp:1765] Handling status update TASK_RUNNING (UUID: 14454a53-c4e5-49bd-be22-cc119dbf206e) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from executor(1)@67.195.138.9:43514
> I0211 21:14:48.874440 21052 master.cpp:2026] Status update TASK_FINISHED (UUID: 9ef8e17e-8569-41fc-93f2-df09a42bf876) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from slave(1)@67.195.138.9:53443
> I0211 21:14:48.874461 21055 slave.cpp:1884] Status update manager successfully handled status update TASK_FINISHED (UUID: 9ef8e17e-8569-41fc-93f2-df09a42bf876) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.874471 21055 slave.cpp:1890] Sending acknowledgement for status update TASK_FINISHED (UUID: 9ef8e17e-8569-41fc-93f2-df09a42bf876) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to executor(1)@67.195.138.9:55901
> I0211 21:14:48.874487 21052 master.hpp:429] Removing task 4 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org)
> I0211 21:14:48.874555 21052 status_update_manager.cpp:314] Received status update TASK_RUNNING (UUID: 14454a53-c4e5-49bd-be22-cc119dbf206e) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.874575 21052 status_update_manager.cpp:493] Creating StatusUpdate stream for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.874647 21052 status_update_manager.cpp:367] Forwarding status update TASK_RUNNING (UUID: 14454a53-c4e5-49bd-be22-cc119dbf206e) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to master@67.195.138.9:53443
> I0211 21:14:48.874707 21135 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.874711 21055 sched.cpp:616] Scheduler::statusUpdate took 141827ns
> I0211 21:14:48.874744 21132 exec.cpp:338] Executor received status update acknowledgement 9ef8e17e-8569-41fc-93f2-df09a42bf876 for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.874634 21054 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):32 (total allocatable: cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000]) on slave 2014-02-11-21:14:47-160088899-53443-21045-1 from framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.874775 21054 slave.cpp:1884] Status update manager successfully handled status update TASK_RUNNING (UUID: 14454a53-c4e5-49bd-be22-cc119dbf206e) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.874785 21054 slave.cpp:1890] Sending acknowledgement for status update TASK_RUNNING (UUID: 14454a53-c4e5-49bd-be22-cc119dbf206e) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to executor(1)@67.195.138.9:43514
> I0211 21:14:48.874802 21052 master.cpp:2026] Status update TASK_RUNNING (UUID: 14454a53-c4e5-49bd-be22-cc119dbf206e) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from slave(3)@67.195.138.9:53443
> I0211 21:14:48.874904 21055 sched.cpp:616] Scheduler::statusUpdate took 76541ns
> I0211 21:14:48.874948 21144 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.874986 21055 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 14454a53-c4e5-49bd-be22-cc119dbf206e) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.875021 21058 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 9ef8e17e-8569-41fc-93f2-df09a42bf876) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.875051 21055 slave.cpp:1371] Status update manager successfully handled status update acknowledgement (UUID: 14454a53-c4e5-49bd-be22-cc119dbf206e) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.875064 21058 status_update_manager.cpp:524] Cleaning up status update stream for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.875071 21135 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.875093 21131 exec.cpp:359] Executor received framework message
> II0211 21:14:48.875123 21131 exec.cpp:368] Executor::frameworkMessage took 17599ns
> 0211 21:14:48.875120 21136 exec.cpp:524] Executor sending status update TASK_FINISHED (UUID: 292fb4b8-d187-497c-8d7f-b8e6f3bba219) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.875174 21136 exec.cpp:338] Executor received status update acknowledgement 14454a53-c4e5-49bd-be22-cc119dbf206e for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.875203 21059 slave.cpp:1371] Status update manager successfully handled status update acknowledgement (UUID: 9ef8e17e-8569-41fc-93f2-df09a42bf876) for task 4 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.875219 21059 slave.cpp:3237] Completing task 4
> I0211 21:14:48.875272 21059 slave.cpp:1943] Sending message for framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to scheduler(1)@67.195.138.9:53443
> I0211 21:14:48.875335 21058 slave.cpp:1765] Handling status update TASK_FINISHED (UUID: 292fb4b8-d187-497c-8d7f-b8e6f3bba219) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from executor(1)@67.195.138.9:43514
> I0211 21:14:48.875358 21058 slave.cpp:3214] Terminating task 3
> I0211 21:14:48.875360 21059 sched.cpp:701] Scheduler::frameworkMessage took 53004ns
> I0211 21:14:48.875466 21059 status_update_manager.cpp:314] Received status update TASK_FINISHED (UUID: 292fb4b8-d187-497c-8d7f-b8e6f3bba219) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.875488 21059 status_update_manager.cpp:367] Forwarding status update TASK_FINISHED (UUID: 292fb4b8-d187-497c-8d7f-b8e6f3bba219) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to master@67.195.138.9:53443
> I0211 21:14:48.875579 21057 slave.cpp:1884] Status update manager successfully handled status update TASK_FINISHED (UUID: 292fb4b8-d187-497c-8d7f-b8e6f3bba219) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.875582 21058 master.cpp:2026] Status update TASK_FINISHED (UUID: 292fb4b8-d187-497c-8d7f-b8e6f3bba219) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 from slave(3)@67.195.138.9:53443
> I0211 21:14:48.875604 21057 slave.cpp:1890] Sending acknowledgement for status update TASK_FINISHED (UUID: 292fb4b8-d187-497c-8d7f-b8e6f3bba219) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to executor(1)@67.195.138.9:43514
> I0211 21:14:48.875639 21058 master.hpp:429] Removing task 3 with resources cpus(*):1; mem(*):32 on slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org)
> I0211 21:14:48.875778 21055 sched.cpp:616] Scheduler::statusUpdate took 143427ns
> I0211 21:14:48.875794 21144 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.875833 21058 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):32 (total allocatable: cpus(*):8; mem(*):6961; disk(*):1.38501e+06; ports(*):[31000-32000]) on slave 2014-02-11-21:14:47-160088899-53443-21045-2 from framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.875932 21138 exec.cpp:338] Executor received status update acknowledgement 292fb4b8-d187-497c-8d7f-b8e6f3bba219 for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.875988 21055 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 292fb4b8-d187-497c-8d7f-b8e6f3bba219) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.876013 21055 status_update_manager.cpp:524] Cleaning up status update stream for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.876006 21144 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.876032 21137 exec.cpp:359] Executor received framework message
> I0211 21:14:48.876083 21137 exec.cpp:368] Executor::frameworkMessage took 36509ns
> I0211 21:14:48.876106 21058 slave.cpp:1371] Status update manager successfully handled status update acknowledgement (UUID: 292fb4b8-d187-497c-8d7f-b8e6f3bba219) for task 3 of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.876121 21058 slave.cpp:3237] Completing task 3
> I0211 21:14:48.876209 21055 slave.cpp:1943] Sending message for framework 2014-02-11-21:14:47-160088899-53443-21045-0000 to scheduler(1)@67.195.138.9:53443
> I0211 21:14:48.876293 21055 sched.cpp:701] Scheduler::frameworkMessage took 59391ns
> I0211 21:14:48.876307 21055 sched.cpp:727] Stopping framework '2014-02-11-21:14:47-160088899-53443-21045-0000'
> I0211 21:14:48.876369 21052 master.cpp:1024] Asked to unregister framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.876387 21052 master.cpp:2682] Removing framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.876422 21055 hierarchical_allocator_process.hpp:408] Deactivated framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.876449 21055 slave.cpp:1142] Asked to shut down framework 2014-02-11-21:14:47-160088899-53443-21045-0000 by master@67.195.138.9:53443
> I0211 21:14:48.876461 21055 slave.cpp:1167] Shutting down framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> Enabling authentication for the framework
> Registered with framework ID 2014-02-11-21:14:47-160088899-53443-21045-0000
> Got 3 resource offers
> Got resource offer 2014-02-11-21:14:47-160088899-53443-21045-0
> Accepting offer on vesta.apache.org to start task 0
> Got resource offer 2014-02-11-21:14:47-160088899-53443-21045-1
> Accepting offer on vesta.apache.org to start task 1
> Got resource offer 2014-02-11-21:14:47-160088899-53443-21045-2
> Accepting offer on vesta.apache.org to start task 2
> Task 2 is in state 1
> Task 2 is in state 2
> Task 1 is in state 1
> Task 1 is in state 2
> Received message: 'data with a \x00 byte'
> Received message: 'data with a \x00 byte'
> Task 0 is in state 1
> Task 0 is in state 2
> Received message: 'data with a \x00 byte'
> Got 3 resource offers
> Got resource offer 2014-02-11-21:14:47-160088899-53443-21045-3
> Accepting offer on vesta.apache.org to start task 3
> Got resource offer 2014-02-11-21:14:47-160088899-53443-21045-4
> Accepting offer on vesta.apache.org to start task 4
> Got resource offer 2014-02-11-21:14:47-160088899-53443-21045-5
> Task 4 is in state 1
> Task 4 is in state 2
> Task 3 is in state 1
> Received message: 'data with a \x00 byte'
> Task 3 is in state 2
> All tasks done, waiting for final framework message
> Received message: 'data with a \x00 byte'
> All tasks done, and all messages received, exiting
> I0211 21:14:48.876477 21055 slave.cpp:2431] Shutting down executor 'default' of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.876525 21052 slave.cpp:1142] Asked to shut down framework 2014-02-11-21:14:47-160088899-53443-21045-0000 by master@67.195.138.9:53443
> I0211 21:14:48.876545 21052 slave.cpp:1167] Shutting down framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.876555 21052 slave.cpp:2431] Shutting down executor 'default' of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.876582 21055 slave.cpp:1142] Asked to shut down framework 2014-02-11-21:14:47-160088899-53443-21045-0000 by master@67.195.138.9:53443
> I0211 21:14:48.876597 21055 slave.cpp:1167] Shutting down framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.876606 21055 slave.cpp:2431] Shutting down executor 'default' of framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.876662 21053 hierarchical_allocator_process.hpp:363] Removed framework 2014-02-11-21:14:47-160088899-53443-21045-0000
> I0211 21:14:48.876766 21133 exec.cpp:378] Executor asked to shutdown
> I0211 21:14:48.876785 21135 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.876814 21133 exec.cpp:393] Executor::shutdown took 7179ns
> I0211 21:14:48.876843 21133 exec.cpp:77] Scheduling shutdown of the executor
> I0211 21:14:48.876899 21144 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.876956 21138 exec.cpp:378] Executor asked to shutdown
> I0211 21:14:48.876988 21126 process.cpp:1010] Socket closed while receiving
> I0211 21:14:48.877019 21138 exec.cpp:393] Executor::shutdown took 22029ns
> I0211 21:14:48.877027 21136 exec.cpp:77] Scheduling shutdown of the executor
> I0211 21:14:48.877110 21122 exec.cpp:378] Executor asked to shutdown
> I0211 21:14:48.877168 21122 exec.cpp:393] Executor::shutdown took 15665ns
> I0211 21:14:48.877185 21123 exec.cpp:77] Scheduling shutdown of the executor
> I0211 21:14:48.881350 21045 master.cpp:587] Master terminating
> I0211 21:14:48.881434 21045 master.cpp:247] Shutting down master
> I0211 21:14:48.881440 21058 slave.cpp:1965] master@67.195.138.9:53443 exited
> W0211 21:14:48.881453 21058 slave.cpp:1968] Master disconnected! Waiting for a new master to be elected
> I0211 21:14:48.881456 21045 master.cpp:290] Removing slave 2014-02-11-21:14:47-160088899-53443-21045-2 (vesta.apache.org)
> I0211 21:14:48.881464 21052 slave.cpp:1965] master@67.195.138.9:53443 exited
> W0211 21:14:48.881475 21052 slave.cpp:1968] Master disconnected! Waiting for a new master to be elected
> I0211 21:14:48.881438 21053 slave.cpp:1965] master@67.195.138.9:53443 exited
> W0211 21:14:48.881515 21053 slave.cpp:1968] Master disconnected! Waiting for a new master to be elected
> I0211 21:14:48.881549 21045 master.cpp:290] Removing slave 2014-02-11-21:14:47-160088899-53443-21045-1 (vesta.apache.org)
> I0211 21:14:48.881618 21045 master.cpp:290] Removing slave 2014-02-11-21:14:47-160088899-53443-21045-0 (vesta.apache.org)
> I0211 21:14:48.882072 21045 slave.cpp:394] Slave terminating
> I0211 21:14:48.882113 21045 slave.cpp:1142] Asked to shut down framework 2014-02-11-21:14:47-160088899-53443-21045-0000 by @0.0.0.0:0
> W0211 21:14:48.882135 21045 slave.cpp:1163] Ignoring shutdown framework 2014-02-11-21:14:47-160088899-53443-21045-0000 because it is terminating
> I0211 21:14:49.300734 21126 process.cpp:1010] Socket closed while receiving
> I0211 21:14:49.300804 21121 exec.cpp:439] Ignoring exited event because the driver is aborted!
> II0211 21:14:49.300813 21135 process.cpp:1010] Socket closed while receiving
> 0211 21:14:49.300820 21144 process.cpp:1010] Socket closed while receiving
> II0211 21:14:49.300904 21138 exec.cpp:439] Ignoring exited event because the driver is aborted!
> 0211 21:14:49.300907 21133 exec.cpp:439] Ignoring exited event because the driver is aborted!
> tests/script.cpp:81: Failure
> Failed
> python_framework_test.sh terminated with signal 'Segmentation fault'
> [  FAILED  ] ExamplesTest.PythonFramework (2484 ms)



--
This message was sent by Atlassian JIRA
(v6.2#6252)