Details
-
Bug
-
Status: Resolved
-
Major
-
Resolution: Invalid
-
0.26.0
-
None
-
None
-
Debian 8, gcc 4.9.2, Docker 1.9.0, vagrant, libvirt,
Vagrantfile seeMESOS-3957.
Description
Running sudo ./bin/mesos-tests.sh --gtest_filter="DockerContainerizerTest.ROOT_DOCKER_Update" --verbose, we get:
[ RUN ] DockerContainerizerTest.ROOT_DOCKER_Update
I1119 14:25:33.490622 30568 leveldb.cpp:176] Opened db in 40.034383ms
I1119 14:25:33.498376 30568 leveldb.cpp:183] Compacted db in 7.599708ms
I1119 14:25:33.498545 30568 leveldb.cpp:198] Created db iterator in 73294ns
I1119 14:25:33.498579 30568 leveldb.cpp:204] Seeked to beginning of db in 5930ns
I1119 14:25:33.498594 30568 leveldb.cpp:273] Iterated through 0 keys in the db in 388ns
I1119 14:25:33.498731 30568 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1119 14:25:33.500977 30589 recover.cpp:449] Starting replica recovery
I1119 14:25:33.502004 30583 recover.cpp:475] Replica is in EMPTY status
I1119 14:25:33.505199 30582 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (4)@127.0.1.1:53940
I1119 14:25:33.506701 30583 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1119 14:25:33.508040 30587 recover.cpp:566] Updating replica status to STARTING
I1119 14:25:33.509750 30589 master.cpp:367] Master d5a4b793-6ed8-42a4-89f9-f481f4576e36 (debian-jessie.vagrantup.com) started on 127.0.1.1:53940
I1119 14:25:33.509860 30589 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/2ng8OG/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/2ng8OG/master" --zk_session_timeout="10secs"
I1119 14:25:33.511498 30589 master.cpp:414] Master only allowing authenticated frameworks to register
I1119 14:25:33.511533 30589 master.cpp:419] Master only allowing authenticated slaves to register
I1119 14:25:33.511560 30589 credentials.hpp:37] Loading credentials for authentication from '/tmp/2ng8OG/credentials'
I1119 14:25:33.514281 30582 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 5.914377ms
I1119 14:25:33.514616 30582 replica.cpp:323] Persisted replica status to STARTING
I1119 14:25:33.515270 30586 recover.cpp:475] Replica is in STARTING status
I1119 14:25:33.515537 30589 master.cpp:458] Using default 'crammd5' authenticator
I1119 14:25:33.516177 30589 authenticator.cpp:520] Initializing server SASL
I1119 14:25:33.517812 30584 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (5)@127.0.1.1:53940
I1119 14:25:33.518755 30588 recover.cpp:195] Received a recover response from a replica in STARTING status
I1119 14:25:33.519742 30583 recover.cpp:566] Updating replica status to VOTING
I1119 14:25:33.524073 30589 master.cpp:495] Authorization enabled
I1119 14:25:33.525710 30588 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 5.247917ms
I1119 14:25:33.526275 30588 replica.cpp:323] Persisted replica status to VOTING
I1119 14:25:33.526548 30585 recover.cpp:580] Successfully joined the Paxos group
I1119 14:25:33.526851 30585 recover.cpp:464] Recover process terminated
I1119 14:25:33.533421 30582 master.cpp:1606] The newly elected leader is master@127.0.1.1:53940 with id d5a4b793-6ed8-42a4-89f9-f481f4576e36
I1119 14:25:33.533522 30582 master.cpp:1619] Elected as the leading master!
I1119 14:25:33.533579 30582 master.cpp:1379] Recovering from registrar
I1119 14:25:33.534111 30582 registrar.cpp:309] Recovering registrar
I1119 14:25:33.535789 30584 log.cpp:661] Attempting to start the writer
I1119 14:25:33.538920 30587 replica.cpp:496] Replica received implicit promise request from (6)@127.0.1.1:53940 with proposal 1
I1119 14:25:33.539789 30587 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 755133ns
I1119 14:25:33.539873 30587 replica.cpp:345] Persisted promised to 1
I1119 14:25:33.541929 30587 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1119 14:25:33.544808 30586 replica.cpp:391] Replica received explicit promise request from (7)@127.0.1.1:53940 for position 0 with proposal 2
I1119 14:25:33.545764 30586 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 811594ns
I1119 14:25:33.545866 30586 replica.cpp:715] Persisted action at 0
I1119 14:25:33.547927 30583 replica.cpp:540] Replica received write request for position 0 from (8)@127.0.1.1:53940
I1119 14:25:33.548092 30583 leveldb.cpp:438] Reading position from leveldb took 71463ns
I1119 14:25:33.548880 30583 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 673351ns
I1119 14:25:33.548950 30583 replica.cpp:715] Persisted action at 0
I1119 14:25:33.550031 30583 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1119 14:25:33.550755 30583 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 641472ns
I1119 14:25:33.550817 30583 replica.cpp:715] Persisted action at 0
I1119 14:25:33.550865 30583 replica.cpp:700] Replica learned NOP action at position 0
I1119 14:25:33.552011 30585 log.cpp:677] Writer started with ending position 0
I1119 14:25:33.554890 30583 leveldb.cpp:438] Reading position from leveldb took 63180ns
I1119 14:25:33.558408 30587 registrar.cpp:342] Successfully fetched the registry (0B) in 24.156928ms
I1119 14:25:33.559008 30587 registrar.cpp:441] Applied 1 operations in 124850ns; attempting to update the 'registry'
I1119 14:25:33.562463 30587 log.cpp:685] Attempting to append 199 bytes to the log
I1119 14:25:33.563092 30587 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1119 14:25:33.565224 30588 replica.cpp:540] Replica received write request for position 1 from (9)@127.0.1.1:53940
I1119 14:25:33.566042 30588 leveldb.cpp:343] Persisting action (218 bytes) to leveldb took 704949ns
I1119 14:25:33.566129 30588 replica.cpp:715] Persisted action at 1
I1119 14:25:33.568075 30588 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1119 14:25:33.568804 30588 leveldb.cpp:343] Persisting action (220 bytes) to leveldb took 638603ns
I1119 14:25:33.568878 30588 replica.cpp:715] Persisted action at 1
I1119 14:25:33.568936 30588 replica.cpp:700] Replica learned APPEND action at position 1
I1119 14:25:33.571494 30588 registrar.cpp:486] Successfully updated the 'registry' in 12.276992ms
I1119 14:25:33.571993 30586 log.cpp:704] Attempting to truncate the log to 1
I1119 14:25:33.572430 30584 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1119 14:25:33.572655 30588 registrar.cpp:372] Successfully recovered registrar
I1119 14:25:33.573920 30586 replica.cpp:540] Replica received write request for position 2 from (10)@127.0.1.1:53940
I1119 14:25:33.574753 30586 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 725369ns
I1119 14:25:33.574837 30586 replica.cpp:715] Persisted action at 2
I1119 14:25:33.576499 30589 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1119 14:25:33.577211 30583 master.cpp:1416] Recovered 0 slaves from the Registry (160B) ; allowing 10mins for slaves to re-register
I1119 14:25:33.577245 30589 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 674297ns
I1119 14:25:33.577389 30589 leveldb.cpp:401] Deleting ~1 keys from leveldb took 63523ns
I1119 14:25:33.577600 30589 replica.cpp:715] Persisted action at 2
I1119 14:25:33.577656 30589 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1119 14:25:33.596401 30586 slave.cpp:191] Slave started on 1)@127.0.1.1:53940
I1119 14:25:33.596827 30586 slave.cpp:192] Flags at startup: --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/DockerContainerizerTest_ROOT_DOCKER_Update_pfNTZI/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="auth.docker.io" --docker_auth_server_port="443" --docker_kill_orphans="true" --docker_local_archives_dir="/tmp/mesos/images/docker" --docker_puller="local" --docker_puller_timeout="60" --docker_registry="registry-1.docker.io" --docker_registry_port="443" --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/DockerContainerizerTest_ROOT_DOCKER_Update_pfNTZI/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="posix/cpu,posix/mem" --launcher_dir="/home/vagrant/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/DockerContainerizerTest_ROOT_DOCKER_Update_pfNTZI"
I1119 14:25:33.597967 30586 credentials.hpp:85] Loading credential for authentication from '/tmp/DockerContainerizerTest_ROOT_DOCKER_Update_pfNTZI/credential'
I1119 14:25:33.598623 30586 slave.cpp:322] Slave using credential for: test-principal
I1119 14:25:33.600559 30586 slave.cpp:392] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1119 14:25:33.600839 30568 sched.cpp:166] Version: 0.26.0
I1119 14:25:33.600934 30586 slave.cpp:400] Slave attributes: [ ]
I1119 14:25:33.601435 30586 slave.cpp:405] Slave hostname: debian-jessie.vagrantup.com
I1119 14:25:33.601593 30586 slave.cpp:410] Slave checkpoint: true
I1119 14:25:33.602473 30582 sched.cpp:264] New master detected at master@127.0.1.1:53940
I1119 14:25:33.602648 30582 sched.cpp:320] Authenticating with master master@127.0.1.1:53940
I1119 14:25:33.602691 30582 sched.cpp:327] Using default CRAM-MD5 authenticatee
I1119 14:25:33.603313 30587 authenticatee.cpp:99] Initializing client SASL
I1119 14:25:33.603878 30587 authenticatee.cpp:123] Creating new client SASL connection
I1119 14:25:33.604363 30582 state.cpp:54] Recovering state from '/tmp/DockerContainerizerTest_ROOT_DOCKER_Update_pfNTZI/meta'
I1119 14:25:33.604822 30586 master.cpp:5150] Authenticating scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940
I1119 14:25:33.605373 30582 status_update_manager.cpp:202] Recovering status update manager
I1119 14:25:33.605687 30586 authenticator.cpp:100] Creating new server SASL connection
I1119 14:25:33.606143 30589 docker.cpp:536] Recovering Docker containers
I1119 14:25:33.606534 30589 slave.cpp:4230] Finished recovery
I1119 14:25:33.606545 30585 authenticatee.cpp:214] Received SASL authentication mechanisms: CRAM-MD5
I1119 14:25:33.606673 30585 authenticatee.cpp:240] Attempting to authenticate with mechanism 'CRAM-MD5'
I1119 14:25:33.606909 30585 authenticator.cpp:205] Received SASL authentication start
I1119 14:25:33.607085 30585 authenticator.cpp:327] Authentication requires more steps
I1119 14:25:33.607655 30585 authenticatee.cpp:260] Received SASL authentication step
I1119 14:25:33.607856 30585 authenticator.cpp:233] Received SASL authentication step
I1119 14:25:33.607985 30586 status_update_manager.cpp:176] Pausing sending status updates
I1119 14:25:33.607867 30589 slave.cpp:729] New master detected at master@127.0.1.1:53940
I1119 14:25:33.608208 30585 authenticator.cpp:319] Authentication success
I1119 14:25:33.608333 30589 slave.cpp:792] Authenticating with master master@127.0.1.1:53940
I1119 14:25:33.608373 30589 slave.cpp:797] Using default CRAM-MD5 authenticatee
I1119 14:25:33.608707 30589 slave.cpp:765] Detecting new master
I1119 14:25:33.608825 30587 authenticatee.cpp:300] Authentication success
I1119 14:25:33.608855 30588 authenticatee.cpp:123] Creating new client SASL connection
I1119 14:25:33.609263 30584 master.cpp:5180] Successfully authenticated principal 'test-principal' at scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940
I1119 14:25:33.609688 30587 sched.cpp:409] Successfully authenticated with master master@127.0.1.1:53940
I1119 14:25:33.613952 30584 master.cpp:2176] Received SUBSCRIBE call for framework 'default' at scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940
I1119 14:25:33.614164 30584 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1119 14:25:33.614570 30584 master.cpp:5150] Authenticating slave(1)@127.0.1.1:53940
I1119 14:25:33.614954 30584 master.cpp:2247] Subscribing framework default with checkpointing disabled and capabilities [ ]
I1119 14:25:33.615363 30585 authenticator.cpp:100] Creating new server SASL connection
I1119 14:25:33.616003 30586 authenticatee.cpp:214] Received SASL authentication mechanisms: CRAM-MD5
I1119 14:25:33.616474 30587 sched.cpp:643] Framework registered with d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
I1119 14:25:33.616508 30586 authenticatee.cpp:240] Attempting to authenticate with mechanism 'CRAM-MD5'
I1119 14:25:33.616231 30585 hierarchical.cpp:195] Added framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
I1119 14:25:33.617579 30584 authenticator.cpp:205] Received SASL authentication start
I1119 14:25:33.617648 30584 authenticator.cpp:327] Authentication requires more steps
I1119 14:25:33.617928 30585 authenticatee.cpp:260] Received SASL authentication step
I1119 14:25:33.618157 30585 authenticator.cpp:233] Received SASL authentication step
I1119 14:25:33.618321 30585 authenticator.cpp:319] Authentication success
I1119 14:25:33.618592 30589 authenticatee.cpp:300] Authentication success
I1119 14:25:33.618661 30585 master.cpp:5180] Successfully authenticated principal 'test-principal' at slave(1)@127.0.1.1:53940
I1119 14:25:33.619609 30589 slave.cpp:860] Successfully authenticated with master master@127.0.1.1:53940
I1119 14:25:33.620424 30588 master.cpp:3859] Registering slave at slave(1)@127.0.1.1:53940 (debian-jessie.vagrantup.com) with id d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0
I1119 14:25:33.621635 30587 registrar.cpp:441] Applied 1 operations in 94919ns; attempting to update the 'registry'
I1119 14:25:33.623123 30584 log.cpp:685] Attempting to append 383 bytes to the log
I1119 14:25:33.623383 30588 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 3
I1119 14:25:33.624845 30589 replica.cpp:540] Replica received write request for position 3 from (16)@127.0.1.1:53940
I1119 14:25:33.625751 30589 leveldb.cpp:343] Persisting action (402 bytes) to leveldb took 729774ns
I1119 14:25:33.625991 30589 replica.cpp:715] Persisted action at 3
I1119 14:25:33.627218 30584 replica.cpp:694] Replica received learned notice for position 3 from @0.0.0.0:0
I1119 14:25:33.627913 30584 leveldb.cpp:343] Persisting action (404 bytes) to leveldb took 602607ns
I1119 14:25:33.627948 30584 replica.cpp:715] Persisted action at 3
I1119 14:25:33.627974 30584 replica.cpp:700] Replica learned APPEND action at position 3
I1119 14:25:33.630290 30585 registrar.cpp:486] Successfully updated the 'registry' in 8.461056ms
I1119 14:25:33.630606 30585 log.cpp:704] Attempting to truncate the log to 3
I1119 14:25:33.630786 30585 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 4
I1119 14:25:33.631690 30585 replica.cpp:540] Replica received write request for position 4 from (17)@127.0.1.1:53940
I1119 14:25:33.632026 30582 master.cpp:3927] Registered slave d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0 at slave(1)@127.0.1.1:53940 (debian-jessie.vagrantup.com) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1119 14:25:33.632179 30584 hierarchical.cpp:344] Added slave d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0 (debian-jessie.vagrantup.com) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
I1119 14:25:33.632314 30586 slave.cpp:904] Registered with master master@127.0.1.1:53940; given slave ID d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0
I1119 14:25:33.633167 30589 status_update_manager.cpp:183] Resuming sending status updates
I1119 14:25:33.633577 30586 slave.cpp:963] Forwarding total oversubscribed resources
I1119 14:25:33.633931 30585 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 1.550221ms
I1119 14:25:33.634268 30585 replica.cpp:715] Persisted action at 4
I1119 14:25:33.634824 30583 master.cpp:4979] Sending 1 offers to framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 (default) at scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940
I1119 14:25:33.635563 30583 master.cpp:4269] Received update of slave d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0 at slave(1)@127.0.1.1:53940 (debian-jessie.vagrantup.com) with total oversubscribed resources
I1119 14:25:33.636200 30584 replica.cpp:694] Replica received learned notice for position 4 from @0.0.0.0:0
I1119 14:25:33.636382 30583 hierarchical.cpp:400] Slave d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0 (debian-jessie.vagrantup.com) updated with oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000])
I1119 14:25:33.637250 30584 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 931215ns
I1119 14:25:33.637323 30584 leveldb.cpp:401] Deleting ~2 keys from leveldb took 41589ns
I1119 14:25:33.637348 30584 replica.cpp:715] Persisted action at 4
I1119 14:25:33.637377 30584 replica.cpp:700] Replica learned TRUNCATE action at position 4
I1119 14:25:33.640512 30582 master.cpp:2915] Processing ACCEPT call for offers: [ d5a4b793-6ed8-42a4-89f9-f481f4576e36-O0 ] on slave d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0 at slave(1)@127.0.1.1:53940 (debian-jessie.vagrantup.com) for framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 (default) at scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940
I1119 14:25:33.640660 30582 master.cpp:2711] Authorizing framework principal 'test-principal' to launch task 1 as user 'root'
I1119 14:25:33.644170 30582 master.hpp:176] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0 (debian-jessie.vagrantup.com)
I1119 14:25:33.644534 30582 master.cpp:3245] Launching task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 (default) at scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0 at slave(1)@127.0.1.1:53940 (debian-jessie.vagrantup.com)
I1119 14:25:33.645370 30585 slave.cpp:1294] Got assigned task 1 for framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
I1119 14:25:33.646550 30585 slave.cpp:1410] Launching task 1 for framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
I1119 14:25:33.648447 30585 paths.cpp:436] Trying to chown '/tmp/DockerContainerizerTest_ROOT_DOCKER_Update_pfNTZI/slaves/d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0/frameworks/d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000/executors/1/runs/b4e876f5-2f2d-4d72-9646-9ffcd15abf12' to user 'root'
I1119 14:25:33.652418 30585 slave.cpp:4999] Launching executor 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 with resources cpus(*):0.1; mem(*):32 in work directory '/tmp/DockerContainerizerTest_ROOT_DOCKER_Update_pfNTZI/slaves/d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0/frameworks/d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000/executors/1/runs/b4e876f5-2f2d-4d72-9646-9ffcd15abf12'
I1119 14:25:33.653911 30585 slave.cpp:1628] Queuing task '1' for executor '1' of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
I1119 14:25:33.659168 30588 docker.cpp:762] Starting container 'b4e876f5-2f2d-4d72-9646-9ffcd15abf12' for task '1' (and executor '1') of framework 'd5a4b793-6ed8-42a4-89f9-f481f4576e36-0000'
I1119 14:25:33.810679 30583 slave.cpp:2405] Got registration for executor '1' of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 from executor(1)@127.0.1.1:55236
I1119 14:25:33.812475 30589 docker.cpp:1012] Ignoring updating container 'b4e876f5-2f2d-4d72-9646-9ffcd15abf12' with resources passed to update is identical to existing resources
I1119 14:25:33.813027 30589 slave.cpp:1793] Sending queued task '1' to executor '1' of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 at executor(1)@127.0.1.1:55236
I1119 14:25:34.548405 30587 slave.cpp:2762] Handling status update TASK_RUNNING (UUID: ff9725dd-4179-44ec-b114-f29f96a6501d) for task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 from executor(1)@127.0.1.1:55236
I1119 14:25:34.549352 30587 status_update_manager.cpp:322] Received status update TASK_RUNNING (UUID: ff9725dd-4179-44ec-b114-f29f96a6501d) for task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
I1119 14:25:34.550582 30587 slave.cpp:3087] Forwarding the update TASK_RUNNING (UUID: ff9725dd-4179-44ec-b114-f29f96a6501d) for task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 to master@127.0.1.1:53940
I1119 14:25:34.550964 30587 slave.cpp:3011] Sending acknowledgement for status update TASK_RUNNING (UUID: ff9725dd-4179-44ec-b114-f29f96a6501d) for task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 to executor(1)@127.0.1.1:55236
I1119 14:25:34.551317 30584 master.cpp:4414] Status update TASK_RUNNING (UUID: ff9725dd-4179-44ec-b114-f29f96a6501d) for task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 from slave d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0 at slave(1)@127.0.1.1:53940 (debian-jessie.vagrantup.com)
I1119 14:25:34.551934 30584 master.cpp:4462] Forwarding status update TASK_RUNNING (UUID: ff9725dd-4179-44ec-b114-f29f96a6501d) for task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
I1119 14:25:34.552428 30584 master.cpp:6066] Updating the state of task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1119 14:25:34.553675 30586 master.cpp:3571] Processing ACKNOWLEDGE call ff9725dd-4179-44ec-b114-f29f96a6501d for task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 (default) at scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940 on slave d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0
I1119 14:25:34.554172 30586 status_update_manager.cpp:394] Received status update acknowledgement (UUID: ff9725dd-4179-44ec-b114-f29f96a6501d) for task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
I1119 14:25:34.860929 30582 docker.cpp:1121] Updated 'cpu.shares' to 1024 at /sys/fs/cgroup/cpu,cpuacct/system.slice/docker-18bb532b8da0567511e474b0e0025a20b5686cc2e85569998a51db4c5d01db8b.scope for container b4e876f5-2f2d-4d72-9646-9ffcd15abf12
W1119 14:25:34.861140 30582 docker.cpp:1133] Container b4e876f5-2f2d-4d72-9646-9ffcd15abf12 does not appear to be a member of a cgroup where the 'memory' subsystem is mounted
../../src/tests/containerizer/docker_containerizer_tests.cpp:851: Failure
memoryHierarchy is NONE
I1119 14:25:34.867549 30584 master.cpp:1122] Framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 (default) at scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940 disconnected
I1119 14:25:34.867699 30584 master.cpp:2472] Disconnecting framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 (default) at scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940
I1119 14:25:34.868075 30584 master.cpp:2496] Deactivating framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 (default) at scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940
I1119 14:25:34.868333 30583 hierarchical.cpp:273] Deactivated framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
I1119 14:25:34.868360 30584 master.cpp:1146] Giving framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 (default) at scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940 0ns to failover
I1119 14:25:34.871822 30586 master.cpp:4827] Framework failover timeout, removing framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 (default) at scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940
I1119 14:25:34.872246 30586 master.cpp:5559] Removing framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 (default) at scheduler-fa6e39d4-95e2-4d62-ab10-2b77c05476e1@127.0.1.1:53940
I1119 14:25:34.873008 30588 slave.cpp:2009] Asked to shut down framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 by master@127.0.1.1:53940
I1119 14:25:34.873186 30588 slave.cpp:2034] Shutting down framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
I1119 14:25:34.873306 30586 master.cpp:6066] Updating the state of task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
I1119 14:25:34.873450 30588 slave.cpp:3863] Shutting down executor '1' of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 at executor(1)@127.0.1.1:55236
I1119 14:25:34.874265 30582 hierarchical.cpp:744] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: ) on slave d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0 from framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
I1119 14:25:34.874752 30586 master.cpp:6132] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 on slave d5a4b793-6ed8-42a4-89f9-f481f4576e36-S0 at slave(1)@127.0.1.1:53940 (debian-jessie.vagrantup.com)
I1119 14:25:34.876019 30586 hierarchical.cpp:230] Removed framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
I1119 14:25:35.169945 30583 slave.cpp:2762] Handling status update TASK_KILLED (UUID: a1a1b2fd-9692-4657-8955-d83f26bff119) for task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 from executor(1)@127.0.1.1:55236
W1119 14:25:35.170104 30583 slave.cpp:2813] Ignoring status update TASK_KILLED (UUID: a1a1b2fd-9692-4657-8955-d83f26bff119) for task 1 of framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000 for terminating framework d5a4b793-6ed8-42a4-89f9-f481f4576e36-0000
F1119 14:25:35.170104 30568 logging.cpp:57] RAW: Pure virtual method called
@ 0x7f52ef223058 google::LogMessage::Fail()
@ 0x7f52ef228658 google::RawLog__()
@ 0x7f52ee481d67 __cxa_pure_virtual
@ 0xa0af38 mesos::internal::tests::Cluster::Slaves::shutdown()
@ 0xa0ada4 mesos::internal::tests::Cluster::Slaves::~Slaves()
@ 0x94bc2e mesos::internal::tests::Cluster::~Cluster()
@ 0x94bc9f mesos::internal::tests::MesosTest::~MesosTest()
@ 0x131376d mesos::internal::tests::DockerContainerizerTest::~DockerContainerizerTest()
@ 0x132364d mesos::internal::tests::DockerContainerizerTest_ROOT_DOCKER_Update_Test::~DockerContainerizerTest_ROOT_DOCKER_Update_Test()
@ 0x132367c mesos::internal::tests::DockerContainerizerTest_ROOT_DOCKER_Update_Test::~DockerContainerizerTest_ROOT_DOCKER_Update_Test()
@ 0x1492004 testing::Test::DeleteSelf_()
@ 0x149c0a0 testing::internal::HandleSehExceptionsInMethodIfSupported<>()
@ 0x1497018 testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x1478b32 testing::TestInfo::Run()
@ 0x1479120 testing::TestCase::Run()
@ 0x147fa6f testing::internal::UnitTestImpl::RunAllTests()
@ 0x149cd2f testing::internal::HandleSehExceptionsInMethodIfSupported<>()
@ 0x1497b6e testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x147e79f testing::UnitTest::Run()
@ 0xd4f3ba RUN_ALL_TESTS()
@ 0xd4ef98 main
@ 0x7f52e9dc1b45 (unknown)
@ 0x944ac9 (unknown)