[ https://issues.apache.org/jira/browse/MESOS-1814?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14139686#comment-14139686 ]
Vinod Kone commented on MESOS-1814: ----------------------------------- https://reviews.apache.org/r/25801/ > 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)