Skip to content

Instantly share code, notes, and snippets.

@neilconway

neilconway/gist:e6134b4717ee022e7fc32a1f95619fa9 Secret

Created April 19, 2016 14:34
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save neilconway/e6134b4717ee022e7fc32a1f95619fa9 to your computer and use it in GitHub Desktop.
Save neilconway/e6134b4717ee022e7fc32a1f95619fa9 to your computer and use it in GitHub Desktop.
Download ZIP
HealthCheckTest.HealthStatusChange test failure
Raw
gistfile1.txt
[ RUN ] HealthCheckTest.HealthStatusChange
I0420 00:33:12.691145 15381 cluster.cpp:149] Creating default 'local' authorizer
I0420 00:33:12.691897 15381 leveldb.cpp:174] Opened db in 620608ns
I0420 00:33:12.692211 15381 leveldb.cpp:181] Compacted db in 283038ns
I0420 00:33:12.692265 15381 leveldb.cpp:196] Created db iterator in 15184ns
I0420 00:33:12.692273 15381 leveldb.cpp:202] Seeked to beginning of db in 2161ns
I0420 00:33:12.692281 15381 leveldb.cpp:271] Iterated through 0 keys in the db in 1084ns
I0420 00:33:12.692312 15381 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0420 00:33:12.693172 15398 recover.cpp:447] Starting replica recovery
I0420 00:33:12.693435 15400 recover.cpp:473] Replica is in EMPTY status
I0420 00:33:12.695106 15400 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (3755)@10.0.2.15:41408
I0420 00:33:12.695829 15400 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0420 00:33:12.696321 15398 recover.cpp:564] Updating replica status to STARTING
I0420 00:33:12.696807 15402 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 101090ns
I0420 00:33:12.696836 15402 replica.cpp:320] Persisted replica status to STARTING
I0420 00:33:12.696964 15402 recover.cpp:473] Replica is in STARTING status
I0420 00:33:12.697968 15400 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (3756)@10.0.2.15:41408
I0420 00:33:12.698274 15400 recover.cpp:193] Received a recover response from a replica in STARTING status
I0420 00:33:12.698691 15400 recover.cpp:564] Updating replica status to VOTING
I0420 00:33:12.698882 15400 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 62549ns
I0420 00:33:12.698938 15400 replica.cpp:320] Persisted replica status to VOTING
I0420 00:33:12.699002 15400 recover.cpp:578] Successfully joined the Paxos group
I0420 00:33:12.699128 15400 recover.cpp:462] Recover process terminated
I0420 00:33:12.721339 15401 master.cpp:382] Master 7cf5923c-3d03-4ed6-826a-efa97f54e765 (archlinux.vagrant.vm) started on 10.0.2.15:41408
I0420 00:33:12.721387 15401 master.cpp:384] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="true" --authenticate_http="true" --authenticate_http_frameworks="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/9zoT36/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --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/9zoT36/master" --zk_session_timeout="10secs"
I0420 00:33:12.721667 15401 master.cpp:433] Master only allowing authenticated frameworks to register
I0420 00:33:12.721736 15401 master.cpp:439] Master only allowing authenticated agents to register
I0420 00:33:12.721745 15401 master.cpp:445] Master only allowing authenticated HTTP frameworks to register
I0420 00:33:12.721750 15401 credentials.hpp:37] Loading credentials for authentication from '/tmp/9zoT36/credentials'
I0420 00:33:12.722005 15401 master.cpp:489] Using default 'crammd5' authenticator
I0420 00:33:12.723206 15401 master.cpp:560] Using default 'basic' HTTP authenticator
I0420 00:33:12.723458 15401 master.cpp:640] Using default 'basic' HTTP framework authenticator
I0420 00:33:12.723574 15401 master.cpp:687] Authorization enabled
I0420 00:33:12.725332 15399 master.cpp:1932] The newly elected leader is master@10.0.2.15:41408 with id 7cf5923c-3d03-4ed6-826a-efa97f54e765
I0420 00:33:12.725376 15399 master.cpp:1945] Elected as the leading master!
I0420 00:33:12.725389 15399 master.cpp:1632] Recovering from registrar
I0420 00:33:12.725544 15399 registrar.cpp:331] Recovering registrar
I0420 00:33:12.726506 15399 log.cpp:524] Attempting to start the writer
I0420 00:33:12.727424 15399 replica.cpp:493] Replica received implicit promise request from (3759)@10.0.2.15:41408 with proposal 1
I0420 00:33:12.727517 15399 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 50404ns
I0420 00:33:12.727541 15399 replica.cpp:342] Persisted promised to 1
I0420 00:33:12.728299 15395 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0420 00:33:12.735360 15402 replica.cpp:388] Replica received explicit promise request from (3760)@10.0.2.15:41408 for position 0 with proposal 2
I0420 00:33:12.735448 15402 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 51677ns
I0420 00:33:12.735525 15402 replica.cpp:712] Persisted action at 0
I0420 00:33:12.736783 15399 replica.cpp:537] Replica received write request for position 0 from (3761)@10.0.2.15:41408
I0420 00:33:12.736955 15399 leveldb.cpp:436] Reading position from leveldb took 27734ns
I0420 00:33:12.737108 15399 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40858ns
I0420 00:33:12.737249 15399 replica.cpp:712] Persisted action at 0
I0420 00:33:12.738021 15398 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0420 00:33:12.738092 15398 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 35952ns
I0420 00:33:12.738131 15398 replica.cpp:712] Persisted action at 0
I0420 00:33:12.738145 15398 replica.cpp:697] Replica learned NOP action at position 0
I0420 00:33:12.739038 15395 log.cpp:540] Writer started with ending position 0
I0420 00:33:12.740397 15400 leveldb.cpp:436] Reading position from leveldb took 43374ns
I0420 00:33:12.741741 15397 registrar.cpp:364] Successfully fetched the registry (0B) in 16.1408ms
I0420 00:33:12.741844 15397 registrar.cpp:463] Applied 1 operations in 22449ns; attempting to update the 'registry'
I0420 00:33:12.742624 15397 log.cpp:548] Attempting to append 185 bytes to the log
I0420 00:33:12.742825 15399 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0420 00:33:12.743827 15399 replica.cpp:537] Replica received write request for position 1 from (3762)@10.0.2.15:41408
I0420 00:33:12.744009 15399 leveldb.cpp:341] Persisting action (204 bytes) to leveldb took 59247ns
I0420 00:33:12.744189 15399 replica.cpp:712] Persisted action at 1
I0420 00:33:12.745023 15397 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0420 00:33:12.745139 15397 leveldb.cpp:341] Persisting action (206 bytes) to leveldb took 65024ns
I0420 00:33:12.745167 15397 replica.cpp:712] Persisted action at 1
I0420 00:33:12.745183 15397 replica.cpp:697] Replica learned APPEND action at position 1
I0420 00:33:12.746696 15395 registrar.cpp:508] Successfully updated the 'registry' in 4.788992ms
I0420 00:33:12.746841 15395 registrar.cpp:394] Successfully recovered registrar
I0420 00:33:12.746913 15401 log.cpp:567] Attempting to truncate the log to 1
I0420 00:33:12.747383 15399 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0420 00:33:12.747747 15395 master.cpp:1740] Recovered 0 agents from the Registry (146B) ; allowing 10mins for agents to re-register
I0420 00:33:12.749722 15397 replica.cpp:537] Replica received write request for position 2 from (3763)@10.0.2.15:41408
I0420 00:33:12.749837 15397 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 51623ns
I0420 00:33:12.749862 15397 replica.cpp:712] Persisted action at 2
I0420 00:33:12.750529 15400 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0420 00:33:12.750602 15400 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 34873ns
I0420 00:33:12.750695 15400 leveldb.cpp:399] Deleting ~1 keys from leveldb took 23637ns
I0420 00:33:12.750730 15400 replica.cpp:712] Persisted action at 2
I0420 00:33:12.750746 15400 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0420 00:33:12.761435 15381 containerizer.cpp:174] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni
W0420 00:33:12.762092 15381 backend.cpp:66] Failed to create 'bind' backend: BindBackend requires root privileges
I0420 00:33:12.810016 15400 slave.cpp:201] Agent started on 76)@10.0.2.15:41408
I0420 00:33:12.810070 15400 slave.cpp:202] Flags at startup: --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http="true" --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/HealthCheckTest_HealthStatusChange_T3YdIF/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/HealthCheckTest_HealthStatusChange_T3YdIF/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="true" --hostname_lookup="true" --http_authenticators="basic" --http_command_executor="false" --http_credentials="/tmp/HealthCheckTest_HealthStatusChange_T3YdIF/http_credentials" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher_dir="/home/vagrant/build-mesos-default-opts/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_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/HealthCheckTest_HealthStatusChange_T3YdIF"
I0420 00:33:12.810362 15400 credentials.hpp:86] Loading credential for authentication from '/tmp/HealthCheckTest_HealthStatusChange_T3YdIF/credential'
I0420 00:33:12.810511 15400 slave.cpp:339] Agent using credential for: test-principal
I0420 00:33:12.810564 15400 credentials.hpp:37] Loading credentials for authentication from '/tmp/HealthCheckTest_HealthStatusChange_T3YdIF/http_credentials'
I0420 00:33:12.810765 15400 slave.cpp:391] Using default 'basic' HTTP authenticator
I0420 00:33:12.839030 15400 slave.cpp:590] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0420 00:33:12.839357 15400 slave.cpp:598] Agent attributes: [ ]
I0420 00:33:12.839551 15400 slave.cpp:603] Agent hostname: archlinux.vagrant.vm
I0420 00:33:12.841415 15400 state.cpp:57] Recovering state from '/tmp/HealthCheckTest_HealthStatusChange_T3YdIF/meta'
I0420 00:33:12.841830 15400 status_update_manager.cpp:200] Recovering status update manager
I0420 00:33:12.842087 15397 containerizer.cpp:439] Recovering containerizer
I0420 00:33:12.843364 15395 provisioner.cpp:245] Provisioner recovery complete
I0420 00:33:12.843719 15395 slave.cpp:4800] Finished recovery
I0420 00:33:12.844300 15395 slave.cpp:945] New master detected at master@10.0.2.15:41408
I0420 00:33:12.844360 15401 status_update_manager.cpp:174] Pausing sending status updates
I0420 00:33:12.844458 15395 slave.cpp:1008] Authenticating with master master@10.0.2.15:41408
I0420 00:33:12.844509 15395 slave.cpp:1013] Using default CRAM-MD5 authenticatee
I0420 00:33:12.844620 15395 slave.cpp:981] Detecting new master
I0420 00:33:12.844779 15395 authenticatee.cpp:121] Creating new client SASL connection
I0420 00:33:12.845008 15395 master.cpp:5801] Authenticating slave(76)@10.0.2.15:41408
I0420 00:33:12.845345 15395 authenticator.cpp:98] Creating new server SASL connection
I0420 00:33:12.845471 15395 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0420 00:33:12.845504 15395 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0420 00:33:12.845552 15395 authenticator.cpp:203] Received SASL authentication start
I0420 00:33:12.845609 15395 authenticator.cpp:325] Authentication requires more steps
I0420 00:33:12.845657 15395 authenticatee.cpp:258] Received SASL authentication step
I0420 00:33:12.845787 15395 authenticator.cpp:231] Received SASL authentication step
I0420 00:33:12.845851 15395 authenticator.cpp:317] Authentication success
I0420 00:33:12.846011 15400 authenticatee.cpp:298] Authentication success
I0420 00:33:12.846009 15396 master.cpp:5831] Successfully authenticated principal 'test-principal' at slave(76)@10.0.2.15:41408
I0420 00:33:12.846340 15400 slave.cpp:1078] Successfully authenticated with master master@10.0.2.15:41408
I0420 00:33:12.846705 15396 master.cpp:4512] Registering agent at slave(76)@10.0.2.15:41408 (archlinux.vagrant.vm) with id 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0
I0420 00:33:12.847108 15396 registrar.cpp:463] Applied 1 operations in 45782ns; attempting to update the 'registry'
I0420 00:33:12.847733 15400 log.cpp:548] Attempting to append 362 bytes to the log
I0420 00:33:12.848198 15401 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I0420 00:33:12.848323 15400 master.cpp:4500] Ignoring register agent message from slave(76)@10.0.2.15:41408 (archlinux.vagrant.vm) as admission is already in progress
I0420 00:33:12.849373 15402 replica.cpp:537] Replica received write request for position 3 from (3779)@10.0.2.15:41408
I0420 00:33:12.849591 15402 leveldb.cpp:341] Persisting action (381 bytes) to leveldb took 56531ns
I0420 00:33:12.849700 15402 replica.cpp:712] Persisted action at 3
I0420 00:33:12.850530 15402 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
I0420 00:33:12.850774 15402 leveldb.cpp:341] Persisting action (383 bytes) to leveldb took 37554ns
I0420 00:33:12.850862 15402 replica.cpp:712] Persisted action at 3
I0420 00:33:12.850985 15402 replica.cpp:697] Replica learned APPEND action at position 3
I0420 00:33:12.852195 15402 registrar.cpp:508] Successfully updated the 'registry' in 4.989952ms
I0420 00:33:12.852668 15395 log.cpp:567] Attempting to truncate the log to 3
I0420 00:33:12.852953 15401 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I0420 00:33:12.853283 15397 master.cpp:4580] Registered agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0 at slave(76)@10.0.2.15:41408 (archlinux.vagrant.vm) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0420 00:33:12.853458 15397 hierarchical.cpp:473] Added agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0 (archlinux.vagrant.vm) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
I0420 00:33:12.853458 15396 slave.cpp:1122] Registered with master master@10.0.2.15:41408; given agent ID 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0
I0420 00:33:12.854084 15396 slave.cpp:1182] Forwarding total oversubscribed resources
I0420 00:33:12.854123 15398 status_update_manager.cpp:181] Resuming sending status updates
I0420 00:33:12.854295 15402 master.cpp:4924] Received update of agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0 at slave(76)@10.0.2.15:41408 (archlinux.vagrant.vm) with total oversubscribed resources
I0420 00:33:12.854722 15402 hierarchical.cpp:531] Agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0 (archlinux.vagrant.vm) updated with oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: )
I0420 00:33:12.855062 15396 replica.cpp:537] Replica received write request for position 4 from (3780)@10.0.2.15:41408
I0420 00:33:12.855365 15396 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 130625ns
I0420 00:33:12.855507 15396 replica.cpp:712] Persisted action at 4
I0420 00:33:12.856474 15398 replica.cpp:691] Replica received learned notice for position 4 from @0.0.0.0:0
I0420 00:33:12.856557 15398 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 37939ns
I0420 00:33:12.856595 15398 leveldb.cpp:399] Deleting ~2 keys from leveldb took 15093ns
I0420 00:33:12.856617 15398 replica.cpp:712] Persisted action at 4
I0420 00:33:12.856632 15398 replica.cpp:697] Replica learned TRUNCATE action at position 4
I0420 00:33:12.895501 15381 sched.cpp:224] Version: 0.29.0
I0420 00:33:12.896266 15397 sched.cpp:328] New master detected at master@10.0.2.15:41408
I0420 00:33:12.896371 15397 sched.cpp:384] Authenticating with master master@10.0.2.15:41408
I0420 00:33:12.896396 15397 sched.cpp:391] Using default CRAM-MD5 authenticatee
I0420 00:33:12.896672 15399 authenticatee.cpp:121] Creating new client SASL connection
I0420 00:33:12.896965 15399 master.cpp:5801] Authenticating scheduler-5bd5e446-a017-45d9-8193-be7d23002487@10.0.2.15:41408
I0420 00:33:12.897411 15399 authenticator.cpp:98] Creating new server SASL connection
I0420 00:33:12.897600 15399 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0420 00:33:12.897644 15399 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0420 00:33:12.897754 15399 authenticator.cpp:203] Received SASL authentication start
I0420 00:33:12.897883 15399 authenticator.cpp:325] Authentication requires more steps
I0420 00:33:12.898066 15399 authenticatee.cpp:258] Received SASL authentication step
I0420 00:33:12.898208 15399 authenticator.cpp:231] Received SASL authentication step
I0420 00:33:12.898401 15399 authenticator.cpp:317] Authentication success
I0420 00:33:12.898542 15399 master.cpp:5831] Successfully authenticated principal 'test-principal' at scheduler-5bd5e446-a017-45d9-8193-be7d23002487@10.0.2.15:41408
I0420 00:33:12.898576 15400 authenticatee.cpp:298] Authentication success
I0420 00:33:12.898938 15400 sched.cpp:474] Successfully authenticated with master master@10.0.2.15:41408
I0420 00:33:12.899281 15400 master.cpp:2463] Received SUBSCRIBE call for framework 'default' at scheduler-5bd5e446-a017-45d9-8193-be7d23002487@10.0.2.15:41408
I0420 00:33:12.899384 15400 master.cpp:1971] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0420 00:33:12.899658 15395 master.cpp:2539] Subscribing framework default with checkpointing disabled and capabilities [ ]
I0420 00:33:12.900406 15395 sched.cpp:706] Framework registered with 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:12.900682 15400 hierarchical.cpp:264] Added framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:12.901666 15399 master.cpp:5630] Sending 1 offers to framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (default) at scheduler-5bd5e446-a017-45d9-8193-be7d23002487@10.0.2.15:41408
I0420 00:33:12.903337 15401 master.cpp:3410] Processing ACCEPT call for offers: [ 7cf5923c-3d03-4ed6-826a-efa97f54e765-O0 ] on agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0 at slave(76)@10.0.2.15:41408 (archlinux.vagrant.vm) for framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (default) at scheduler-5bd5e446-a017-45d9-8193-be7d23002487@10.0.2.15:41408
I0420 00:33:12.903411 15401 master.cpp:3013] Authorizing framework principal 'test-principal' to launch task 1 as user 'vagrant'
I0420 00:33:12.904501 15399 master.hpp:177] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0 (archlinux.vagrant.vm)
I0420 00:33:12.904616 15399 master.cpp:3895] Launching task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (default) at scheduler-5bd5e446-a017-45d9-8193-be7d23002487@10.0.2.15:41408 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0 at slave(76)@10.0.2.15:41408 (archlinux.vagrant.vm)
I0420 00:33:12.904985 15401 slave.cpp:1514] Got assigned task 1 for framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:12.905398 15401 slave.cpp:1633] Launching task 1 for framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:12.905660 15401 paths.cpp:528] Trying to chown '/tmp/HealthCheckTest_HealthStatusChange_T3YdIF/slaves/7cf5923c-3d03-4ed6-826a-efa97f54e765-S0/frameworks/7cf5923c-3d03-4ed6-826a-efa97f54e765-0000/executors/1/runs/8e9198d4-5a23-40f2-b372-8130ec375783' to user 'vagrant'
I0420 00:33:12.909620 15401 slave.cpp:5620] Launching executor 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 with resources cpus(*):0.1; mem(*):32 in work directory '/tmp/HealthCheckTest_HealthStatusChange_T3YdIF/slaves/7cf5923c-3d03-4ed6-826a-efa97f54e765-S0/frameworks/7cf5923c-3d03-4ed6-826a-efa97f54e765-0000/executors/1/runs/8e9198d4-5a23-40f2-b372-8130ec375783'
I0420 00:33:12.910140 15401 slave.cpp:1851] Queuing task '1' for executor '1' of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:12.910404 15395 containerizer.cpp:698] Starting container '8e9198d4-5a23-40f2-b372-8130ec375783' for executor '1' of framework '7cf5923c-3d03-4ed6-826a-efa97f54e765-0000'
I0420 00:33:12.914448 15395 launcher.cpp:123] Forked child with pid '20895' for container '8e9198d4-5a23-40f2-b372-8130ec375783'
I0420 00:33:13.059639 20895 exec.cpp:150] Version: 0.29.0
I0420 00:33:13.065830 15399 slave.cpp:2842] Got registration for executor '1' of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 from executor(1)@10.0.2.15:37107
I0420 00:33:13.067417 15402 slave.cpp:2016] Sending queued task '1' to executor '1' of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 at executor(1)@10.0.2.15:37107
I0420 00:33:13.068193 20923 exec.cpp:225] Executor registered on agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0
Registered executor on archlinux.vagrant.vm
Starting task 1
sh -c 'sleep 120'
Forked command at 20931
Launching health check process: /home/vagrant/build-mesos-default-opts/src/mesos-health-check --executor=(1)@10.0.2.15:37107 --health_check_json={"command":{"shell":true,"value":"rm \/tmp\/1NKfr1 || (touch \/tmp\/1NKfr1 && exit 1)"},"consecutive_failures":3,"delay_seconds":0.0,"grace_period_seconds":0.0,"interval_seconds":0.0,"timeout_seconds":20.0} --task_id=1
Health check process launched at pid: 20932
I0420 00:33:13.075927 15396 slave.cpp:3201] Handling status update TASK_RUNNING (UUID: 02c2030b-ec12-485c-83e8-5ae201178bea) for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 from executor(1)@10.0.2.15:37107
I0420 00:33:13.077280 15396 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 02c2030b-ec12-485c-83e8-5ae201178bea) for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:13.077841 15396 slave.cpp:3599] Forwarding the update TASK_RUNNING (UUID: 02c2030b-ec12-485c-83e8-5ae201178bea) for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 to master@10.0.2.15:41408
I0420 00:33:13.077960 15396 slave.cpp:3509] Sending acknowledgement for status update TASK_RUNNING (UUID: 02c2030b-ec12-485c-83e8-5ae201178bea) for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 to executor(1)@10.0.2.15:37107
I0420 00:33:13.078277 15397 master.cpp:5069] Status update TASK_RUNNING (UUID: 02c2030b-ec12-485c-83e8-5ae201178bea) for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 from agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0 at slave(76)@10.0.2.15:41408 (archlinux.vagrant.vm)
I0420 00:33:13.078330 15397 master.cpp:5117] Forwarding status update TASK_RUNNING (UUID: 02c2030b-ec12-485c-83e8-5ae201178bea) for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:13.078431 15397 master.cpp:6725] Updating the state of task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0420 00:33:13.079056 15397 master.cpp:4224] Processing ACKNOWLEDGE call 02c2030b-ec12-485c-83e8-5ae201178bea for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (default) at scheduler-5bd5e446-a017-45d9-8193-be7d23002487@10.0.2.15:41408 on agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0
I0420 00:33:13.079445 15396 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 02c2030b-ec12-485c-83e8-5ae201178bea) for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
Received task health update, healthy: true
I0420 00:33:13.302896 15396 slave.cpp:3201] Handling status update TASK_RUNNING (UUID: 8506a0b4-03cd-435c-bdfa-b88fffe1d977) for task 1 in health state healthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 from executor(1)@10.0.2.15:37107
I0420 00:33:13.304239 15396 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 8506a0b4-03cd-435c-bdfa-b88fffe1d977) for task 1 in health state healthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:13.304553 15396 slave.cpp:3599] Forwarding the update TASK_RUNNING (UUID: 8506a0b4-03cd-435c-bdfa-b88fffe1d977) for task 1 in health state healthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 to master@10.0.2.15:41408
I0420 00:33:13.304700 15396 slave.cpp:3509] Sending acknowledgement for status update TASK_RUNNING (UUID: 8506a0b4-03cd-435c-bdfa-b88fffe1d977) for task 1 in health state healthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 to executor(1)@10.0.2.15:37107
I0420 00:33:13.305068 15396 master.cpp:5069] Status update TASK_RUNNING (UUID: 8506a0b4-03cd-435c-bdfa-b88fffe1d977) for task 1 in health state healthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 from agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0 at slave(76)@10.0.2.15:41408 (archlinux.vagrant.vm)
I0420 00:33:13.305097 15396 master.cpp:5117] Forwarding status update TASK_RUNNING (UUID: 8506a0b4-03cd-435c-bdfa-b88fffe1d977) for task 1 in health state healthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:13.305197 15396 master.cpp:6725] Updating the state of task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0420 00:33:13.306653 15396 master.cpp:4224] Processing ACKNOWLEDGE call 8506a0b4-03cd-435c-bdfa-b88fffe1d977 for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (default) at scheduler-5bd5e446-a017-45d9-8193-be7d23002487@10.0.2.15:41408 on agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0
I0420 00:33:13.307194 15395 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 8506a0b4-03cd-435c-bdfa-b88fffe1d977) for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
rm: cannot remove '/tmp/1NKfr1': No such file or directory
I0420 00:33:13.308562 15401 http.cpp:313] HTTP GET for /master/state from 10.0.2.15:44472
I0420 00:33:13.314609 15396 http.cpp:178] HTTP GET for /slave(76)/state from 10.0.2.15:44474
Received task health update, healthy: false
I0420 00:33:13.489945 15396 slave.cpp:3201] Handling status update TASK_RUNNING (UUID: 34c9cab0-3f63-4ee6-b2a0-5db4e406afbd) for task 1 in health state unhealthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 from executor(1)@10.0.2.15:37107
I0420 00:33:13.492075 15399 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 34c9cab0-3f63-4ee6-b2a0-5db4e406afbd) for task 1 in health state unhealthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:13.492472 15400 slave.cpp:3599] Forwarding the update TASK_RUNNING (UUID: 34c9cab0-3f63-4ee6-b2a0-5db4e406afbd) for task 1 in health state unhealthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 to master@10.0.2.15:41408
I0420 00:33:13.492743 15400 slave.cpp:3509] Sending acknowledgement for status update TASK_RUNNING (UUID: 34c9cab0-3f63-4ee6-b2a0-5db4e406afbd) for task 1 in health state unhealthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 to executor(1)@10.0.2.15:37107
I0420 00:33:13.492822 15397 master.cpp:5069] Status update TASK_RUNNING (UUID: 34c9cab0-3f63-4ee6-b2a0-5db4e406afbd) for task 1 in health state unhealthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 from agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0 at slave(76)@10.0.2.15:41408 (archlinux.vagrant.vm)
I0420 00:33:13.492871 15397 master.cpp:5117] Forwarding status update TASK_RUNNING (UUID: 34c9cab0-3f63-4ee6-b2a0-5db4e406afbd) for task 1 in health state unhealthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:13.493135 15397 master.cpp:6725] Updating the state of task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0420 00:33:13.493801 15398 master.cpp:4224] Processing ACKNOWLEDGE call 34c9cab0-3f63-4ee6-b2a0-5db4e406afbd for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (default) at scheduler-5bd5e446-a017-45d9-8193-be7d23002487@10.0.2.15:41408 on agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0
I0420 00:33:13.494067 15399 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 34c9cab0-3f63-4ee6-b2a0-5db4e406afbd) for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:13.497138 15400 http.cpp:313] HTTP GET for /master/state from 10.0.2.15:44478
Received task health update, healthy: true
I0420 00:33:13.502598 15400 slave.cpp:3201] Handling status update TASK_RUNNING (UUID: e19c76cc-096a-4398-b616-afb628b8e5b8) for task 1 in health state healthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 from executor(1)@10.0.2.15:37107
I0420 00:33:13.504456 15400 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: e19c76cc-096a-4398-b616-afb628b8e5b8) for task 1 in health state healthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:13.505009 15400 slave.cpp:3599] Forwarding the update TASK_RUNNING (UUID: e19c76cc-096a-4398-b616-afb628b8e5b8) for task 1 in health state healthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 to master@10.0.2.15:41408
I0420 00:33:13.505167 15400 slave.cpp:3509] Sending acknowledgement for status update TASK_RUNNING (UUID: e19c76cc-096a-4398-b616-afb628b8e5b8) for task 1 in health state healthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 to executor(1)@10.0.2.15:37107
I0420 00:33:13.505524 15400 master.cpp:5069] Status update TASK_RUNNING (UUID: e19c76cc-096a-4398-b616-afb628b8e5b8) for task 1 in health state healthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 from agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0 at slave(76)@10.0.2.15:41408 (archlinux.vagrant.vm)
I0420 00:33:13.505602 15400 master.cpp:5117] Forwarding status update TASK_RUNNING (UUID: e19c76cc-096a-4398-b616-afb628b8e5b8) for task 1 in health state healthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:13.505738 15400 master.cpp:6725] Updating the state of task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0420 00:33:13.505985 15400 master.cpp:4224] Processing ACKNOWLEDGE call e19c76cc-096a-4398-b616-afb628b8e5b8 for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (default) at scheduler-5bd5e446-a017-45d9-8193-be7d23002487@10.0.2.15:41408 on agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0
I0420 00:33:13.506142 15400 status_update_manager.cpp:392] Received status update acknowledgement (UUID: e19c76cc-096a-4398-b616-afb628b8e5b8) for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
rm: cannot remove '/tmp/1NKfr1': No such file or directory
I0420 00:33:13.508203 15400 http.cpp:178] HTTP GET for /slave(76)/state from 10.0.2.15:44482
../../mesos/src/tests/health_check_tests.cpp:647: Failure
Value of: (find).get()
Actual: 16-byte object <05-00 00-00 00-00 00-00 90-C4 2D-03 00-00 00-00>
Expected: false
Which is: false
*** Aborted at 1461076393 (unix time) try "date -d @1461076393" if you are using GNU date ***
PC: @ 0x1899ba0 testing::UnitTest::AddTestPartResult()
*** SIGSEGV (@0x0) received by PID 15381 (TID 0x7f0aa958a7c0) from PID 0; stack trace: ***
@ 0x7f0aa3259e80 (unknown)
@ 0x1899ba0 testing::UnitTest::AddTestPartResult()
@ 0x188e319 testing::internal::AssertHelper::operator=()
@ 0xdfa79a mesos::internal::tests::HealthCheckTest_HealthStatusChange_Test::TestBody()
@ 0x18b7e16 testing::internal::HandleSehExceptionsInMethodIfSupported<>()
@ 0x18b2e52 testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x189379e testing::Test::Run()
@ 0x1893f56 testing::TestInfo::Run()
@ 0x18945a7 testing::TestCase::Run()
@ 0x189b0e5 testing::internal::UnitTestImpl::RunAllTests()
@ 0x18b8add testing::internal::HandleSehExceptionsInMethodIfSupported<>()
@ 0x18b3992 testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x1899dc1 testing::UnitTest::Run()
Received task health update, healthy: false
@ 0xf9375c RUN_ALL_TESTS()
I0420 00:33:13.603853 15399 slave.cpp:3201] Handling status update TASK_RUNNING (UUID: 1b2154a8-6f83-4b4a-a811-1db971288986) for task 1 in health state unhealthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 from executor(1)@10.0.2.15:37107
@ 0xf93378 main
@ 0x7f0aa27b7710 __libc_start_main
I0420 00:33:13.605831 15399 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 1b2154a8-6f83-4b4a-a811-1db971288986) for task 1 in health state unhealthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:13.606142 15399 slave.cpp:3599] Forwarding the update TASK_RUNNING (UUID: 1b2154a8-6f83-4b4a-a811-1db971288986) for task 1 in health state unhealthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 to master@10.0.2.15:41408
I0420 00:33:13.606263 15399 slave.cpp:3509] Sending acknowledgement for status update TASK_RUNNING (UUID: 1b2154a8-6f83-4b4a-a811-1db971288986) for task 1 in health state unhealthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 to executor(1)@10.0.2.15:37107
I0420 00:33:13.606644 15399 master.cpp:5069] Status update TASK_RUNNING (UUID: 1b2154a8-6f83-4b4a-a811-1db971288986) for task 1 in health state unhealthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 from agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0 at slave(76)@10.0.2.15:41408 (archlinux.vagrant.vm)
I0420 00:33:13.606685 15399 master.cpp:5117] Forwarding status update TASK_RUNNING (UUID: 1b2154a8-6f83-4b4a-a811-1db971288986) for task 1 in health state unhealthy of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
I0420 00:33:13.606780 15399 master.cpp:6725] Updating the state of task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0420 00:33:13.607326 15399 master.cpp:4224] Processing ACKNOWLEDGE call 1b2154a8-6f83-4b4a-a811-1db971288986 for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000 (default) at scheduler-5bd5e446-a017-45d9-8193-be7d23002487@10.0.2.15:41408 on agent 7cf5923c-3d03-4ed6-826a-efa97f54e765-S0
I0420 00:33:13.607579 15399 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 1b2154a8-6f83-4b4a-a811-1db971288986) for task 1 of framework 7cf5923c-3d03-4ed6-826a-efa97f54e765-0000
@ 0xa644d9 _start
@ 0x0 (unknown)
I0420 00:33:13.701517 20926 exec.cpp:481] Agent exited ... shutting down
Segmentation fault (core dumped)
vagrant@archlinux:~/build-mesos-default-opts$ Received task health update, healthy: true
Shutting down
Sending SIGTERM to process tree at pid 20931
E0420 00:33:13.705188 20930 process.cpp:1963] Failed to shutdown socket with fd 11: Transport endpoint is not connected
rm: cannot remove '/tmp/1NKfr1': No such file or directory
Sent SIGTERM to the following process trees:
[
--- 20931 sleep 120
]
Command terminated with signal Terminated (pid: 20931)
E0420 00:33:13.786746 20930 process.cpp:1963] Failed to shutdown socket with fd 8: Transport endpoint is not connected
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment