[
https://issues.apache.org/jira/browse/MESOS-3937?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Jan Schlicht updated MESOS-3937:
--------------------------------
Comment: was deleted
(was: Running {{sudo docker run --rm --hostname foo -it tnachen/test-executor
cat /etc/hosts}} shows the expected behavior ({{/etc/hosts}} being changed) but
running {{docker run --rm --hostname foo -it tnachen/test-executor
./bin/test-executor & cat /etc/hosts}} shows the problem.
As the executor is written in Go it should be this docker bug:
https://github.com/docker/docker/issues/17190. Racy conditions are triggered
because Docker and the Executor are both written in Go, resulting in
{{/etc/hosts}} not being changed by Docker, alas being the same as the one of
the host. Because Mesos' containerizer reuses the agents hostname for
containers, hostname resolution in the container won't fail if the agents
{{/etc/hosts}} contains an entry for the hostame.)
> 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
> 8 CPUs, 16 GB memory
> Vagrant, libvirt/Virtual Box or VMware
> Reporter: Bernd Mathiske
> Assignee: Jan Schlicht
> Labels: mesosphere
>
> {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)
