You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@mesos.apache.org by "Jian Qiu (JIRA)" <ji...@apache.org> on 2016/02/16 07:54:18 UTC
[jira] [Updated] (MESOS-4682) ExamplesTest.PythonFramework fails on
OSX
[ https://issues.apache.org/jira/browse/MESOS-4682?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Jian Qiu updated MESOS-4682:
----------------------------
Description:
{code}
Using temporary directory '/tmp/ExamplesTest_PythonFramework_ZvbuJl'
Enabling authentication for the framework
I0216 14:48:17.029909 2007810816 leveldb.cpp:174] Opened db in 3570us
I0216 14:48:17.030324 2007810816 leveldb.cpp:181] Compacted db in 383us
I0216 14:48:17.030375 2007810816 leveldb.cpp:196] Created db iterator in 24us
I0216 14:48:17.030388 2007810816 leveldb.cpp:202] Seeked to beginning of db in 8us
I0216 14:48:17.030411 2007810816 leveldb.cpp:271] Iterated through 0 keys in the db in 6us
I0216 14:48:17.030468 2007810816 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0216 14:48:17.031262 138493952 recover.cpp:447] Starting replica recovery
I0216 14:48:17.031478 138493952 recover.cpp:473] Replica is in EMPTY status
I0216 14:48:17.031772 2007810816 local.cpp:239] Using 'local' authorizer
I0216 14:48:17.032449 135274496 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (4)@9.110.49.144:57199
I0216 14:48:17.032662 137420800 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0216 14:48:17.032914 137957376 recover.cpp:564] Updating replica status to STARTING
I0216 14:48:17.033349 136347648 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 316us
I0216 14:48:17.033375 136347648 replica.cpp:320] Persisted replica status to STARTING
I0216 14:48:17.033488 139030528 recover.cpp:473] Replica is in STARTING status
I0216 14:48:17.034047 135811072 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (5)@9.110.49.144:57199
I0216 14:48:17.034220 139030528 recover.cpp:193] Received a recover response from a replica in STARTING status
I0216 14:48:17.034494 135811072 recover.cpp:564] Updating replica status to VOTING
I0216 14:48:17.034744 136884224 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 135us
I0216 14:48:17.034764 136884224 replica.cpp:320] Persisted replica status to VOTING
I0216 14:48:17.034814 137957376 recover.cpp:578] Successfully joined the Paxos group
I0216 14:48:17.034934 137957376 recover.cpp:462] Recover process terminated
I0216 14:48:17.069952 137957376 master.cpp:374] Master bd54ad91-3083-42a3-a39f-0c7e2e08b0a0 (9.110.49.144) started on 9.110.49.144:57199
I0216 14:48:17.070006 137957376 master.cpp:376] Flags at startup: --acls="permissive: false
register_frameworks {
principals {
type: SOME
values: "test-principal"
}
roles {
type: SOME
values: "*"
}
}
run_tasks {
principals {
type: SOME
values: "test-principal"
}
users {
type: SOME
values: "qiujian"
}
}
" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="true" --authenticate_http="false" --authenticate_slaves="false" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ExamplesTest_PythonFramework_ZvbuJl/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="5secs" --registry_strict="false" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/Users/qiujian/Documents/mesos/src/webui" --work_dir="/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ" --zk_session_timeout="10secs"
I0216 14:48:17.070543 137957376 master.cpp:421] Master only allowing authenticated frameworks to register
I0216 14:48:17.070564 137957376 master.cpp:428] Master allowing unauthenticated slaves to register
I0216 14:48:17.070576 137957376 credentials.hpp:35] Loading credentials for authentication from '/tmp/ExamplesTest_PythonFramework_ZvbuJl/credentials'
W0216 14:48:17.070650 137957376 credentials.hpp:50] Permissions on credentials file '/tmp/ExamplesTest_PythonFramework_ZvbuJl/credentials' are too open. It is recommended that your credentials file is NOT accessible by others.
I0216 14:48:17.070757 137957376 master.cpp:466] Using default 'crammd5' authenticator
I0216 14:48:17.070843 137957376 authenticator.cpp:518] Initializing server SASL
I0216 14:48:17.071966 2007810816 containerizer.cpp:143] Using isolation: filesystem/posix,posix/cpu,posix/mem
I0216 14:48:17.074555 136347648 slave.cpp:192] Slave started on 1)@9.110.49.144:57199
I0216 14:48:17.074591 136347648 slave.cpp:193] Flags at startup: --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5" --container_disk_watch_interval="15secs" --containerizers="mesos" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="https://auth.docker.io" --docker_kill_orphans="true" --docker_puller_timeout="60" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="filesystem/posix,posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/Users/qiujian/Documents/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --resources="cpus:2;mem:10240" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --version="false" --work_dir="/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0"
I0216 14:48:17.075846 2007810816 containerizer.cpp:143] Using isolation: filesystem/posix,posix/cpu,posix/mem
I0216 14:48:17.075814 136347648 slave.cpp:463] Slave resources: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
I0216 14:48:17.075888 136347648 slave.cpp:471] Slave attributes: [ ]
I0216 14:48:17.075906 136347648 slave.cpp:476] Slave hostname: 9.110.49.144
I0216 14:48:17.077810 135274496 slave.cpp:192] Slave started on 2)@9.110.49.144:57199
I0216 14:48:17.077849 135274496 slave.cpp:193] Flags at startup: --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5" --container_disk_watch_interval="15secs" --containerizers="mesos" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="https://auth.docker.io" --docker_kill_orphans="true" --docker_puller_timeout="60" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="filesystem/posix,posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/Users/qiujian/Documents/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --resources="cpus:2;mem:10240" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --version="false" --work_dir="/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1"
I0216 14:48:17.078251 137420800 state.cpp:58] Recovering state from '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0/meta'
I0216 14:48:17.078466 135811072 status_update_manager.cpp:200] Recovering status update manager
I0216 14:48:17.078577 139030528 containerizer.cpp:390] Recovering containerizer
I0216 14:48:17.078850 135274496 slave.cpp:463] Slave resources: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
I0216 14:48:17.078938 135274496 slave.cpp:471] Slave attributes: [ ]
I0216 14:48:17.078953 135274496 slave.cpp:476] Slave hostname: 9.110.49.144
I0216 14:48:17.079116 2007810816 containerizer.cpp:143] Using isolation: filesystem/posix,posix/cpu,posix/mem
I0216 14:48:17.079588 135811072 state.cpp:58] Recovering state from '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1/meta'
I0216 14:48:17.079758 137420800 status_update_manager.cpp:200] Recovering status update manager
I0216 14:48:17.079970 136884224 provisioner.cpp:245] Provisioner recovery complete
I0216 14:48:17.079979 135811072 containerizer.cpp:390] Recovering containerizer
I0216 14:48:17.080253 139030528 slave.cpp:4495] Finished recovery
I0216 14:48:17.081012 137420800 provisioner.cpp:245] Provisioner recovery complete
I0216 14:48:17.081208 136347648 status_update_manager.cpp:174] Pausing sending status updates
I0216 14:48:17.081240 139030528 slave.cpp:795] New master detected at master@9.110.49.144:57199
I0216 14:48:17.081372 136884224 slave.cpp:4495] Finished recovery
I0216 14:48:17.081378 139030528 slave.cpp:820] No credentials provided. Attempting to register without authentication
I0216 14:48:17.081450 139030528 slave.cpp:831] Detecting new master
I0216 14:48:17.081544 135274496 slave.cpp:192] Slave started on 3)@9.110.49.144:57199
I0216 14:48:17.081575 135274496 slave.cpp:193] Flags at startup: --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5" --container_disk_watch_interval="15secs" --containerizers="mesos" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="https://auth.docker.io" --docker_kill_orphans="true" --docker_puller_timeout="60" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="filesystem/posix,posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/Users/qiujian/Documents/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --resources="cpus:2;mem:10240" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --version="false" --work_dir="/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2"
I0216 14:48:17.081957 137420800 status_update_manager.cpp:174] Pausing sending status updates
I0216 14:48:17.081981 138493952 slave.cpp:795] New master detected at master@9.110.49.144:57199
I0216 14:48:17.082057 138493952 slave.cpp:820] No credentials provided. Attempting to register without authentication
I0216 14:48:17.082092 138493952 slave.cpp:831] Detecting new master
I0216 14:48:17.082464 2007810816 sched.cpp:164] Version: 0.27.0
I0216 14:48:17.082598 135274496 slave.cpp:463] Slave resources: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
I0216 14:48:17.082653 135274496 slave.cpp:471] Slave attributes: [ ]
I0216 14:48:17.082664 135274496 slave.cpp:476] Slave hostname: 9.110.49.144
I0216 14:48:17.082993 137420800 state.cpp:58] Recovering state from '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2/meta'
I0216 14:48:17.083070 136884224 status_update_manager.cpp:200] Recovering status update manager
I0216 14:48:17.083226 136884224 containerizer.cpp:390] Recovering containerizer
I0216 14:48:17.083827 136884224 sched.cpp:268] New master detected at master@9.110.49.144:57199
I0216 14:48:17.083879 136884224 sched.cpp:324] Authenticating with master master@9.110.49.144:57199
I0216 14:48:17.083905 136884224 sched.cpp:331] Using default CRAM-MD5 authenticatee
I0216 14:48:17.083920 137420800 provisioner.cpp:245] Provisioner recovery complete
I0216 14:48:17.084105 138493952 slave.cpp:4495] Finished recovery
I0216 14:48:17.084203 135811072 authenticatee.cpp:97] Initializing client SASL
I0216 14:48:17.084527 139030528 status_update_manager.cpp:174] Pausing sending status updates
I0216 14:48:17.084537 138493952 slave.cpp:795] New master detected at master@9.110.49.144:57199
I0216 14:48:17.084585 138493952 slave.cpp:820] No credentials provided. Attempting to register without authentication
I0216 14:48:17.084607 138493952 slave.cpp:831] Detecting new master
I0216 14:48:17.085896 137957376 master.cpp:569] Authorization enabled
I0216 14:48:17.087232 135811072 authenticatee.cpp:121] Creating new client SASL connection
I0216 14:48:17.087606 135811072 master.cpp:1710] The newly elected leader is master@9.110.49.144:57199 with id bd54ad91-3083-42a3-a39f-0c7e2e08b0a0
I0216 14:48:17.087625 135811072 master.cpp:1723] Elected as the leading master!
I0216 14:48:17.087635 135811072 master.cpp:1468] Recovering from registrar
I0216 14:48:17.087730 139030528 registrar.cpp:307] Recovering registrar
I0216 14:48:17.088078 136347648 log.cpp:659] Attempting to start the writer
I0216 14:48:17.089102 135274496 replica.cpp:493] Replica received implicit promise request from (45)@9.110.49.144:57199 with proposal 1
I0216 14:48:17.089292 135274496 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 179us
I0216 14:48:17.089316 135274496 replica.cpp:342] Persisted promised to 1
I0216 14:48:17.089699 135811072 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0216 14:48:17.090502 137957376 replica.cpp:388] Replica received explicit promise request from (46)@9.110.49.144:57199 for position 0 with proposal 2
I0216 14:48:17.090670 137957376 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 148us
I0216 14:48:17.090692 137957376 replica.cpp:712] Persisted action at 0
I0216 14:48:17.091337 138493952 replica.cpp:537] Replica received write request for position 0 from (47)@9.110.49.144:57199
I0216 14:48:17.091375 138493952 leveldb.cpp:436] Reading position from leveldb took 21us
I0216 14:48:17.091470 138493952 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 85us
I0216 14:48:17.091492 138493952 replica.cpp:712] Persisted action at 0
I0216 14:48:17.091790 137957376 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0216 14:48:17.091884 137957376 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 88us
I0216 14:48:17.091910 137957376 replica.cpp:712] Persisted action at 0
I0216 14:48:17.091919 137957376 replica.cpp:697] Replica learned NOP action at position 0
I0216 14:48:17.092175 136884224 log.cpp:675] Writer started with ending position 0
I0216 14:48:17.092670 136884224 leveldb.cpp:436] Reading position from leveldb took 21us
I0216 14:48:17.098273 139030528 registrar.cpp:340] Successfully fetched the registry (0B) in 10.49088ms
I0216 14:48:17.098387 139030528 registrar.cpp:439] Applied 1 operations in 30us; attempting to update the 'registry'
I0216 14:48:17.103885 135811072 log.cpp:683] Attempting to append 176 bytes to the log
I0216 14:48:17.103982 139030528 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0216 14:48:17.104568 138493952 replica.cpp:537] Replica received write request for position 1 from (48)@9.110.49.144:57199
I0216 14:48:17.104753 138493952 leveldb.cpp:341] Persisting action (195 bytes) to leveldb took 168us
I0216 14:48:17.104778 138493952 replica.cpp:712] Persisted action at 1
I0216 14:48:17.105162 136884224 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0216 14:48:17.105304 136884224 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 114us
I0216 14:48:17.105327 136884224 replica.cpp:712] Persisted action at 1
I0216 14:48:17.105337 136884224 replica.cpp:697] Replica learned APPEND action at position 1
I0216 14:48:17.105900 139030528 registrar.cpp:484] Successfully updated the 'registry' in 7.475968ms
I0216 14:48:17.105955 139030528 registrar.cpp:370] Successfully recovered registrar
I0216 14:48:17.106034 137420800 log.cpp:702] Attempting to truncate the log to 1
I0216 14:48:17.106153 135274496 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0216 14:48:17.106171 136884224 master.cpp:1520] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I0216 14:48:17.106647 136884224 replica.cpp:537] Replica received write request for position 2 from (49)@9.110.49.144:57199
I0216 14:48:17.106855 136884224 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 195us
I0216 14:48:17.106879 136884224 replica.cpp:712] Persisted action at 2
I0216 14:48:17.107234 138493952 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0216 14:48:17.107352 138493952 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 105us
I0216 14:48:17.107383 138493952 leveldb.cpp:399] Deleting ~1 keys from leveldb took 15us
I0216 14:48:17.107395 138493952 replica.cpp:712] Persisted action at 2
I0216 14:48:17.107405 138493952 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0216 14:48:17.482161 139030528 master.cpp:4235] Registering slave at slave(2)@9.110.49.144:57199 (9.110.49.144) with id bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0
I0216 14:48:17.482571 138493952 registrar.cpp:439] Applied 1 operations in 87us; attempting to update the 'registry'
I0216 14:48:17.482996 136884224 log.cpp:683] Attempting to append 345 bytes to the log
I0216 14:48:17.483249 136347648 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I0216 14:48:17.484277 137957376 replica.cpp:537] Replica received write request for position 3 from (50)@9.110.49.144:57199
I0216 14:48:17.486208 137957376 leveldb.cpp:341] Persisting action (364 bytes) to leveldb took 1903us
I0216 14:48:17.486256 137957376 replica.cpp:712] Persisted action at 3
I0216 14:48:17.486912 139030528 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
I0216 14:48:17.487145 139030528 leveldb.cpp:341] Persisting action (366 bytes) to leveldb took 213us
I0216 14:48:17.487197 139030528 replica.cpp:712] Persisted action at 3
I0216 14:48:17.487217 139030528 replica.cpp:697] Replica learned APPEND action at position 3
I0216 14:48:17.488268 138493952 registrar.cpp:484] Successfully updated the 'registry' in 5.644032ms
I0216 14:48:17.488488 137420800 log.cpp:702] Attempting to truncate the log to 3
I0216 14:48:17.488611 135811072 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I0216 14:48:17.489032 136884224 slave.cpp:970] Registered with master master@9.110.49.144:57199; given slave ID bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0
I0216 14:48:17.489004 135274496 master.cpp:4303] Registered slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
I0216 14:48:17.489162 139030528 hierarchical.cpp:471] Added slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000] (allocated: )
I0216 14:48:17.489202 137420800 status_update_manager.cpp:181] Resuming sending status updates
I0216 14:48:17.489259 138493952 replica.cpp:537] Replica received write request for position 4 from (51)@9.110.49.144:57199
I0216 14:48:17.489431 138493952 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 145us
I0216 14:48:17.489464 138493952 replica.cpp:712] Persisted action at 4
I0216 14:48:17.489720 136884224 slave.cpp:1029] Forwarding total oversubscribed resources
I0216 14:48:17.489950 138493952 master.cpp:4644] Received update of slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144) with total oversubscribed resources
I0216 14:48:17.489982 136884224 replica.cpp:691] Replica received learned notice for position 4 from @0.0.0.0:0
I0216 14:48:17.490124 136884224 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 134us
I0216 14:48:17.490180 136884224 leveldb.cpp:399] Deleting ~2 keys from leveldb took 32us
I0216 14:48:17.490203 136884224 replica.cpp:712] Persisted action at 4
I0216 14:48:17.490222 136884224 replica.cpp:697] Replica learned TRUNCATE action at position 4
I0216 14:48:17.490353 139030528 hierarchical.cpp:527] Slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 (9.110.49.144) updated with oversubscribed resources (total: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000], allocated: )
I0216 14:48:17.871284 137957376 master.cpp:4235] Registering slave at slave(3)@9.110.49.144:57199 (9.110.49.144) with id bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1
I0216 14:48:17.871639 135274496 registrar.cpp:439] Applied 1 operations in 86us; attempting to update the 'registry'
I0216 14:48:17.879560 137957376 log.cpp:683] Attempting to append 511 bytes to the log
I0216 14:48:17.879673 138493952 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 5
I0216 14:48:17.880383 135274496 replica.cpp:537] Replica received write request for position 5 from (52)@9.110.49.144:57199
I0216 14:48:17.882351 135274496 leveldb.cpp:341] Persisting action (530 bytes) to leveldb took 1963us
I0216 14:48:17.882412 135274496 replica.cpp:712] Persisted action at 5
I0216 14:48:17.882884 137957376 replica.cpp:691] Replica received learned notice for position 5 from @0.0.0.0:0
I0216 14:48:17.883061 137957376 leveldb.cpp:341] Persisting action (532 bytes) to leveldb took 159us
I0216 14:48:17.883086 137957376 replica.cpp:712] Persisted action at 5
I0216 14:48:17.883100 137957376 replica.cpp:697] Replica learned APPEND action at position 5
I0216 14:48:17.883944 136884224 registrar.cpp:484] Successfully updated the 'registry' in 12.240896ms
I0216 14:48:17.884099 135811072 log.cpp:702] Attempting to truncate the log to 5
I0216 14:48:17.884183 137957376 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 6
I0216 14:48:17.884481 136347648 slave.cpp:970] Registered with master master@9.110.49.144:57199; given slave ID bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1
I0216 14:48:17.884461 138493952 master.cpp:4303] Registered slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
I0216 14:48:17.884563 136884224 hierarchical.cpp:471] Added slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000] (allocated: )
I0216 14:48:17.884598 138493952 status_update_manager.cpp:181] Resuming sending status updates
I0216 14:48:17.884815 139030528 replica.cpp:537] Replica received write request for position 6 from (53)@9.110.49.144:57199
I0216 14:48:17.884955 139030528 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 124us
I0216 14:48:17.884979 139030528 replica.cpp:712] Persisted action at 6
I0216 14:48:17.885087 136347648 slave.cpp:1029] Forwarding total oversubscribed resources
I0216 14:48:17.885210 136884224 master.cpp:4644] Received update of slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144) with total oversubscribed resources
I0216 14:48:17.885401 135811072 replica.cpp:691] Replica received learned notice for position 6 from @0.0.0.0:0
I0216 14:48:17.885530 135811072 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 115us
I0216 14:48:17.885571 135811072 leveldb.cpp:399] Deleting ~2 keys from leveldb took 22us
I0216 14:48:17.885571 138493952 hierarchical.cpp:527] Slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 (9.110.49.144) updated with oversubscribed resources (total: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000], allocated: )
I0216 14:48:17.885586 135811072 replica.cpp:712] Persisted action at 6
I0216 14:48:17.885624 135811072 replica.cpp:697] Replica learned TRUNCATE action at position 6
I0216 14:48:17.925969 136884224 master.cpp:4235] Registering slave at slave(1)@9.110.49.144:57199 (9.110.49.144) with id bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2
I0216 14:48:17.926264 135274496 registrar.cpp:439] Applied 1 operations in 94us; attempting to update the 'registry'
I0216 14:48:17.926900 136884224 log.cpp:683] Attempting to append 677 bytes to the log
I0216 14:48:17.927024 138493952 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 7
I0216 14:48:17.927765 138493952 replica.cpp:537] Replica received write request for position 7 from (54)@9.110.49.144:57199
I0216 14:48:17.929934 138493952 leveldb.cpp:341] Persisting action (696 bytes) to leveldb took 2156us
I0216 14:48:17.930001 138493952 replica.cpp:712] Persisted action at 7
I0216 14:48:17.930696 138493952 replica.cpp:691] Replica received learned notice for position 7 from @0.0.0.0:0
I0216 14:48:17.930933 138493952 leveldb.cpp:341] Persisting action (698 bytes) to leveldb took 204us
I0216 14:48:17.930963 138493952 replica.cpp:712] Persisted action at 7
I0216 14:48:17.930977 138493952 replica.cpp:697] Replica learned APPEND action at position 7
I0216 14:48:17.932322 137420800 registrar.cpp:484] Successfully updated the 'registry' in 6.00192ms
I0216 14:48:17.932672 135811072 log.cpp:702] Attempting to truncate the log to 7
I0216 14:48:17.932793 137957376 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 8
I0216 14:48:17.932906 139030528 master.cpp:4303] Registered slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
I0216 14:48:17.932986 137420800 slave.cpp:970] Registered with master master@9.110.49.144:57199; given slave ID bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2
I0216 14:48:17.933056 135274496 hierarchical.cpp:471] Added slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000] (allocated: )
I0216 14:48:17.933195 135811072 status_update_manager.cpp:181] Resuming sending status updates
I0216 14:48:17.933538 136884224 replica.cpp:537] Replica received write request for position 8 from (55)@9.110.49.144:57199
I0216 14:48:17.933676 136884224 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 121us
I0216 14:48:17.933697 136884224 replica.cpp:712] Persisted action at 8
I0216 14:48:17.934065 137420800 slave.cpp:1029] Forwarding total oversubscribed resources
I0216 14:48:17.934103 137957376 replica.cpp:691] Replica received learned notice for position 8 from @0.0.0.0:0
I0216 14:48:17.934258 136884224 master.cpp:4644] Received update of slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144) with total oversubscribed resources
I0216 14:48:17.934262 137957376 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 128us
I0216 14:48:17.934309 137957376 leveldb.cpp:399] Deleting ~2 keys from leveldb took 22us
I0216 14:48:17.934325 137957376 replica.cpp:712] Persisted action at 8
I0216 14:48:17.934340 137957376 replica.cpp:697] Replica learned TRUNCATE action at position 8
I0216 14:48:17.934569 137420800 hierarchical.cpp:527] Slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 (9.110.49.144) updated with oversubscribed resources (total: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000], allocated: )
W0216 14:48:22.089092 135274496 sched.cpp:435] Authentication timed out
I0216 14:48:22.089346 135274496 sched.cpp:393] Failed to authenticate with master master@9.110.49.144:57199: Authentication discarded
I0216 14:48:22.089409 135274496 sched.cpp:324] Authenticating with master master@9.110.49.144:57199
I0216 14:48:22.089431 135274496 sched.cpp:331] Using default CRAM-MD5 authenticatee
I0216 14:48:22.089582 135811072 authenticatee.cpp:121] Creating new client SASL connection
I0216 14:48:22.089874 136884224 master.cpp:5521] Authenticating scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
I0216 14:48:22.090229 137957376 authenticator.cpp:98] Creating new server SASL connection
I0216 14:48:22.090343 137420800 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0216 14:48:22.090389 137420800 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0216 14:48:22.090502 138493952 authenticator.cpp:203] Received SASL authentication start
I0216 14:48:22.090595 138493952 authenticator.cpp:325] Authentication requires more steps
I0216 14:48:22.090697 138493952 authenticatee.cpp:258] Received SASL authentication step
I0216 14:48:22.090849 137420800 authenticator.cpp:231] Received SASL authentication step
I0216 14:48:22.090951 137420800 authenticator.cpp:317] Authentication success
I0216 14:48:22.091037 138493952 authenticatee.cpp:298] Authentication success
I0216 14:48:22.091207 136884224 master.cpp:5551] Successfully authenticated principal 'test-principal' at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
I0216 14:48:22.091363 136347648 sched.cpp:413] Successfully authenticated with master master@9.110.49.144:57199
I0216 14:48:22.091696 137957376 master.cpp:2278] Received SUBSCRIBE call for framework 'Test Framework (Python)' at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
I0216 14:48:22.091780 137957376 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0216 14:48:22.091997 137957376 master.cpp:2349] Subscribing framework Test Framework (Python) with checkpointing enabled and capabilities [ ]
I0216 14:48:22.092391 135811072 hierarchical.cpp:265] Added framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.092584 136884224 sched.cpp:649] Framework registered with bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
Registered with framework ID bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.093969 136347648 master.cpp:5350] Sending 3 offers to framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
Received offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O0 with cpus: 2.0 and mem: 10240.0
Launching task 0 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O0
Launching task 1 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O0
Received offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O1 with cpus: 2.0 and mem: 10240.0
Launching task 2 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O1
Launching task 3 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O1
Received offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O2 with cpus: 2.0 and mem: 10240.0
Launching task 4 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O2
I0216 14:48:22.098026 136347648 master.cpp:3136] Processing ACCEPT call for offers: [ bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O0 ] on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144) for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
I0216 14:48:22.098060 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 0 as user 'qiujian'
I0216 14:48:22.098148 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 1 as user 'qiujian'
I0216 14:48:22.098811 136347648 master.cpp:3136] Processing ACCEPT call for offers: [ bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O1 ] on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144) for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
I0216 14:48:22.098841 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 2 as user 'qiujian'
I0216 14:48:22.098899 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 3 as user 'qiujian'
I0216 14:48:22.099567 136347648 master.cpp:3136] Processing ACCEPT call for offers: [ bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O2 ] on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144) for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
I0216 14:48:22.099593 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 4 as user 'qiujian'
W0216 14:48:22.100142 136347648 validation.cpp:404] 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.
W0216 14:48:22.100172 136347648 validation.cpp:416] 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.
I0216 14:48:22.100311 136347648 master.hpp:176] Adding task 0 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 (9.110.49.144)
I0216 14:48:22.100349 136347648 master.cpp:3621] Launching task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.100525 136884224 slave.cpp:1360] Got assigned task 0 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
W0216 14:48:22.100664 136347648 validation.cpp:404] 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.
W0216 14:48:22.100685 136347648 validation.cpp:416] 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.
I0216 14:48:22.100767 136347648 master.hpp:176] Adding task 1 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 (9.110.49.144)
I0216 14:48:22.100803 136347648 master.cpp:3621] Launching task 1 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144)
W0216 14:48:22.101121 136347648 validation.cpp:404] 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.
W0216 14:48:22.101142 136347648 validation.cpp:416] 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.
I0216 14:48:22.101235 136347648 master.hpp:176] Adding task 2 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 (9.110.49.144)
I0216 14:48:22.101272 136347648 master.cpp:3621] Launching task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.101332 136884224 slave.cpp:1360] Got assigned task 1 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.101418 135811072 slave.cpp:1360] Got assigned task 2 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.101534 136884224 slave.cpp:1479] Launching task 0 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
W0216 14:48:22.101618 136347648 validation.cpp:404] Executor default for task 3 uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0216 14:48:22.101642 136347648 validation.cpp:416] Executor default for task 3 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0216 14:48:22.101730 136347648 master.hpp:176] Adding task 3 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 (9.110.49.144)
I0216 14:48:22.101768 136347648 master.cpp:3621] Launching task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
W0216 14:48:22.102140 136347648 validation.cpp:404] Executor default for task 4 uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0216 14:48:22.102160 136347648 validation.cpp:416] Executor default for task 4 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0216 14:48:22.102179 135811072 slave.cpp:1360] Got assigned task 3 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.102251 136347648 master.hpp:176] Adding task 4 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 (9.110.49.144)
I0216 14:48:22.102283 136347648 master.cpp:3621] Launching task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.102332 135811072 slave.cpp:1479] Launching task 2 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.102411 138493952 slave.cpp:1360] Got assigned task 4 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.103031 138493952 slave.cpp:1479] Launching task 4 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.103332 138493952 paths.cpp:472] Trying to chown '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/47d30577-e035-4556-93dc-16efd22c7a74' to user 'qiujian'
I0216 14:48:22.108590 136884224 paths.cpp:472] Trying to chown '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/90328de4-42b3-4213-a4ec-2a125c558cfa' to user 'qiujian'
I0216 14:48:22.112316 135811072 paths.cpp:472] Trying to chown '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/e6d4d1ff-0a38-42a8-850e-d40636ee55bb' to user 'qiujian'
I0216 14:48:22.114683 138493952 slave.cpp:5281] Launching executor default of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 with resources in work directory '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/47d30577-e035-4556-93dc-16efd22c7a74'
I0216 14:48:22.114984 137420800 containerizer.cpp:649] Starting container '47d30577-e035-4556-93dc-16efd22c7a74' for executor 'default' of framework 'bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000'
I0216 14:48:22.115456 138493952 slave.cpp:1697] Queuing task '4' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.116789 136884224 slave.cpp:5281] Launching executor default of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 with resources in work directory '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/90328de4-42b3-4213-a4ec-2a125c558cfa'
I0216 14:48:22.117841 139030528 containerizer.cpp:649] Starting container '90328de4-42b3-4213-a4ec-2a125c558cfa' for executor 'default' of framework 'bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000'
I0216 14:48:22.118047 137420800 launcher.cpp:132] Forked child with pid '46820' for container '47d30577-e035-4556-93dc-16efd22c7a74'
I0216 14:48:22.118191 137420800 containerizer.cpp:1003] Checkpointing executor's forked pid 46820 to '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0/meta/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/47d30577-e035-4556-93dc-16efd22c7a74/pids/forked.pid'
I0216 14:48:22.118674 136884224 slave.cpp:1697] Queuing task '0' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.118751 136884224 slave.cpp:1479] Launching task 1 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.119292 136884224 slave.cpp:1697] Queuing task '1' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.119415 135811072 slave.cpp:5281] Launching executor default of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 with resources in work directory '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/e6d4d1ff-0a38-42a8-850e-d40636ee55bb'
I0216 14:48:22.119585 137420800 containerizer.cpp:649] Starting container 'e6d4d1ff-0a38-42a8-850e-d40636ee55bb' for executor 'default' of framework 'bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000'
I0216 14:48:22.120576 135811072 slave.cpp:1697] Queuing task '2' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.120816 136347648 launcher.cpp:132] Forked child with pid '46821' for container '90328de4-42b3-4213-a4ec-2a125c558cfa'
I0216 14:48:22.120893 135811072 slave.cpp:1479] Launching task 3 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.120962 136347648 containerizer.cpp:1003] Checkpointing executor's forked pid 46821 to '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2/meta/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/90328de4-42b3-4213-a4ec-2a125c558cfa/pids/forked.pid'
I0216 14:48:22.121409 135811072 slave.cpp:1697] Queuing task '3' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.122586 137420800 launcher.cpp:132] Forked child with pid '46822' for container 'e6d4d1ff-0a38-42a8-850e-d40636ee55bb'
I0216 14:48:22.122828 137420800 containerizer.cpp:1003] Checkpointing executor's forked pid 46822 to '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1/meta/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/e6d4d1ff-0a38-42a8-850e-d40636ee55bb/pids/forked.pid'
Failed to parse the flags: Failed to load unknown flag 'directory'
Failed to parse the flags: Failed to load unknown flag 'directory'
Failed to parse the flags: Failed to load unknown flag 'directory'
I0216 14:48:22.218507 135274496 containerizer.cpp:1443] Executor for container '90328de4-42b3-4213-a4ec-2a125c558cfa' has exited
I0216 14:48:22.218523 137957376 containerizer.cpp:1443] Executor for container '47d30577-e035-4556-93dc-16efd22c7a74' has exited
I0216 14:48:22.218564 135274496 containerizer.cpp:1227] Destroying container '90328de4-42b3-4213-a4ec-2a125c558cfa'
I0216 14:48:22.218578 137957376 containerizer.cpp:1227] Destroying container '47d30577-e035-4556-93dc-16efd22c7a74'
I0216 14:48:22.218655 136347648 containerizer.cpp:1443] Executor for container 'e6d4d1ff-0a38-42a8-850e-d40636ee55bb' has exited
I0216 14:48:22.218679 136347648 containerizer.cpp:1227] Destroying container 'e6d4d1ff-0a38-42a8-850e-d40636ee55bb'
I0216 14:48:22.234441 136884224 provisioner.cpp:306] Ignoring destroy request for unknown container 90328de4-42b3-4213-a4ec-2a125c558cfa
I0216 14:48:22.234467 137957376 provisioner.cpp:306] Ignoring destroy request for unknown container 47d30577-e035-4556-93dc-16efd22c7a74
I0216 14:48:22.234486 137420800 provisioner.cpp:306] Ignoring destroy request for unknown container e6d4d1ff-0a38-42a8-850e-d40636ee55bb
I0216 14:48:22.234663 139030528 slave.cpp:3816] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 exited with status 1
I0216 14:48:22.234663 137420800 slave.cpp:3816] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 exited with status 1
I0216 14:48:22.234678 137957376 slave.cpp:3816] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 exited with status 1
I0216 14:48:22.234769 139030528 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
W0216 14:48:22.234916 135274496 containerizer.cpp:1119] Ignoring update for unknown container: 47d30577-e035-4556-93dc-16efd22c7a74
I0216 14:48:22.235157 135811072 master.cpp:4891] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144): exited with status 1
I0216 14:48:22.235188 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.235198 135811072 master.cpp:6540] Removing executor 'default' with resources of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.235726 135274496 status_update_manager.cpp:824] Checkpointing UPDATE for status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.237979 136347648 slave.cpp:3353] Forwarding the update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 to master@9.110.49.144:57199
I0216 14:48:22.238145 135811072 master.cpp:4789] Status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.238205 135811072 master.cpp:4837] Forwarding status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.238288 135811072 master.cpp:6445] Updating the state of task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
Task 4 is in state TASK_FAILED
The update data did not match!
Expected: 'data with a \x00 byte'
Actual: ''
Failed to call scheduler's statusUpdate
I0216 14:48:22.241416 137957376 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
W0216 14:48:22.241564 135274496 containerizer.cpp:1119] Ignoring update for unknown container: e6d4d1ff-0a38-42a8-850e-d40636ee55bb
I0216 14:48:22.241678 137957376 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
W0216 14:48:22.241750 139030528 containerizer.cpp:1119] Ignoring update for unknown container: e6d4d1ff-0a38-42a8-850e-d40636ee55bb
I0216 14:48:22.241940 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.241960 136347648 master.cpp:4891] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144): exited with status 1
I0216 14:48:22.241996 136347648 master.cpp:6540] Removing executor 'default' with resources of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.242317 135274496 status_update_manager.cpp:824] Checkpointing UPDATE for status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.242673 135811072 slave.cpp:3353] Forwarding the update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 to master@9.110.49.144:57199
I0216 14:48:22.242723 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.242826 136347648 master.cpp:4789] Status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.242862 136347648 master.cpp:4837] Forwarding status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.242959 136347648 master.cpp:6445] Updating the state of task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
I0216 14:48:22.243000 135274496 status_update_manager.cpp:824] Checkpointing UPDATE for status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.243325 138493952 slave.cpp:3353] Forwarding the update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 to master@9.110.49.144:57199
I0216 14:48:22.243482 135811072 master.cpp:4789] Status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.243510 135811072 master.cpp:4837] Forwarding status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.243562 135811072 master.cpp:6445] Updating the state of task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
I0216 14:48:22.245151 137420800 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
W0216 14:48:22.245280 139030528 containerizer.cpp:1119] Ignoring update for unknown container: 90328de4-42b3-4213-a4ec-2a125c558cfa
I0216 14:48:22.245340 137420800 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 96bebf09-9ca8-4206-a2df-dcf76fa73799) for task 1 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
W0216 14:48:22.245426 137957376 containerizer.cpp:1119] Ignoring update for unknown container: 90328de4-42b3-4213-a4ec-2a125c558cfa
I0216 14:48:22.245648 138493952 master.cpp:4891] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144): exited with status 1
I0216 14:48:22.245681 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.245692 138493952 master.cpp:6540] Removing executor 'default' with resources of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.245982 135274496 status_update_manager.cpp:824] Checkpointing UPDATE for status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.246345 137957376 slave.cpp:3353] Forwarding the update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 to master@9.110.49.144:57199
I0216 14:48:22.246383 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 96bebf09-9ca8-4206-a2df-dcf76fa73799) for task 1 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.246520 138493952 master.cpp:4789] Status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.246548 138493952 master.cpp:4837] Forwarding status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
../../src/tests/script.cpp:81: Failure
Failed
python_framework_test.sh terminated with signal Abort trap: 6
[ FAILED ] ExamplesTest.PythonFramework (7101 ms)
[----------] 1 test from ExamplesTest (7101 ms total)
[----------] Global test environment tear-down
[==========] 1 test from 1 test case ran. (7115 ms total)
[ PASSED ] 0 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ExamplesTest.PythonFramework
{code}
was:
Using temporary directory '/tmp/ExamplesTest_PythonFramework_ZvbuJl'
Enabling authentication for the framework
I0216 14:48:17.029909 2007810816 leveldb.cpp:174] Opened db in 3570us
I0216 14:48:17.030324 2007810816 leveldb.cpp:181] Compacted db in 383us
I0216 14:48:17.030375 2007810816 leveldb.cpp:196] Created db iterator in 24us
I0216 14:48:17.030388 2007810816 leveldb.cpp:202] Seeked to beginning of db in 8us
I0216 14:48:17.030411 2007810816 leveldb.cpp:271] Iterated through 0 keys in the db in 6us
I0216 14:48:17.030468 2007810816 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0216 14:48:17.031262 138493952 recover.cpp:447] Starting replica recovery
I0216 14:48:17.031478 138493952 recover.cpp:473] Replica is in EMPTY status
I0216 14:48:17.031772 2007810816 local.cpp:239] Using 'local' authorizer
I0216 14:48:17.032449 135274496 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (4)@9.110.49.144:57199
I0216 14:48:17.032662 137420800 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0216 14:48:17.032914 137957376 recover.cpp:564] Updating replica status to STARTING
I0216 14:48:17.033349 136347648 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 316us
I0216 14:48:17.033375 136347648 replica.cpp:320] Persisted replica status to STARTING
I0216 14:48:17.033488 139030528 recover.cpp:473] Replica is in STARTING status
I0216 14:48:17.034047 135811072 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (5)@9.110.49.144:57199
I0216 14:48:17.034220 139030528 recover.cpp:193] Received a recover response from a replica in STARTING status
I0216 14:48:17.034494 135811072 recover.cpp:564] Updating replica status to VOTING
I0216 14:48:17.034744 136884224 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 135us
I0216 14:48:17.034764 136884224 replica.cpp:320] Persisted replica status to VOTING
I0216 14:48:17.034814 137957376 recover.cpp:578] Successfully joined the Paxos group
I0216 14:48:17.034934 137957376 recover.cpp:462] Recover process terminated
I0216 14:48:17.069952 137957376 master.cpp:374] Master bd54ad91-3083-42a3-a39f-0c7e2e08b0a0 (9.110.49.144) started on 9.110.49.144:57199
I0216 14:48:17.070006 137957376 master.cpp:376] Flags at startup: --acls="permissive: false
register_frameworks {
principals {
type: SOME
values: "test-principal"
}
roles {
type: SOME
values: "*"
}
}
run_tasks {
principals {
type: SOME
values: "test-principal"
}
users {
type: SOME
values: "qiujian"
}
}
" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="true" --authenticate_http="false" --authenticate_slaves="false" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ExamplesTest_PythonFramework_ZvbuJl/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="5secs" --registry_strict="false" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/Users/qiujian/Documents/mesos/src/webui" --work_dir="/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ" --zk_session_timeout="10secs"
I0216 14:48:17.070543 137957376 master.cpp:421] Master only allowing authenticated frameworks to register
I0216 14:48:17.070564 137957376 master.cpp:428] Master allowing unauthenticated slaves to register
I0216 14:48:17.070576 137957376 credentials.hpp:35] Loading credentials for authentication from '/tmp/ExamplesTest_PythonFramework_ZvbuJl/credentials'
W0216 14:48:17.070650 137957376 credentials.hpp:50] Permissions on credentials file '/tmp/ExamplesTest_PythonFramework_ZvbuJl/credentials' are too open. It is recommended that your credentials file is NOT accessible by others.
I0216 14:48:17.070757 137957376 master.cpp:466] Using default 'crammd5' authenticator
I0216 14:48:17.070843 137957376 authenticator.cpp:518] Initializing server SASL
I0216 14:48:17.071966 2007810816 containerizer.cpp:143] Using isolation: filesystem/posix,posix/cpu,posix/mem
I0216 14:48:17.074555 136347648 slave.cpp:192] Slave started on 1)@9.110.49.144:57199
I0216 14:48:17.074591 136347648 slave.cpp:193] Flags at startup: --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5" --container_disk_watch_interval="15secs" --containerizers="mesos" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="https://auth.docker.io" --docker_kill_orphans="true" --docker_puller_timeout="60" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="filesystem/posix,posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/Users/qiujian/Documents/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --resources="cpus:2;mem:10240" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --version="false" --work_dir="/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0"
I0216 14:48:17.075846 2007810816 containerizer.cpp:143] Using isolation: filesystem/posix,posix/cpu,posix/mem
I0216 14:48:17.075814 136347648 slave.cpp:463] Slave resources: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
I0216 14:48:17.075888 136347648 slave.cpp:471] Slave attributes: [ ]
I0216 14:48:17.075906 136347648 slave.cpp:476] Slave hostname: 9.110.49.144
I0216 14:48:17.077810 135274496 slave.cpp:192] Slave started on 2)@9.110.49.144:57199
I0216 14:48:17.077849 135274496 slave.cpp:193] Flags at startup: --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5" --container_disk_watch_interval="15secs" --containerizers="mesos" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="https://auth.docker.io" --docker_kill_orphans="true" --docker_puller_timeout="60" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="filesystem/posix,posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/Users/qiujian/Documents/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --resources="cpus:2;mem:10240" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --version="false" --work_dir="/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1"
I0216 14:48:17.078251 137420800 state.cpp:58] Recovering state from '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0/meta'
I0216 14:48:17.078466 135811072 status_update_manager.cpp:200] Recovering status update manager
I0216 14:48:17.078577 139030528 containerizer.cpp:390] Recovering containerizer
I0216 14:48:17.078850 135274496 slave.cpp:463] Slave resources: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
I0216 14:48:17.078938 135274496 slave.cpp:471] Slave attributes: [ ]
I0216 14:48:17.078953 135274496 slave.cpp:476] Slave hostname: 9.110.49.144
I0216 14:48:17.079116 2007810816 containerizer.cpp:143] Using isolation: filesystem/posix,posix/cpu,posix/mem
I0216 14:48:17.079588 135811072 state.cpp:58] Recovering state from '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1/meta'
I0216 14:48:17.079758 137420800 status_update_manager.cpp:200] Recovering status update manager
I0216 14:48:17.079970 136884224 provisioner.cpp:245] Provisioner recovery complete
I0216 14:48:17.079979 135811072 containerizer.cpp:390] Recovering containerizer
I0216 14:48:17.080253 139030528 slave.cpp:4495] Finished recovery
I0216 14:48:17.081012 137420800 provisioner.cpp:245] Provisioner recovery complete
I0216 14:48:17.081208 136347648 status_update_manager.cpp:174] Pausing sending status updates
I0216 14:48:17.081240 139030528 slave.cpp:795] New master detected at master@9.110.49.144:57199
I0216 14:48:17.081372 136884224 slave.cpp:4495] Finished recovery
I0216 14:48:17.081378 139030528 slave.cpp:820] No credentials provided. Attempting to register without authentication
I0216 14:48:17.081450 139030528 slave.cpp:831] Detecting new master
I0216 14:48:17.081544 135274496 slave.cpp:192] Slave started on 3)@9.110.49.144:57199
I0216 14:48:17.081575 135274496 slave.cpp:193] Flags at startup: --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5" --container_disk_watch_interval="15secs" --containerizers="mesos" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="https://auth.docker.io" --docker_kill_orphans="true" --docker_puller_timeout="60" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="filesystem/posix,posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/Users/qiujian/Documents/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --resources="cpus:2;mem:10240" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --version="false" --work_dir="/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2"
I0216 14:48:17.081957 137420800 status_update_manager.cpp:174] Pausing sending status updates
I0216 14:48:17.081981 138493952 slave.cpp:795] New master detected at master@9.110.49.144:57199
I0216 14:48:17.082057 138493952 slave.cpp:820] No credentials provided. Attempting to register without authentication
I0216 14:48:17.082092 138493952 slave.cpp:831] Detecting new master
I0216 14:48:17.082464 2007810816 sched.cpp:164] Version: 0.27.0
I0216 14:48:17.082598 135274496 slave.cpp:463] Slave resources: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
I0216 14:48:17.082653 135274496 slave.cpp:471] Slave attributes: [ ]
I0216 14:48:17.082664 135274496 slave.cpp:476] Slave hostname: 9.110.49.144
I0216 14:48:17.082993 137420800 state.cpp:58] Recovering state from '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2/meta'
I0216 14:48:17.083070 136884224 status_update_manager.cpp:200] Recovering status update manager
I0216 14:48:17.083226 136884224 containerizer.cpp:390] Recovering containerizer
I0216 14:48:17.083827 136884224 sched.cpp:268] New master detected at master@9.110.49.144:57199
I0216 14:48:17.083879 136884224 sched.cpp:324] Authenticating with master master@9.110.49.144:57199
I0216 14:48:17.083905 136884224 sched.cpp:331] Using default CRAM-MD5 authenticatee
I0216 14:48:17.083920 137420800 provisioner.cpp:245] Provisioner recovery complete
I0216 14:48:17.084105 138493952 slave.cpp:4495] Finished recovery
I0216 14:48:17.084203 135811072 authenticatee.cpp:97] Initializing client SASL
I0216 14:48:17.084527 139030528 status_update_manager.cpp:174] Pausing sending status updates
I0216 14:48:17.084537 138493952 slave.cpp:795] New master detected at master@9.110.49.144:57199
I0216 14:48:17.084585 138493952 slave.cpp:820] No credentials provided. Attempting to register without authentication
I0216 14:48:17.084607 138493952 slave.cpp:831] Detecting new master
I0216 14:48:17.085896 137957376 master.cpp:569] Authorization enabled
I0216 14:48:17.087232 135811072 authenticatee.cpp:121] Creating new client SASL connection
I0216 14:48:17.087606 135811072 master.cpp:1710] The newly elected leader is master@9.110.49.144:57199 with id bd54ad91-3083-42a3-a39f-0c7e2e08b0a0
I0216 14:48:17.087625 135811072 master.cpp:1723] Elected as the leading master!
I0216 14:48:17.087635 135811072 master.cpp:1468] Recovering from registrar
I0216 14:48:17.087730 139030528 registrar.cpp:307] Recovering registrar
I0216 14:48:17.088078 136347648 log.cpp:659] Attempting to start the writer
I0216 14:48:17.089102 135274496 replica.cpp:493] Replica received implicit promise request from (45)@9.110.49.144:57199 with proposal 1
I0216 14:48:17.089292 135274496 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 179us
I0216 14:48:17.089316 135274496 replica.cpp:342] Persisted promised to 1
I0216 14:48:17.089699 135811072 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0216 14:48:17.090502 137957376 replica.cpp:388] Replica received explicit promise request from (46)@9.110.49.144:57199 for position 0 with proposal 2
I0216 14:48:17.090670 137957376 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 148us
I0216 14:48:17.090692 137957376 replica.cpp:712] Persisted action at 0
I0216 14:48:17.091337 138493952 replica.cpp:537] Replica received write request for position 0 from (47)@9.110.49.144:57199
I0216 14:48:17.091375 138493952 leveldb.cpp:436] Reading position from leveldb took 21us
I0216 14:48:17.091470 138493952 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 85us
I0216 14:48:17.091492 138493952 replica.cpp:712] Persisted action at 0
I0216 14:48:17.091790 137957376 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0216 14:48:17.091884 137957376 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 88us
I0216 14:48:17.091910 137957376 replica.cpp:712] Persisted action at 0
I0216 14:48:17.091919 137957376 replica.cpp:697] Replica learned NOP action at position 0
I0216 14:48:17.092175 136884224 log.cpp:675] Writer started with ending position 0
I0216 14:48:17.092670 136884224 leveldb.cpp:436] Reading position from leveldb took 21us
I0216 14:48:17.098273 139030528 registrar.cpp:340] Successfully fetched the registry (0B) in 10.49088ms
I0216 14:48:17.098387 139030528 registrar.cpp:439] Applied 1 operations in 30us; attempting to update the 'registry'
I0216 14:48:17.103885 135811072 log.cpp:683] Attempting to append 176 bytes to the log
I0216 14:48:17.103982 139030528 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0216 14:48:17.104568 138493952 replica.cpp:537] Replica received write request for position 1 from (48)@9.110.49.144:57199
I0216 14:48:17.104753 138493952 leveldb.cpp:341] Persisting action (195 bytes) to leveldb took 168us
I0216 14:48:17.104778 138493952 replica.cpp:712] Persisted action at 1
I0216 14:48:17.105162 136884224 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0216 14:48:17.105304 136884224 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 114us
I0216 14:48:17.105327 136884224 replica.cpp:712] Persisted action at 1
I0216 14:48:17.105337 136884224 replica.cpp:697] Replica learned APPEND action at position 1
I0216 14:48:17.105900 139030528 registrar.cpp:484] Successfully updated the 'registry' in 7.475968ms
I0216 14:48:17.105955 139030528 registrar.cpp:370] Successfully recovered registrar
I0216 14:48:17.106034 137420800 log.cpp:702] Attempting to truncate the log to 1
I0216 14:48:17.106153 135274496 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0216 14:48:17.106171 136884224 master.cpp:1520] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I0216 14:48:17.106647 136884224 replica.cpp:537] Replica received write request for position 2 from (49)@9.110.49.144:57199
I0216 14:48:17.106855 136884224 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 195us
I0216 14:48:17.106879 136884224 replica.cpp:712] Persisted action at 2
I0216 14:48:17.107234 138493952 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0216 14:48:17.107352 138493952 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 105us
I0216 14:48:17.107383 138493952 leveldb.cpp:399] Deleting ~1 keys from leveldb took 15us
I0216 14:48:17.107395 138493952 replica.cpp:712] Persisted action at 2
I0216 14:48:17.107405 138493952 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0216 14:48:17.482161 139030528 master.cpp:4235] Registering slave at slave(2)@9.110.49.144:57199 (9.110.49.144) with id bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0
I0216 14:48:17.482571 138493952 registrar.cpp:439] Applied 1 operations in 87us; attempting to update the 'registry'
I0216 14:48:17.482996 136884224 log.cpp:683] Attempting to append 345 bytes to the log
I0216 14:48:17.483249 136347648 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I0216 14:48:17.484277 137957376 replica.cpp:537] Replica received write request for position 3 from (50)@9.110.49.144:57199
I0216 14:48:17.486208 137957376 leveldb.cpp:341] Persisting action (364 bytes) to leveldb took 1903us
I0216 14:48:17.486256 137957376 replica.cpp:712] Persisted action at 3
I0216 14:48:17.486912 139030528 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
I0216 14:48:17.487145 139030528 leveldb.cpp:341] Persisting action (366 bytes) to leveldb took 213us
I0216 14:48:17.487197 139030528 replica.cpp:712] Persisted action at 3
I0216 14:48:17.487217 139030528 replica.cpp:697] Replica learned APPEND action at position 3
I0216 14:48:17.488268 138493952 registrar.cpp:484] Successfully updated the 'registry' in 5.644032ms
I0216 14:48:17.488488 137420800 log.cpp:702] Attempting to truncate the log to 3
I0216 14:48:17.488611 135811072 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I0216 14:48:17.489032 136884224 slave.cpp:970] Registered with master master@9.110.49.144:57199; given slave ID bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0
I0216 14:48:17.489004 135274496 master.cpp:4303] Registered slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
I0216 14:48:17.489162 139030528 hierarchical.cpp:471] Added slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000] (allocated: )
I0216 14:48:17.489202 137420800 status_update_manager.cpp:181] Resuming sending status updates
I0216 14:48:17.489259 138493952 replica.cpp:537] Replica received write request for position 4 from (51)@9.110.49.144:57199
I0216 14:48:17.489431 138493952 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 145us
I0216 14:48:17.489464 138493952 replica.cpp:712] Persisted action at 4
I0216 14:48:17.489720 136884224 slave.cpp:1029] Forwarding total oversubscribed resources
I0216 14:48:17.489950 138493952 master.cpp:4644] Received update of slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144) with total oversubscribed resources
I0216 14:48:17.489982 136884224 replica.cpp:691] Replica received learned notice for position 4 from @0.0.0.0:0
I0216 14:48:17.490124 136884224 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 134us
I0216 14:48:17.490180 136884224 leveldb.cpp:399] Deleting ~2 keys from leveldb took 32us
I0216 14:48:17.490203 136884224 replica.cpp:712] Persisted action at 4
I0216 14:48:17.490222 136884224 replica.cpp:697] Replica learned TRUNCATE action at position 4
I0216 14:48:17.490353 139030528 hierarchical.cpp:527] Slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 (9.110.49.144) updated with oversubscribed resources (total: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000], allocated: )
I0216 14:48:17.871284 137957376 master.cpp:4235] Registering slave at slave(3)@9.110.49.144:57199 (9.110.49.144) with id bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1
I0216 14:48:17.871639 135274496 registrar.cpp:439] Applied 1 operations in 86us; attempting to update the 'registry'
I0216 14:48:17.879560 137957376 log.cpp:683] Attempting to append 511 bytes to the log
I0216 14:48:17.879673 138493952 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 5
I0216 14:48:17.880383 135274496 replica.cpp:537] Replica received write request for position 5 from (52)@9.110.49.144:57199
I0216 14:48:17.882351 135274496 leveldb.cpp:341] Persisting action (530 bytes) to leveldb took 1963us
I0216 14:48:17.882412 135274496 replica.cpp:712] Persisted action at 5
I0216 14:48:17.882884 137957376 replica.cpp:691] Replica received learned notice for position 5 from @0.0.0.0:0
I0216 14:48:17.883061 137957376 leveldb.cpp:341] Persisting action (532 bytes) to leveldb took 159us
I0216 14:48:17.883086 137957376 replica.cpp:712] Persisted action at 5
I0216 14:48:17.883100 137957376 replica.cpp:697] Replica learned APPEND action at position 5
I0216 14:48:17.883944 136884224 registrar.cpp:484] Successfully updated the 'registry' in 12.240896ms
I0216 14:48:17.884099 135811072 log.cpp:702] Attempting to truncate the log to 5
I0216 14:48:17.884183 137957376 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 6
I0216 14:48:17.884481 136347648 slave.cpp:970] Registered with master master@9.110.49.144:57199; given slave ID bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1
I0216 14:48:17.884461 138493952 master.cpp:4303] Registered slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
I0216 14:48:17.884563 136884224 hierarchical.cpp:471] Added slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000] (allocated: )
I0216 14:48:17.884598 138493952 status_update_manager.cpp:181] Resuming sending status updates
I0216 14:48:17.884815 139030528 replica.cpp:537] Replica received write request for position 6 from (53)@9.110.49.144:57199
I0216 14:48:17.884955 139030528 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 124us
I0216 14:48:17.884979 139030528 replica.cpp:712] Persisted action at 6
I0216 14:48:17.885087 136347648 slave.cpp:1029] Forwarding total oversubscribed resources
I0216 14:48:17.885210 136884224 master.cpp:4644] Received update of slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144) with total oversubscribed resources
I0216 14:48:17.885401 135811072 replica.cpp:691] Replica received learned notice for position 6 from @0.0.0.0:0
I0216 14:48:17.885530 135811072 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 115us
I0216 14:48:17.885571 135811072 leveldb.cpp:399] Deleting ~2 keys from leveldb took 22us
I0216 14:48:17.885571 138493952 hierarchical.cpp:527] Slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 (9.110.49.144) updated with oversubscribed resources (total: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000], allocated: )
I0216 14:48:17.885586 135811072 replica.cpp:712] Persisted action at 6
I0216 14:48:17.885624 135811072 replica.cpp:697] Replica learned TRUNCATE action at position 6
I0216 14:48:17.925969 136884224 master.cpp:4235] Registering slave at slave(1)@9.110.49.144:57199 (9.110.49.144) with id bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2
I0216 14:48:17.926264 135274496 registrar.cpp:439] Applied 1 operations in 94us; attempting to update the 'registry'
I0216 14:48:17.926900 136884224 log.cpp:683] Attempting to append 677 bytes to the log
I0216 14:48:17.927024 138493952 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 7
I0216 14:48:17.927765 138493952 replica.cpp:537] Replica received write request for position 7 from (54)@9.110.49.144:57199
I0216 14:48:17.929934 138493952 leveldb.cpp:341] Persisting action (696 bytes) to leveldb took 2156us
I0216 14:48:17.930001 138493952 replica.cpp:712] Persisted action at 7
I0216 14:48:17.930696 138493952 replica.cpp:691] Replica received learned notice for position 7 from @0.0.0.0:0
I0216 14:48:17.930933 138493952 leveldb.cpp:341] Persisting action (698 bytes) to leveldb took 204us
I0216 14:48:17.930963 138493952 replica.cpp:712] Persisted action at 7
I0216 14:48:17.930977 138493952 replica.cpp:697] Replica learned APPEND action at position 7
I0216 14:48:17.932322 137420800 registrar.cpp:484] Successfully updated the 'registry' in 6.00192ms
I0216 14:48:17.932672 135811072 log.cpp:702] Attempting to truncate the log to 7
I0216 14:48:17.932793 137957376 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 8
I0216 14:48:17.932906 139030528 master.cpp:4303] Registered slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
I0216 14:48:17.932986 137420800 slave.cpp:970] Registered with master master@9.110.49.144:57199; given slave ID bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2
I0216 14:48:17.933056 135274496 hierarchical.cpp:471] Added slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000] (allocated: )
I0216 14:48:17.933195 135811072 status_update_manager.cpp:181] Resuming sending status updates
I0216 14:48:17.933538 136884224 replica.cpp:537] Replica received write request for position 8 from (55)@9.110.49.144:57199
I0216 14:48:17.933676 136884224 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 121us
I0216 14:48:17.933697 136884224 replica.cpp:712] Persisted action at 8
I0216 14:48:17.934065 137420800 slave.cpp:1029] Forwarding total oversubscribed resources
I0216 14:48:17.934103 137957376 replica.cpp:691] Replica received learned notice for position 8 from @0.0.0.0:0
I0216 14:48:17.934258 136884224 master.cpp:4644] Received update of slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144) with total oversubscribed resources
I0216 14:48:17.934262 137957376 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 128us
I0216 14:48:17.934309 137957376 leveldb.cpp:399] Deleting ~2 keys from leveldb took 22us
I0216 14:48:17.934325 137957376 replica.cpp:712] Persisted action at 8
I0216 14:48:17.934340 137957376 replica.cpp:697] Replica learned TRUNCATE action at position 8
I0216 14:48:17.934569 137420800 hierarchical.cpp:527] Slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 (9.110.49.144) updated with oversubscribed resources (total: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000], allocated: )
W0216 14:48:22.089092 135274496 sched.cpp:435] Authentication timed out
I0216 14:48:22.089346 135274496 sched.cpp:393] Failed to authenticate with master master@9.110.49.144:57199: Authentication discarded
I0216 14:48:22.089409 135274496 sched.cpp:324] Authenticating with master master@9.110.49.144:57199
I0216 14:48:22.089431 135274496 sched.cpp:331] Using default CRAM-MD5 authenticatee
I0216 14:48:22.089582 135811072 authenticatee.cpp:121] Creating new client SASL connection
I0216 14:48:22.089874 136884224 master.cpp:5521] Authenticating scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
I0216 14:48:22.090229 137957376 authenticator.cpp:98] Creating new server SASL connection
I0216 14:48:22.090343 137420800 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0216 14:48:22.090389 137420800 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0216 14:48:22.090502 138493952 authenticator.cpp:203] Received SASL authentication start
I0216 14:48:22.090595 138493952 authenticator.cpp:325] Authentication requires more steps
I0216 14:48:22.090697 138493952 authenticatee.cpp:258] Received SASL authentication step
I0216 14:48:22.090849 137420800 authenticator.cpp:231] Received SASL authentication step
I0216 14:48:22.090951 137420800 authenticator.cpp:317] Authentication success
I0216 14:48:22.091037 138493952 authenticatee.cpp:298] Authentication success
I0216 14:48:22.091207 136884224 master.cpp:5551] Successfully authenticated principal 'test-principal' at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
I0216 14:48:22.091363 136347648 sched.cpp:413] Successfully authenticated with master master@9.110.49.144:57199
I0216 14:48:22.091696 137957376 master.cpp:2278] Received SUBSCRIBE call for framework 'Test Framework (Python)' at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
I0216 14:48:22.091780 137957376 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0216 14:48:22.091997 137957376 master.cpp:2349] Subscribing framework Test Framework (Python) with checkpointing enabled and capabilities [ ]
I0216 14:48:22.092391 135811072 hierarchical.cpp:265] Added framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.092584 136884224 sched.cpp:649] Framework registered with bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
Registered with framework ID bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.093969 136347648 master.cpp:5350] Sending 3 offers to framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
Received offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O0 with cpus: 2.0 and mem: 10240.0
Launching task 0 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O0
Launching task 1 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O0
Received offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O1 with cpus: 2.0 and mem: 10240.0
Launching task 2 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O1
Launching task 3 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O1
Received offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O2 with cpus: 2.0 and mem: 10240.0
Launching task 4 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O2
I0216 14:48:22.098026 136347648 master.cpp:3136] Processing ACCEPT call for offers: [ bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O0 ] on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144) for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
I0216 14:48:22.098060 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 0 as user 'qiujian'
I0216 14:48:22.098148 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 1 as user 'qiujian'
I0216 14:48:22.098811 136347648 master.cpp:3136] Processing ACCEPT call for offers: [ bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O1 ] on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144) for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
I0216 14:48:22.098841 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 2 as user 'qiujian'
I0216 14:48:22.098899 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 3 as user 'qiujian'
I0216 14:48:22.099567 136347648 master.cpp:3136] Processing ACCEPT call for offers: [ bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O2 ] on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144) for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
I0216 14:48:22.099593 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 4 as user 'qiujian'
W0216 14:48:22.100142 136347648 validation.cpp:404] 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.
W0216 14:48:22.100172 136347648 validation.cpp:416] 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.
I0216 14:48:22.100311 136347648 master.hpp:176] Adding task 0 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 (9.110.49.144)
I0216 14:48:22.100349 136347648 master.cpp:3621] Launching task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.100525 136884224 slave.cpp:1360] Got assigned task 0 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
W0216 14:48:22.100664 136347648 validation.cpp:404] 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.
W0216 14:48:22.100685 136347648 validation.cpp:416] 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.
I0216 14:48:22.100767 136347648 master.hpp:176] Adding task 1 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 (9.110.49.144)
I0216 14:48:22.100803 136347648 master.cpp:3621] Launching task 1 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144)
W0216 14:48:22.101121 136347648 validation.cpp:404] 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.
W0216 14:48:22.101142 136347648 validation.cpp:416] 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.
I0216 14:48:22.101235 136347648 master.hpp:176] Adding task 2 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 (9.110.49.144)
I0216 14:48:22.101272 136347648 master.cpp:3621] Launching task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.101332 136884224 slave.cpp:1360] Got assigned task 1 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.101418 135811072 slave.cpp:1360] Got assigned task 2 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.101534 136884224 slave.cpp:1479] Launching task 0 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
W0216 14:48:22.101618 136347648 validation.cpp:404] Executor default for task 3 uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0216 14:48:22.101642 136347648 validation.cpp:416] Executor default for task 3 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0216 14:48:22.101730 136347648 master.hpp:176] Adding task 3 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 (9.110.49.144)
I0216 14:48:22.101768 136347648 master.cpp:3621] Launching task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
W0216 14:48:22.102140 136347648 validation.cpp:404] Executor default for task 4 uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0216 14:48:22.102160 136347648 validation.cpp:416] Executor default for task 4 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0216 14:48:22.102179 135811072 slave.cpp:1360] Got assigned task 3 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.102251 136347648 master.hpp:176] Adding task 4 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 (9.110.49.144)
I0216 14:48:22.102283 136347648 master.cpp:3621] Launching task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.102332 135811072 slave.cpp:1479] Launching task 2 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.102411 138493952 slave.cpp:1360] Got assigned task 4 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.103031 138493952 slave.cpp:1479] Launching task 4 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.103332 138493952 paths.cpp:472] Trying to chown '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/47d30577-e035-4556-93dc-16efd22c7a74' to user 'qiujian'
I0216 14:48:22.108590 136884224 paths.cpp:472] Trying to chown '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/90328de4-42b3-4213-a4ec-2a125c558cfa' to user 'qiujian'
I0216 14:48:22.112316 135811072 paths.cpp:472] Trying to chown '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/e6d4d1ff-0a38-42a8-850e-d40636ee55bb' to user 'qiujian'
I0216 14:48:22.114683 138493952 slave.cpp:5281] Launching executor default of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 with resources in work directory '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/47d30577-e035-4556-93dc-16efd22c7a74'
I0216 14:48:22.114984 137420800 containerizer.cpp:649] Starting container '47d30577-e035-4556-93dc-16efd22c7a74' for executor 'default' of framework 'bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000'
I0216 14:48:22.115456 138493952 slave.cpp:1697] Queuing task '4' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.116789 136884224 slave.cpp:5281] Launching executor default of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 with resources in work directory '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/90328de4-42b3-4213-a4ec-2a125c558cfa'
I0216 14:48:22.117841 139030528 containerizer.cpp:649] Starting container '90328de4-42b3-4213-a4ec-2a125c558cfa' for executor 'default' of framework 'bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000'
I0216 14:48:22.118047 137420800 launcher.cpp:132] Forked child with pid '46820' for container '47d30577-e035-4556-93dc-16efd22c7a74'
I0216 14:48:22.118191 137420800 containerizer.cpp:1003] Checkpointing executor's forked pid 46820 to '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0/meta/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/47d30577-e035-4556-93dc-16efd22c7a74/pids/forked.pid'
I0216 14:48:22.118674 136884224 slave.cpp:1697] Queuing task '0' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.118751 136884224 slave.cpp:1479] Launching task 1 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.119292 136884224 slave.cpp:1697] Queuing task '1' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.119415 135811072 slave.cpp:5281] Launching executor default of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 with resources in work directory '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/e6d4d1ff-0a38-42a8-850e-d40636ee55bb'
I0216 14:48:22.119585 137420800 containerizer.cpp:649] Starting container 'e6d4d1ff-0a38-42a8-850e-d40636ee55bb' for executor 'default' of framework 'bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000'
I0216 14:48:22.120576 135811072 slave.cpp:1697] Queuing task '2' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.120816 136347648 launcher.cpp:132] Forked child with pid '46821' for container '90328de4-42b3-4213-a4ec-2a125c558cfa'
I0216 14:48:22.120893 135811072 slave.cpp:1479] Launching task 3 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.120962 136347648 containerizer.cpp:1003] Checkpointing executor's forked pid 46821 to '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2/meta/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/90328de4-42b3-4213-a4ec-2a125c558cfa/pids/forked.pid'
I0216 14:48:22.121409 135811072 slave.cpp:1697] Queuing task '3' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.122586 137420800 launcher.cpp:132] Forked child with pid '46822' for container 'e6d4d1ff-0a38-42a8-850e-d40636ee55bb'
I0216 14:48:22.122828 137420800 containerizer.cpp:1003] Checkpointing executor's forked pid 46822 to '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1/meta/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/e6d4d1ff-0a38-42a8-850e-d40636ee55bb/pids/forked.pid'
Failed to parse the flags: Failed to load unknown flag 'directory'
Failed to parse the flags: Failed to load unknown flag 'directory'
Failed to parse the flags: Failed to load unknown flag 'directory'
I0216 14:48:22.218507 135274496 containerizer.cpp:1443] Executor for container '90328de4-42b3-4213-a4ec-2a125c558cfa' has exited
I0216 14:48:22.218523 137957376 containerizer.cpp:1443] Executor for container '47d30577-e035-4556-93dc-16efd22c7a74' has exited
I0216 14:48:22.218564 135274496 containerizer.cpp:1227] Destroying container '90328de4-42b3-4213-a4ec-2a125c558cfa'
I0216 14:48:22.218578 137957376 containerizer.cpp:1227] Destroying container '47d30577-e035-4556-93dc-16efd22c7a74'
I0216 14:48:22.218655 136347648 containerizer.cpp:1443] Executor for container 'e6d4d1ff-0a38-42a8-850e-d40636ee55bb' has exited
I0216 14:48:22.218679 136347648 containerizer.cpp:1227] Destroying container 'e6d4d1ff-0a38-42a8-850e-d40636ee55bb'
I0216 14:48:22.234441 136884224 provisioner.cpp:306] Ignoring destroy request for unknown container 90328de4-42b3-4213-a4ec-2a125c558cfa
I0216 14:48:22.234467 137957376 provisioner.cpp:306] Ignoring destroy request for unknown container 47d30577-e035-4556-93dc-16efd22c7a74
I0216 14:48:22.234486 137420800 provisioner.cpp:306] Ignoring destroy request for unknown container e6d4d1ff-0a38-42a8-850e-d40636ee55bb
I0216 14:48:22.234663 139030528 slave.cpp:3816] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 exited with status 1
I0216 14:48:22.234663 137420800 slave.cpp:3816] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 exited with status 1
I0216 14:48:22.234678 137957376 slave.cpp:3816] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 exited with status 1
I0216 14:48:22.234769 139030528 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
W0216 14:48:22.234916 135274496 containerizer.cpp:1119] Ignoring update for unknown container: 47d30577-e035-4556-93dc-16efd22c7a74
I0216 14:48:22.235157 135811072 master.cpp:4891] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144): exited with status 1
I0216 14:48:22.235188 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.235198 135811072 master.cpp:6540] Removing executor 'default' with resources of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.235726 135274496 status_update_manager.cpp:824] Checkpointing UPDATE for status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.237979 136347648 slave.cpp:3353] Forwarding the update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 to master@9.110.49.144:57199
I0216 14:48:22.238145 135811072 master.cpp:4789] Status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.238205 135811072 master.cpp:4837] Forwarding status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.238288 135811072 master.cpp:6445] Updating the state of task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
Task 4 is in state TASK_FAILED
The update data did not match!
Expected: 'data with a \x00 byte'
Actual: ''
Failed to call scheduler's statusUpdate
I0216 14:48:22.241416 137957376 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
W0216 14:48:22.241564 135274496 containerizer.cpp:1119] Ignoring update for unknown container: e6d4d1ff-0a38-42a8-850e-d40636ee55bb
I0216 14:48:22.241678 137957376 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
W0216 14:48:22.241750 139030528 containerizer.cpp:1119] Ignoring update for unknown container: e6d4d1ff-0a38-42a8-850e-d40636ee55bb
I0216 14:48:22.241940 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.241960 136347648 master.cpp:4891] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144): exited with status 1
I0216 14:48:22.241996 136347648 master.cpp:6540] Removing executor 'default' with resources of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.242317 135274496 status_update_manager.cpp:824] Checkpointing UPDATE for status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.242673 135811072 slave.cpp:3353] Forwarding the update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 to master@9.110.49.144:57199
I0216 14:48:22.242723 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.242826 136347648 master.cpp:4789] Status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.242862 136347648 master.cpp:4837] Forwarding status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.242959 136347648 master.cpp:6445] Updating the state of task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
I0216 14:48:22.243000 135274496 status_update_manager.cpp:824] Checkpointing UPDATE for status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.243325 138493952 slave.cpp:3353] Forwarding the update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 to master@9.110.49.144:57199
I0216 14:48:22.243482 135811072 master.cpp:4789] Status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.243510 135811072 master.cpp:4837] Forwarding status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.243562 135811072 master.cpp:6445] Updating the state of task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
I0216 14:48:22.245151 137420800 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
W0216 14:48:22.245280 139030528 containerizer.cpp:1119] Ignoring update for unknown container: 90328de4-42b3-4213-a4ec-2a125c558cfa
I0216 14:48:22.245340 137420800 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 96bebf09-9ca8-4206-a2df-dcf76fa73799) for task 1 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
W0216 14:48:22.245426 137957376 containerizer.cpp:1119] Ignoring update for unknown container: 90328de4-42b3-4213-a4ec-2a125c558cfa
I0216 14:48:22.245648 138493952 master.cpp:4891] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144): exited with status 1
I0216 14:48:22.245681 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.245692 138493952 master.cpp:6540] Removing executor 'default' with resources of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.245982 135274496 status_update_manager.cpp:824] Checkpointing UPDATE for status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.246345 137957376 slave.cpp:3353] Forwarding the update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 to master@9.110.49.144:57199
I0216 14:48:22.246383 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 96bebf09-9ca8-4206-a2df-dcf76fa73799) for task 1 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
I0216 14:48:22.246520 138493952 master.cpp:4789] Status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144)
I0216 14:48:22.246548 138493952 master.cpp:4837] Forwarding status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
../../src/tests/script.cpp:81: Failure
Failed
python_framework_test.sh terminated with signal Abort trap: 6
[ FAILED ] ExamplesTest.PythonFramework (7101 ms)
[----------] 1 test from ExamplesTest (7101 ms total)
[----------] Global test environment tear-down
[==========] 1 test from 1 test case ran. (7115 ms total)
[ PASSED ] 0 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ExamplesTest.PythonFramework
> ExamplesTest.PythonFramework fails on OSX
> -----------------------------------------
>
> Key: MESOS-4682
> URL: https://issues.apache.org/jira/browse/MESOS-4682
> Project: Mesos
> Issue Type: Bug
> Environment: OSX 10.10.05
> Reporter: Jian Qiu
> Labels: test
>
> {code}
> Using temporary directory '/tmp/ExamplesTest_PythonFramework_ZvbuJl'
> Enabling authentication for the framework
> I0216 14:48:17.029909 2007810816 leveldb.cpp:174] Opened db in 3570us
> I0216 14:48:17.030324 2007810816 leveldb.cpp:181] Compacted db in 383us
> I0216 14:48:17.030375 2007810816 leveldb.cpp:196] Created db iterator in 24us
> I0216 14:48:17.030388 2007810816 leveldb.cpp:202] Seeked to beginning of db in 8us
> I0216 14:48:17.030411 2007810816 leveldb.cpp:271] Iterated through 0 keys in the db in 6us
> I0216 14:48:17.030468 2007810816 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> I0216 14:48:17.031262 138493952 recover.cpp:447] Starting replica recovery
> I0216 14:48:17.031478 138493952 recover.cpp:473] Replica is in EMPTY status
> I0216 14:48:17.031772 2007810816 local.cpp:239] Using 'local' authorizer
> I0216 14:48:17.032449 135274496 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (4)@9.110.49.144:57199
> I0216 14:48:17.032662 137420800 recover.cpp:193] Received a recover response from a replica in EMPTY status
> I0216 14:48:17.032914 137957376 recover.cpp:564] Updating replica status to STARTING
> I0216 14:48:17.033349 136347648 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 316us
> I0216 14:48:17.033375 136347648 replica.cpp:320] Persisted replica status to STARTING
> I0216 14:48:17.033488 139030528 recover.cpp:473] Replica is in STARTING status
> I0216 14:48:17.034047 135811072 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (5)@9.110.49.144:57199
> I0216 14:48:17.034220 139030528 recover.cpp:193] Received a recover response from a replica in STARTING status
> I0216 14:48:17.034494 135811072 recover.cpp:564] Updating replica status to VOTING
> I0216 14:48:17.034744 136884224 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 135us
> I0216 14:48:17.034764 136884224 replica.cpp:320] Persisted replica status to VOTING
> I0216 14:48:17.034814 137957376 recover.cpp:578] Successfully joined the Paxos group
> I0216 14:48:17.034934 137957376 recover.cpp:462] Recover process terminated
> I0216 14:48:17.069952 137957376 master.cpp:374] Master bd54ad91-3083-42a3-a39f-0c7e2e08b0a0 (9.110.49.144) started on 9.110.49.144:57199
> I0216 14:48:17.070006 137957376 master.cpp:376] Flags at startup: --acls="permissive: false
> register_frameworks {
> principals {
> type: SOME
> values: "test-principal"
> }
> roles {
> type: SOME
> values: "*"
> }
> }
> run_tasks {
> principals {
> type: SOME
> values: "test-principal"
> }
> users {
> type: SOME
> values: "qiujian"
> }
> }
> " --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="true" --authenticate_http="false" --authenticate_slaves="false" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ExamplesTest_PythonFramework_ZvbuJl/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="5secs" --registry_strict="false" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/Users/qiujian/Documents/mesos/src/webui" --work_dir="/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ" --zk_session_timeout="10secs"
> I0216 14:48:17.070543 137957376 master.cpp:421] Master only allowing authenticated frameworks to register
> I0216 14:48:17.070564 137957376 master.cpp:428] Master allowing unauthenticated slaves to register
> I0216 14:48:17.070576 137957376 credentials.hpp:35] Loading credentials for authentication from '/tmp/ExamplesTest_PythonFramework_ZvbuJl/credentials'
> W0216 14:48:17.070650 137957376 credentials.hpp:50] Permissions on credentials file '/tmp/ExamplesTest_PythonFramework_ZvbuJl/credentials' are too open. It is recommended that your credentials file is NOT accessible by others.
> I0216 14:48:17.070757 137957376 master.cpp:466] Using default 'crammd5' authenticator
> I0216 14:48:17.070843 137957376 authenticator.cpp:518] Initializing server SASL
> I0216 14:48:17.071966 2007810816 containerizer.cpp:143] Using isolation: filesystem/posix,posix/cpu,posix/mem
> I0216 14:48:17.074555 136347648 slave.cpp:192] Slave started on 1)@9.110.49.144:57199
> I0216 14:48:17.074591 136347648 slave.cpp:193] Flags at startup: --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5" --container_disk_watch_interval="15secs" --containerizers="mesos" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="https://auth.docker.io" --docker_kill_orphans="true" --docker_puller_timeout="60" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="filesystem/posix,posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/Users/qiujian/Documents/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --resources="cpus:2;mem:10240" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --version="false" --work_dir="/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0"
> I0216 14:48:17.075846 2007810816 containerizer.cpp:143] Using isolation: filesystem/posix,posix/cpu,posix/mem
> I0216 14:48:17.075814 136347648 slave.cpp:463] Slave resources: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
> I0216 14:48:17.075888 136347648 slave.cpp:471] Slave attributes: [ ]
> I0216 14:48:17.075906 136347648 slave.cpp:476] Slave hostname: 9.110.49.144
> I0216 14:48:17.077810 135274496 slave.cpp:192] Slave started on 2)@9.110.49.144:57199
> I0216 14:48:17.077849 135274496 slave.cpp:193] Flags at startup: --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5" --container_disk_watch_interval="15secs" --containerizers="mesos" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="https://auth.docker.io" --docker_kill_orphans="true" --docker_puller_timeout="60" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="filesystem/posix,posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/Users/qiujian/Documents/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --resources="cpus:2;mem:10240" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --version="false" --work_dir="/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1"
> I0216 14:48:17.078251 137420800 state.cpp:58] Recovering state from '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0/meta'
> I0216 14:48:17.078466 135811072 status_update_manager.cpp:200] Recovering status update manager
> I0216 14:48:17.078577 139030528 containerizer.cpp:390] Recovering containerizer
> I0216 14:48:17.078850 135274496 slave.cpp:463] Slave resources: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
> I0216 14:48:17.078938 135274496 slave.cpp:471] Slave attributes: [ ]
> I0216 14:48:17.078953 135274496 slave.cpp:476] Slave hostname: 9.110.49.144
> I0216 14:48:17.079116 2007810816 containerizer.cpp:143] Using isolation: filesystem/posix,posix/cpu,posix/mem
> I0216 14:48:17.079588 135811072 state.cpp:58] Recovering state from '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1/meta'
> I0216 14:48:17.079758 137420800 status_update_manager.cpp:200] Recovering status update manager
> I0216 14:48:17.079970 136884224 provisioner.cpp:245] Provisioner recovery complete
> I0216 14:48:17.079979 135811072 containerizer.cpp:390] Recovering containerizer
> I0216 14:48:17.080253 139030528 slave.cpp:4495] Finished recovery
> I0216 14:48:17.081012 137420800 provisioner.cpp:245] Provisioner recovery complete
> I0216 14:48:17.081208 136347648 status_update_manager.cpp:174] Pausing sending status updates
> I0216 14:48:17.081240 139030528 slave.cpp:795] New master detected at master@9.110.49.144:57199
> I0216 14:48:17.081372 136884224 slave.cpp:4495] Finished recovery
> I0216 14:48:17.081378 139030528 slave.cpp:820] No credentials provided. Attempting to register without authentication
> I0216 14:48:17.081450 139030528 slave.cpp:831] Detecting new master
> I0216 14:48:17.081544 135274496 slave.cpp:192] Slave started on 3)@9.110.49.144:57199
> I0216 14:48:17.081575 135274496 slave.cpp:193] Flags at startup: --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5" --container_disk_watch_interval="15secs" --containerizers="mesos" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="https://auth.docker.io" --docker_kill_orphans="true" --docker_puller_timeout="60" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="filesystem/posix,posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/Users/qiujian/Documents/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --resources="cpus:2;mem:10240" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --version="false" --work_dir="/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2"
> I0216 14:48:17.081957 137420800 status_update_manager.cpp:174] Pausing sending status updates
> I0216 14:48:17.081981 138493952 slave.cpp:795] New master detected at master@9.110.49.144:57199
> I0216 14:48:17.082057 138493952 slave.cpp:820] No credentials provided. Attempting to register without authentication
> I0216 14:48:17.082092 138493952 slave.cpp:831] Detecting new master
> I0216 14:48:17.082464 2007810816 sched.cpp:164] Version: 0.27.0
> I0216 14:48:17.082598 135274496 slave.cpp:463] Slave resources: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
> I0216 14:48:17.082653 135274496 slave.cpp:471] Slave attributes: [ ]
> I0216 14:48:17.082664 135274496 slave.cpp:476] Slave hostname: 9.110.49.144
> I0216 14:48:17.082993 137420800 state.cpp:58] Recovering state from '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2/meta'
> I0216 14:48:17.083070 136884224 status_update_manager.cpp:200] Recovering status update manager
> I0216 14:48:17.083226 136884224 containerizer.cpp:390] Recovering containerizer
> I0216 14:48:17.083827 136884224 sched.cpp:268] New master detected at master@9.110.49.144:57199
> I0216 14:48:17.083879 136884224 sched.cpp:324] Authenticating with master master@9.110.49.144:57199
> I0216 14:48:17.083905 136884224 sched.cpp:331] Using default CRAM-MD5 authenticatee
> I0216 14:48:17.083920 137420800 provisioner.cpp:245] Provisioner recovery complete
> I0216 14:48:17.084105 138493952 slave.cpp:4495] Finished recovery
> I0216 14:48:17.084203 135811072 authenticatee.cpp:97] Initializing client SASL
> I0216 14:48:17.084527 139030528 status_update_manager.cpp:174] Pausing sending status updates
> I0216 14:48:17.084537 138493952 slave.cpp:795] New master detected at master@9.110.49.144:57199
> I0216 14:48:17.084585 138493952 slave.cpp:820] No credentials provided. Attempting to register without authentication
> I0216 14:48:17.084607 138493952 slave.cpp:831] Detecting new master
> I0216 14:48:17.085896 137957376 master.cpp:569] Authorization enabled
> I0216 14:48:17.087232 135811072 authenticatee.cpp:121] Creating new client SASL connection
> I0216 14:48:17.087606 135811072 master.cpp:1710] The newly elected leader is master@9.110.49.144:57199 with id bd54ad91-3083-42a3-a39f-0c7e2e08b0a0
> I0216 14:48:17.087625 135811072 master.cpp:1723] Elected as the leading master!
> I0216 14:48:17.087635 135811072 master.cpp:1468] Recovering from registrar
> I0216 14:48:17.087730 139030528 registrar.cpp:307] Recovering registrar
> I0216 14:48:17.088078 136347648 log.cpp:659] Attempting to start the writer
> I0216 14:48:17.089102 135274496 replica.cpp:493] Replica received implicit promise request from (45)@9.110.49.144:57199 with proposal 1
> I0216 14:48:17.089292 135274496 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 179us
> I0216 14:48:17.089316 135274496 replica.cpp:342] Persisted promised to 1
> I0216 14:48:17.089699 135811072 coordinator.cpp:238] Coordinator attempting to fill missing positions
> I0216 14:48:17.090502 137957376 replica.cpp:388] Replica received explicit promise request from (46)@9.110.49.144:57199 for position 0 with proposal 2
> I0216 14:48:17.090670 137957376 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 148us
> I0216 14:48:17.090692 137957376 replica.cpp:712] Persisted action at 0
> I0216 14:48:17.091337 138493952 replica.cpp:537] Replica received write request for position 0 from (47)@9.110.49.144:57199
> I0216 14:48:17.091375 138493952 leveldb.cpp:436] Reading position from leveldb took 21us
> I0216 14:48:17.091470 138493952 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 85us
> I0216 14:48:17.091492 138493952 replica.cpp:712] Persisted action at 0
> I0216 14:48:17.091790 137957376 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
> I0216 14:48:17.091884 137957376 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 88us
> I0216 14:48:17.091910 137957376 replica.cpp:712] Persisted action at 0
> I0216 14:48:17.091919 137957376 replica.cpp:697] Replica learned NOP action at position 0
> I0216 14:48:17.092175 136884224 log.cpp:675] Writer started with ending position 0
> I0216 14:48:17.092670 136884224 leveldb.cpp:436] Reading position from leveldb took 21us
> I0216 14:48:17.098273 139030528 registrar.cpp:340] Successfully fetched the registry (0B) in 10.49088ms
> I0216 14:48:17.098387 139030528 registrar.cpp:439] Applied 1 operations in 30us; attempting to update the 'registry'
> I0216 14:48:17.103885 135811072 log.cpp:683] Attempting to append 176 bytes to the log
> I0216 14:48:17.103982 139030528 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
> I0216 14:48:17.104568 138493952 replica.cpp:537] Replica received write request for position 1 from (48)@9.110.49.144:57199
> I0216 14:48:17.104753 138493952 leveldb.cpp:341] Persisting action (195 bytes) to leveldb took 168us
> I0216 14:48:17.104778 138493952 replica.cpp:712] Persisted action at 1
> I0216 14:48:17.105162 136884224 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
> I0216 14:48:17.105304 136884224 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 114us
> I0216 14:48:17.105327 136884224 replica.cpp:712] Persisted action at 1
> I0216 14:48:17.105337 136884224 replica.cpp:697] Replica learned APPEND action at position 1
> I0216 14:48:17.105900 139030528 registrar.cpp:484] Successfully updated the 'registry' in 7.475968ms
> I0216 14:48:17.105955 139030528 registrar.cpp:370] Successfully recovered registrar
> I0216 14:48:17.106034 137420800 log.cpp:702] Attempting to truncate the log to 1
> I0216 14:48:17.106153 135274496 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
> I0216 14:48:17.106171 136884224 master.cpp:1520] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
> I0216 14:48:17.106647 136884224 replica.cpp:537] Replica received write request for position 2 from (49)@9.110.49.144:57199
> I0216 14:48:17.106855 136884224 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 195us
> I0216 14:48:17.106879 136884224 replica.cpp:712] Persisted action at 2
> I0216 14:48:17.107234 138493952 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
> I0216 14:48:17.107352 138493952 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 105us
> I0216 14:48:17.107383 138493952 leveldb.cpp:399] Deleting ~1 keys from leveldb took 15us
> I0216 14:48:17.107395 138493952 replica.cpp:712] Persisted action at 2
> I0216 14:48:17.107405 138493952 replica.cpp:697] Replica learned TRUNCATE action at position 2
> I0216 14:48:17.482161 139030528 master.cpp:4235] Registering slave at slave(2)@9.110.49.144:57199 (9.110.49.144) with id bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0
> I0216 14:48:17.482571 138493952 registrar.cpp:439] Applied 1 operations in 87us; attempting to update the 'registry'
> I0216 14:48:17.482996 136884224 log.cpp:683] Attempting to append 345 bytes to the log
> I0216 14:48:17.483249 136347648 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
> I0216 14:48:17.484277 137957376 replica.cpp:537] Replica received write request for position 3 from (50)@9.110.49.144:57199
> I0216 14:48:17.486208 137957376 leveldb.cpp:341] Persisting action (364 bytes) to leveldb took 1903us
> I0216 14:48:17.486256 137957376 replica.cpp:712] Persisted action at 3
> I0216 14:48:17.486912 139030528 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
> I0216 14:48:17.487145 139030528 leveldb.cpp:341] Persisting action (366 bytes) to leveldb took 213us
> I0216 14:48:17.487197 139030528 replica.cpp:712] Persisted action at 3
> I0216 14:48:17.487217 139030528 replica.cpp:697] Replica learned APPEND action at position 3
> I0216 14:48:17.488268 138493952 registrar.cpp:484] Successfully updated the 'registry' in 5.644032ms
> I0216 14:48:17.488488 137420800 log.cpp:702] Attempting to truncate the log to 3
> I0216 14:48:17.488611 135811072 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
> I0216 14:48:17.489032 136884224 slave.cpp:970] Registered with master master@9.110.49.144:57199; given slave ID bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0
> I0216 14:48:17.489004 135274496 master.cpp:4303] Registered slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
> I0216 14:48:17.489162 139030528 hierarchical.cpp:471] Added slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000] (allocated: )
> I0216 14:48:17.489202 137420800 status_update_manager.cpp:181] Resuming sending status updates
> I0216 14:48:17.489259 138493952 replica.cpp:537] Replica received write request for position 4 from (51)@9.110.49.144:57199
> I0216 14:48:17.489431 138493952 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 145us
> I0216 14:48:17.489464 138493952 replica.cpp:712] Persisted action at 4
> I0216 14:48:17.489720 136884224 slave.cpp:1029] Forwarding total oversubscribed resources
> I0216 14:48:17.489950 138493952 master.cpp:4644] Received update of slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144) with total oversubscribed resources
> I0216 14:48:17.489982 136884224 replica.cpp:691] Replica received learned notice for position 4 from @0.0.0.0:0
> I0216 14:48:17.490124 136884224 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 134us
> I0216 14:48:17.490180 136884224 leveldb.cpp:399] Deleting ~2 keys from leveldb took 32us
> I0216 14:48:17.490203 136884224 replica.cpp:712] Persisted action at 4
> I0216 14:48:17.490222 136884224 replica.cpp:697] Replica learned TRUNCATE action at position 4
> I0216 14:48:17.490353 139030528 hierarchical.cpp:527] Slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 (9.110.49.144) updated with oversubscribed resources (total: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000], allocated: )
> I0216 14:48:17.871284 137957376 master.cpp:4235] Registering slave at slave(3)@9.110.49.144:57199 (9.110.49.144) with id bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1
> I0216 14:48:17.871639 135274496 registrar.cpp:439] Applied 1 operations in 86us; attempting to update the 'registry'
> I0216 14:48:17.879560 137957376 log.cpp:683] Attempting to append 511 bytes to the log
> I0216 14:48:17.879673 138493952 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 5
> I0216 14:48:17.880383 135274496 replica.cpp:537] Replica received write request for position 5 from (52)@9.110.49.144:57199
> I0216 14:48:17.882351 135274496 leveldb.cpp:341] Persisting action (530 bytes) to leveldb took 1963us
> I0216 14:48:17.882412 135274496 replica.cpp:712] Persisted action at 5
> I0216 14:48:17.882884 137957376 replica.cpp:691] Replica received learned notice for position 5 from @0.0.0.0:0
> I0216 14:48:17.883061 137957376 leveldb.cpp:341] Persisting action (532 bytes) to leveldb took 159us
> I0216 14:48:17.883086 137957376 replica.cpp:712] Persisted action at 5
> I0216 14:48:17.883100 137957376 replica.cpp:697] Replica learned APPEND action at position 5
> I0216 14:48:17.883944 136884224 registrar.cpp:484] Successfully updated the 'registry' in 12.240896ms
> I0216 14:48:17.884099 135811072 log.cpp:702] Attempting to truncate the log to 5
> I0216 14:48:17.884183 137957376 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 6
> I0216 14:48:17.884481 136347648 slave.cpp:970] Registered with master master@9.110.49.144:57199; given slave ID bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1
> I0216 14:48:17.884461 138493952 master.cpp:4303] Registered slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
> I0216 14:48:17.884563 136884224 hierarchical.cpp:471] Added slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000] (allocated: )
> I0216 14:48:17.884598 138493952 status_update_manager.cpp:181] Resuming sending status updates
> I0216 14:48:17.884815 139030528 replica.cpp:537] Replica received write request for position 6 from (53)@9.110.49.144:57199
> I0216 14:48:17.884955 139030528 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 124us
> I0216 14:48:17.884979 139030528 replica.cpp:712] Persisted action at 6
> I0216 14:48:17.885087 136347648 slave.cpp:1029] Forwarding total oversubscribed resources
> I0216 14:48:17.885210 136884224 master.cpp:4644] Received update of slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144) with total oversubscribed resources
> I0216 14:48:17.885401 135811072 replica.cpp:691] Replica received learned notice for position 6 from @0.0.0.0:0
> I0216 14:48:17.885530 135811072 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 115us
> I0216 14:48:17.885571 135811072 leveldb.cpp:399] Deleting ~2 keys from leveldb took 22us
> I0216 14:48:17.885571 138493952 hierarchical.cpp:527] Slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 (9.110.49.144) updated with oversubscribed resources (total: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000], allocated: )
> I0216 14:48:17.885586 135811072 replica.cpp:712] Persisted action at 6
> I0216 14:48:17.885624 135811072 replica.cpp:697] Replica learned TRUNCATE action at position 6
> I0216 14:48:17.925969 136884224 master.cpp:4235] Registering slave at slave(1)@9.110.49.144:57199 (9.110.49.144) with id bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2
> I0216 14:48:17.926264 135274496 registrar.cpp:439] Applied 1 operations in 94us; attempting to update the 'registry'
> I0216 14:48:17.926900 136884224 log.cpp:683] Attempting to append 677 bytes to the log
> I0216 14:48:17.927024 138493952 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 7
> I0216 14:48:17.927765 138493952 replica.cpp:537] Replica received write request for position 7 from (54)@9.110.49.144:57199
> I0216 14:48:17.929934 138493952 leveldb.cpp:341] Persisting action (696 bytes) to leveldb took 2156us
> I0216 14:48:17.930001 138493952 replica.cpp:712] Persisted action at 7
> I0216 14:48:17.930696 138493952 replica.cpp:691] Replica received learned notice for position 7 from @0.0.0.0:0
> I0216 14:48:17.930933 138493952 leveldb.cpp:341] Persisting action (698 bytes) to leveldb took 204us
> I0216 14:48:17.930963 138493952 replica.cpp:712] Persisted action at 7
> I0216 14:48:17.930977 138493952 replica.cpp:697] Replica learned APPEND action at position 7
> I0216 14:48:17.932322 137420800 registrar.cpp:484] Successfully updated the 'registry' in 6.00192ms
> I0216 14:48:17.932672 135811072 log.cpp:702] Attempting to truncate the log to 7
> I0216 14:48:17.932793 137957376 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 8
> I0216 14:48:17.932906 139030528 master.cpp:4303] Registered slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000]
> I0216 14:48:17.932986 137420800 slave.cpp:970] Registered with master master@9.110.49.144:57199; given slave ID bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2
> I0216 14:48:17.933056 135274496 hierarchical.cpp:471] Added slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 (9.110.49.144) with cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000] (allocated: )
> I0216 14:48:17.933195 135811072 status_update_manager.cpp:181] Resuming sending status updates
> I0216 14:48:17.933538 136884224 replica.cpp:537] Replica received write request for position 8 from (55)@9.110.49.144:57199
> I0216 14:48:17.933676 136884224 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 121us
> I0216 14:48:17.933697 136884224 replica.cpp:712] Persisted action at 8
> I0216 14:48:17.934065 137420800 slave.cpp:1029] Forwarding total oversubscribed resources
> I0216 14:48:17.934103 137957376 replica.cpp:691] Replica received learned notice for position 8 from @0.0.0.0:0
> I0216 14:48:17.934258 136884224 master.cpp:4644] Received update of slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144) with total oversubscribed resources
> I0216 14:48:17.934262 137957376 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 128us
> I0216 14:48:17.934309 137957376 leveldb.cpp:399] Deleting ~2 keys from leveldb took 22us
> I0216 14:48:17.934325 137957376 replica.cpp:712] Persisted action at 8
> I0216 14:48:17.934340 137957376 replica.cpp:697] Replica learned TRUNCATE action at position 8
> I0216 14:48:17.934569 137420800 hierarchical.cpp:527] Slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 (9.110.49.144) updated with oversubscribed resources (total: cpus(*):2; mem(*):10240; disk(*):470832; ports(*):[31000-32000], allocated: )
> W0216 14:48:22.089092 135274496 sched.cpp:435] Authentication timed out
> I0216 14:48:22.089346 135274496 sched.cpp:393] Failed to authenticate with master master@9.110.49.144:57199: Authentication discarded
> I0216 14:48:22.089409 135274496 sched.cpp:324] Authenticating with master master@9.110.49.144:57199
> I0216 14:48:22.089431 135274496 sched.cpp:331] Using default CRAM-MD5 authenticatee
> I0216 14:48:22.089582 135811072 authenticatee.cpp:121] Creating new client SASL connection
> I0216 14:48:22.089874 136884224 master.cpp:5521] Authenticating scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
> I0216 14:48:22.090229 137957376 authenticator.cpp:98] Creating new server SASL connection
> I0216 14:48:22.090343 137420800 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
> I0216 14:48:22.090389 137420800 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
> I0216 14:48:22.090502 138493952 authenticator.cpp:203] Received SASL authentication start
> I0216 14:48:22.090595 138493952 authenticator.cpp:325] Authentication requires more steps
> I0216 14:48:22.090697 138493952 authenticatee.cpp:258] Received SASL authentication step
> I0216 14:48:22.090849 137420800 authenticator.cpp:231] Received SASL authentication step
> I0216 14:48:22.090951 137420800 authenticator.cpp:317] Authentication success
> I0216 14:48:22.091037 138493952 authenticatee.cpp:298] Authentication success
> I0216 14:48:22.091207 136884224 master.cpp:5551] Successfully authenticated principal 'test-principal' at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
> I0216 14:48:22.091363 136347648 sched.cpp:413] Successfully authenticated with master master@9.110.49.144:57199
> I0216 14:48:22.091696 137957376 master.cpp:2278] Received SUBSCRIBE call for framework 'Test Framework (Python)' at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
> I0216 14:48:22.091780 137957376 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
> I0216 14:48:22.091997 137957376 master.cpp:2349] Subscribing framework Test Framework (Python) with checkpointing enabled and capabilities [ ]
> I0216 14:48:22.092391 135811072 hierarchical.cpp:265] Added framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.092584 136884224 sched.cpp:649] Framework registered with bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> Registered with framework ID bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.093969 136347648 master.cpp:5350] Sending 3 offers to framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
> Received offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O0 with cpus: 2.0 and mem: 10240.0
> Launching task 0 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O0
> Launching task 1 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O0
> Received offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O1 with cpus: 2.0 and mem: 10240.0
> Launching task 2 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O1
> Launching task 3 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O1
> Received offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O2 with cpus: 2.0 and mem: 10240.0
> Launching task 4 using offer bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O2
> I0216 14:48:22.098026 136347648 master.cpp:3136] Processing ACCEPT call for offers: [ bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O0 ] on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144) for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
> I0216 14:48:22.098060 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 0 as user 'qiujian'
> I0216 14:48:22.098148 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 1 as user 'qiujian'
> I0216 14:48:22.098811 136347648 master.cpp:3136] Processing ACCEPT call for offers: [ bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O1 ] on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144) for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
> I0216 14:48:22.098841 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 2 as user 'qiujian'
> I0216 14:48:22.098899 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 3 as user 'qiujian'
> I0216 14:48:22.099567 136347648 master.cpp:3136] Processing ACCEPT call for offers: [ bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-O2 ] on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144) for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199
> I0216 14:48:22.099593 136347648 master.cpp:2823] Authorizing framework principal 'test-principal' to launch task 4 as user 'qiujian'
> W0216 14:48:22.100142 136347648 validation.cpp:404] 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.
> W0216 14:48:22.100172 136347648 validation.cpp:416] 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.
> I0216 14:48:22.100311 136347648 master.hpp:176] Adding task 0 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 (9.110.49.144)
> I0216 14:48:22.100349 136347648 master.cpp:3621] Launching task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144)
> I0216 14:48:22.100525 136884224 slave.cpp:1360] Got assigned task 0 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> W0216 14:48:22.100664 136347648 validation.cpp:404] 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.
> W0216 14:48:22.100685 136347648 validation.cpp:416] 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.
> I0216 14:48:22.100767 136347648 master.hpp:176] Adding task 1 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 (9.110.49.144)
> I0216 14:48:22.100803 136347648 master.cpp:3621] Launching task 1 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144)
> W0216 14:48:22.101121 136347648 validation.cpp:404] 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.
> W0216 14:48:22.101142 136347648 validation.cpp:416] 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.
> I0216 14:48:22.101235 136347648 master.hpp:176] Adding task 2 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 (9.110.49.144)
> I0216 14:48:22.101272 136347648 master.cpp:3621] Launching task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
> I0216 14:48:22.101332 136884224 slave.cpp:1360] Got assigned task 1 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.101418 135811072 slave.cpp:1360] Got assigned task 2 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.101534 136884224 slave.cpp:1479] Launching task 0 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> W0216 14:48:22.101618 136347648 validation.cpp:404] Executor default for task 3 uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
> W0216 14:48:22.101642 136347648 validation.cpp:416] Executor default for task 3 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
> I0216 14:48:22.101730 136347648 master.hpp:176] Adding task 3 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 (9.110.49.144)
> I0216 14:48:22.101768 136347648 master.cpp:3621] Launching task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
> W0216 14:48:22.102140 136347648 validation.cpp:404] Executor default for task 4 uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
> W0216 14:48:22.102160 136347648 validation.cpp:416] Executor default for task 4 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
> I0216 14:48:22.102179 135811072 slave.cpp:1360] Got assigned task 3 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.102251 136347648 master.hpp:176] Adding task 4 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 (9.110.49.144)
> I0216 14:48:22.102283 136347648 master.cpp:3621] Launching task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (Test Framework (Python)) at scheduler-432c516b-e626-48c1-8f61-38125c023b0e@9.110.49.144:57199 with resources cpus(*):1; mem(*):128 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144)
> I0216 14:48:22.102332 135811072 slave.cpp:1479] Launching task 2 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.102411 138493952 slave.cpp:1360] Got assigned task 4 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.103031 138493952 slave.cpp:1479] Launching task 4 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.103332 138493952 paths.cpp:472] Trying to chown '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/47d30577-e035-4556-93dc-16efd22c7a74' to user 'qiujian'
> I0216 14:48:22.108590 136884224 paths.cpp:472] Trying to chown '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/90328de4-42b3-4213-a4ec-2a125c558cfa' to user 'qiujian'
> I0216 14:48:22.112316 135811072 paths.cpp:472] Trying to chown '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/e6d4d1ff-0a38-42a8-850e-d40636ee55bb' to user 'qiujian'
> I0216 14:48:22.114683 138493952 slave.cpp:5281] Launching executor default of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 with resources in work directory '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/47d30577-e035-4556-93dc-16efd22c7a74'
> I0216 14:48:22.114984 137420800 containerizer.cpp:649] Starting container '47d30577-e035-4556-93dc-16efd22c7a74' for executor 'default' of framework 'bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000'
> I0216 14:48:22.115456 138493952 slave.cpp:1697] Queuing task '4' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.116789 136884224 slave.cpp:5281] Launching executor default of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 with resources in work directory '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/90328de4-42b3-4213-a4ec-2a125c558cfa'
> I0216 14:48:22.117841 139030528 containerizer.cpp:649] Starting container '90328de4-42b3-4213-a4ec-2a125c558cfa' for executor 'default' of framework 'bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000'
> I0216 14:48:22.118047 137420800 launcher.cpp:132] Forked child with pid '46820' for container '47d30577-e035-4556-93dc-16efd22c7a74'
> I0216 14:48:22.118191 137420800 containerizer.cpp:1003] Checkpointing executor's forked pid 46820 to '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/0/meta/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/47d30577-e035-4556-93dc-16efd22c7a74/pids/forked.pid'
> I0216 14:48:22.118674 136884224 slave.cpp:1697] Queuing task '0' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.118751 136884224 slave.cpp:1479] Launching task 1 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.119292 136884224 slave.cpp:1697] Queuing task '1' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.119415 135811072 slave.cpp:5281] Launching executor default of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 with resources in work directory '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/e6d4d1ff-0a38-42a8-850e-d40636ee55bb'
> I0216 14:48:22.119585 137420800 containerizer.cpp:649] Starting container 'e6d4d1ff-0a38-42a8-850e-d40636ee55bb' for executor 'default' of framework 'bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000'
> I0216 14:48:22.120576 135811072 slave.cpp:1697] Queuing task '2' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.120816 136347648 launcher.cpp:132] Forked child with pid '46821' for container '90328de4-42b3-4213-a4ec-2a125c558cfa'
> I0216 14:48:22.120893 135811072 slave.cpp:1479] Launching task 3 for framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.120962 136347648 containerizer.cpp:1003] Checkpointing executor's forked pid 46821 to '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/2/meta/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/90328de4-42b3-4213-a4ec-2a125c558cfa/pids/forked.pid'
> I0216 14:48:22.121409 135811072 slave.cpp:1697] Queuing task '3' for executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.122586 137420800 launcher.cpp:132] Forked child with pid '46822' for container 'e6d4d1ff-0a38-42a8-850e-d40636ee55bb'
> I0216 14:48:22.122828 137420800 containerizer.cpp:1003] Checkpointing executor's forked pid 46822 to '/var/folders/_4/hjy0h2s15kv3mt9ft2ndx5jh0000gn/T/mesos-XXXXXX.FIXeeEhQ/1/meta/slaves/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0/frameworks/bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000/executors/default/runs/e6d4d1ff-0a38-42a8-850e-d40636ee55bb/pids/forked.pid'
> Failed to parse the flags: Failed to load unknown flag 'directory'
> Failed to parse the flags: Failed to load unknown flag 'directory'
> Failed to parse the flags: Failed to load unknown flag 'directory'
> I0216 14:48:22.218507 135274496 containerizer.cpp:1443] Executor for container '90328de4-42b3-4213-a4ec-2a125c558cfa' has exited
> I0216 14:48:22.218523 137957376 containerizer.cpp:1443] Executor for container '47d30577-e035-4556-93dc-16efd22c7a74' has exited
> I0216 14:48:22.218564 135274496 containerizer.cpp:1227] Destroying container '90328de4-42b3-4213-a4ec-2a125c558cfa'
> I0216 14:48:22.218578 137957376 containerizer.cpp:1227] Destroying container '47d30577-e035-4556-93dc-16efd22c7a74'
> I0216 14:48:22.218655 136347648 containerizer.cpp:1443] Executor for container 'e6d4d1ff-0a38-42a8-850e-d40636ee55bb' has exited
> I0216 14:48:22.218679 136347648 containerizer.cpp:1227] Destroying container 'e6d4d1ff-0a38-42a8-850e-d40636ee55bb'
> I0216 14:48:22.234441 136884224 provisioner.cpp:306] Ignoring destroy request for unknown container 90328de4-42b3-4213-a4ec-2a125c558cfa
> I0216 14:48:22.234467 137957376 provisioner.cpp:306] Ignoring destroy request for unknown container 47d30577-e035-4556-93dc-16efd22c7a74
> I0216 14:48:22.234486 137420800 provisioner.cpp:306] Ignoring destroy request for unknown container e6d4d1ff-0a38-42a8-850e-d40636ee55bb
> I0216 14:48:22.234663 139030528 slave.cpp:3816] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 exited with status 1
> I0216 14:48:22.234663 137420800 slave.cpp:3816] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 exited with status 1
> I0216 14:48:22.234678 137957376 slave.cpp:3816] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 exited with status 1
> I0216 14:48:22.234769 139030528 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
> W0216 14:48:22.234916 135274496 containerizer.cpp:1119] Ignoring update for unknown container: 47d30577-e035-4556-93dc-16efd22c7a74
> I0216 14:48:22.235157 135811072 master.cpp:4891] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144): exited with status 1
> I0216 14:48:22.235188 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.235198 135811072 master.cpp:6540] Removing executor 'default' with resources of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144)
> I0216 14:48:22.235726 135274496 status_update_manager.cpp:824] Checkpointing UPDATE for status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.237979 136347648 slave.cpp:3353] Forwarding the update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 to master@9.110.49.144:57199
> I0216 14:48:22.238145 135811072 master.cpp:4789] Status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S2 at slave(1)@9.110.49.144:57199 (9.110.49.144)
> I0216 14:48:22.238205 135811072 master.cpp:4837] Forwarding status update TASK_FAILED (UUID: 5397dc9b-1319-4f05-812b-9502b7bbb0f6) for task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.238288 135811072 master.cpp:6445] Updating the state of task 4 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
> Task 4 is in state TASK_FAILED
> The update data did not match!
> Expected: 'data with a \x00 byte'
> Actual: ''
> Failed to call scheduler's statusUpdate
> I0216 14:48:22.241416 137957376 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
> W0216 14:48:22.241564 135274496 containerizer.cpp:1119] Ignoring update for unknown container: e6d4d1ff-0a38-42a8-850e-d40636ee55bb
> I0216 14:48:22.241678 137957376 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
> W0216 14:48:22.241750 139030528 containerizer.cpp:1119] Ignoring update for unknown container: e6d4d1ff-0a38-42a8-850e-d40636ee55bb
> I0216 14:48:22.241940 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.241960 136347648 master.cpp:4891] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144): exited with status 1
> I0216 14:48:22.241996 136347648 master.cpp:6540] Removing executor 'default' with resources of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
> I0216 14:48:22.242317 135274496 status_update_manager.cpp:824] Checkpointing UPDATE for status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.242673 135811072 slave.cpp:3353] Forwarding the update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 to master@9.110.49.144:57199
> I0216 14:48:22.242723 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.242826 136347648 master.cpp:4789] Status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
> I0216 14:48:22.242862 136347648 master.cpp:4837] Forwarding status update TASK_FAILED (UUID: 6fb75dec-d881-4816-ba95-61b7082fe361) for task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.242959 136347648 master.cpp:6445] Updating the state of task 2 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
> I0216 14:48:22.243000 135274496 status_update_manager.cpp:824] Checkpointing UPDATE for status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.243325 138493952 slave.cpp:3353] Forwarding the update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 to master@9.110.49.144:57199
> I0216 14:48:22.243482 135811072 master.cpp:4789] Status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S0 at slave(2)@9.110.49.144:57199 (9.110.49.144)
> I0216 14:48:22.243510 135811072 master.cpp:4837] Forwarding status update TASK_FAILED (UUID: 8843685a-422a-44c9-a4fa-8e50011b5d8a) for task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.243562 135811072 master.cpp:6445] Updating the state of task 3 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
> I0216 14:48:22.245151 137420800 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
> W0216 14:48:22.245280 139030528 containerizer.cpp:1119] Ignoring update for unknown container: 90328de4-42b3-4213-a4ec-2a125c558cfa
> I0216 14:48:22.245340 137420800 slave.cpp:3001] Handling status update TASK_FAILED (UUID: 96bebf09-9ca8-4206-a2df-dcf76fa73799) for task 1 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from @0.0.0.0:0
> W0216 14:48:22.245426 137957376 containerizer.cpp:1119] Ignoring update for unknown container: 90328de4-42b3-4213-a4ec-2a125c558cfa
> I0216 14:48:22.245648 138493952 master.cpp:4891] Executor 'default' of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144): exited with status 1
> I0216 14:48:22.245681 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.245692 138493952 master.cpp:6540] Removing executor 'default' with resources of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 on slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144)
> I0216 14:48:22.245982 135274496 status_update_manager.cpp:824] Checkpointing UPDATE for status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.246345 137957376 slave.cpp:3353] Forwarding the update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 to master@9.110.49.144:57199
> I0216 14:48:22.246383 135274496 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 96bebf09-9ca8-4206-a2df-dcf76fa73799) for task 1 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> I0216 14:48:22.246520 138493952 master.cpp:4789] Status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000 from slave bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-S1 at slave(3)@9.110.49.144:57199 (9.110.49.144)
> I0216 14:48:22.246548 138493952 master.cpp:4837] Forwarding status update TASK_FAILED (UUID: 8a69758e-b2e7-49ba-98b2-48f4af12d07b) for task 0 of framework bd54ad91-3083-42a3-a39f-0c7e2e08b0a0-0000
> ../../src/tests/script.cpp:81: Failure
> Failed
> python_framework_test.sh terminated with signal Abort trap: 6
> [ FAILED ] ExamplesTest.PythonFramework (7101 ms)
> [----------] 1 test from ExamplesTest (7101 ms total)
> [----------] Global test environment tear-down
> [==========] 1 test from 1 test case ran. (7115 ms total)
> [ PASSED ] 0 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] ExamplesTest.PythonFramework
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)