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

Vinod Kone updated MESOS-1814:
------------------------------
          Component/s: test
               Sprint: Mesos Q3 Sprint 5
     Target Version/s: 0.21.0
    Affects Version/s: 0.21.0
             Shepherd: Yan Xu
         Story Points: 2
              Summary: Task attempted to use more offers than requested in 
example jave and python frameworks  (was: Task attempted to use more offers 
than requested in example framework)

This is a latent bug in both the java and python example frameworks. Both these 
frameworks launch tasks without looking at whether the resources offered to it 
are enough to launch the task.

We are seeing this now because of the recently landed change that offers 
frameworks resources with no memory or no cpu. Before this change, no such 
offers were made and hence the framework was lucky that any offer that it 
received matched its task requirements.

I'll send a patch shortly.

> Task attempted to use more offers than requested in example jave and python 
> frameworks
> --------------------------------------------------------------------------------------
>
>                 Key: MESOS-1814
>                 URL: https://issues.apache.org/jira/browse/MESOS-1814
>             Project: Mesos
>          Issue Type: Bug
>          Components: test
>    Affects Versions: 0.21.0
>            Reporter: Vinod Kone
>            Assignee: Vinod Kone
>
> {code}
> [ RUN      ] ExamplesTest.JavaFramework
> Using temporary directory '/tmp/ExamplesTest_JavaFramework_2PcFCh'
> Enabling authentication for the framework
> WARNING: Logging before InitGoogleLogging() is written to STDERR
> I0917 23:14:35.199069 31510 process.cpp:1771] libprocess is initialized on 
> 127.0.1.1:34609 for 8 cpus
> I0917 23:14:35.199794 31510 logging.cpp:177] Logging to STDERR
> I0917 23:14:35.225342 31510 leveldb.cpp:176] Opened db in 22.197149ms
> I0917 23:14:35.231133 31510 leveldb.cpp:183] Compacted db in 5.601897ms
> I0917 23:14:35.231498 31510 leveldb.cpp:198] Created db iterator in 215441ns
> I0917 23:14:35.231608 31510 leveldb.cpp:204] Seeked to beginning of db in 
> 11488ns
> I0917 23:14:35.231722 31510 leveldb.cpp:273] Iterated through 0 keys in the 
> db in 14016ns
> I0917 23:14:35.231917 31510 replica.cpp:741] Replica recovered with log 
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0917 23:14:35.233129 31526 recover.cpp:425] Starting replica recovery
> I0917 23:14:35.233614 31526 recover.cpp:451] Replica is in EMPTY status
> I0917 23:14:35.234994 31526 replica.cpp:638] Replica in EMPTY status received 
> a broadcasted recover request
> I0917 23:14:35.240116 31519 recover.cpp:188] Received a recover response from 
> a replica in EMPTY status
> I0917 23:14:35.240782 31519 recover.cpp:542] Updating replica status to 
> STARTING
> I0917 23:14:35.242846 31524 master.cpp:286] Master 
> 20140917-231435-16842879-34609-31503 (saucy) started on 127.0.1.1:34609
> I0917 23:14:35.243191 31524 master.cpp:332] Master only allowing 
> authenticated frameworks to register
> I0917 23:14:35.243288 31524 master.cpp:339] Master allowing unauthenticated 
> slaves to register
> I0917 23:14:35.243399 31524 credentials.hpp:36] Loading credentials for 
> authentication from '/tmp/ExamplesTest_JavaFramework_2PcFCh/credentials'
> W0917 23:14:35.243588 31524 credentials.hpp:51] Permissions on credentials 
> file '/tmp/ExamplesTest_JavaFramework_2PcFCh/credentials' are too open. It is 
> recommended that your credentials file is NOT accessible by others.
> I0917 23:14:35.243846 31524 master.cpp:366] Authorization enabled
> I0917 23:14:35.244882 31520 hierarchical_allocator_process.hpp:299] 
> Initializing hierarchical allocator process with master : 
> master@127.0.1.1:34609
> I0917 23:14:35.245224 31520 master.cpp:120] No whitelist given. Advertising 
> offers for all slaves
> I0917 23:14:35.246934 31524 master.cpp:1211] The newly elected leader is 
> master@127.0.1.1:34609 with id 20140917-231435-16842879-34609-31503
> I0917 23:14:35.247234 31524 master.cpp:1224] Elected as the leading master!
> I0917 23:14:35.247336 31524 master.cpp:1042] Recovering from registrar
> I0917 23:14:35.247542 31526 registrar.cpp:313] Recovering registrar
> I0917 23:14:35.250555 31510 containerizer.cpp:89] Using isolation: 
> posix/cpu,posix/mem
> I0917 23:14:35.252326 31510 containerizer.cpp:89] Using isolation: 
> posix/cpu,posix/mem
> I0917 23:14:35.252821 31520 slave.cpp:169] Slave started on 1)@127.0.1.1:34609
> I0917 23:14:35.253552 31520 slave.cpp:289] Slave resources: cpus(*):1; 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]
> I0917 23:14:35.253906 31520 slave.cpp:317] Slave hostname: saucy
> I0917 23:14:35.254004 31520 slave.cpp:318] Slave checkpoint: true
> I0917 23:14:35.254818 31520 state.cpp:33] Recovering state from 
> '/tmp/mesos-w8snRW/0/meta'
> I0917 23:14:35.255106 31519 leveldb.cpp:306] Persisting metadata (8 bytes) to 
> leveldb took 13.99622ms
> I0917 23:14:35.255235 31519 replica.cpp:320] Persisted replica status to 
> STARTING
> I0917 23:14:35.255419 31519 recover.cpp:451] Replica is in STARTING status
> I0917 23:14:35.255834 31519 replica.cpp:638] Replica in STARTING status 
> received a broadcasted recover request
> I0917 23:14:35.256000 31519 recover.cpp:188] Received a recover response from 
> a replica in STARTING status
> I0917 23:14:35.256217 31519 recover.cpp:542] Updating replica status to VOTING
> I0917 23:14:35.256641 31520 status_update_manager.cpp:193] Recovering status 
> update manager
> I0917 23:14:35.257064 31520 containerizer.cpp:252] Recovering containerizer
> I0917 23:14:35.257725 31520 slave.cpp:3220] Finished recovery
> I0917 23:14:35.258463 31520 slave.cpp:600] New master detected at 
> master@127.0.1.1:34609
> I0917 23:14:35.258769 31524 status_update_manager.cpp:167] New master 
> detected at master@127.0.1.1:34609
> I0917 23:14:35.258885 31520 slave.cpp:636] No credentials provided. 
> Attempting to register without authentication
> I0917 23:14:35.259024 31520 slave.cpp:647] Detecting new master
> I0917 23:14:35.259863 31520 slave.cpp:169] Slave started on 2)@127.0.1.1:34609
> I0917 23:14:35.260288 31520 slave.cpp:289] Slave resources: cpus(*):1; 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]
> I0917 23:14:35.260493 31520 slave.cpp:317] Slave hostname: saucy
> I0917 23:14:35.260588 31520 slave.cpp:318] Slave checkpoint: true
> I0917 23:14:35.265127 31510 containerizer.cpp:89] Using isolation: 
> posix/cpu,posix/mem
> I0917 23:14:35.265877 31519 leveldb.cpp:306] Persisting metadata (8 bytes) to 
> leveldb took 9.536278ms
> I0917 23:14:35.265983 31519 replica.cpp:320] Persisted replica status to 
> VOTING
> I0917 23:14:35.266324 31519 recover.cpp:556] Successfully joined the Paxos 
> group
> I0917 23:14:35.266511 31519 recover.cpp:440] Recover process terminated
> I0917 23:14:35.266978 31519 log.cpp:656] Attempting to start the writer
> I0917 23:14:35.268165 31523 replica.cpp:474] Replica received implicit 
> promise request with proposal 1
> I0917 23:14:35.269850 31525 slave.cpp:169] Slave started on 3)@127.0.1.1:34609
> I0917 23:14:35.270365 31525 slave.cpp:289] Slave resources: cpus(*):1; 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]
> I0917 23:14:35.270658 31525 slave.cpp:317] Slave hostname: saucy
> I0917 23:14:35.270781 31525 slave.cpp:318] Slave checkpoint: true
> I0917 23:14:35.271332 31525 state.cpp:33] Recovering state from 
> '/tmp/mesos-w8snRW/2/meta'
> I0917 23:14:35.271580 31522 status_update_manager.cpp:193] Recovering status 
> update manager
> I0917 23:14:35.271838 31522 containerizer.cpp:252] Recovering containerizer
> I0917 23:14:35.272238 31525 slave.cpp:3220] Finished recovery
> I0917 23:14:35.273002 31525 slave.cpp:600] New master detected at 
> master@127.0.1.1:34609
> I0917 23:14:35.273252 31521 status_update_manager.cpp:167] New master 
> detected at master@127.0.1.1:34609
> I0917 23:14:35.273360 31525 slave.cpp:636] No credentials provided. 
> Attempting to register without authentication
> I0917 23:14:35.273507 31525 slave.cpp:647] Detecting new master
> I0917 23:14:35.275413 31525 state.cpp:33] Recovering state from 
> '/tmp/mesos-w8snRW/1/meta'
> I0917 23:14:35.278506 31523 leveldb.cpp:306] Persisting metadata (8 bytes) to 
> leveldb took 10.232514ms
> I0917 23:14:35.278712 31523 replica.cpp:342] Persisted promised to 1
> I0917 23:14:35.279585 31523 coordinator.cpp:230] Coordinator attemping to 
> fill missing position
> I0917 23:14:35.280400 31523 replica.cpp:375] Replica received explicit 
> promise request for position 0 with proposal 2
> I0917 23:14:35.280900 31526 status_update_manager.cpp:193] Recovering status 
> update manager
> I0917 23:14:35.281282 31519 containerizer.cpp:252] Recovering containerizer
> I0917 23:14:35.281615 31520 slave.cpp:3220] Finished recovery
> I0917 23:14:35.281891 31510 sched.cpp:137] Version: 0.21.0
> I0917 23:14:35.282306 31526 sched.cpp:233] New master detected at 
> master@127.0.1.1:34609
> I0917 23:14:35.282464 31526 sched.cpp:283] Authenticating with master 
> master@127.0.1.1:34609
> I0917 23:14:35.282891 31526 authenticatee.hpp:104] Initializing client SASL
> I0917 23:14:35.284816 31526 authenticatee.hpp:128] Creating new client SASL 
> connection
> I0917 23:14:35.285428 31519 master.cpp:873] Dropping 
> 'mesos.internal.AuthenticateMessage' message since not recovered yet
> I0917 23:14:35.288007 31521 slave.cpp:600] New master detected at 
> master@127.0.1.1:34609
> I0917 23:14:35.288399 31521 slave.cpp:636] No credentials provided. 
> Attempting to register without authentication
> I0917 23:14:35.288535 31521 slave.cpp:647] Detecting new master
> I0917 23:14:35.288501 31519 status_update_manager.cpp:167] New master 
> detected at master@127.0.1.1:34609
> I0917 23:14:35.289625 31523 leveldb.cpp:343] Persisting action (8 bytes) to 
> leveldb took 8.997343ms
> I0917 23:14:35.289784 31523 replica.cpp:676] Persisted action at 0
> I0917 23:14:35.292667 31521 replica.cpp:508] Replica received write request 
> for position 0
> I0917 23:14:35.293112 31521 leveldb.cpp:438] Reading position from leveldb 
> took 325638ns
> I0917 23:14:35.301774 31521 leveldb.cpp:343] Persisting action (14 bytes) to 
> leveldb took 8.576338ms
> I0917 23:14:35.301916 31521 replica.cpp:676] Persisted action at 0
> I0917 23:14:35.302289 31521 replica.cpp:655] Replica received learned notice 
> for position 0
> I0917 23:14:35.310542 31521 leveldb.cpp:343] Persisting action (16 bytes) to 
> leveldb took 8.087789ms
> I0917 23:14:35.310675 31521 replica.cpp:676] Persisted action at 0
> I0917 23:14:35.310946 31521 replica.cpp:661] Replica learned NOP action at 
> position 0
> I0917 23:14:35.311254 31521 log.cpp:672] Writer started with ending position 0
> I0917 23:14:35.311957 31521 leveldb.cpp:438] Reading position from leveldb 
> took 35110ns
> I0917 23:14:35.320283 31521 registrar.cpp:346] Successfully fetched the 
> registry (0B)
> I0917 23:14:35.320513 31521 registrar.cpp:422] Attempting to update the 
> 'registry'
> I0917 23:14:35.322226 31525 log.cpp:680] Attempting to append 118 bytes to 
> the log
> I0917 23:14:35.322549 31525 coordinator.cpp:340] Coordinator attempting to 
> write APPEND action at position 1
> I0917 23:14:35.322931 31525 replica.cpp:508] Replica received write request 
> for position 1
> I0917 23:14:35.330169 31525 leveldb.cpp:343] Persisting action (135 bytes) to 
> leveldb took 7.133053ms
> I0917 23:14:35.330340 31525 replica.cpp:676] Persisted action at 1
> I0917 23:14:35.330890 31525 replica.cpp:655] Replica received learned notice 
> for position 1
> I0917 23:14:35.339218 31525 leveldb.cpp:343] Persisting action (137 bytes) to 
> leveldb took 8.192024ms
> I0917 23:14:35.339380 31525 replica.cpp:676] Persisted action at 1
> I0917 23:14:35.339715 31525 replica.cpp:661] Replica learned APPEND action at 
> position 1
> I0917 23:14:35.340615 31525 registrar.cpp:479] Successfully updated 'registry'
> I0917 23:14:35.340802 31525 registrar.cpp:372] Successfully recovered 
> registrar
> I0917 23:14:35.341104 31525 log.cpp:699] Attempting to truncate the log to 1
> I0917 23:14:35.341351 31525 master.cpp:1069] Recovered 0 slaves from the 
> Registry (82B) ; allowing 10mins for slaves to re-register
> I0917 23:14:35.341527 31525 coordinator.cpp:340] Coordinator attempting to 
> write TRUNCATE action at position 2
> I0917 23:14:35.341964 31525 replica.cpp:508] Replica received write request 
> for position 2
> I0917 23:14:35.352336 31525 leveldb.cpp:343] Persisting action (16 bytes) to 
> leveldb took 10.213086ms
> I0917 23:14:35.352494 31525 replica.cpp:676] Persisted action at 2
> I0917 23:14:35.356258 31523 replica.cpp:655] Replica received learned notice 
> for position 2
> I0917 23:14:35.364992 31523 leveldb.cpp:343] Persisting action (18 bytes) to 
> leveldb took 8.606522ms
> I0917 23:14:35.365166 31523 leveldb.cpp:401] Deleting ~1 keys from leveldb 
> took 48378ns
> I0917 23:14:35.365404 31523 replica.cpp:676] Persisted action at 2
> I0917 23:14:35.365537 31523 replica.cpp:661] Replica learned TRUNCATE action 
> at position 2
> I0917 23:14:35.568366 31523 slave.cpp:994] Will retry registration in 
> 423.208575ms if necessary
> I0917 23:14:35.568840 31522 master.cpp:2870] Registering slave at 
> slave(3)@127.0.1.1:34609 (saucy) with id 
> 20140917-231435-16842879-34609-31503-0
> I0917 23:14:35.569422 31522 registrar.cpp:422] Attempting to update the 
> 'registry'
> I0917 23:14:35.572013 31522 log.cpp:680] Attempting to append 289 bytes to 
> the log
> I0917 23:14:35.572273 31519 coordinator.cpp:340] Coordinator attempting to 
> write APPEND action at position 3
> I0917 23:14:35.572816 31519 replica.cpp:508] Replica received write request 
> for position 3
> I0917 23:14:35.579784 31519 leveldb.cpp:343] Persisting action (308 bytes) to 
> leveldb took 6.809365ms
> I0917 23:14:35.579907 31519 replica.cpp:676] Persisted action at 3
> I0917 23:14:35.580512 31519 replica.cpp:655] Replica received learned notice 
> for position 3
> I0917 23:14:35.588748 31519 leveldb.cpp:343] Persisting action (310 bytes) to 
> leveldb took 8.112519ms
> I0917 23:14:35.588888 31519 replica.cpp:676] Persisted action at 3
> I0917 23:14:35.588985 31519 replica.cpp:661] Replica learned APPEND action at 
> position 3
> I0917 23:14:35.589754 31519 registrar.cpp:479] Successfully updated 'registry'
> I0917 23:14:35.590070 31519 master.cpp:2910] Registered slave 
> 20140917-231435-16842879-34609-31503-0 at slave(3)@127.0.1.1:34609 (saucy)
> I0917 23:14:35.590255 31519 master.cpp:4118] Adding slave 
> 20140917-231435-16842879-34609-31503-0 at slave(3)@127.0.1.1:34609 (saucy) 
> with cpus(*):1; mem(*):1001; disk(*):24988; ports(*):[31000-32000]
> I0917 23:14:35.590831 31519 slave.cpp:765] Registered with master 
> master@127.0.1.1:34609; given slave ID 20140917-231435-16842879-34609-31503-0
> I0917 23:14:35.589913 31523 log.cpp:699] Attempting to truncate the log to 3
> I0917 23:14:35.591414 31523 coordinator.cpp:340] Coordinator attempting to 
> write TRUNCATE action at position 4
> I0917 23:14:35.591815 31523 replica.cpp:508] Replica received write request 
> for position 4
> I0917 23:14:35.591117 31521 hierarchical_allocator_process.hpp:442] Added 
> slave 20140917-231435-16842879-34609-31503-0 (saucy) with cpus(*):1; 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000] (and cpus(*):1; 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000] available)
> I0917 23:14:35.592293 31521 hierarchical_allocator_process.hpp:679] Performed 
> allocation for slave 20140917-231435-16842879-34609-31503-0 in 64364ns
> I0917 23:14:35.592953 31519 slave.cpp:778] Checkpointing SlaveInfo to 
> '/tmp/mesos-w8snRW/2/meta/slaves/20140917-231435-16842879-34609-31503-0/slave.info'
> I0917 23:14:35.593475 31519 slave.cpp:2347] Received ping from 
> slave-observer(1)@127.0.1.1:34609
> I0917 23:14:35.601356 31523 leveldb.cpp:343] Persisting action (16 bytes) to 
> leveldb took 9.420461ms
> I0917 23:14:35.601539 31523 replica.cpp:676] Persisted action at 4
> I0917 23:14:35.602325 31523 replica.cpp:655] Replica received learned notice 
> for position 4
> I0917 23:14:35.610779 31523 leveldb.cpp:343] Persisting action (18 bytes) to 
> leveldb took 8.34398ms
> I0917 23:14:35.611114 31523 leveldb.cpp:401] Deleting ~2 keys from leveldb 
> took 66521ns
> I0917 23:14:35.611554 31523 replica.cpp:676] Persisted action at 4
> I0917 23:14:35.611690 31523 replica.cpp:661] Replica learned TRUNCATE action 
> at position 4
> I0917 23:14:36.033941 31523 slave.cpp:994] Will retry registration in 
> 322.705631ms if necessary
> I0917 23:14:36.034276 31521 master.cpp:2870] Registering slave at 
> slave(1)@127.0.1.1:34609 (saucy) with id 
> 20140917-231435-16842879-34609-31503-1
> I0917 23:14:36.034536 31521 registrar.cpp:422] Attempting to update the 
> 'registry'
> I0917 23:14:36.035889 31521 log.cpp:680] Attempting to append 454 bytes to 
> the log
> I0917 23:14:36.036099 31524 coordinator.cpp:340] Coordinator attempting to 
> write APPEND action at position 5
> I0917 23:14:36.036416 31524 replica.cpp:508] Replica received write request 
> for position 5
> I0917 23:14:36.046672 31524 leveldb.cpp:343] Persisting action (473 bytes) to 
> leveldb took 10.160627ms
> I0917 23:14:36.047035 31524 replica.cpp:676] Persisted action at 5
> I0917 23:14:36.047613 31524 replica.cpp:655] Replica received learned notice 
> for position 5
> I0917 23:14:36.053006 31524 leveldb.cpp:343] Persisting action (475 bytes) to 
> leveldb took 5.180742ms
> I0917 23:14:36.053246 31524 replica.cpp:676] Persisted action at 5
> I0917 23:14:36.053678 31524 replica.cpp:661] Replica learned APPEND action at 
> position 5
> I0917 23:14:36.060384 31524 registrar.cpp:479] Successfully updated 'registry'
> I0917 23:14:36.061328 31524 master.cpp:2910] Registered slave 
> 20140917-231435-16842879-34609-31503-1 at slave(1)@127.0.1.1:34609 (saucy)
> I0917 23:14:36.061537 31524 master.cpp:4118] Adding slave 
> 20140917-231435-16842879-34609-31503-1 at slave(1)@127.0.1.1:34609 (saucy) 
> with cpus(*):1; mem(*):1001; disk(*):24988; ports(*):[31000-32000]
> I0917 23:14:36.061982 31524 slave.cpp:765] Registered with master 
> master@127.0.1.1:34609; given slave ID 20140917-231435-16842879-34609-31503-1
> I0917 23:14:36.062891 31524 slave.cpp:778] Checkpointing SlaveInfo to 
> '/tmp/mesos-w8snRW/0/meta/slaves/20140917-231435-16842879-34609-31503-1/slave.info'
> I0917 23:14:36.061050 31525 log.cpp:699] Attempting to truncate the log to 5
> I0917 23:14:36.063244 31525 coordinator.cpp:340] Coordinator attempting to 
> write TRUNCATE action at position 6
> I0917 23:14:36.063746 31525 replica.cpp:508] Replica received write request 
> for position 6
> I0917 23:14:36.062386 31520 hierarchical_allocator_process.hpp:442] Added 
> slave 20140917-231435-16842879-34609-31503-1 (saucy) with cpus(*):1; 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000] (and cpus(*):1; 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000] available)
> I0917 23:14:36.064352 31520 hierarchical_allocator_process.hpp:679] Performed 
> allocation for slave 20140917-231435-16842879-34609-31503-1 in 35730ns
> I0917 23:14:36.065166 31524 slave.cpp:2347] Received ping from 
> slave-observer(2)@127.0.1.1:34609
> I0917 23:14:36.070137 31525 leveldb.cpp:343] Persisting action (16 bytes) to 
> leveldb took 6.242192ms
> I0917 23:14:36.070355 31525 replica.cpp:676] Persisted action at 6
> I0917 23:14:36.071005 31525 replica.cpp:655] Replica received learned notice 
> for position 6
> I0917 23:14:36.076560 31525 leveldb.cpp:343] Persisting action (18 bytes) to 
> leveldb took 5.368532ms
> I0917 23:14:36.077137 31525 leveldb.cpp:401] Deleting ~2 keys from leveldb 
> took 371245ns
> I0917 23:14:36.077241 31525 replica.cpp:676] Persisted action at 6
> I0917 23:14:36.077345 31525 replica.cpp:661] Replica learned TRUNCATE action 
> at position 6
> I0917 23:14:36.141270 31522 slave.cpp:994] Will retry registration in 
> 1.857205901secs if necessary
> I0917 23:14:36.141644 31522 master.cpp:2870] Registering slave at 
> slave(2)@127.0.1.1:34609 (saucy) with id 
> 20140917-231435-16842879-34609-31503-2
> I0917 23:14:36.141930 31522 registrar.cpp:422] Attempting to update the 
> 'registry'
> I0917 23:14:36.143316 31521 log.cpp:680] Attempting to append 619 bytes to 
> the log
> I0917 23:14:36.143646 31521 coordinator.cpp:340] Coordinator attempting to 
> write APPEND action at position 7
> I0917 23:14:36.143954 31521 replica.cpp:508] Replica received write request 
> for position 7
> I0917 23:14:36.148875 31521 leveldb.cpp:343] Persisting action (638 bytes) to 
> leveldb took 4.787834ms
> I0917 23:14:36.149085 31521 replica.cpp:676] Persisted action at 7
> I0917 23:14:36.149673 31521 replica.cpp:655] Replica received learned notice 
> for position 7
> I0917 23:14:36.155232 31521 leveldb.cpp:343] Persisting action (640 bytes) to 
> leveldb took 5.472209ms
> I0917 23:14:36.155522 31521 replica.cpp:676] Persisted action at 7
> I0917 23:14:36.155936 31521 replica.cpp:661] Replica learned APPEND action at 
> position 7
> I0917 23:14:36.156481 31521 registrar.cpp:479] Successfully updated 'registry'
> I0917 23:14:36.156663 31526 log.cpp:699] Attempting to truncate the log to 7
> I0917 23:14:36.156813 31526 coordinator.cpp:340] Coordinator attempting to 
> write TRUNCATE action at position 8
> I0917 23:14:36.157155 31526 replica.cpp:508] Replica received write request 
> for position 8
> I0917 23:14:36.157510 31520 master.cpp:2910] Registered slave 
> 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 (saucy)
> I0917 23:14:36.157645 31520 master.cpp:4118] Adding slave 
> 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 (saucy) 
> with cpus(*):1; mem(*):1001; disk(*):24988; ports(*):[31000-32000]
> I0917 23:14:36.157928 31520 slave.cpp:765] Registered with master 
> master@127.0.1.1:34609; given slave ID 20140917-231435-16842879-34609-31503-2
> I0917 23:14:36.158304 31520 slave.cpp:778] Checkpointing SlaveInfo to 
> '/tmp/mesos-w8snRW/1/meta/slaves/20140917-231435-16842879-34609-31503-2/slave.info'
> I0917 23:14:36.158685 31520 hierarchical_allocator_process.hpp:442] Added 
> slave 20140917-231435-16842879-34609-31503-2 (saucy) with cpus(*):1; 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000] (and cpus(*):1; 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000] available)
> I0917 23:14:36.158821 31520 hierarchical_allocator_process.hpp:679] Performed 
> allocation for slave 20140917-231435-16842879-34609-31503-2 in 23287ns
> I0917 23:14:36.158965 31520 slave.cpp:2347] Received ping from 
> slave-observer(3)@127.0.1.1:34609
> I0917 23:14:36.167183 31526 leveldb.cpp:343] Persisting action (16 bytes) to 
> leveldb took 9.894561ms
> I0917 23:14:36.167323 31526 replica.cpp:676] Persisted action at 8
> I0917 23:14:36.167765 31526 replica.cpp:655] Replica received learned notice 
> for position 8
> I0917 23:14:36.177480 31526 leveldb.cpp:343] Persisting action (18 bytes) to 
> leveldb took 9.585411ms
> I0917 23:14:36.177675 31526 leveldb.cpp:401] Deleting ~2 keys from leveldb 
> took 37564ns
> I0917 23:14:36.177973 31526 replica.cpp:676] Persisted action at 8
> I0917 23:14:36.178089 31526 replica.cpp:661] Replica learned TRUNCATE action 
> at position 8
> I0917 23:14:36.245735 31526 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 96108ns
> I0917 23:14:37.246182 31519 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 83121ns
> I0917 23:14:38.246640 31519 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 126479ns
> I0917 23:14:39.247378 31526 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 81524ns
> I0917 23:14:39.895262 31488 exec.cpp:86] Committing suicide by killing the 
> process group
> I0917 23:14:39.900475 31494 exec.cpp:86] Committing suicide by killing the 
> process group
> I0917 23:14:39.904479 31482 exec.cpp:86] Committing suicide by killing the 
> process group
> I0917 23:14:40.246654 31520 master.cpp:120] No whitelist given. Advertising 
> offers for all slaves
> I0917 23:14:40.247879 31524 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 84970ns
> W0917 23:14:40.283375 31522 sched.cpp:378] Authentication timed out
> I0917 23:14:40.283819 31522 sched.cpp:338] Failed to authenticate with master 
> master@127.0.1.1:34609: Authentication discarded
> I0917 23:14:40.283980 31522 sched.cpp:283] Authenticating with master 
> master@127.0.1.1:34609
> I0917 23:14:40.284317 31522 authenticatee.hpp:128] Creating new client SASL 
> connection
> I0917 23:14:40.284855 31522 master.cpp:3669] Authenticating 
> scheduler-4c79cf12-ea1b-49e5-bae1-d34f91605227@127.0.1.1:34609
> I0917 23:14:40.285302 31522 authenticator.hpp:94] Initializing server SASL
> I0917 23:14:40.285907 31522 auxprop.cpp:45] Initialized in-memory auxiliary 
> property plugin
> I0917 23:14:40.286022 31522 authenticator.hpp:156] Creating new server SASL 
> connection
> I0917 23:14:40.286351 31525 authenticatee.hpp:219] Received SASL 
> authentication mechanisms: CRAM-MD5
> I0917 23:14:40.286486 31525 authenticatee.hpp:245] Attempting to authenticate 
> with mechanism 'CRAM-MD5'
> I0917 23:14:40.286731 31522 authenticator.hpp:262] Received SASL 
> authentication start
> I0917 23:14:40.286923 31522 authenticator.hpp:384] Authentication requires 
> more steps
> I0917 23:14:40.287080 31524 authenticatee.hpp:265] Received SASL 
> authentication step
> I0917 23:14:40.287230 31522 authenticator.hpp:290] Received SASL 
> authentication step
> I0917 23:14:40.287385 31522 auxprop.cpp:81] Request to lookup properties for 
> user: 'test-principal' realm: 'saucy' server FQDN: 'saucy' 
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
> SASL_AUXPROP_AUTHZID: false 
> I0917 23:14:40.287508 31522 auxprop.cpp:153] Looking up auxiliary property 
> '*userPassword'
> I0917 23:14:40.287664 31522 auxprop.cpp:153] Looking up auxiliary property 
> '*cmusaslsecretCRAM-MD5'
> I0917 23:14:40.287777 31522 auxprop.cpp:81] Request to lookup properties for 
> user: 'test-principal' realm: 'saucy' server FQDN: 'saucy' 
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
> SASL_AUXPROP_AUTHZID: true 
> I0917 23:14:40.287912 31522 auxprop.cpp:103] Skipping auxiliary property 
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0917 23:14:40.288020 31522 auxprop.cpp:103] Skipping auxiliary property 
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0917 23:14:40.288214 31522 authenticator.hpp:376] Authentication success
> I0917 23:14:40.288396 31526 authenticatee.hpp:305] Authentication success
> I0917 23:14:40.291566 31526 sched.cpp:357] Successfully authenticated with 
> master master@127.0.1.1:34609
> I0917 23:14:40.291960 31521 master.cpp:3709] Successfully authenticated 
> principal 'test-principal' at 
> scheduler-4c79cf12-ea1b-49e5-bae1-d34f91605227@127.0.1.1:34609
> I0917 23:14:40.292358 31526 sched.cpp:476] Sending registration request to 
> master@127.0.1.1:34609
> I0917 23:14:40.292563 31525 master.cpp:1330] Received registration request 
> from scheduler-4c79cf12-ea1b-49e5-bae1-d34f91605227@127.0.1.1:34609
> I0917 23:14:40.292762 31525 master.cpp:1290] Authorizing framework principal 
> 'test-principal' to receive offers for role '*'
> I0917 23:14:40.293253 31525 master.cpp:1389] Registering framework 
> 20140917-231435-16842879-34609-31503-0000 at 
> scheduler-4c79cf12-ea1b-49e5-bae1-d34f91605227@127.0.1.1:34609
> I0917 23:14:40.293767 31525 hierarchical_allocator_process.hpp:329] Added 
> framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.294075 31525 hierarchical_allocator_process.hpp:734] Offering 
> cpus(*):1; mem(*):1001; disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-0 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.294450 31525 hierarchical_allocator_process.hpp:734] Offering 
> cpus(*):1; mem(*):1001; disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-1 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.294659 31525 hierarchical_allocator_process.hpp:734] Offering 
> cpus(*):1; mem(*):1001; disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-2 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.295035 31520 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-0 with resources cpus(*):1; mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-0 (saucy)
> I0917 23:14:40.295318 31520 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-1 with resources cpus(*):1; mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-2 (saucy)
> I0917 23:14:40.295614 31520 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-2 with resources cpus(*):1; mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-1 (saucy)
> I0917 23:14:40.295778 31520 master.cpp:3616] Sending 3 offers to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.295984 31525 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 1.975722ms
> I0917 23:14:40.296185 31526 sched.cpp:407] Framework registered with 
> 20140917-231435-16842879-34609-31503-0000
> Registered! ID = 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.317849 31526 sched.cpp:421] Scheduler::registered took 
> 21.576128ms
> Launching task 0
> Launching task 1
> Launching task 2
> I0917 23:14:40.365347 31526 sched.cpp:544] Scheduler::resourceOffers took 
> 47.086567ms
> I0917 23:14:40.365958 31523 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-0 with resources cpus(*):1; mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-0 (saucy)
> I0917 23:14:40.366112 31523 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-0 ] on slave 
> 20140917-231435-16842879-34609-31503-0 at slave(3)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> W0917 23:14:40.366549 31523 master.cpp:1898] Executor default for task 0 uses 
> less CPUs (None) than the minimum required (0.01). Please update your 
> executor, as this will be mandatory in future releases.
> W0917 23:14:40.366693 31523 master.cpp:1909] Executor default for task 0 uses 
> less memory (None) than the minimum required (32MB). Please update your 
> executor, as this will be mandatory in future releases.
> I0917 23:14:40.366950 31523 master.cpp:2311] Authorizing framework principal 
> 'test-principal' to launch task 0 as user 'jenkins'
> I0917 23:14:40.367545 31523 master.hpp:839] Adding task 0 with resources 
> cpus(*):1; mem(*):128 on slave 20140917-231435-16842879-34609-31503-0 (saucy)
> I0917 23:14:40.367696 31523 master.cpp:2377] Launching task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000 with resources cpus(*):1; 
> mem(*):128 on slave 20140917-231435-16842879-34609-31503-0 at 
> slave(3)@127.0.1.1:34609 (saucy)
> I0917 23:14:40.367955 31524 slave.cpp:1025] Got assigned task 0 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.368505 31524 slave.cpp:1135] Launching task 0 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.370308 31522 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):873; disk(*):24988; ports(*):[31000-32000] (total allocatable: 
> mem(*):873; disk(*):24988; ports(*):[31000-32000]) on slave 
> 20140917-231435-16842879-34609-31503-0 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.370450 31522 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-0 for 1secs
> I0917 23:14:40.371031 31520 containerizer.cpp:394] Starting container 
> 'a70a0cfd-ee78-43a0-b0b7-26bcd205f142' for executor 'default' of framework 
> '20140917-231435-16842879-34609-31503-0000'
> I0917 23:14:40.373828 31524 slave.cpp:1248] Queuing task '0' for executor 
> default of framework '20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.374595 31524 slave.cpp:554] Successfully attached file 
> '/tmp/mesos-w8snRW/2/slaves/20140917-231435-16842879-34609-31503-0/frameworks/20140917-231435-16842879-34609-31503-0000/executors/default/runs/a70a0cfd-ee78-43a0-b0b7-26bcd205f142'
> I0917 23:14:40.374486 31520 launcher.cpp:137] Forked child with pid '31534' 
> for container 'a70a0cfd-ee78-43a0-b0b7-26bcd205f142'
> I0917 23:14:40.375830 31520 containerizer.cpp:510] Fetching URIs for 
> container 'a70a0cfd-ee78-43a0-b0b7-26bcd205f142' using command 
> '/var/jenkins/workspace/mesos-ubuntu-13.10-clang/src/mesos-fetcher'
> I0917 23:14:40.377596 31523 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-1 with resources cpus(*):1; mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-2 (saucy)
> I0917 23:14:40.377781 31523 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-1 ] on slave 
> 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> W0917 23:14:40.378062 31523 master.cpp:1898] Executor default for task 1 uses 
> less CPUs (None) than the minimum required (0.01). Please update your 
> executor, as this will be mandatory in future releases.
> W0917 23:14:40.378233 31523 master.cpp:1909] Executor default for task 1 uses 
> less memory (None) than the minimum required (32MB). Please update your 
> executor, as this will be mandatory in future releases.
> I0917 23:14:40.378429 31523 master.cpp:2311] Authorizing framework principal 
> 'test-principal' to launch task 1 as user 'jenkins'
> I0917 23:14:40.379017 31523 master.hpp:839] Adding task 1 with resources 
> cpus(*):1; mem(*):128 on slave 20140917-231435-16842879-34609-31503-2 (saucy)
> I0917 23:14:40.379166 31523 master.cpp:2377] Launching task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000 with resources cpus(*):1; 
> mem(*):128 on slave 20140917-231435-16842879-34609-31503-2 at 
> slave(2)@127.0.1.1:34609 (saucy)
> I0917 23:14:40.379525 31525 slave.cpp:1025] Got assigned task 1 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.379914 31525 slave.cpp:1135] Launching task 1 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.381691 31519 containerizer.cpp:394] Starting container 
> '1c6cf8b1-972b-4b73-8467-bc4503dd9332' for executor 'default' of framework 
> '20140917-231435-16842879-34609-31503-0000'
> I0917 23:14:40.383585 31525 slave.cpp:1248] Queuing task '1' for executor 
> default of framework '20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.384318 31522 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):873; disk(*):24988; ports(*):[31000-32000] (total allocatable: 
> mem(*):873; disk(*):24988; ports(*):[31000-32000]) on slave 
> 20140917-231435-16842879-34609-31503-2 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.384598 31522 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-2 for 1secs
> I0917 23:14:40.384814 31525 slave.cpp:554] Successfully attached file 
> '/tmp/mesos-w8snRW/1/slaves/20140917-231435-16842879-34609-31503-2/frameworks/20140917-231435-16842879-34609-31503-0000/executors/default/runs/1c6cf8b1-972b-4b73-8467-bc4503dd9332'
> I0917 23:14:40.385326 31526 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-2 with resources cpus(*):1; mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-1 (saucy)
> I0917 23:14:40.385509 31526 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-2 ] on slave 
> 20140917-231435-16842879-34609-31503-1 at slave(1)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> W0917 23:14:40.385666 31526 master.cpp:1898] Executor default for task 2 uses 
> less CPUs (None) than the minimum required (0.01). Please update your 
> executor, as this will be mandatory in future releases.
> W0917 23:14:40.385856 31526 master.cpp:1909] Executor default for task 2 uses 
> less memory (None) than the minimum required (32MB). Please update your 
> executor, as this will be mandatory in future releases.
> I0917 23:14:40.386008 31526 master.cpp:2311] Authorizing framework principal 
> 'test-principal' to launch task 2 as user 'jenkins'
> I0917 23:14:40.386518 31526 master.hpp:839] Adding task 2 with resources 
> cpus(*):1; mem(*):128 on slave 20140917-231435-16842879-34609-31503-1 (saucy)
> I0917 23:14:40.386818 31519 launcher.cpp:137] Forked child with pid '31536' 
> for container '1c6cf8b1-972b-4b73-8467-bc4503dd9332'
> I0917 23:14:40.393805 31519 containerizer.cpp:510] Fetching URIs for 
> container '1c6cf8b1-972b-4b73-8467-bc4503dd9332' using command 
> '/var/jenkins/workspace/mesos-ubuntu-13.10-clang/src/mesos-fetcher'
> I0917 23:14:40.395980 31526 master.cpp:2377] Launching task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000 with resources cpus(*):1; 
> mem(*):128 on slave 20140917-231435-16842879-34609-31503-1 at 
> slave(1)@127.0.1.1:34609 (saucy)
> I0917 23:14:40.396574 31521 slave.cpp:1025] Got assigned task 2 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.396946 31521 slave.cpp:1135] Launching task 2 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.398582 31521 slave.cpp:1248] Queuing task '2' for executor 
> default of framework '20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.400519 31521 slave.cpp:554] Successfully attached file 
> '/tmp/mesos-w8snRW/0/slaves/20140917-231435-16842879-34609-31503-1/frameworks/20140917-231435-16842879-34609-31503-0000/executors/default/runs/6add4792-3bc4-4ac9-8225-969f09279561'
> I0917 23:14:40.400287 31525 containerizer.cpp:394] Starting container 
> '6add4792-3bc4-4ac9-8225-969f09279561' for executor 'default' of framework 
> '20140917-231435-16842879-34609-31503-0000'
> I0917 23:14:40.401595 31522 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):873; disk(*):24988; ports(*):[31000-32000] (total allocatable: 
> mem(*):873; disk(*):24988; ports(*):[31000-32000]) on slave 
> 20140917-231435-16842879-34609-31503-1 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:40.403118 31522 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-1 for 1secs
> I0917 23:14:40.431401 31525 launcher.cpp:137] Forked child with pid '31551' 
> for container '6add4792-3bc4-4ac9-8225-969f09279561'
> I0917 23:14:40.436882 31525 containerizer.cpp:510] Fetching URIs for 
> container '6add4792-3bc4-4ac9-8225-969f09279561' using command 
> '/var/jenkins/workspace/mesos-ubuntu-13.10-clang/src/mesos-fetcher'
> I0917 23:14:41.248602 31523 hierarchical_allocator_process.hpp:816] Filtered 
> mem(*):873; disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-2 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:41.249043 31523 hierarchical_allocator_process.hpp:816] Filtered 
> mem(*):873; disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-0 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:41.249259 31523 hierarchical_allocator_process.hpp:816] Filtered 
> mem(*):873; disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-1 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:41.249377 31523 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 1.040603ms
> I0917 23:14:41.384321 31526 slave.cpp:2560] Monitoring executor 'default' of 
> framework '20140917-231435-16842879-34609-31503-0000' in container 
> 'a70a0cfd-ee78-43a0-b0b7-26bcd205f142'
> I0917 23:14:41.395431 31526 slave.cpp:2560] Monitoring executor 'default' of 
> framework '20140917-231435-16842879-34609-31503-0000' in container 
> '1c6cf8b1-972b-4b73-8467-bc4503dd9332'
> I0917 23:14:41.413548 31522 slave.cpp:2560] Monitoring executor 'default' of 
> framework '20140917-231435-16842879-34609-31503-0000' in container 
> '6add4792-3bc4-4ac9-8225-969f09279561'
> WARNING: Logging before InitGoogleLogging() is written to STDERR
> WARNING: Logging before InitGoogleLogging() is written to STDERR
> WARNING: Logging before InitGoogleLogging() is written to STDERR
> I0917 23:14:41.935613 31641 process.cpp:1771] libprocess is initialized on 
> 127.0.1.1:40557 for 8 cpus
> I0917 23:14:41.938254 31641 logging.cpp:177] Logging to STDERR
> I0917 23:14:41.934036 31643 process.cpp:1771] libprocess is initialized on 
> 127.0.1.1:33558 for 8 cpus
> I0917 23:14:41.939977 31643 logging.cpp:177] Logging to STDERR
> I0917 23:14:41.937566 31644 process.cpp:1771] libprocess is initialized on 
> 127.0.1.1:51898 for 8 cpus
> II0917 23:14:41.941807 31644 logging.cpp:177] Logging to STDERR
> II0917 23:14:41.943460 31641 exec.cpp:132] Version: 0.21.0
> 0917 23:14:41.941642 31643 exec.cpp:132] Version: 0.21.0
> 0917 23:14:41.943018 31644 exec.cpp:132] Version: 0.21.0
> II0917 23:14:41.950268 31683 exec.cpp:182] Executor started at: 
> executor(1)@127.0.1.1:40557 with pid 31636
> II0917 23:14:41.951695 31522 slave.cpp:1758] Got registration for executor 
> 'default' of framework 20140917-231435-16842879-34609-31503-0000 from 
> executor(1)@127.0.1.1:40557
> I0917 23:14:41.952024 31522 slave.cpp:1877] Flushing queued task 0 for 
> executor 'default' of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:41.951012 31674 exec.cpp:182] Executor started at: 
> executor(1)@127.0.1.1:33558 with pid 31639
> I0917 23:14:41.954056 31526 slave.cpp:1758] Got registration for executor 
> 'default' of framework 20140917-231435-16842879-34609-31503-0000 from 
> executor(1)@127.0.1.1:33558
> I0917 23:14:41.954582 31526 slave.cpp:1877] Flushing queued task 1 for 
> executor 'default' of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:41.950121 31692 exec.cpp:182] Executor started at: 
> executor(1)@127.0.1.1:51898 with pid 31642
> I0917 23:14:41.955857 31521 slave.cpp:1758] Got registration for executor 
> 'default' of framework 20140917-231435-16842879-34609-31503-0000 from 
> executor(1)@127.0.1.1:51898
> I0917 23:14:41.957639 31521 slave.cpp:1877] Flushing queued task 2 for 
> executor 'default' of framework 20140917-231435-16842879-34609-31503-0000
> 0917 23:14:41.955232 31676 exec.cpp:206] Executor registered on slave 
> 20140917-231435-16842879-34609-31503-2
> 0917 23:14:41.953346 31685 exec.cpp:206] Executor registered on slave 
> 20140917-231435-16842879-34609-31503-0
> I0917 23:14:41.968797 31694 exec.cpp:206] Executor registered on slave 
> 20140917-231435-16842879-34609-31503-1
> Registered executor on saucyRegistered executor on saucyRegistered executor 
> on saucy
> II
> I0917 23:14:42.169991 31694 exec.cpp:218] Executor::registered took 
> 199.821555ms
> I0917 23:14:42.170224 31676 exec.cpp:218] Executor::registered took 
> 208.770192ms
> I0917 23:14:42.170574 31685 exec.cpp:218] Executor::registered took 
> 205.42106ms
> I0917 23:14:42.171221 31676 exec.cpp:293] Executor asked to run task '1'
> 0917 23:14:42.170928 31694 exec.cpp:293] Executor asked to run task '2'
> 0917 23:14:42.171532 31685 exec.cpp:293] Executor asked to run task '0'
> III0917 23:14:42.194025 31685 exec.cpp:302] Executor::launchTask took 
> 20.907244ms
> 0917 23:14:42.194463 31694 exec.cpp:302] Executor::launchTask took 22.463085ms
> 0917 23:14:42.193789 31676 exec.cpp:302] Executor::launchTask took 22.090512ms
> I0917 23:14:42.249930 31520 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):873; disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-0 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.250046 31520 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):873; disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-1 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.250120 31520 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):873; disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-2 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.250221 31520 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 427470ns
> I0917 23:14:42.250301 31520 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-3 with resources mem(*):873; 
> disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-0 (saucy)
> I0917 23:14:42.250375 31520 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-4 with resources mem(*):873; 
> disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-2 (saucy)
> I0917 23:14:42.250427 31520 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-5 with resources mem(*):873; 
> disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-1 (saucy)
> I0917 23:14:42.250454 31520 master.cpp:3616] Sending 3 offers to framework 
> 20140917-231435-16842879-34609-31503-0000
> Launching task 3
> Launching task 4
> I0917 23:14:42.256711 31520 sched.cpp:544] Scheduler::resourceOffers took 
> 6.128709ms
> I0917 23:14:42.257067 31519 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-3 with resources mem(*):873; 
> disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-0 (saucy)
> I0917 23:14:42.259182 31519 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-3 ] on slave 
> 20140917-231435-16842879-34609-31503-0 at slave(3)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> II0917 23:14:42.263245 31519 master.cpp:3234] Sending status update TASK_LOST 
> (UUID: 6c082b40-ec70-4c8a-a1b8-5580374e3340) for task 3 of framework 
> 20140917-231435-16842879-34609-31503-0000 'Task 3 attempted to use cpus(*):1; 
> mem(*):128 which is greater than offered mem(*):873; disk(*):24988; 
> ports(*):[31000-32000]'
> I0917 23:14:42.263723 31523 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):873; disk(*):24988; ports(*):[31000-32000] (total allocatable: 
> mem(*):873; disk(*):24988; ports(*):[31000-32000]) on slave 
> 20140917-231435-16842879-34609-31503-0 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.264802 31523 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-0 for 1secs
> I0917 23:14:42.265305 31522 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-4 with resources mem(*):873; 
> disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-2 (saucy)
> II0917 23:14:42.266269 31522 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-4 ] on slave 
> 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.266079 31689 exec.cpp:525] Executor sending status update 
> TASK_RUNNING (UUID: d4ac4252-ea9d-4c1d-b8c9-ea2d9704e6ad) for task 2 of 
> framework 20140917-231435-16842879-34609-31503-0000
> 0917 23:14:42.267781 31672 exec.cpp:525] Executor sending status update 
> TASK_RUNNING (UUID: 3a405ad5-f8f8-4a7d-9f3d-ba0d02ab4cdb) for task 1 of 
> framework 20140917-231435-16842879-34609-31503-0000
> 0917 23:14:42.262806 31678 exec.cpp:525] Executor sending status update 
> TASK_RUNNING (UUID: 774aa76c-87bd-4d39-a5e2-d880206fedb3) for task 0 of 
> framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.276619 31521 slave.cpp:2111] Handling status update 
> TASK_RUNNING (UUID: 3a405ad5-f8f8-4a7d-9f3d-ba0d02ab4cdb) for task 1 of 
> framework 20140917-231435-16842879-34609-31503-0000 from 
> executor(1)@127.0.1.1:33558
> I0917 23:14:42.277762 31521 status_update_manager.cpp:320] Received status 
> update TASK_RUNNING (UUID: 3a405ad5-f8f8-4a7d-9f3d-ba0d02ab4cdb) for task 1 
> of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.277570 31525 slave.cpp:2111] Handling status update 
> TASK_RUNNING (UUID: 774aa76c-87bd-4d39-a5e2-d880206fedb3) for task 0 of 
> framework 20140917-231435-16842879-34609-31503-0000 from 
> executor(1)@127.0.1.1:40557
> I0917 23:14:42.277437 31526 slave.cpp:2111] Handling status update 
> TASK_RUNNING (UUID: d4ac4252-ea9d-4c1d-b8c9-ea2d9704e6ad) for task 2 of 
> framework 20140917-231435-16842879-34609-31503-0000 from 
> executor(1)@127.0.1.1:51898
> I0917 23:14:42.280566 31526 status_update_manager.cpp:320] Received status 
> update TASK_RUNNING (UUID: d4ac4252-ea9d-4c1d-b8c9-ea2d9704e6ad) for task 2 
> of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.280719 31526 status_update_manager.cpp:499] Creating 
> StatusUpdate stream for task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.280987 31526 status_update_manager.cpp:373] Forwarding status 
> update TASK_RUNNING (UUID: d4ac4252-ea9d-4c1d-b8c9-ea2d9704e6ad) for task 2 
> of framework 20140917-231435-16842879-34609-31503-0000 to 
> master@127.0.1.1:34609
> I0917 23:14:42.281231 31526 slave.cpp:2268] Status update manager 
> successfully handled status update TASK_RUNNING (UUID: 
> d4ac4252-ea9d-4c1d-b8c9-ea2d9704e6ad) for task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.281352 31526 slave.cpp:2274] Sending acknowledgement for 
> status update TASK_RUNNING (UUID: d4ac4252-ea9d-4c1d-b8c9-ea2d9704e6ad) for 
> task 2 of framework 20140917-231435-16842879-34609-31503-0000 to 
> executor(1)@127.0.1.1:51898
> I0917 23:14:42.280252 31525 status_update_manager.cpp:320] Received status 
> update TASK_RUNNING (UUID: 774aa76c-87bd-4d39-a5e2-d880206fedb3) for task 0 
> of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.281714 31525 status_update_manager.cpp:499] Creating 
> StatusUpdate stream for task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.281883 31525 status_update_manager.cpp:373] Forwarding status 
> update TASK_RUNNING (UUID: 774aa76c-87bd-4d39-a5e2-d880206fedb3) for task 0 
> of framework 20140917-231435-16842879-34609-31503-0000 to 
> master@127.0.1.1:34609
> I0917 23:14:42.282068 31525 slave.cpp:2268] Status update manager 
> successfully handled status update TASK_RUNNING (UUID: 
> 774aa76c-87bd-4d39-a5e2-d880206fedb3) for task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.282349 31525 slave.cpp:2274] Sending acknowledgement for 
> status update TASK_RUNNING (UUID: 774aa76c-87bd-4d39-a5e2-d880206fedb3) for 
> task 0 of framework 20140917-231435-16842879-34609-31503-0000 to 
> executor(1)@127.0.1.1:40557
> I0917 23:14:42.282624 31521 status_update_manager.cpp:499] Creating 
> StatusUpdate stream for task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.282802 31521 status_update_manager.cpp:373] Forwarding status 
> update TASK_RUNNING (UUID: 3a405ad5-f8f8-4a7d-9f3d-ba0d02ab4cdb) for task 1 
> of framework 20140917-231435-16842879-34609-31503-0000 to 
> master@127.0.1.1:34609
> I0917 23:14:42.282940 31522 master.cpp:3234] Sending status update TASK_LOST 
> (UUID: 24d8174b-ab65-47d0-8e4b-9ad1b5c05030) for task 4 of framework 
> 20140917-231435-16842879-34609-31503-0000 'Task 4 attempted to use cpus(*):1; 
> mem(*):128 which is greater than offered mem(*):873; disk(*):24988; 
> ports(*):[31000-32000]'
> I0917 23:14:42.283248 31524 slave.cpp:2268] Status update manager 
> successfully handled status update TASK_RUNNING (UUID: 
> 3a405ad5-f8f8-4a7d-9f3d-ba0d02ab4cdb) for task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000
> II0917 23:14:42.283634 31524 slave.cpp:2274] Sending acknowledgement for 
> status update TASK_RUNNING (UUID: 3a405ad5-f8f8-4a7d-9f3d-ba0d02ab4cdb) for 
> task 1 of framework 20140917-231435-16842879-34609-31503-0000 to 
> executor(1)@127.0.1.1:33558
> I0917 23:14:42.284031 31522 master.cpp:3239] Forwarding status update 
> TASK_RUNNING (UUID: d4ac4252-ea9d-4c1d-b8c9-ea2d9704e6ad) for task 2 of 
> framework 20140917-231435-16842879-34609-31503-0000
> 0917 23:14:42.283514 31684 exec.cpp:339] Executor received status update 
> acknowledgement 774aa76c-87bd-4d39-a5e2-d880206fedb3 for task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.285044 31522 master.cpp:3205] Status update TASK_RUNNING 
> (UUID: d4ac4252-ea9d-4c1d-b8c9-ea2d9704e6ad) for task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000 from slave 
> 20140917-231435-16842879-34609-31503-1 at slave(1)@127.0.1.1:34609 (saucy)
> I0917 23:14:42.284976 31525 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):873; disk(*):24988; ports(*):[31000-32000] (total allocatable: 
> mem(*):873; disk(*):24988; ports(*):[31000-32000]) on slave 
> 20140917-231435-16842879-34609-31503-2 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.285399 31525 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-2 for 1secs
> I0917 23:14:42.285539 31522 master.cpp:3239] Forwarding status update 
> TASK_RUNNING (UUID: 774aa76c-87bd-4d39-a5e2-d880206fedb3) for task 0 of 
> framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.286206 31522 master.cpp:3205] Status update TASK_RUNNING 
> (UUID: 774aa76c-87bd-4d39-a5e2-d880206fedb3) for task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000 from slave 
> 20140917-231435-16842879-34609-31503-0 at slave(3)@127.0.1.1:34609 (saucy)
> I0917 23:14:42.286468 31522 master.cpp:3239] Forwarding status update 
> TASK_RUNNING (UUID: 3a405ad5-f8f8-4a7d-9f3d-ba0d02ab4cdb) for task 1 of 
> framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.286607 31522 master.cpp:3205] Status update TASK_RUNNING 
> (UUID: 3a405ad5-f8f8-4a7d-9f3d-ba0d02ab4cdb) for task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000 from slave 
> 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 (saucy)
> I0917 23:14:42.286854 31524 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-5 with resources mem(*):873; 
> disk(*):24988; ports(*):[31000-32000] on slave 
> 20140917-231435-16842879-34609-31503-1 (saucy)
> II0917 23:14:42.287259 31524 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-5 ] on slave 
> 20140917-231435-16842879-34609-31503-1 at slave(1)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> 0917 23:14:42.287132 31671 exec.cpp:339] Executor received status update 
> acknowledgement 3a405ad5-f8f8-4a7d-9f3d-ba0d02ab4cdb for task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.287842 31524 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):873; disk(*):24988; ports(*):[31000-32000] (total allocatable: 
> mem(*):873; disk(*):24988; ports(*):[31000-32000]) on slave 
> 20140917-231435-16842879-34609-31503-1 from framework 
> 20140917-231435-16842879-34609-31503-0000
> II0917 23:14:42.291944 31524 hierarchical_allocator_process.hpp:599] 
> Framework 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-1 for 1secs
> 0917 23:14:42.288897 31688 exec.cpp:339] Executor received status update 
> acknowledgement d4ac4252-ea9d-4c1d-b8c9-ea2d9704e6ad for task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000
> Status update: task 3 is in state TASK_LOST
> I0917 23:14:42.314281 31520 sched.cpp:635] Scheduler::statusUpdate took 
> 21.943967ms
> Status update: task 4 is in state TASK_LOST
> I0917 23:14:42.314991 31520 sched.cpp:635] Scheduler::statusUpdate took 
> 513983ns
> Status update: task 2 is in state TASK_RUNNING
> I0917 23:14:42.316504 31520 sched.cpp:635] Scheduler::statusUpdate took 
> 1.370298ms
> I0917 23:14:42.316826 31526 master.cpp:2720] Forwarding status update 
> acknowledgement d4ac4252-ea9d-4c1d-b8c9-ea2d9704e6ad for task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000 to slave 
> 20140917-231435-16842879-34609-31503-1 at slave(1)@127.0.1.1:34609 (saucy)
> I0917 23:14:42.318004 31526 status_update_manager.cpp:398] Received status 
> update acknowledgement (UUID: d4ac4252-ea9d-4c1d-b8c9-ea2d9704e6ad) for task 
> 2 of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.318320 31526 slave.cpp:1698] Status update manager 
> successfully handled status update acknowledgement (UUID: 
> d4ac4252-ea9d-4c1d-b8c9-ea2d9704e6ad) for task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000
> Status update: task 0 is in state TASK_RUNNING
> I0917 23:14:42.319246 31520 sched.cpp:635] Scheduler::statusUpdate took 
> 546461ns
> I0917 23:14:42.319432 31521 master.cpp:2720] Forwarding status update 
> acknowledgement 774aa76c-87bd-4d39-a5e2-d880206fedb3 for task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000 to slave 
> 20140917-231435-16842879-34609-31503-0 at slave(3)@127.0.1.1:34609 (saucy)
> I0917 23:14:42.319612 31521 status_update_manager.cpp:398] Received status 
> update acknowledgement (UUID: 774aa76c-87bd-4d39-a5e2-d880206fedb3) for task 
> 0 of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.319789 31521 slave.cpp:1698] Status update manager 
> successfully handled status update acknowledgement (UUID: 
> 774aa76c-87bd-4d39-a5e2-d880206fedb3) for task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000
> Status update: task 1 is in state TASK_RUNNING
> I0917 23:14:42.325856 31520 sched.cpp:635] Scheduler::statusUpdate took 
> 5.910398ms
> I0917 23:14:42.326161 31519 master.cpp:2720] Forwarding status update 
> acknowledgement 3a405ad5-f8f8-4a7d-9f3d-ba0d02ab4cdb for task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000 to slave 
> 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 (saucy)
> I0917 23:14:42.326392 31522 status_update_manager.cpp:398] Received status 
> update acknowledgement (UUID: 3a405ad5-f8f8-4a7d-9f3d-ba0d02ab4cdb) for task 
> 1 of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.326689 31522 slave.cpp:1698] Status update manager 
> successfully handled status update acknowledgement (UUID: 
> 3a405ad5-f8f8-4a7d-9f3d-ba0d02ab4cdb) for task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.385427 31524 monitor.cpp:140] Failed to collect resource usage 
> for container 'a70a0cfd-ee78-43a0-b0b7-26bcd205f142' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> a70a0cfd-ee78-43a0-b0b7-26bcd205f142
> I0917 23:14:42.396478 31524 monitor.cpp:140] Failed to collect resource usage 
> for container '1c6cf8b1-972b-4b73-8467-bc4503dd9332' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> 1c6cf8b1-972b-4b73-8467-bc4503dd9332
> Running task value: "1"
> Running task value: "0"
> Running task value: "2"
> I0917 23:14:42.747750 31669 exec.cpp:525] Executor sending status update 
> TASK_FINISHED (UUID: c3e603da-200e-4ac6-8ec4-ab09bd839be7) for task 1 of 
> framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.748468 31525 slave.cpp:2111] Handling status update 
> TASK_FINISHED (UUID: c3e603da-200e-4ac6-8ec4-ab09bd839be7) for task 1 of 
> framework 20140917-231435-16842879-34609-31503-0000 from 
> executor(1)@127.0.1.1:33558
> I0917 23:14:42.748540 31525 slave.cpp:3938] Terminating task 1
> I0917 23:14:42.748910 31525 status_update_manager.cpp:320] Received status 
> update TASK_FINISHED (UUID: c3e603da-200e-4ac6-8ec4-ab09bd839be7) for task 1 
> of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.748955 31525 status_update_manager.cpp:373] Forwarding status 
> update TASK_FINISHED (UUID: c3e603da-200e-4ac6-8ec4-ab09bd839be7) for task 1 
> of framework 20140917-231435-16842879-34609-31503-0000 to 
> master@127.0.1.1:34609
> I0917 23:14:42.749049 31525 master.cpp:3239] Forwarding status update 
> TASK_FINISHED (UUID: c3e603da-200e-4ac6-8ec4-ab09bd839be7) for task 1 of 
> framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.749084 31525 master.cpp:3205] Status update TASK_FINISHED 
> (UUID: c3e603da-200e-4ac6-8ec4-ab09bd839be7) for task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000 from slave 
> 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 (saucy)
> I0917 23:14:42.749125 31525 master.cpp:4385] Removing task 1 with resources 
> cpus(*):1; mem(*):128 of framework 20140917-231435-16842879-34609-31503-0000 
> on slave 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 
> (saucy)
> I0917 23:14:42.749271 31525 slave.cpp:2268] Status update manager 
> successfully handled status update TASK_FINISHED (UUID: 
> c3e603da-200e-4ac6-8ec4-ab09bd839be7) for task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.749285 31525 slave.cpp:2274] Sending acknowledgement for 
> status update TASK_FINISHED (UUID: c3e603da-200e-4ac6-8ec4-ab09bd839be7) for 
> task 1 of framework 20140917-231435-16842879-34609-31503-0000 to 
> executor(1)@127.0.1.1:33558
> I0917 23:14:42.749987 31521 hierarchical_allocator_process.hpp:563] Recovered 
> cpus(*):1; mem(*):128 (total allocatable: mem(*):1001; disk(*):24988; 
> ports(*):[31000-32000]; cpus(*):1) on slave 
> 20140917-231435-16842879-34609-31503-2 from framework 
> 20140917-231435-16842879-34609-31503-0000
> Status update: task 1 is in state TASK_FINISHED
> Finished tasks: 1
> I0917 23:14:42.751500 31525 sched.cpp:635] Scheduler::statusUpdate took 
> 2.067671ms
> I0917 23:14:42.751701 31521 master.cpp:2720] Forwarding status update 
> acknowledgement c3e603da-200e-4ac6-8ec4-ab09bd839be7 for task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000 to slave 
> 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 (saucy)
> I0917 23:14:42.751891 31521 status_update_manager.cpp:398] Received status 
> update acknowledgement (UUID: c3e603da-200e-4ac6-8ec4-ab09bd839be7) for task 
> 1 of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.752101 31521 status_update_manager.cpp:530] Cleaning up status 
> update stream for task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.752358 31521 slave.cpp:1698] Status update manager 
> successfully handled status update acknowledgement (UUID: 
> c3e603da-200e-4ac6-8ec4-ab09bd839be7) for task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.752497 31521 slave.cpp:3977] Completing task 1
> III0917 23:14:42.753000 31669 exec.cpp:339] Executor received status update 
> acknowledgement c3e603da-200e-4ac6-8ec4-ab09bd839be7 for task 1 of framework 
> 20140917-231435-16842879-34609-31503-0000
> 0917 23:14:42.753515 31680 exec.cpp:525] Executor sending status update 
> TASK_FINISHED (UUID: 7870de4c-5721-4dbb-b50c-0077513d6e78) for task 0 of 
> framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.755370 31519 slave.cpp:2111] Handling status update 
> TASK_FINISHED (UUID: 7870de4c-5721-4dbb-b50c-0077513d6e78) for task 0 of 
> framework 20140917-231435-16842879-34609-31503-0000 from 
> executor(1)@127.0.1.1:40557
> I0917 23:14:42.755519 31519 slave.cpp:3938] Terminating task 0
> I0917 23:14:42.755897 31519 status_update_manager.cpp:320] Received status 
> update TASK_FINISHED (UUID: 7870de4c-5721-4dbb-b50c-0077513d6e78) for task 0 
> of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.756033 31519 status_update_manager.cpp:373] Forwarding status 
> update TASK_FINISHED (UUID: 7870de4c-5721-4dbb-b50c-0077513d6e78) for task 0 
> of framework 20140917-231435-16842879-34609-31503-0000 to 
> master@127.0.1.1:34609
> I0917 23:14:42.756324 31519 master.cpp:3239] Forwarding status update 
> TASK_FINISHED (UUID: 7870de4c-5721-4dbb-b50c-0077513d6e78) for task 0 of 
> framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.756497 31519 master.cpp:3205] Status update TASK_FINISHED 
> (UUID: 7870de4c-5721-4dbb-b50c-0077513d6e78) for task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000 from slave 
> 20140917-231435-16842879-34609-31503-0 at slave(3)@127.0.1.1:34609 (saucy)
> 0917 23:14:42.754186 31693 exec.cpp:525] Executor sending status update 
> TASK_FINISHED (UUID: de91c600-abe2-4081-ad39-25fbd637b938) for task 2 of 
> framework 20140917-231435-16842879-34609-31503-0000
> Status update: task 0 is in state TASK_FINISHEDI0917 23:14:42.764149 31519 
> master.cpp:4385] Removing task 0 with resources cpus(*):1; mem(*):128 of 
> framework 20140917-231435-16842879-34609-31503-0000 on slave 
> 20140917-231435-16842879-34609-31503-0 at slave(3)@127.0.1.1:34609 (saucy)
> I0917 23:14:42.756443 31523 slave.cpp:2268] Status update manager 
> successfully handled status update TASK_FINISHED (UUID: 
> 7870de4c-5721-4dbb-b50c-0077513d6e78) for task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.766275 31523 slave.cpp:2274] Sending acknowledgement for 
> status update TASK_FINISHED (UUID: 7870de4c-5721-4dbb-b50c-0077513d6e78) for 
> task 0 of framework 20140917-231435-16842879-34609-31503-0000 to 
> executor(1)@127.0.1.1:40557
> I0917 23:14:42.766705 31523 hierarchical_allocator_process.hpp:563] Recovered 
> cpus(*):1; mem(*):128 (total allocatable: mem(*):1001; disk(*):24988; 
> ports(*):[31000-32000]; cpus(*):1) on slave 
> 20140917-231435-16842879-34609-31503-0 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.767081 31519 slave.cpp:2111] Handling status update 
> TASK_FINISHED (UUID: de91c600-abe2-4081-ad39-25fbd637b938) for task 2 of 
> framework 20140917-231435-16842879-34609-31503-0000 from 
> executor(1)@127.0.1.1:51898
> I0917 23:14:42.767195 31519 slave.cpp:3938] Terminating task 2
> I0917 23:14:42.767546 31519 status_update_manager.cpp:320] Received status 
> update TASK_FINISHED (UUID: de91c600-abe2-4081-ad39-25fbd637b938) for task 2 
> of framework 20140917-231435-16842879-34609-31503-0000
> Finished tasks: 2
> I0917 23:14:42.768301 31519 status_update_manager.cpp:373] Forwarding status 
> update TASK_FINISHED (UUID: de91c600-abe2-4081-ad39-25fbd637b938) for task 2 
> of framework 20140917-231435-16842879-34609-31503-0000 to 
> master@127.0.1.1:34609
> I0917 23:14:42.768503 31519 master.cpp:3239] Forwarding status update 
> TASK_FINISHED (UUID: de91c600-abe2-4081-ad39-25fbd637b938) for task 2 of 
> framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.768614 31523 slave.cpp:2268] Status update manager 
> successfully handled status update TASK_FINISHED (UUID: 
> de91c600-abe2-4081-ad39-25fbd637b938) for task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.768723 31523 slave.cpp:2274] Sending acknowledgement for 
> status update TASK_FINISHED (UUID: de91c600-abe2-4081-ad39-25fbd637b938) for 
> task 2 of framework 20140917-231435-16842879-34609-31503-0000 to 
> executor(1)@127.0.1.1:51898
> I0917 23:14:42.768264 31521 sched.cpp:635] Scheduler::statusUpdate took 
> 7.95946ms
> I0917 23:14:42.769163 31519 master.cpp:3205] Status update TASK_FINISHED 
> (UUID: de91c600-abe2-4081-ad39-25fbd637b938) for task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000 from slave 
> 20140917-231435-16842879-34609-31503-1 at slave(1)@127.0.1.1:34609 (saucy)
> Status update: task 2 is in state TASK_FINISHEDII0917 23:14:42.769947 31691 
> exec.cpp:339] Executor received status update acknowledgement 
> de91c600-abe2-4081-ad39-25fbd637b938 for task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000
> 0917 23:14:42.770182 31682 exec.cpp:339] Executor received status update 
> acknowledgement 7870de4c-5721-4dbb-b50c-0077513d6e78 for task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000
> Finished tasks: 3
> I0917 23:14:42.776676 31519 master.cpp:4385] Removing task 2 with resources 
> cpus(*):1; mem(*):128 of framework 20140917-231435-16842879-34609-31503-0000 
> on slave 20140917-231435-16842879-34609-31503-1 at slave(1)@127.0.1.1:34609 
> (saucy)
> I0917 23:14:42.776577 31523 sched.cpp:635] Scheduler::statusUpdate took 
> 7.246343ms
> I0917 23:14:42.777061 31519 master.cpp:2720] Forwarding status update 
> acknowledgement 7870de4c-5721-4dbb-b50c-0077513d6e78 for task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000 to slave 
> 20140917-231435-16842879-34609-31503-0 at slave(3)@127.0.1.1:34609 (saucy)
> I0917 23:14:42.777197 31523 hierarchical_allocator_process.hpp:563] Recovered 
> cpus(*):1; mem(*):128 (total allocatable: mem(*):1001; disk(*):24988; 
> ports(*):[31000-32000]; cpus(*):1) on slave 
> 20140917-231435-16842879-34609-31503-1 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.777384 31519 master.cpp:2720] Forwarding status update 
> acknowledgement de91c600-abe2-4081-ad39-25fbd637b938 for task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000 to slave 
> 20140917-231435-16842879-34609-31503-1 at slave(1)@127.0.1.1:34609 (saucy)
> I0917 23:14:42.777580 31519 status_update_manager.cpp:398] Received status 
> update acknowledgement (UUID: de91c600-abe2-4081-ad39-25fbd637b938) for task 
> 2 of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.777721 31519 status_update_manager.cpp:530] Cleaning up status 
> update stream for task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.777523 31523 status_update_manager.cpp:398] Received status 
> update acknowledgement (UUID: 7870de4c-5721-4dbb-b50c-0077513d6e78) for task 
> 0 of framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.777992 31523 status_update_manager.cpp:530] Cleaning up status 
> update stream for task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.778156 31519 slave.cpp:1698] Status update manager 
> successfully handled status update acknowledgement (UUID: 
> de91c600-abe2-4081-ad39-25fbd637b938) for task 2 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.778313 31519 slave.cpp:3977] Completing task 2
> I0917 23:14:42.778291 31521 slave.cpp:1698] Status update manager 
> successfully handled status update acknowledgement (UUID: 
> 7870de4c-5721-4dbb-b50c-0077513d6e78) for task 0 of framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:42.779542 31521 slave.cpp:3977] Completing task 0
> I0917 23:14:43.250752 31520 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:43.251107 31520 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:43.251287 31520 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:43.251521 31520 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 867376ns
> I0917 23:14:43.251665 31523 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-6 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 (saucy)
> I0917 23:14:43.251854 31523 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-7 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 (saucy)
> I0917 23:14:43.252030 31523 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-8 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 (saucy)
> I0917 23:14:43.252184 31523 master.cpp:3616] Sending 3 offers to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:43.253651 31523 sched.cpp:544] Scheduler::resourceOffers took 
> 1.199343ms
> I0917 23:14:43.254057 31524 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-6 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 (saucy)
> I0917 23:14:43.254179 31524 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-6 ] on slave 
> 20140917-231435-16842879-34609-31503-0 at slave(3)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:43.254555 31524 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 (total 
> allocatable: mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1) 
> on slave 20140917-231435-16842879-34609-31503-0 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:43.254693 31524 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-0 for 1secs
> I0917 23:14:43.254902 31521 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-7 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 (saucy)
> I0917 23:14:43.255035 31521 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-7 ] on slave 
> 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:43.255257 31521 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 (total 
> allocatable: mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1) 
> on slave 20140917-231435-16842879-34609-31503-2 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:43.255414 31521 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-2 for 1secs
> I0917 23:14:43.255630 31522 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-8 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 (saucy)
> I0917 23:14:43.255754 31522 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-8 ] on slave 
> 20140917-231435-16842879-34609-31503-1 at slave(1)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:43.255944 31522 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 (total 
> allocatable: mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1) 
> on slave 20140917-231435-16842879-34609-31503-1 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:43.256085 31522 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-1 for 1secs
> I0917 23:14:43.386253 31522 monitor.cpp:140] Failed to collect resource usage 
> for container 'a70a0cfd-ee78-43a0-b0b7-26bcd205f142' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> a70a0cfd-ee78-43a0-b0b7-26bcd205f142
> I0917 23:14:43.397584 31521 monitor.cpp:140] Failed to collect resource usage 
> for container '1c6cf8b1-972b-4b73-8467-bc4503dd9332' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> 1c6cf8b1-972b-4b73-8467-bc4503dd9332
> I0917 23:14:44.252192 31525 hierarchical_allocator_process.hpp:816] Filtered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:44.252557 31525 hierarchical_allocator_process.hpp:816] Filtered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:44.252712 31525 hierarchical_allocator_process.hpp:816] Filtered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:44.252879 31525 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 791479ns
> I0917 23:14:44.386862 31523 monitor.cpp:140] Failed to collect resource usage 
> for container 'a70a0cfd-ee78-43a0-b0b7-26bcd205f142' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> a70a0cfd-ee78-43a0-b0b7-26bcd205f142
> I0917 23:14:44.398048 31524 monitor.cpp:140] Failed to collect resource usage 
> for container '1c6cf8b1-972b-4b73-8467-bc4503dd9332' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> 1c6cf8b1-972b-4b73-8467-bc4503dd9332
> I0917 23:14:45.247548 31520 master.cpp:120] No whitelist given. Advertising 
> offers for all slaves
> I0917 23:14:45.253939 31521 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:45.254165 31521 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:45.254356 31521 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:45.254585 31521 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 762921ns
> I0917 23:14:45.254741 31523 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-9 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 (saucy)
> I0917 23:14:45.254945 31523 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-10 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 (saucy)
> I0917 23:14:45.255112 31523 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-11 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 (saucy)
> I0917 23:14:45.255259 31523 master.cpp:3616] Sending 3 offers to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:45.256947 31523 sched.cpp:544] Scheduler::resourceOffers took 
> 1.430971ms
> I0917 23:14:45.257366 31524 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-9 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 (saucy)
> I0917 23:14:45.257498 31524 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-9 ] on slave 
> 20140917-231435-16842879-34609-31503-1 at slave(1)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:45.257766 31524 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 (total 
> allocatable: mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1) 
> on slave 20140917-231435-16842879-34609-31503-1 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:45.257901 31524 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-1 for 1secs
> I0917 23:14:45.258277 31522 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-10 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 (saucy)
> I0917 23:14:45.258407 31522 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-10 ] on slave 
> 20140917-231435-16842879-34609-31503-0 at slave(3)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:45.258625 31522 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 (total 
> allocatable: mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1) 
> on slave 20140917-231435-16842879-34609-31503-0 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:45.258771 31522 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-0 for 1secs
> I0917 23:14:45.258975 31522 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-11 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 (saucy)
> I0917 23:14:45.259114 31522 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-11 ] on slave 
> 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:45.259313 31522 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 (total 
> allocatable: mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1) 
> on slave 20140917-231435-16842879-34609-31503-2 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:45.259464 31522 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-2 for 1secs
> I0917 23:14:45.388000 31524 monitor.cpp:140] Failed to collect resource usage 
> for container 'a70a0cfd-ee78-43a0-b0b7-26bcd205f142' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> a70a0cfd-ee78-43a0-b0b7-26bcd205f142
> I0917 23:14:45.399271 31521 monitor.cpp:140] Failed to collect resource usage 
> for container '1c6cf8b1-972b-4b73-8467-bc4503dd9332' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> 1c6cf8b1-972b-4b73-8467-bc4503dd9332
> I0917 23:14:46.254964 31523 hierarchical_allocator_process.hpp:816] Filtered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:46.255506 31523 hierarchical_allocator_process.hpp:816] Filtered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:46.255667 31523 hierarchical_allocator_process.hpp:816] Filtered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:46.255867 31523 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 1.022627ms
> I0917 23:14:46.388937 31525 monitor.cpp:140] Failed to collect resource usage 
> for container 'a70a0cfd-ee78-43a0-b0b7-26bcd205f142' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> a70a0cfd-ee78-43a0-b0b7-26bcd205f142
> I0917 23:14:46.400216 31520 monitor.cpp:140] Failed to collect resource usage 
> for container '1c6cf8b1-972b-4b73-8467-bc4503dd9332' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> 1c6cf8b1-972b-4b73-8467-bc4503dd9332
> I0917 23:14:47.256769 31523 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:47.257114 31523 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:47.257302 31523 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:47.257544 31523 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 848269ns
> I0917 23:14:47.257709 31521 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-12 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 (saucy)
> I0917 23:14:47.257920 31521 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-13 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 (saucy)
> I0917 23:14:47.258103 31521 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-14 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 (saucy)
> I0917 23:14:47.258236 31521 master.cpp:3616] Sending 3 offers to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:47.260226 31521 sched.cpp:544] Scheduler::resourceOffers took 
> 1.743624ms
> I0917 23:14:47.260470 31525 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-12 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 (saucy)
> I0917 23:14:47.260594 31525 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-12 ] on slave 
> 20140917-231435-16842879-34609-31503-0 at slave(3)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:47.260891 31525 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 (total 
> allocatable: mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1) 
> on slave 20140917-231435-16842879-34609-31503-0 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:47.261092 31525 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-0 for 1secs
> I0917 23:14:47.261380 31519 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-13 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 (saucy)
> I0917 23:14:47.261514 31519 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-13 ] on slave 
> 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:47.261744 31519 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 (total 
> allocatable: mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1) 
> on slave 20140917-231435-16842879-34609-31503-2 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:47.261873 31519 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-2 for 1secs
> I0917 23:14:47.262086 31520 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-14 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 (saucy)
> I0917 23:14:47.262212 31520 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-14 ] on slave 
> 20140917-231435-16842879-34609-31503-1 at slave(1)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:47.262408 31520 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 (total 
> allocatable: mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1) 
> on slave 20140917-231435-16842879-34609-31503-1 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:47.262526 31520 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-1 for 1secs
> I0917 23:14:47.390128 31520 monitor.cpp:140] Failed to collect resource usage 
> for container 'a70a0cfd-ee78-43a0-b0b7-26bcd205f142' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> a70a0cfd-ee78-43a0-b0b7-26bcd205f142
> I0917 23:14:47.401535 31520 monitor.cpp:140] Failed to collect resource usage 
> for container '1c6cf8b1-972b-4b73-8467-bc4503dd9332' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> 1c6cf8b1-972b-4b73-8467-bc4503dd9332
> I0917 23:14:48.258159 31520 hierarchical_allocator_process.hpp:816] Filtered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:48.258453 31520 hierarchical_allocator_process.hpp:816] Filtered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:48.258616 31520 hierarchical_allocator_process.hpp:816] Filtered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 for framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:48.258735 31520 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 726125ns
> I0917 23:14:48.390913 31519 monitor.cpp:140] Failed to collect resource usage 
> for container 'a70a0cfd-ee78-43a0-b0b7-26bcd205f142' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> a70a0cfd-ee78-43a0-b0b7-26bcd205f142
> I0917 23:14:48.402195 31523 monitor.cpp:140] Failed to collect resource usage 
> for container '1c6cf8b1-972b-4b73-8467-bc4503dd9332' for executor 'default' 
> of framework '20140917-231435-16842879-34609-31503-0000': Unknown container: 
> 1c6cf8b1-972b-4b73-8467-bc4503dd9332
> I0917 23:14:49.260015 31519 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:49.260422 31519 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:49.260701 31519 hierarchical_allocator_process.hpp:734] Offering 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:49.260953 31519 hierarchical_allocator_process.hpp:659] Performed 
> allocation for 3 slaves in 1.015379ms
> I0917 23:14:49.261144 31520 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-15 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 (saucy)
> I0917 23:14:49.261371 31520 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-16 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-0 (saucy)
> I0917 23:14:49.261576 31520 master.hpp:862] Adding offer 
> 20140917-231435-16842879-34609-31503-17 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-1 (saucy)
> I0917 23:14:49.261729 31520 master.cpp:3616] Sending 3 offers to framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:49.263228 31520 sched.cpp:544] Scheduler::resourceOffers took 
> 1.214892ms
> I0917 23:14:49.263566 31524 master.hpp:871] Removing offer 
> 20140917-231435-16842879-34609-31503-15 with resources mem(*):1001; 
> disk(*):24988; ports(*):[31000-32000]; cpus(*):1 on slave 
> 20140917-231435-16842879-34609-31503-2 (saucy)
> I0917 23:14:49.263701 31524 master.cpp:2228] Processing reply for offers: [ 
> 20140917-231435-16842879-34609-31503-15 ] on slave 
> 20140917-231435-16842879-34609-31503-2 at slave(2)@127.0.1.1:34609 (saucy) 
> for framework 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:49.264742 31524 hierarchical_allocator_process.hpp:563] Recovered 
> mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1 (total 
> allocatable: mem(*):1001; disk(*):24988; ports(*):[31000-32000]; cpus(*):1) 
> on slave 20140917-231435-16842879-34609-31503-2 from framework 
> 20140917-231435-16842879-34609-31503-0000
> I0917 23:14:49.264775 31524 hierarchical_allocator_process.hpp:599] Framework 
> 20140917-231435-16842879-34609-31503-0000 filtered slave 
> 20140917-231435-16842879-34609-31503-2 for 1secs
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to