[ https://issues.apache.org/jira/browse/MESOS-4030?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Till Toenshoff updated MESOS-4030: ---------------------------------- Component/s: test > DockerContainerizerTest.ROOT_DOCKER_NC_PortMapping is flaky > ----------------------------------------------------------- > > Key: MESOS-4030 > URL: https://issues.apache.org/jira/browse/MESOS-4030 > Project: Mesos > Issue Type: Bug > Components: test > Environment: [Ubuntu > 14|https://github.com/tillt/mesos-vagrant-ci/blob/master/ubuntu14/setup.sh], > 0.26.0 RC (wip) enable-ssl & enable-libevent, root test-run > Reporter: Till Toenshoff > Labels: flaky, flaky-test > > {noformat} > [ RUN ] DockerContainerizerTest.ROOT_DOCKER_NC_PortMapping > I1201 02:18:00.325283 18931 leveldb.cpp:176] Opened db in 3.877576ms > I1201 02:18:00.326195 18931 leveldb.cpp:183] Compacted db in 831923ns > I1201 02:18:00.326288 18931 leveldb.cpp:198] Created db iterator in 21460ns > I1201 02:18:00.326305 18931 leveldb.cpp:204] Seeked to beginning of db in > 1431ns > I1201 02:18:00.326316 18931 leveldb.cpp:273] Iterated through 0 keys in the > db in 178ns > I1201 02:18:00.326354 18931 replica.cpp:780] Replica recovered with log > positions 0 -> 0 with 1 holes and 0 unlearned > I1201 02:18:00.327128 18952 recover.cpp:449] Starting replica recovery > I1201 02:18:00.327481 18948 recover.cpp:475] Replica is in EMPTY status > I1201 02:18:00.328354 18945 replica.cpp:676] Replica in EMPTY status received > a broadcasted recover request from (88123)@127.0.1.1:45788 > I1201 02:18:00.328660 18950 recover.cpp:195] Received a recover response from > a replica in EMPTY status > I1201 02:18:00.329139 18951 recover.cpp:566] Updating replica status to > STARTING > I1201 02:18:00.330413 18949 master.cpp:367] Master > 9577131b-f0b1-47bd-8f88-f5edbf2f026d (ubuntu14) started on 127.0.1.1:45788 > I1201 02:18:00.330474 18949 master.cpp:369] Flags at startup: --acls="" > --allocation_interval="1secs" --allocator="HierarchicalDRF" > --authenticate="true" --authenticate_slaves="true" --authenticators="crammd5" > --authorizers="local" --credentials="/tmp/dHFLJX/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/dHFLJX/master" > --zk_session_timeout="10secs" > I1201 02:18:00.330662 18949 master.cpp:414] Master only allowing > authenticated frameworks to register > I1201 02:18:00.330670 18949 master.cpp:419] Master only allowing > authenticated slaves to register > I1201 02:18:00.330682 18949 credentials.hpp:37] Loading credentials for > authentication from '/tmp/dHFLJX/credentials' > I1201 02:18:00.330950 18945 leveldb.cpp:306] Persisting metadata (8 bytes) to > leveldb took 1.585892ms > I1201 02:18:00.331248 18945 replica.cpp:323] Persisted replica status to > STARTING > I1201 02:18:00.330968 18949 master.cpp:458] Using default 'crammd5' > authenticator > I1201 02:18:00.331681 18949 master.cpp:495] Authorization enabled > I1201 02:18:00.331717 18945 recover.cpp:475] Replica is in STARTING status > I1201 02:18:00.332875 18947 replica.cpp:676] Replica in STARTING status > received a broadcasted recover request from (88124)@127.0.1.1:45788 > I1201 02:18:00.333344 18947 recover.cpp:195] Received a recover response from > a replica in STARTING status > I1201 02:18:00.333760 18950 recover.cpp:566] Updating replica status to VOTING > I1201 02:18:00.333875 18945 master.cpp:1606] The newly elected leader is > master@127.0.1.1:45788 with id 9577131b-f0b1-47bd-8f88-f5edbf2f026d > I1201 02:18:00.334624 18951 leveldb.cpp:306] Persisting metadata (8 bytes) to > leveldb took 307292ns > I1201 02:18:00.334652 18951 replica.cpp:323] Persisted replica status to > VOTING > I1201 02:18:00.334656 18945 master.cpp:1619] Elected as the leading master! > I1201 02:18:00.334758 18951 recover.cpp:580] Successfully joined the Paxos > group > I1201 02:18:00.334933 18945 master.cpp:1379] Recovering from registrar > I1201 02:18:00.335108 18951 recover.cpp:464] Recover process terminated > I1201 02:18:00.335183 18951 registrar.cpp:309] Recovering registrar > I1201 02:18:00.335577 18950 log.cpp:661] Attempting to start the writer > I1201 02:18:00.336777 18952 replica.cpp:496] Replica received implicit > promise request from (88125)@127.0.1.1:45788 with proposal 1 > I1201 02:18:00.337200 18952 leveldb.cpp:306] Persisting metadata (8 bytes) to > leveldb took 377903ns > I1201 02:18:00.337235 18952 replica.cpp:345] Persisted promised to 1 > I1201 02:18:00.337725 18948 coordinator.cpp:240] Coordinator attempting to > fill missing positions > I1201 02:18:00.338968 18945 replica.cpp:391] Replica received explicit > promise request from (88126)@127.0.1.1:45788 for position 0 with proposal 2 > I1201 02:18:00.339468 18945 leveldb.cpp:343] Persisting action (8 bytes) to > leveldb took 254651ns > I1201 02:18:00.339565 18945 replica.cpp:715] Persisted action at 0 > I1201 02:18:00.340770 18945 replica.cpp:540] Replica received write request > for position 0 from (88127)@127.0.1.1:45788 > I1201 02:18:00.340873 18945 leveldb.cpp:438] Reading position from leveldb > took 32475ns > I1201 02:18:00.341209 18945 leveldb.cpp:343] Persisting action (14 bytes) to > leveldb took 258750ns > I1201 02:18:00.341254 18945 replica.cpp:715] Persisted action at 0 > I1201 02:18:00.341680 18945 replica.cpp:694] Replica received learned notice > for position 0 from @0.0.0.0:0 > I1201 02:18:00.342133 18945 leveldb.cpp:343] Persisting action (16 bytes) to > leveldb took 203599ns > I1201 02:18:00.342175 18945 replica.cpp:715] Persisted action at 0 > I1201 02:18:00.342192 18945 replica.cpp:700] Replica learned NOP action at > position 0 > I1201 02:18:00.342663 18949 log.cpp:677] Writer started with ending position 0 > I1201 02:18:00.343571 18949 leveldb.cpp:438] Reading position from leveldb > took 25359ns > I1201 02:18:00.344327 18946 registrar.cpp:342] Successfully fetched the > registry (0B) in 9.10592ms > I1201 02:18:00.344470 18946 registrar.cpp:441] Applied 1 operations in > 25617ns; attempting to update the 'registry' > I1201 02:18:00.344972 18951 log.cpp:685] Attempting to append 158 bytes to > the log > I1201 02:18:00.345088 18946 coordinator.cpp:350] Coordinator attempting to > write APPEND action at position 1 > I1201 02:18:00.345747 18949 replica.cpp:540] Replica received write request > for position 1 from (88128)@127.0.1.1:45788 > I1201 02:18:00.346061 18949 leveldb.cpp:343] Persisting action (177 bytes) to > leveldb took 278973ns > I1201 02:18:00.346106 18949 replica.cpp:715] Persisted action at 1 > I1201 02:18:00.346619 18948 replica.cpp:694] Replica received learned notice > for position 1 from @0.0.0.0:0 > I1201 02:18:00.346879 18948 leveldb.cpp:343] Persisting action (179 bytes) to > leveldb took 228650ns > I1201 02:18:00.346925 18948 replica.cpp:715] Persisted action at 1 > I1201 02:18:00.346945 18948 replica.cpp:700] Replica learned APPEND action at > position 1 > I1201 02:18:00.347740 18949 registrar.cpp:486] Successfully updated the > 'registry' in 3.218944ms > I1201 02:18:00.347865 18949 registrar.cpp:372] Successfully recovered > registrar > I1201 02:18:00.347954 18948 log.cpp:704] Attempting to truncate the log to 1 > I1201 02:18:00.348150 18952 coordinator.cpp:350] Coordinator attempting to > write TRUNCATE action at position 2 > I1201 02:18:00.348173 18949 master.cpp:1416] Recovered 0 slaves from the > Registry (120B) ; allowing 10mins for slaves to re-register > I1201 02:18:00.348839 18952 replica.cpp:540] Replica received write request > for position 2 from (88129)@127.0.1.1:45788 > I1201 02:18:00.349135 18952 leveldb.cpp:343] Persisting action (16 bytes) to > leveldb took 260954ns > I1201 02:18:00.349159 18952 replica.cpp:715] Persisted action at 2 > I1201 02:18:00.349786 18951 replica.cpp:694] Replica received learned notice > for position 2 from @0.0.0.0:0 > I1201 02:18:00.350144 18951 leveldb.cpp:343] Persisting action (18 bytes) to > leveldb took 235916ns > I1201 02:18:00.350208 18951 leveldb.cpp:401] Deleting ~1 keys from leveldb > took 22017ns > I1201 02:18:00.350222 18951 replica.cpp:715] Persisted action at 2 > I1201 02:18:00.350239 18951 replica.cpp:700] Replica learned TRUNCATE action > at position 2 > I1201 02:18:00.364928 18950 slave.cpp:191] Slave started on > 2684)@127.0.1.1:45788 > I1201 02:18:00.365010 18950 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_NC_PortMapping_nnBZ8r/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_NC_PortMapping_nnBZ8r/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:1;mem:1024;ports:[10000-10000]" > --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_NC_PortMapping_nnBZ8r" > I1201 02:18:00.365272 18950 credentials.hpp:85] Loading credential for > authentication from > '/tmp/DockerContainerizerTest_ROOT_DOCKER_NC_PortMapping_nnBZ8r/credential' > I1201 02:18:00.365859 18950 slave.cpp:322] Slave using credential for: > test-principal > I1201 02:18:00.366387 18950 slave.cpp:392] Slave resources: cpus(*):1; > mem(*):1024; ports(*):[10000-10000]; disk(*):34068 > I1201 02:18:00.366448 18950 slave.cpp:400] Slave attributes: [ ] > I1201 02:18:00.366461 18950 slave.cpp:405] Slave hostname: ubuntu14 > I1201 02:18:00.366471 18950 slave.cpp:410] Slave checkpoint: true > I1201 02:18:00.366482 18931 sched.cpp:166] Version: 0.26.0 > I1201 02:18:00.367183 18950 sched.cpp:264] New master detected at > master@127.0.1.1:45788 > I1201 02:18:00.367272 18950 sched.cpp:320] Authenticating with master > master@127.0.1.1:45788 > I1201 02:18:00.367290 18950 sched.cpp:327] Using default CRAM-MD5 > authenticatee > I1201 02:18:00.367285 18947 state.cpp:54] Recovering state from > '/tmp/DockerContainerizerTest_ROOT_DOCKER_NC_PortMapping_nnBZ8r/meta' > I1201 02:18:00.367503 18948 authenticatee.cpp:123] Creating new client SASL > connection > I1201 02:18:00.368007 18945 status_update_manager.cpp:202] Recovering status > update manager > I1201 02:18:00.368036 18948 master.cpp:5150] Authenticating > scheduler-ce98c85f-caf7-4fc2-8489-e495997d85a2@127.0.1.1:45788 > I1201 02:18:00.368218 18947 docker.cpp:536] Recovering Docker containers > I1201 02:18:00.368382 18947 slave.cpp:4230] Finished recovery > I1201 02:18:00.368770 18949 authenticator.cpp:100] Creating new server SASL > connection > I1201 02:18:00.369230 18949 authenticatee.cpp:214] Received SASL > authentication mechanisms: CRAM-MD5 > I1201 02:18:00.369258 18949 authenticatee.cpp:240] Attempting to authenticate > with mechanism 'CRAM-MD5' > I1201 02:18:00.369276 18947 slave.cpp:729] New master detected at > master@127.0.1.1:45788 > I1201 02:18:00.369437 18947 slave.cpp:792] Authenticating with master > master@127.0.1.1:45788 > I1201 02:18:00.369457 18947 slave.cpp:797] Using default CRAM-MD5 > authenticatee > I1201 02:18:00.369376 18946 authenticator.cpp:205] Received SASL > authentication start > I1201 02:18:00.369617 18946 authenticator.cpp:327] Authentication requires > more steps > I1201 02:18:00.369724 18952 authenticatee.cpp:260] Received SASL > authentication step > I1201 02:18:00.369735 18950 authenticatee.cpp:123] Creating new client SASL > connection > I1201 02:18:00.369889 18952 authenticator.cpp:233] Received SASL > authentication step > I1201 02:18:00.370023 18952 authenticator.cpp:319] Authentication success > I1201 02:18:00.370049 18946 master.cpp:5150] Authenticating > slave(2684)@127.0.1.1:45788 > I1201 02:18:00.370193 18952 authenticatee.cpp:300] Authentication success > I1201 02:18:00.370312 18946 master.cpp:5180] Successfully authenticated > principal 'test-principal' at > scheduler-ce98c85f-caf7-4fc2-8489-e495997d85a2@127.0.1.1:45788 > I1201 02:18:00.369740 18947 slave.cpp:765] Detecting new master > I1201 02:18:00.369304 18949 status_update_manager.cpp:176] Pausing sending > status updates > I1201 02:18:00.370473 18945 authenticator.cpp:100] Creating new server SASL > connection > I1201 02:18:00.370939 18952 sched.cpp:409] Successfully authenticated with > master master@127.0.1.1:45788 > I1201 02:18:00.371057 18950 authenticatee.cpp:214] Received SASL > authentication mechanisms: CRAM-MD5 > I1201 02:18:00.371094 18950 authenticatee.cpp:240] Attempting to authenticate > with mechanism 'CRAM-MD5' > I1201 02:18:00.371177 18945 master.cpp:2176] Received SUBSCRIBE call for > framework 'default' at > scheduler-ce98c85f-caf7-4fc2-8489-e495997d85a2@127.0.1.1:45788 > I1201 02:18:00.371233 18950 authenticator.cpp:205] Received SASL > authentication start > I1201 02:18:00.371269 18945 master.cpp:1645] Authorizing framework principal > 'test-principal' to receive offers for role '*' > I1201 02:18:00.371312 18950 authenticator.cpp:327] Authentication requires > more steps > I1201 02:18:00.371520 18951 authenticatee.cpp:260] Received SASL > authentication step > I1201 02:18:00.371672 18948 master.cpp:2247] Subscribing framework default > with checkpointing disabled and capabilities [ ] > I1201 02:18:00.372081 18950 hierarchical.cpp:195] Added framework > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 > I1201 02:18:00.372110 18948 sched.cpp:643] Framework registered with > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 > I1201 02:18:00.372175 18946 authenticator.cpp:233] Received SASL > authentication step > I1201 02:18:00.372274 18946 authenticator.cpp:319] Authentication success > I1201 02:18:00.372493 18950 authenticatee.cpp:300] Authentication success > I1201 02:18:00.372541 18946 master.cpp:5180] Successfully authenticated > principal 'test-principal' at slave(2684)@127.0.1.1:45788 > I1201 02:18:00.372917 18946 slave.cpp:860] Successfully authenticated with > master master@127.0.1.1:45788 > I1201 02:18:00.373227 18951 master.cpp:3859] Registering slave at > slave(2684)@127.0.1.1:45788 (ubuntu14) with id > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 > I1201 02:18:00.373683 18946 registrar.cpp:441] Applied 1 operations in > 42387ns; attempting to update the 'registry' > I1201 02:18:00.374644 18946 log.cpp:685] Attempting to append 322 bytes to > the log > I1201 02:18:00.374825 18948 coordinator.cpp:350] Coordinator attempting to > write APPEND action at position 3 > I1201 02:18:00.375551 18952 replica.cpp:540] Replica received write request > for position 3 from (88135)@127.0.1.1:45788 > I1201 02:18:00.376076 18952 leveldb.cpp:343] Persisting action (341 bytes) to > leveldb took 449684ns > I1201 02:18:00.376128 18952 replica.cpp:715] Persisted action at 3 > I1201 02:18:00.376878 18949 replica.cpp:694] Replica received learned notice > for position 3 from @0.0.0.0:0 > I1201 02:18:00.377210 18949 leveldb.cpp:343] Persisting action (343 bytes) to > leveldb took 304057ns > I1201 02:18:00.377234 18949 replica.cpp:715] Persisted action at 3 > I1201 02:18:00.377251 18949 replica.cpp:700] Replica learned APPEND action at > position 3 > I1201 02:18:00.378463 18950 registrar.cpp:486] Successfully updated the > 'registry' in 4.696064ms > I1201 02:18:00.378602 18948 log.cpp:704] Attempting to truncate the log to 3 > I1201 02:18:00.379117 18950 hierarchical.cpp:344] Added slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 (ubuntu14) with cpus(*):1; > mem(*):1024; ports(*):[10000-10000]; disk(*):34068 (allocated: ) > I1201 02:18:00.379145 18949 slave.cpp:904] Registered with master > master@127.0.1.1:45788; given slave ID 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 > I1201 02:18:00.379194 18946 coordinator.cpp:350] Coordinator attempting to > write TRUNCATE action at position 4 > I1201 02:18:00.379246 18952 status_update_manager.cpp:183] Resuming sending > status updates > I1201 02:18:00.379061 18951 master.cpp:3927] Registered slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 at slave(2684)@127.0.1.1:45788 > (ubuntu14) with cpus(*):1; mem(*):1024; ports(*):[10000-10000]; disk(*):34068 > I1201 02:18:00.379521 18949 slave.cpp:963] Forwarding total oversubscribed > resources > I1201 02:18:00.379618 18946 master.cpp:4979] Sending 1 offers to framework > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 (default) at > scheduler-ce98c85f-caf7-4fc2-8489-e495997d85a2@127.0.1.1:45788 > I1201 02:18:00.379784 18946 master.cpp:4269] Received update of slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 at slave(2684)@127.0.1.1:45788 > (ubuntu14) with total oversubscribed resources > I1201 02:18:00.379813 18948 replica.cpp:540] Replica received write request > for position 4 from (88136)@127.0.1.1:45788 > I1201 02:18:00.380010 18946 hierarchical.cpp:400] Slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 (ubuntu14) updated with > oversubscribed resources (total: cpus(*):1; mem(*):1024; > ports(*):[10000-10000]; disk(*):34068, allocated: cpus(*):1; mem(*):1024; > ports(*):[10000-10000]; disk(*):34068) > I1201 02:18:00.380147 18948 leveldb.cpp:343] Persisting action (16 bytes) to > leveldb took 300743ns > I1201 02:18:00.380168 18948 replica.cpp:715] Persisted action at 4 > I1201 02:18:00.380645 18950 replica.cpp:694] Replica received learned notice > for position 4 from @0.0.0.0:0 > I1201 02:18:00.380972 18950 leveldb.cpp:343] Persisting action (18 bytes) to > leveldb took 295998ns > I1201 02:18:00.381049 18950 leveldb.cpp:401] Deleting ~2 keys from leveldb > took 29531ns > I1201 02:18:00.381065 18950 replica.cpp:715] Persisted action at 4 > I1201 02:18:00.381083 18950 replica.cpp:700] Replica learned TRUNCATE action > at position 4 > I1201 02:18:00.382171 18948 master.cpp:2915] Processing ACCEPT call for > offers: [ 9577131b-f0b1-47bd-8f88-f5edbf2f026d-O0 ] on slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 at slave(2684)@127.0.1.1:45788 > (ubuntu14) for framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 (default) > at scheduler-ce98c85f-caf7-4fc2-8489-e495997d85a2@127.0.1.1:45788 > I1201 02:18:00.382246 18948 master.cpp:2711] Authorizing framework principal > 'test-principal' to launch task 1 as user 'root' > I1201 02:18:00.383256 18948 master.hpp:176] Adding task 1 with resources > cpus(*):1; mem(*):1024; ports(*):[10000-10000]; disk(*):34068 on slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 (ubuntu14) > I1201 02:18:00.383625 18948 master.cpp:3245] Launching task 1 of framework > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 (default) at > scheduler-ce98c85f-caf7-4fc2-8489-e495997d85a2@127.0.1.1:45788 with resources > cpus(*):1; mem(*):1024; ports(*):[10000-10000]; disk(*):34068 on slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 at slave(2684)@127.0.1.1:45788 > (ubuntu14) > I1201 02:18:00.383908 18946 slave.cpp:1294] Got assigned task 1 for framework > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 > I1201 02:18:00.384404 18946 slave.cpp:1410] Launching task 1 for framework > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 > I1201 02:18:00.384793 18946 paths.cpp:436] Trying to chown > '/tmp/DockerContainerizerTest_ROOT_DOCKER_NC_PortMapping_nnBZ8r/slaves/9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0/frameworks/9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000/executors/1/runs/f419764a-a0e4-4ec5-b828-95070950e06c' > to user 'root' > I1201 02:18:00.391932 18946 slave.cpp:4999] Launching executor 1 of framework > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 with resources cpus(*):0.1; > mem(*):32 in work directory > '/tmp/DockerContainerizerTest_ROOT_DOCKER_NC_PortMapping_nnBZ8r/slaves/9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0/frameworks/9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000/executors/1/runs/f419764a-a0e4-4ec5-b828-95070950e06c' > I1201 02:18:00.396006 18946 slave.cpp:1628] Queuing task '1' for executor '1' > of framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 > I1201 02:18:00.399181 18951 docker.cpp:762] Starting container > 'f419764a-a0e4-4ec5-b828-95070950e06c' for task '1' (and executor '1') of > framework '9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000' > 2015-12-01 > 02:18:00,535:18931(0x7f25a6ff5700):ZOO_ERROR@handle_socket_error_msg@1697: > Socket [127.0.0.1:43463] zk retcode=-4, errno=111(Connection refused): server > refused to accept the client > I1201 02:18:00.573997 18948 slave.cpp:2405] Got registration for executor '1' > of framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 from > executor(1)@127.0.1.1:42439 > I1201 02:18:00.574838 18948 docker.cpp:1012] Ignoring updating container > 'f419764a-a0e4-4ec5-b828-95070950e06c' with resources passed to update is > identical to existing resources > I1201 02:18:00.575112 18948 slave.cpp:1793] Sending queued task '1' to > executor '1' of framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 at > executor(1)@127.0.1.1:42439 > 2015-12-01 > 02:18:00,686:18931(0x7f25abfff700):ZOO_ERROR@handle_socket_error_msg@1697: > Socket [127.0.0.1:38003] zk retcode=-4, errno=111(Connection refused): server > refused to accept the client > 2015-12-01 > 02:18:00,829:18931(0x7f26022f0700):ZOO_ERROR@handle_socket_error_msg@1697: > Socket [127.0.0.1:40169] zk retcode=-4, errno=111(Connection refused): server > refused to accept the client > I1201 02:18:01.299674 18945 slave.cpp:2762] Handling status update > TASK_RUNNING (UUID: baf10be9-a22a-413c-978b-6a0e73952997) for task 1 of > framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 from > executor(1)@127.0.1.1:42439 > I1201 02:18:01.300400 18945 status_update_manager.cpp:322] Received status > update TASK_RUNNING (UUID: baf10be9-a22a-413c-978b-6a0e73952997) for task 1 > of framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 > I1201 02:18:01.301292 18945 slave.cpp:3087] Forwarding the update > TASK_RUNNING (UUID: baf10be9-a22a-413c-978b-6a0e73952997) for task 1 of > framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 to master@127.0.1.1:45788 > I1201 02:18:01.301728 18945 slave.cpp:3011] Sending acknowledgement for > status update TASK_RUNNING (UUID: baf10be9-a22a-413c-978b-6a0e73952997) for > task 1 of framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 to > executor(1)@127.0.1.1:42439 > I1201 02:18:01.301913 18948 master.cpp:4414] Status update TASK_RUNNING > (UUID: baf10be9-a22a-413c-978b-6a0e73952997) for task 1 of framework > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 from slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 at slave(2684)@127.0.1.1:45788 > (ubuntu14) > I1201 02:18:01.302580 18948 master.cpp:4462] Forwarding status update > TASK_RUNNING (UUID: baf10be9-a22a-413c-978b-6a0e73952997) for task 1 of > framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 > I1201 02:18:01.302733 18948 master.cpp:6066] Updating the state of task 1 of > framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 (latest state: > TASK_RUNNING, status update state: TASK_RUNNING) > I1201 02:18:01.303413 18948 master.cpp:3571] Processing ACKNOWLEDGE call > baf10be9-a22a-413c-978b-6a0e73952997 for task 1 of framework > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 (default) at > scheduler-ce98c85f-caf7-4fc2-8489-e495997d85a2@127.0.1.1:45788 on slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 > I1201 02:18:01.307530 18946 status_update_manager.cpp:394] Received status > update acknowledgement (UUID: baf10be9-a22a-413c-978b-6a0e73952997) for task > 1 of framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 > 2015-12-01 > 02:18:01,355:18931(0x7f25f9ffb700):ZOO_ERROR@handle_socket_error_msg@1697: > Socket [127.0.0.1:43780] zk retcode=-4, errno=111(Connection refused): server > refused to accept the client > I1201 02:18:01.606086 18948 slave.cpp:2762] Handling status update > TASK_FINISHED (UUID: ce1b89b6-cdf0-45ca-a59a-406294e34a4f) for task 1 of > framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 from > executor(1)@127.0.1.1:42439 > I1201 02:18:01.747001 18949 status_update_manager.cpp:322] Received status > update TASK_FINISHED (UUID: ce1b89b6-cdf0-45ca-a59a-406294e34a4f) for task 1 > of framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 > I1201 02:18:01.747721 18947 slave.cpp:3087] Forwarding the update > TASK_FINISHED (UUID: ce1b89b6-cdf0-45ca-a59a-406294e34a4f) for task 1 of > framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 to master@127.0.1.1:45788 > I1201 02:18:01.747911 18947 slave.cpp:3011] Sending acknowledgement for > status update TASK_FINISHED (UUID: ce1b89b6-cdf0-45ca-a59a-406294e34a4f) for > task 1 of framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 to > executor(1)@127.0.1.1:42439 > I1201 02:18:01.748107 18949 master.cpp:4414] Status update TASK_FINISHED > (UUID: ce1b89b6-cdf0-45ca-a59a-406294e34a4f) for task 1 of framework > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 from slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 at slave(2684)@127.0.1.1:45788 > (ubuntu14) > I1201 02:18:01.748625 18949 master.cpp:4462] Forwarding status update > TASK_FINISHED (UUID: ce1b89b6-cdf0-45ca-a59a-406294e34a4f) for task 1 of > framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 > I1201 02:18:01.749027 18949 master.cpp:6066] Updating the state of task 1 of > framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 (latest state: > TASK_FINISHED, status update state: TASK_FINISHED) > ../../src/tests/containerizer/docker_containerizer_tests.cpp:2012: Failure > Value of: containsLine(lines, uuid) > Actual: false > Expected: true > *** Aborted at 1448936281 (unix time) try "date -d @1448936281" if you are > using GNU date *** > I1201 02:18:01.750568 18949 master.cpp:3571] Processing ACKNOWLEDGE call > ce1b89b6-cdf0-45ca-a59a-406294e34a4f for task 1 of framework > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 (default) at > scheduler-ce98c85f-caf7-4fc2-8489-e495997d85a2@127.0.1.1:45788 on slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 > PC: @ 0x1443ea6 testing::UnitTest::AddTestPartResult() > I1201 02:18:01.751319 18949 master.cpp:6132] Removing task 1 with resources > cpus(*):1; mem(*):1024; ports(*):[10000-10000]; disk(*):34068 of framework > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 on slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 at slave(2684)@127.0.1.1:45788 > (ubuntu14) > *** SIGSEGV (@0x0) received by PID 18931 (TID 0x7f2650567800) from PID 0; > stack trace: *** > I1201 02:18:01.751198 18947 hierarchical.cpp:744] Recovered cpus(*):1; > mem(*):1024; ports(*):[10000-10000]; disk(*):34068 (total: cpus(*):1; > mem(*):1024; ports(*):[10000-10000]; disk(*):34068, allocated: ) on slave > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-S0 from framework > 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 > I1201 02:18:01.752058 18952 status_update_manager.cpp:394] Received status > update acknowledgement (UUID: ce1b89b6-cdf0-45ca-a59a-406294e34a4f) for task > 1 of framework 9577131b-f0b1-47bd-8f88-f5edbf2f026d-0000 > @ 0x7f262f9c30b7 os::Linux::chained_handler() > @ 0x7f262f9c7219 JVM_handle_linux_signal > @ 0x7f264a3f8340 (unknown) > @ 0x1443ea6 testing::UnitTest::AddTestPartResult() > @ 0x1438ba5 testing::internal::AssertHelper::operator=() > @ 0x12cc7ae > mesos::internal::tests::DockerContainerizerTest_ROOT_DOCKER_NC_PortMapping_Test::TestBody() > @ 0x146188e > testing::internal::HandleSehExceptionsInMethodIfSupported<>() > @ 0x145c704 > testing::internal::HandleExceptionsInMethodIfSupported<>() > @ 0x143de0d testing::Test::Run() > @ 0x143e590 testing::TestInfo::Run() > @ 0x143ebd6 testing::TestCase::Run() > @ 0x144531e testing::internal::UnitTestImpl::RunAllTests() > @ 0x14624b3 > testing::internal::HandleSehExceptionsInMethodIfSupported<>() > @ 0x145d27a > testing::internal::HandleExceptionsInMethodIfSupported<>() > @ 0x14440ba testing::UnitTest::Run() > @ 0xd15cd4 RUN_ALL_TESTS() > @ 0xd158c1 main > @ 0x7f264a044ec5 (unknown) > @ 0x913009 (unknown) > {noformat} -- This message was sent by Atlassian JIRA (v6.3.4#6332)