You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@mesos.apache.org by "Vaibhav Khanduja (JIRA)" <ji...@apache.org> on 2015/11/18 01:53:10 UTC
[jira] [Comment Edited] (MESOS-3937) Test
DockerContainerizerTest.ROOT_DOCKER_Launch_Executor fails.
[ https://issues.apache.org/jira/browse/MESOS-3937?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15009956#comment-15009956 ]
Vaibhav Khanduja edited comment on MESOS-3937 at 11/18/15 12:52 AM:
--------------------------------------------------------------------
Is the way Kernel was compiled ... possible not with .. CONFIG_MEMCG_SWAP_ENABLED .. ubuntu had that issue with 12.04 and I guess it carried forward with 14.04 trusty .. phusion seems to have solved the issue ... I ran into same issue on my local compile with vagrant and moving to kernel with this enabled, solved it ... please try this .. it might fix at your end too ... btw, there is suggestions on internet by making changes in grud file to solve this, they did not work for me ... but would be worth trying ...
add to:
/etc/default/grub:
GRUB_CMDLINE_LINUX_DEFAULT="cgroup_enable=memory swapaccount=1"
then sudo grub-update && sudo reboot
was (Author: vaibhavkhanduja):
Is the way Kernel was compiled ... possible not with .. CONFIG_MEMCG_SWAP_ENABLED .. ubuntu had that issue with 12.04 and I guess it carried forward with 14.04 trusty .. phusin seems to have solved the issue ... I ran into same issue on my local compile with vagrant and moving to kernel with this enabled solved it ... please try this .. it might fix at your end too ... btw, there is suggestions on net to make changes in grud file to solve this, they did not work for me ... but would be worth trying ...
add to:
/etc/default/grub:
GRUB_CMDLINE_LINUX_DEFAULT="cgroup_enable=memory swapaccount=1"
then sudo grub-update && sudo reboot
> Test DockerContainerizerTest.ROOT_DOCKER_Launch_Executor fails.
> ---------------------------------------------------------------
>
> Key: MESOS-3937
> URL: https://issues.apache.org/jira/browse/MESOS-3937
> Project: Mesos
> Issue Type: Bug
> Components: docker
> Affects Versions: 0.26.0
> Environment: Ubuntu 14.04, gcc 4.8.4, Docker version 1.6.2
> Reporter: Bernd Mathiske
>
> {noformat}
> ../configure
> make check
> sudo ./bin/mesos-tests.sh --gtest_filter="DockerContainerizerTest.ROOT_DOCKER_Launch_Executor" --verbose
> {noformat}
> {noformat}
> [==========] Running 1 test from 1 test case.
> [----------] Global test environment set-up.
> [----------] 1 test from DockerContainerizerTest
> I1117 15:08:09.265943 26380 leveldb.cpp:176] Opened db in 3.199666ms
> I1117 15:08:09.267761 26380 leveldb.cpp:183] Compacted db in 1.684873ms
> I1117 15:08:09.267902 26380 leveldb.cpp:198] Created db iterator in 58313ns
> I1117 15:08:09.267966 26380 leveldb.cpp:204] Seeked to beginning of db in 4927ns
> I1117 15:08:09.267997 26380 leveldb.cpp:273] Iterated through 0 keys in the db in 1605ns
> I1117 15:08:09.268156 26380 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> I1117 15:08:09.270148 26396 recover.cpp:449] Starting replica recovery
> I1117 15:08:09.272105 26396 recover.cpp:475] Replica is in EMPTY status
> I1117 15:08:09.275640 26396 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (4)@10.0.2.15:50088
> I1117 15:08:09.276578 26399 recover.cpp:195] Received a recover response from a replica in EMPTY status
> I1117 15:08:09.277600 26397 recover.cpp:566] Updating replica status to STARTING
> I1117 15:08:09.279613 26396 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 1.016098ms
> I1117 15:08:09.279731 26396 replica.cpp:323] Persisted replica status to STARTING
> I1117 15:08:09.280306 26399 recover.cpp:475] Replica is in STARTING status
> I1117 15:08:09.282181 26400 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (5)@10.0.2.15:50088
> I1117 15:08:09.282552 26400 master.cpp:367] Master 59c600f1-92ff-4926-9c84-073d9b81f68a (vagrant-ubuntu-trusty-64) started on 10.0.2.15:50088
> I1117 15:08:09.283021 26400 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/40AlT8/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/40AlT8/master" --zk_session_timeout="10secs"
> I1117 15:08:09.283920 26400 master.cpp:414] Master only allowing authenticated frameworks to register
> I1117 15:08:09.283972 26400 master.cpp:419] Master only allowing authenticated slaves to register
> I1117 15:08:09.284032 26400 credentials.hpp:37] Loading credentials for authentication from '/tmp/40AlT8/credentials'
> I1117 15:08:09.282944 26401 recover.cpp:195] Received a recover response from a replica in STARTING status
> I1117 15:08:09.284639 26401 recover.cpp:566] Updating replica status to VOTING
> I1117 15:08:09.285539 26400 master.cpp:458] Using default 'crammd5' authenticator
> I1117 15:08:09.285995 26401 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 1.075466ms
> I1117 15:08:09.286062 26401 replica.cpp:323] Persisted replica status to VOTING
> I1117 15:08:09.286200 26401 recover.cpp:580] Successfully joined the Paxos group
> I1117 15:08:09.286471 26401 recover.cpp:464] Recover process terminated
> I1117 15:08:09.287303 26400 authenticator.cpp:520] Initializing server SASL
> I1117 15:08:09.289371 26400 master.cpp:495] Authorization enabled
> I1117 15:08:09.296018 26399 master.cpp:1606] The newly elected leader is master@10.0.2.15:50088 with id 59c600f1-92ff-4926-9c84-073d9b81f68a
> I1117 15:08:09.296115 26399 master.cpp:1619] Elected as the leading master!
> I1117 15:08:09.296187 26399 master.cpp:1379] Recovering from registrar
> I1117 15:08:09.296717 26397 registrar.cpp:309] Recovering registrar
> I1117 15:08:09.298842 26396 log.cpp:661] Attempting to start the writer
> I1117 15:08:09.301563 26394 replica.cpp:496] Replica received implicit promise request from (6)@10.0.2.15:50088 with proposal 1
> I1117 15:08:09.302561 26394 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 922719ns
> I1117 15:08:09.302635 26394 replica.cpp:345] Persisted promised to 1
> I1117 15:08:09.303755 26394 coordinator.cpp:240] Coordinator attempting to fill missing positions
> I1117 15:08:09.306161 26394 replica.cpp:391] Replica received explicit promise request from (7)@10.0.2.15:50088 for position 0 with proposal 2
> I1117 15:08:09.306972 26394 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 711749ns
> I1117 15:08:09.307034 26394 replica.cpp:715] Persisted action at 0
> I1117 15:08:09.308732 26401 replica.cpp:540] Replica received write request for position 0 from (8)@10.0.2.15:50088
> I1117 15:08:09.308830 26401 leveldb.cpp:438] Reading position from leveldb took 46444ns
> I1117 15:08:09.309710 26401 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 779098ns
> I1117 15:08:09.309754 26401 replica.cpp:715] Persisted action at 0
> I1117 15:08:09.311007 26397 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
> I1117 15:08:09.311652 26397 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 567289ns
> I1117 15:08:09.311731 26397 replica.cpp:715] Persisted action at 0
> I1117 15:08:09.311771 26397 replica.cpp:700] Replica learned NOP action at position 0
> I1117 15:08:09.313212 26397 log.cpp:677] Writer started with ending position 0
> I1117 15:08:09.315682 26399 leveldb.cpp:438] Reading position from leveldb took 27974ns
> I1117 15:08:09.318694 26395 registrar.cpp:342] Successfully fetched the registry (0B) in 21.862144ms
> I1117 15:08:09.319007 26395 registrar.cpp:441] Applied 1 operations in 91867ns; attempting to update the 'registry'
> I1117 15:08:09.321730 26395 log.cpp:685] Attempting to append 193 bytes to the log
> I1117 15:08:09.321935 26397 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
> I1117 15:08:09.323103 26399 replica.cpp:540] Replica received write request for position 1 from (9)@10.0.2.15:50088
> I1117 15:08:09.323917 26399 leveldb.cpp:343] Persisting action (212 bytes) to leveldb took 735223ns
> I1117 15:08:09.323983 26399 replica.cpp:715] Persisted action at 1
> I1117 15:08:09.324975 26398 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
> I1117 15:08:09.325695 26398 leveldb.cpp:343] Persisting action (214 bytes) to leveldb took 668268ns
> I1117 15:08:09.325741 26398 replica.cpp:715] Persisted action at 1
> I1117 15:08:09.325778 26398 replica.cpp:700] Replica learned APPEND action at position 1
> I1117 15:08:09.327258 26396 registrar.cpp:486] Successfully updated the 'registry' in 8.090112ms
> I1117 15:08:09.327525 26396 registrar.cpp:372] Successfully recovered registrar
> I1117 15:08:09.328083 26400 log.cpp:704] Attempting to truncate the log to 1
> I1117 15:08:09.328251 26394 master.cpp:1416] Recovered 0 slaves from the Registry (154B) ; allowing 10mins for slaves to re-register
> I1117 15:08:09.328814 26396 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
> I1117 15:08:09.330158 26401 replica.cpp:540] Replica received write request for position 2 from (10)@10.0.2.15:50088
> I1117 15:08:09.330994 26401 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 760471ns
> I1117 15:08:09.331055 26401 replica.cpp:715] Persisted action at 2
> I1117 15:08:09.331583 26401 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
> I1117 15:08:09.332172 26401 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 497457ns
> I1117 15:08:09.332500 26401 leveldb.cpp:401] Deleting ~1 keys from leveldb took 49327ns
> I1117 15:08:09.332715 26401 replica.cpp:715] Persisted action at 2
> I1117 15:08:09.332964 26401 replica.cpp:700] Replica learned TRUNCATE action at position 2
> I1117 15:08:09.354073 26401 slave.cpp:191] Slave started on 1)@10.0.2.15:50088
> I1117 15:08:09.354316 26401 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_Launch_Executor_HaKhAQ/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_Launch_Executor_HaKhAQ/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_Launch_Executor_HaKhAQ"
> I1117 15:08:09.355077 26401 credentials.hpp:85] Loading credential for authentication from '/tmp/DockerContainerizerTest_ROOT_DOCKER_Launch_Executor_HaKhAQ/credential'
> I1117 15:08:09.355587 26401 slave.cpp:322] Slave using credential for: test-principal
> I1117 15:08:09.357144 26401 slave.cpp:392] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I1117 15:08:09.357477 26401 slave.cpp:400] Slave attributes: [ ]
> I1117 15:08:09.357719 26401 slave.cpp:405] Slave hostname: vagrant-ubuntu-trusty-64
> I1117 15:08:09.357936 26380 sched.cpp:166] Version: 0.26.0
> I1117 15:08:09.358010 26401 slave.cpp:410] Slave checkpoint: true
> I1117 15:08:09.359058 26400 sched.cpp:264] New master detected at master@10.0.2.15:50088
> I1117 15:08:09.359216 26400 sched.cpp:320] Authenticating with master master@10.0.2.15:50088
> I1117 15:08:09.359277 26400 sched.cpp:327] Using default CRAM-MD5 authenticatee
> I1117 15:08:09.359856 26400 authenticatee.cpp:99] Initializing client SASL
> I1117 15:08:09.360539 26400 authenticatee.cpp:123] Creating new client SASL connection
> I1117 15:08:09.361399 26398 state.cpp:54] Recovering state from '/tmp/DockerContainerizerTest_ROOT_DOCKER_Launch_Executor_HaKhAQ/meta'
> I1117 15:08:09.361994 26398 status_update_manager.cpp:202] Recovering status update manager
> I1117 15:08:09.362191 26395 master.cpp:5150] Authenticating scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088
> I1117 15:08:09.362565 26401 docker.cpp:536] Recovering Docker containers
> I1117 15:08:09.362908 26395 authenticator.cpp:100] Creating new server SASL connection
> I1117 15:08:09.363533 26401 slave.cpp:4230] Finished recovery
> I1117 15:08:09.363675 26394 authenticatee.cpp:214] Received SASL authentication mechanisms: CRAM-MD5
> I1117 15:08:09.363950 26394 authenticatee.cpp:240] Attempting to authenticate with mechanism 'CRAM-MD5'
> I1117 15:08:09.364137 26394 authenticator.cpp:205] Received SASL authentication start
> I1117 15:08:09.364241 26394 authenticator.cpp:327] Authentication requires more steps
> I1117 15:08:09.364481 26394 authenticatee.cpp:260] Received SASL authentication step
> I1117 15:08:09.364667 26394 authenticator.cpp:233] Received SASL authentication step
> I1117 15:08:09.364828 26394 authenticator.cpp:319] Authentication success
> I1117 15:08:09.365039 26398 authenticatee.cpp:300] Authentication success
> I1117 15:08:09.365170 26398 master.cpp:5180] Successfully authenticated principal 'test-principal' at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088
> I1117 15:08:09.365656 26398 sched.cpp:409] Successfully authenticated with master master@10.0.2.15:50088
> I1117 15:08:09.366044 26401 slave.cpp:729] New master detected at master@10.0.2.15:50088
> I1117 15:08:09.366283 26398 master.cpp:2176] Received SUBSCRIBE call for framework 'default' at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088
> I1117 15:08:09.366317 26401 slave.cpp:792] Authenticating with master master@10.0.2.15:50088
> I1117 15:08:09.366688 26401 slave.cpp:797] Using default CRAM-MD5 authenticatee
> I1117 15:08:09.366525 26395 status_update_manager.cpp:176] Pausing sending status updates
> I1117 15:08:09.366442 26398 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
> I1117 15:08:09.367207 26401 slave.cpp:765] Detecting new master
> I1117 15:08:09.367496 26395 master.cpp:2247] Subscribing framework default with checkpointing disabled and capabilities [ ]
> I1117 15:08:09.368417 26396 hierarchical.cpp:195] Added framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:08:09.367250 26398 authenticatee.cpp:123] Creating new client SASL connection
> I1117 15:08:09.368506 26395 sched.cpp:643] Framework registered with 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:08:09.369287 26398 master.cpp:5150] Authenticating slave(1)@10.0.2.15:50088
> I1117 15:08:09.370213 26401 authenticator.cpp:100] Creating new server SASL connection
> I1117 15:08:09.370846 26396 authenticatee.cpp:214] Received SASL authentication mechanisms: CRAM-MD5
> I1117 15:08:09.370964 26396 authenticatee.cpp:240] Attempting to authenticate with mechanism 'CRAM-MD5'
> I1117 15:08:09.371233 26396 authenticator.cpp:205] Received SASL authentication start
> I1117 15:08:09.371387 26396 authenticator.cpp:327] Authentication requires more steps
> I1117 15:08:09.371707 26398 authenticatee.cpp:260] Received SASL authentication step
> I1117 15:08:09.371835 26398 authenticator.cpp:233] Received SASL authentication step
> I1117 15:08:09.371944 26398 authenticator.cpp:319] Authentication success
> I1117 15:08:09.372195 26396 authenticatee.cpp:300] Authentication success
> I1117 15:08:09.372248 26398 master.cpp:5180] Successfully authenticated principal 'test-principal' at slave(1)@10.0.2.15:50088
> I1117 15:08:09.373002 26396 slave.cpp:860] Successfully authenticated with master master@10.0.2.15:50088
> I1117 15:08:09.373566 26398 master.cpp:3859] Registering slave at slave(1)@10.0.2.15:50088 (vagrant-ubuntu-trusty-64) with id 59c600f1-92ff-4926-9c84-073d9b81f68a-S0
> I1117 15:08:09.374301 26401 registrar.cpp:441] Applied 1 operations in 65094ns; attempting to update the 'registry'
> I1117 15:08:09.376809 26400 log.cpp:685] Attempting to append 374 bytes to the log
> I1117 15:08:09.376994 26399 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 3
> I1117 15:08:09.377960 26397 replica.cpp:540] Replica received write request for position 3 from (16)@10.0.2.15:50088
> I1117 15:08:09.378844 26397 leveldb.cpp:343] Persisting action (393 bytes) to leveldb took 805302ns
> I1117 15:08:09.378904 26397 replica.cpp:715] Persisted action at 3
> I1117 15:08:09.379823 26400 replica.cpp:694] Replica received learned notice for position 3 from @0.0.0.0:0
> I1117 15:08:09.380592 26400 leveldb.cpp:343] Persisting action (395 bytes) to leveldb took 691729ns
> I1117 15:08:09.380666 26400 replica.cpp:715] Persisted action at 3
> I1117 15:08:09.380702 26400 replica.cpp:700] Replica learned APPEND action at position 3
> I1117 15:08:09.382014 26398 registrar.cpp:486] Successfully updated the 'registry' in 7.384064ms
> I1117 15:08:09.382184 26400 log.cpp:704] Attempting to truncate the log to 3
> I1117 15:08:09.382380 26398 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 4
> I1117 15:08:09.383361 26399 master.cpp:3927] Registered slave 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 at slave(1)@10.0.2.15:50088 (vagrant-ubuntu-trusty-64) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I1117 15:08:09.383437 26396 slave.cpp:904] Registered with master master@10.0.2.15:50088; given slave ID 59c600f1-92ff-4926-9c84-073d9b81f68a-S0
> I1117 15:08:09.383741 26400 status_update_manager.cpp:183] Resuming sending status updates
> I1117 15:08:09.384004 26401 hierarchical.cpp:344] Added slave 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 (vagrant-ubuntu-trusty-64) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
> I1117 15:08:09.384101 26396 slave.cpp:963] Forwarding total oversubscribed resources
> I1117 15:08:09.384831 26396 master.cpp:4269] Received update of slave 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 at slave(1)@10.0.2.15:50088 (vagrant-ubuntu-trusty-64) with total oversubscribed resources
> I1117 15:08:09.384466 26398 replica.cpp:540] Replica received write request for position 4 from (17)@10.0.2.15:50088
> I1117 15:08:09.385957 26397 master.cpp:4979] Sending 1 offers to framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (default) at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088
> I1117 15:08:09.386066 26401 hierarchical.cpp:400] Slave 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 (vagrant-ubuntu-trusty-64) updated with oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000])
> I1117 15:08:09.386219 26398 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 605641ns
> I1117 15:08:09.386445 26398 replica.cpp:715] Persisted action at 4
> I1117 15:08:09.388450 26397 replica.cpp:694] Replica received learned notice for position 4 from @0.0.0.0:0
> I1117 15:08:09.389235 26397 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 715846ns
> I1117 15:08:09.389345 26397 leveldb.cpp:401] Deleting ~2 keys from leveldb took 40455ns
> I1117 15:08:09.389402 26397 replica.cpp:715] Persisted action at 4
> I1117 15:08:09.389464 26397 replica.cpp:700] Replica learned TRUNCATE action at position 4
> I1117 15:08:09.390585 26394 master.cpp:2915] Processing ACCEPT call for offers: [ 59c600f1-92ff-4926-9c84-073d9b81f68a-O0 ] on slave 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 at slave(1)@10.0.2.15:50088 (vagrant-ubuntu-trusty-64) for framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (default) at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088
> I1117 15:08:09.390805 26394 master.cpp:2711] Authorizing framework principal 'test-principal' to launch task 1 as user 'root'
> W1117 15:08:09.393517 26396 validation.cpp:422] Executor e1 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.
> W1117 15:08:09.393632 26396 validation.cpp:434] Executor e1 for task 1 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
> I1117 15:08:09.394270 26396 master.hpp:176] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 (vagrant-ubuntu-trusty-64)
> I1117 15:08:09.394580 26396 master.cpp:3245] Launching task 1 of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (default) at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 at slave(1)@10.0.2.15:50088 (vagrant-ubuntu-trusty-64)
> I1117 15:08:09.395247 26396 slave.cpp:1294] Got assigned task 1 for framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:08:09.396234 26396 slave.cpp:1410] Launching task 1 for framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:08:09.398111 26396 paths.cpp:436] Trying to chown '/tmp/DockerContainerizerTest_ROOT_DOCKER_Launch_Executor_HaKhAQ/slaves/59c600f1-92ff-4926-9c84-073d9b81f68a-S0/frameworks/59c600f1-92ff-4926-9c84-073d9b81f68a-0000/executors/e1/runs/e00106a7-b249-41c7-bff1-739485fe2d15' to user 'root'
> I1117 15:08:09.402022 26396 slave.cpp:4999] Launching executor e1 of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 with resources in work directory '/tmp/DockerContainerizerTest_ROOT_DOCKER_Launch_Executor_HaKhAQ/slaves/59c600f1-92ff-4926-9c84-073d9b81f68a-S0/frameworks/59c600f1-92ff-4926-9c84-073d9b81f68a-0000/executors/e1/runs/e00106a7-b249-41c7-bff1-739485fe2d15'
> I1117 15:08:09.405066 26396 slave.cpp:1628] Queuing task '1' for executor 'e1' of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:08:09.407642 26399 docker.cpp:767] Starting container 'e00106a7-b249-41c7-bff1-739485fe2d15' for executor 'e1' and framework '59c600f1-92ff-4926-9c84-073d9b81f68a-0000'
> E1117 15:08:09.976763 26396 slave.cpp:3440] Container 'e00106a7-b249-41c7-bff1-739485fe2d15' for executor 'e1' of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 failed to start: Container exited on error: exited with status 255
> I1117 15:08:09.977694 26400 slave.cpp:3546] Executor 'e1' of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 has terminated with unknown status
> I1117 15:08:09.979370 26400 slave.cpp:2762] Handling status update TASK_FAILED (UUID: c414cb06-6240-4893-b6ae-c2adec5258c3) for task 1 of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 from @0.0.0.0:0
> W1117 15:08:09.980294 26400 docker.cpp:998] Ignoring updating unknown container: e00106a7-b249-41c7-bff1-739485fe2d15
> I1117 15:08:09.980996 26400 master.cpp:4516] Executor 'e1' of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 on slave 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 at slave(1)@10.0.2.15:50088 (vagrant-ubuntu-trusty-64): terminated with signal Unknown signal 127
> I1117 15:08:09.981009 26401 status_update_manager.cpp:322] Received status update TASK_FAILED (UUID: c414cb06-6240-4893-b6ae-c2adec5258c3) for task 1 of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:08:09.981204 26400 master.cpp:6161] Removing executor 'e1' with resources of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 on slave 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 at slave(1)@10.0.2.15:50088 (vagrant-ubuntu-trusty-64)
> I1117 15:08:09.982161 26401 slave.cpp:3087] Forwarding the update TASK_FAILED (UUID: c414cb06-6240-4893-b6ae-c2adec5258c3) for task 1 of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 to master@10.0.2.15:50088
> I1117 15:08:09.982632 26401 master.cpp:4414] Status update TASK_FAILED (UUID: c414cb06-6240-4893-b6ae-c2adec5258c3) for task 1 of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 from slave 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 at slave(1)@10.0.2.15:50088 (vagrant-ubuntu-trusty-64)
> I1117 15:08:09.982789 26401 master.cpp:4462] Forwarding status update TASK_FAILED (UUID: c414cb06-6240-4893-b6ae-c2adec5258c3) for task 1 of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:08:09.983026 26401 master.cpp:6066] Updating the state of task 1 of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
> ../../src/tests/containerizer/docker_containerizer_tests.cpp:255: Failure
> Value of: statusRunning.get().state()
> Actual: TASK_FAILED
> Expected: TASK_RUNNING
> I1117 15:08:09.985121 26395 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 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 from framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:08:09.985277 26401 master.cpp:3571] Processing ACKNOWLEDGE call c414cb06-6240-4893-b6ae-c2adec5258c3 for task 1 of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (default) at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088 on slave 59c600f1-92ff-4926-9c84-073d9b81f68a-S0
> I1117 15:08:09.985471 26401 master.cpp:6132] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 on slave 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 at slave(1)@10.0.2.15:50088 (vagrant-ubuntu-trusty-64)
> I1117 15:08:09.986150 26394 status_update_manager.cpp:394] Received status update acknowledgement (UUID: c414cb06-6240-4893-b6ae-c2adec5258c3) for task 1 of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:08:09.986804 26394 slave.cpp:3657] Cleaning up executor 'e1' of framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:08:09.987223 26401 gc.cpp:56] Scheduling '/tmp/DockerContainerizerTest_ROOT_DOCKER_Launch_Executor_HaKhAQ/slaves/59c600f1-92ff-4926-9c84-073d9b81f68a-S0/frameworks/59c600f1-92ff-4926-9c84-073d9b81f68a-0000/executors/e1/runs/e00106a7-b249-41c7-bff1-739485fe2d15' for gc 6.99998857599407days in the future
> I1117 15:08:09.987319 26394 slave.cpp:3745] Cleaning up framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:08:09.987622 26397 status_update_manager.cpp:284] Closing status update streams for framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:08:09.987833 26401 gc.cpp:56] Scheduling '/tmp/DockerContainerizerTest_ROOT_DOCKER_Launch_Executor_HaKhAQ/slaves/59c600f1-92ff-4926-9c84-073d9b81f68a-S0/frameworks/59c600f1-92ff-4926-9c84-073d9b81f68a-0000/executors/e1' for gc 6.99998857381037days in the future
> I1117 15:08:09.987995 26401 gc.cpp:56] Scheduling '/tmp/DockerContainerizerTest_ROOT_DOCKER_Launch_Executor_HaKhAQ/slaves/59c600f1-92ff-4926-9c84-073d9b81f68a-S0/frameworks/59c600f1-92ff-4926-9c84-073d9b81f68a-0000' for gc 6.99998856968593days in the future
> I1117 15:08:10.300747 26395 master.cpp:4979] Sending 1 offers to framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (default) at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088
> I1117 15:09:09.400656 26395 slave.cpp:4039] Current disk usage 14.14%. Max allowed age: 5.310351133117882days
> I1117 15:09:09.848752 26396 slave.cpp:3947] Framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 seems to have exited. Ignoring registration timeout for executor 'e1'
> ../../src/tests/containerizer/docker_containerizer_tests.cpp:256: Failure
> Failed to wait 1mins for statusFinished
> ../../src/tests/containerizer/docker_containerizer_tests.cpp:247: Failure
> Actual function call count doesn't match EXPECT_CALL(sched, statusUpdate(&driver, _))...
> Expected: to be called twice
> Actual: called once - unsatisfied and active
> I1117 15:09:09.993629 26396 master.cpp:1122] Framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (default) at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088 disconnected
> I1117 15:09:09.993923 26396 master.cpp:2472] Disconnecting framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (default) at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088
> I1117 15:09:09.993984 26396 master.cpp:2496] Deactivating framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (default) at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088
> W1117 15:09:09.994297 26396 master.hpp:1540] Master attempted to send message to disconnected framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (default) at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088
> I1117 15:09:09.994554 26396 master.cpp:1146] Giving framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (default) at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088 0ns to failover
> I1117 15:09:09.994380 26400 hierarchical.cpp:273] Deactivated framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:09:09.994999 26400 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 59c600f1-92ff-4926-9c84-073d9b81f68a-S0 from framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:09:09.998314 26395 master.cpp:4827] Framework failover timeout, removing framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (default) at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088
> I1117 15:09:09.998366 26395 master.cpp:5559] Removing framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 (default) at scheduler-38aa807a-672a-4e1e-b823-71f119980e86@10.0.2.15:50088
> I1117 15:09:09.998642 26401 slave.cpp:2009] Asked to shut down framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000 by master@10.0.2.15:50088
> W1117 15:09:09.998677 26401 slave.cpp:2024] Cannot shut down unknown framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> I1117 15:09:09.999388 26400 hierarchical.cpp:230] Removed framework 59c600f1-92ff-4926-9c84-073d9b81f68a-0000
> F1117 15:09:09.999388 26380 logging.cpp:57] RAW: Pure virtual method called
> @ 0x7f62e980e918 google::LogMessage::Fail()
> @ 0x7f62e981403e google::RawLog__()
> @ 0x7f62e8aa0adc __cxa_pure_virtual
> @ 0x9d8e17 mesos::internal::tests::Cluster::Slaves::shutdown()
> @ 0x9d8c62 mesos::internal::tests::Cluster::Slaves::~Slaves()
> @ 0x91a048 mesos::internal::tests::Cluster::~Cluster()
> @ 0x91a0b9 mesos::internal::tests::MesosTest::~MesosTest()
> @ 0x12dd9d1 mesos::internal::tests::DockerContainerizerTest::~DockerContainerizerTest()
> @ 0x12ed7cd mesos::internal::tests::DockerContainerizerTest_ROOT_DOCKER_Launch_Executor_Test::~DockerContainerizerTest_ROOT_DOCKER_Launch_Executor_Test()
> @ 0x12ed7fc mesos::internal::tests::DockerContainerizerTest_ROOT_DOCKER_Launch_Executor_Test::~DockerContainerizerTest_ROOT_DOCKER_Launch_Executor_Test()
> @ 0x1457316 testing::Test::DeleteSelf_()
> @ 0x14614e4 testing::internal::HandleSehExceptionsInMethodIfSupported<>()
> @ 0x145c35a testing::internal::HandleExceptionsInMethodIfSupported<>()
> @ 0x143e233 testing::TestInfo::Run()
> @ 0x143e82c testing::TestCase::Run()
> @ 0x1444f74 testing::internal::UnitTestImpl::RunAllTests()
> @ 0x1462109 testing::internal::HandleSehExceptionsInMethodIfSupported<>()
> @ 0x145ced0 testing::internal::HandleExceptionsInMethodIfSupported<>()
> @ 0x1443d10 testing::UnitTest::Run()
> @ 0xd1589a RUN_ALL_TESTS()
> @ 0xd15487 main
> @ 0x7f62e4482ec5 (unknown)
> @ 0x912f99 (unknown)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)