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

Vinod Kone updated MESOS-1814:
------------------------------
    Shepherd: Benjamin Mahler  (was: Yan Xu)

> 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