[
https://issues.apache.org/jira/browse/MESOS-5860?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15391240#comment-15391240
]
haosdent commented on MESOS-5860:
---------------------------------
After apply the patch, could not reproduce with {{stress --cpu 4 --timeout
3600s}}
> MasterAPITest.GetTasks is flaky
> -------------------------------
>
> Key: MESOS-5860
> URL: https://issues.apache.org/jira/browse/MESOS-5860
> Project: Mesos
> Issue Type: Bug
> Reporter: haosdent
> Assignee: haosdent
>
> From
> https://builds.apache.org/job/Mesos/2517/BUILDTOOL=autotools,COMPILER=clang,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu:14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)&&(!ubuntu-6)/consoleFull
> A failed run
> {code}
> [ RUN ] ContentType/MasterAPITest.GetTasks/0
> I0716 01:32:50.418465 26921 cluster.cpp:155] Creating default 'local'
> authorizer
> I0716 01:32:50.536353 26921 leveldb.cpp:174] Opened db in 117.63543ms
> I0716 01:32:50.570127 26921 leveldb.cpp:181] Compacted db in 33.607723ms
> I0716 01:32:50.570349 26921 leveldb.cpp:196] Created db iterator in 51989ns
> I0716 01:32:50.570523 26921 leveldb.cpp:202] Seeked to beginning of db in
> 28500ns
> I0716 01:32:50.570641 26921 leveldb.cpp:271] Iterated through 0 keys in the
> db in 13608ns
> I0716 01:32:50.570794 26921 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0716 01:32:50.571712 26949 recover.cpp:451] Starting replica recovery
> I0716 01:32:50.571979 26949 recover.cpp:477] Replica is in EMPTY status
> I0716 01:32:50.576714 26942 replica.cpp:673] Replica in EMPTY status received
> a broadcasted recover request from (15981)@172.17.0.8:44669
> I0716 01:32:50.576823 26939 master.cpp:382] Master
> 2949f69e-5d82-48a7-80da-ba654dac4ed1 (f1ca07e700ef) started on
> 172.17.0.8:44669
> I0716 01:32:50.576858 26939 master.cpp:384] Flags at startup: --acls=""
> --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate_agents="true" --authenticate_frameworks="true"
> --authenticate_http="true" --authenticate_http_frameworks="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/ZWBVTM/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_agent_ping_timeouts="5" --max_completed_frameworks="50"
> --max_completed_tasks_per_framework="1000" --quiet="false"
> --recovery_agent_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="100secs"
> --registry_strict="true" --root_submissions="true" --user_sorter="drf"
> --version="false" --webui_dir="/mesos/mesos-1.1.0/_inst/share/mesos/webui"
> --work_dir="/tmp/ZWBVTM/master" --zk_session_timeout="10secs"
> I0716 01:32:50.577327 26939 master.cpp:434] Master only allowing
> authenticated frameworks to register
> I0716 01:32:50.577342 26939 master.cpp:448] Master only allowing
> authenticated agents to register
> I0716 01:32:50.577350 26939 master.cpp:461] Master only allowing
> authenticated HTTP frameworks to register
> I0716 01:32:50.577360 26939 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/ZWBVTM/credentials'
> I0716 01:32:50.577958 26944 recover.cpp:197] Received a recover response from
> a replica in EMPTY status
> I0716 01:32:50.578735 26944 recover.cpp:568] Updating replica status to
> STARTING
> I0716 01:32:50.578871 26939 master.cpp:506] Using default 'crammd5'
> authenticator
> I0716 01:32:50.579008 26939 master.cpp:578] Using default 'basic' HTTP
> authenticator
> I0716 01:32:50.579143 26939 master.cpp:658] Using default 'basic' HTTP
> framework authenticator
> I0716 01:32:50.579239 26939 master.cpp:705] Authorization enabled
> I0716 01:32:50.579459 26951 whitelist_watcher.cpp:77] No whitelist given
> I0716 01:32:50.580548 26946 hierarchical.cpp:151] Initialized hierarchical
> allocator process
> I0716 01:32:50.582908 26942 master.cpp:1973] The newly elected leader is
> [email protected]:44669 with id 2949f69e-5d82-48a7-80da-ba654dac4ed1
> I0716 01:32:50.582962 26942 master.cpp:1986] Elected as the leading master!
> I0716 01:32:50.582976 26942 master.cpp:1673] Recovering from registrar
> I0716 01:32:50.583252 26952 registrar.cpp:332] Recovering registrar
> I0716 01:32:50.609922 26944 leveldb.cpp:304] Persisting metadata (8 bytes) to
> leveldb took 30.925255ms
> I0716 01:32:50.610015 26944 replica.cpp:320] Persisted replica status to
> STARTING
> I0716 01:32:50.610350 26944 recover.cpp:477] Replica is in STARTING status
> I0716 01:32:50.613060 26951 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (15985)@172.17.0.8:44669
> I0716 01:32:50.615031 26944 recover.cpp:197] Received a recover response from
> a replica in STARTING status
> I0716 01:32:50.615545 26941 recover.cpp:568] Updating replica status to VOTING
> I0716 01:32:50.646492 26941 leveldb.cpp:304] Persisting metadata (8 bytes) to
> leveldb took 30.72503ms
> I0716 01:32:50.646581 26941 replica.cpp:320] Persisted replica status to
> VOTING
> I0716 01:32:50.646854 26941 recover.cpp:582] Successfully joined the Paxos
> group
> I0716 01:32:50.647066 26941 recover.cpp:466] Recover process terminated
> I0716 01:32:50.647867 26944 log.cpp:553] Attempting to start the writer
> I0716 01:32:50.651500 26945 replica.cpp:493] Replica received implicit
> promise request from (15986)@172.17.0.8:44669 with proposal 1
> I0716 01:32:50.671548 26945 leveldb.cpp:304] Persisting metadata (8 bytes) to
> leveldb took 20.039474ms
> I0716 01:32:50.671633 26945 replica.cpp:342] Persisted promised to 1
> I0716 01:32:50.673152 26943 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0716 01:32:50.675154 26943 replica.cpp:388] Replica received explicit
> promise request from (15987)@172.17.0.8:44669 for position 0 with proposal 2
> I0716 01:32:50.696714 26943 leveldb.cpp:341] Persisting action (8 bytes) to
> leveldb took 21.465357ms
> I0716 01:32:50.696805 26943 replica.cpp:712] Persisted action at 0
> I0716 01:32:50.698724 26947 replica.cpp:537] Replica received write request
> for position 0 from (15988)@172.17.0.8:44669
> I0716 01:32:50.698840 26947 leveldb.cpp:436] Reading position from leveldb
> took 63125ns
> I0716 01:32:50.721994 26947 leveldb.cpp:341] Persisting action (14 bytes) to
> leveldb took 23.129832ms
> I0716 01:32:50.722702 26947 replica.cpp:712] Persisted action at 0
> I0716 01:32:50.724701 26947 replica.cpp:691] Replica received learned notice
> for position 0 from @0.0.0.0:0
> I0716 01:32:50.747094 26947 leveldb.cpp:341] Persisting action (16 bytes) to
> leveldb took 22.064167ms
> I0716 01:32:50.747727 26947 replica.cpp:712] Persisted action at 0
> I0716 01:32:50.748145 26947 replica.cpp:697] Replica learned NOP action at
> position 0
> I0716 01:32:50.749789 26950 log.cpp:569] Writer started with ending position 0
> I0716 01:32:50.751765 26950 leveldb.cpp:436] Reading position from leveldb
> took 74145ns
> I0716 01:32:50.753523 26943 registrar.cpp:365] Successfully fetched the
> registry (0B) in 170.22208ms
> I0716 01:32:50.754050 26943 registrar.cpp:464] Applied 1 operations in
> 49444ns; attempting to update the 'registry'
> I0716 01:32:50.755728 26950 log.cpp:577] Attempting to append 168 bytes to
> the log
> I0716 01:32:50.756314 26943 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0716 01:32:50.758147 26943 replica.cpp:537] Replica received write request
> for position 1 from (15989)@172.17.0.8:44669
> I0716 01:32:50.785879 26943 leveldb.cpp:341] Persisting action (187 bytes) to
> leveldb took 27.261512ms
> I0716 01:32:50.785967 26943 replica.cpp:712] Persisted action at 1
> I0716 01:32:50.788110 26954 replica.cpp:691] Replica received learned notice
> for position 1 from @0.0.0.0:0
> I0716 01:32:50.805907 26954 leveldb.cpp:341] Persisting action (189 bytes) to
> leveldb took 17.773266ms
> I0716 01:32:50.806097 26954 replica.cpp:712] Persisted action at 1
> I0716 01:32:50.806252 26954 replica.cpp:697] Replica learned APPEND action at
> position 1
> I0716 01:32:50.807741 26945 registrar.cpp:509] Successfully updated the
> 'registry' in 53.299968ms
> I0716 01:32:50.808043 26954 log.cpp:596] Attempting to truncate the log to 1
> I0716 01:32:50.808254 26954 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0716 01:32:50.808502 26945 registrar.cpp:395] Successfully recovered
> registrar
> I0716 01:32:50.809427 26945 master.cpp:1781] Recovered 0 agents from the
> Registry (129B) ; allowing 10mins for agents to re-register
> I0716 01:32:50.809613 26952 hierarchical.cpp:178] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0716 01:32:50.809664 26951 replica.cpp:537] Replica received write request
> for position 2 from (15990)@172.17.0.8:44669
> I0716 01:32:50.830983 26951 leveldb.cpp:341] Persisting action (16 bytes) to
> leveldb took 20.868656ms
> I0716 01:32:50.831116 26951 replica.cpp:712] Persisted action at 2
> I0716 01:32:50.832618 26952 replica.cpp:691] Replica received learned notice
> for position 2 from @0.0.0.0:0
> I0716 01:32:50.856155 26952 leveldb.cpp:341] Persisting action (18 bytes) to
> leveldb took 23.506659ms
> I0716 01:32:50.856313 26952 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 84579ns
> I0716 01:32:50.856344 26952 replica.cpp:712] Persisted action at 2
> I0716 01:32:50.856379 26952 replica.cpp:697] Replica learned TRUNCATE action
> at position 2
> I0716 01:32:50.865809 26921 cluster.cpp:432] Creating default 'local'
> authorizer
> I0716 01:32:50.868458 26940 slave.cpp:205] Agent started on
> 443)@172.17.0.8:44669
> I0716 01:32:50.868494 26940 slave.cpp:206] Flags at startup: --acls=""
> --appc_simple_discovery_uri_prefix="http://";
> --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http="true"
> --authenticatee="crammd5" --authentication_backoff_factor="1secs"
> --authorizer="local" --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/ContentType_MasterAPITest_GetTasks_0_nF2pJL/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"
> --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
> --enforce_container_disk_quota="false"
> --executor_registration_timeout="1mins"
> --executor_shutdown_grace_period="5secs"
> --fetcher_cache_dir="/tmp/ContentType_MasterAPITest_GetTasks_0_nF2pJL/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/ContentType_MasterAPITest_GetTasks_0_nF2pJL/http_credentials"
> --image_provisioner_backend="copy" --initialize_driver_logging="true"
> --isolation="posix/cpu,posix/mem"
> --launcher_dir="/mesos/mesos-1.1.0/_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;gpus:0;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/ContentType_MasterAPITest_GetTasks_0_nF2pJL"
> I0716 01:32:50.869688 26940 credentials.hpp:86] Loading credential for
> authentication from
> '/tmp/ContentType_MasterAPITest_GetTasks_0_nF2pJL/credential'
> I0716 01:32:50.870079 26940 slave.cpp:343] Agent using credential for:
> test-principal
> I0716 01:32:50.870344 26940 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_MasterAPITest_GetTasks_0_nF2pJL/http_credentials'
> I0716 01:32:50.870832 26940 slave.cpp:395] Using default 'basic' HTTP
> authenticator
> I0716 01:32:50.871497 26940 resources.cpp:572] Parsing resources as JSON
> failed: cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]
> Trying semicolon-delimited string format instead
> I0716 01:32:50.872261 26940 resources.cpp:572] Parsing resources as JSON
> failed: cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]
> Trying semicolon-delimited string format instead
> I0716 01:32:50.873101 26940 slave.cpp:594] Agent resources: cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0716 01:32:50.873483 26940 slave.cpp:602] Agent attributes: [ ]
> I0716 01:32:50.873859 26940 slave.cpp:607] Agent hostname: f1ca07e700ef
> I0716 01:32:50.875046 26921 sched.cpp:226] Version: 1.1.0
> I0716 01:32:50.876268 26952 state.cpp:57] Recovering state from
> '/tmp/ContentType_MasterAPITest_GetTasks_0_nF2pJL/meta'
> I0716 01:32:50.876366 26940 sched.cpp:330] New master detected at
> [email protected]:44669
> I0716 01:32:50.876677 26940 sched.cpp:396] Authenticating with master
> [email protected]:44669
> I0716 01:32:50.876759 26940 sched.cpp:403] Using default CRAM-MD5
> authenticatee
> I0716 01:32:50.876907 26952 status_update_manager.cpp:200] Recovering status
> update manager
> I0716 01:32:50.877213 26952 authenticatee.cpp:121] Creating new client SASL
> connection
> I0716 01:32:50.877348 26940 slave.cpp:4856] Finished recovery
> I0716 01:32:50.877779 26952 master.cpp:6006] Authenticating
> [email protected]:44669
> I0716 01:32:50.877959 26940 slave.cpp:5028] Querying resource estimator for
> oversubscribable resources
> I0716 01:32:50.878078 26952 authenticator.cpp:414] Starting authentication
> session for crammd5_authenticatee(916)@172.17.0.8:44669
> I0716 01:32:50.878319 26940 slave.cpp:969] New master detected at
> [email protected]:44669
> I0716 01:32:50.878448 26940 slave.cpp:1028] Authenticating with master
> [email protected]:44669
> I0716 01:32:50.878523 26939 status_update_manager.cpp:174] Pausing sending
> status updates
> I0716 01:32:50.878772 26939 authenticator.cpp:98] Creating new server SASL
> connection
> I0716 01:32:50.879057 26952 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> I0716 01:32:50.879104 26952 authenticatee.cpp:239] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0716 01:32:50.879220 26952 authenticator.cpp:204] Received SASL
> authentication start
> I0716 01:32:50.879286 26940 slave.cpp:1039] Using default CRAM-MD5
> authenticatee
> I0716 01:32:50.879297 26952 authenticator.cpp:326] Authentication requires
> more steps
> I0716 01:32:50.879634 26951 authenticatee.cpp:259] Received SASL
> authentication step
> I0716 01:32:50.879743 26951 authenticator.cpp:232] Received SASL
> authentication step
> I0716 01:32:50.879848 26951 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'f1ca07e700ef' server FQDN: 'f1ca07e700ef'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> I0716 01:32:50.879953 26951 auxprop.cpp:181] Looking up auxiliary property
> '*userPassword'
> I0716 01:32:50.880079 26951 auxprop.cpp:181] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0716 01:32:50.880189 26951 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'f1ca07e700ef' server FQDN: 'f1ca07e700ef'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> I0716 01:32:50.880283 26951 auxprop.cpp:131] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0716 01:32:50.880374 26951 auxprop.cpp:131] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0716 01:32:50.880496 26951 authenticator.cpp:318] Authentication success
> I0716 01:32:50.880745 26951 authenticatee.cpp:299] Authentication success
> I0716 01:32:50.880849 26951 master.cpp:6036] Successfully authenticated
> principal 'test-principal' at
> [email protected]:44669
> I0716 01:32:50.880964 26951 authenticator.cpp:432] Authentication session
> cleanup for crammd5_authenticatee(916)@172.17.0.8:44669
> I0716 01:32:50.881366 26951 sched.cpp:502] Successfully authenticated with
> master [email protected]:44669
> I0716 01:32:50.881392 26951 sched.cpp:820] Sending SUBSCRIBE call to
> [email protected]:44669
> I0716 01:32:50.881651 26951 sched.cpp:853] Will retry registration in
> 229.664721ms if necessary
> I0716 01:32:50.881934 26952 master.cpp:2550] Received SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669
> I0716 01:32:50.882000 26952 master.cpp:2012] Authorizing framework principal
> 'test-principal' to receive offers for role '*'
> I0716 01:32:50.882587 26952 master.cpp:2626] Subscribing framework default
> with checkpointing disabled and capabilities [ ]
> I0716 01:32:50.883420 26952 hierarchical.cpp:271] Added framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:50.883642 26949 sched.cpp:743] Framework registered with
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:50.883785 26949 sched.cpp:757] Scheduler::registered took 33974ns
> I0716 01:32:50.883600 26952 hierarchical.cpp:1537] No allocations performed
> I0716 01:32:50.883970 26940 slave.cpp:1001] Detecting new master
> I0716 01:32:50.884094 26952 hierarchical.cpp:1632] No inverse offers to send
> out!
> I0716 01:32:50.884191 26940 slave.cpp:5042] Received oversubscribable
> resources from the resource estimator
> I0716 01:32:50.884492 26949 authenticatee.cpp:121] Creating new client SASL
> connection
> I0716 01:32:50.884531 26952 hierarchical.cpp:1172] Performed allocation for 0
> agents in 1.098019ms
> I0716 01:32:50.884908 26946 master.cpp:6006] Authenticating
> slave(443)@172.17.0.8:44669
> I0716 01:32:50.885133 26946 authenticator.cpp:414] Starting authentication
> session for crammd5_authenticatee(917)@172.17.0.8:44669
> I0716 01:32:50.885511 26946 authenticator.cpp:98] Creating new server SASL
> connection
> I0716 01:32:50.885757 26949 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> I0716 01:32:50.885792 26949 authenticatee.cpp:239] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0716 01:32:50.885886 26949 authenticator.cpp:204] Received SASL
> authentication start
> I0716 01:32:50.885944 26949 authenticator.cpp:326] Authentication requires
> more steps
> I0716 01:32:50.886020 26949 authenticatee.cpp:259] Received SASL
> authentication step
> I0716 01:32:50.886106 26949 authenticator.cpp:232] Received SASL
> authentication step
> I0716 01:32:50.886137 26949 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'f1ca07e700ef' server FQDN: 'f1ca07e700ef'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> I0716 01:32:50.886149 26949 auxprop.cpp:181] Looking up auxiliary property
> '*userPassword'
> I0716 01:32:50.886185 26949 auxprop.cpp:181] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0716 01:32:50.886207 26949 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'f1ca07e700ef' server FQDN: 'f1ca07e700ef'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> I0716 01:32:50.886220 26949 auxprop.cpp:131] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0716 01:32:50.886231 26949 auxprop.cpp:131] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0716 01:32:50.886248 26949 authenticator.cpp:318] Authentication success
> I0716 01:32:50.886387 26949 authenticatee.cpp:299] Authentication success
> I0716 01:32:50.886618 26949 master.cpp:6036] Successfully authenticated
> principal 'test-principal' at slave(443)@172.17.0.8:44669
> I0716 01:32:50.886695 26949 authenticator.cpp:432] Authentication session
> cleanup for crammd5_authenticatee(917)@172.17.0.8:44669
> I0716 01:32:50.886988 26949 slave.cpp:1123] Successfully authenticated with
> master [email protected]:44669
> I0716 01:32:50.887161 26949 slave.cpp:1529] Will retry registration in
> 8.740926ms if necessary
> I0716 01:32:50.887598 26949 master.cpp:4676] Registering agent at
> slave(443)@172.17.0.8:44669 (f1ca07e700ef) with id
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0
> I0716 01:32:50.888099 26949 registrar.cpp:464] Applied 1 operations in
> 82483ns; attempting to update the 'registry'
> I0716 01:32:50.889273 26947 log.cpp:577] Attempting to append 337 bytes to
> the log
> I0716 01:32:50.889516 26942 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 3
> I0716 01:32:50.890645 26942 replica.cpp:537] Replica received write request
> for position 3 from (15996)@172.17.0.8:44669
> I0716 01:32:50.896863 26944 slave.cpp:1529] Will retry registration in
> 16.748832ms if necessary
> I0716 01:32:50.897285 26944 master.cpp:4664] Ignoring register agent message
> from slave(443)@172.17.0.8:44669 (f1ca07e700ef) as admission is already in
> progress
> I0716 01:32:50.914973 26951 master.cpp:4664] Ignoring register agent message
> from slave(443)@172.17.0.8:44669 (f1ca07e700ef) as admission is already in
> progress
> I0716 01:32:50.914651 26939 slave.cpp:1529] Will retry registration in
> 4.693356ms if necessary
> I0716 01:32:50.920524 26942 leveldb.cpp:341] Persisting action (356 bytes) to
> leveldb took 29.849165ms
> I0716 01:32:50.920678 26942 replica.cpp:712] Persisted action at 3
> I0716 01:32:50.920810 26945 slave.cpp:1529] Will retry registration in
> 140.669866ms if necessary
> I0716 01:32:50.921087 26942 master.cpp:4664] Ignoring register agent message
> from slave(443)@172.17.0.8:44669 (f1ca07e700ef) as admission is already in
> progress
> I0716 01:32:50.922183 26946 replica.cpp:691] Replica received learned notice
> for position 3 from @0.0.0.0:0
> I0716 01:32:50.962424 26946 leveldb.cpp:341] Persisting action (358 bytes) to
> leveldb took 39.939635ms
> I0716 01:32:50.962512 26946 replica.cpp:712] Persisted action at 3
> I0716 01:32:50.962548 26946 replica.cpp:697] Replica learned APPEND action at
> position 3
> I0716 01:32:50.965457 26945 log.cpp:596] Attempting to truncate the log to 3
> I0716 01:32:50.965677 26942 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 4
> I0716 01:32:50.965787 26946 registrar.cpp:509] Successfully updated the
> 'registry' in 77.241088ms
> I0716 01:32:50.966897 26939 replica.cpp:537] Replica received write request
> for position 4 from (15997)@172.17.0.8:44669
> I0716 01:32:50.966904 26945 slave.cpp:3760] Received ping from
> slave-observer(411)@172.17.0.8:44669
> I0716 01:32:50.966961 26946 master.cpp:4745] Registered agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at slave(443)@172.17.0.8:44669
> (f1ca07e700ef) with cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000]
> I0716 01:32:50.967288 26945 slave.cpp:1169] Registered with master
> [email protected]:44669; given agent ID
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0
> I0716 01:32:50.967479 26945 fetcher.cpp:86] Clearing fetcher cache
> I0716 01:32:50.967458 26954 hierarchical.cpp:478] Added agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 (f1ca07e700ef) with cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
> I0716 01:32:50.967780 26946 status_update_manager.cpp:181] Resuming sending
> status updates
> I0716 01:32:50.968631 26954 hierarchical.cpp:1632] No inverse offers to send
> out!
> I0716 01:32:50.968713 26954 hierarchical.cpp:1195] Performed allocation for
> agent 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 in 1.009599ms
> I0716 01:32:50.969025 26941 master.cpp:5835] Sending 1 offers to framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (default) at
> [email protected]:44669
> I0716 01:32:50.969563 26954 sched.cpp:917] Scheduler::resourceOffers took
> 135476ns
> I0716 01:32:50.971268 26945 slave.cpp:1192] Checkpointing SlaveInfo to
> '/tmp/ContentType_MasterAPITest_GetTasks_0_nF2pJL/meta/slaves/2949f69e-5d82-48a7-80da-ba654dac4ed1-S0/slave.info'
> I0716 01:32:50.971293 26940 master.cpp:3468] Processing ACCEPT call for
> offers: [ 2949f69e-5d82-48a7-80da-ba654dac4ed1-O0 ] on agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at slave(443)@172.17.0.8:44669
> (f1ca07e700ef) for framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> (default) at [email protected]:44669
> I0716 01:32:50.971374 26940 master.cpp:3106] Authorizing framework principal
> 'test-principal' to launch task 1
> I0716 01:32:50.971781 26945 slave.cpp:1229] Forwarding total oversubscribed
> resources
> I0716 01:32:50.972097 26940 master.cpp:5128] Received update of agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at slave(443)@172.17.0.8:44669
> (f1ca07e700ef) with total oversubscribed resources
> I0716 01:32:50.972338 26940 hierarchical.cpp:542] Agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 (f1ca07e700ef) updated with
> oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000])
> I0716 01:32:50.972527 26940 hierarchical.cpp:1537] No allocations performed
> I0716 01:32:50.972671 26940 hierarchical.cpp:1632] No inverse offers to send
> out!
> I0716 01:32:50.972820 26940 hierarchical.cpp:1195] Performed allocation for
> agent 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 in 437908ns
> W0716 01:32:50.973783 26950 validation.cpp:650] Executor default 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.
> W0716 01:32:50.973839 26950 validation.cpp:662] Executor default for task 1
> uses less memory (None) than the minimum required (32MB). Please update your
> executor, as this will be mandatory in future releases.
> I0716 01:32:50.974295 26950 master.cpp:7565] Adding task 1 with resources
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 (f1ca07e700ef)
> I0716 01:32:50.974551 26950 master.cpp:3957] Launching task 1 of framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (default) at
> [email protected]:44669 with
> resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> agent 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at slave(443)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:50.975044 26940 slave.cpp:1569] Got assigned task 1 for framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:50.975647 26940 slave.cpp:1688] Launching task 1 for framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:50.976299 26940 paths.cpp:528] Trying to chown
> '/tmp/ContentType_MasterAPITest_GetTasks_0_nF2pJL/slaves/2949f69e-5d82-48a7-80da-ba654dac4ed1-S0/frameworks/2949f69e-5d82-48a7-80da-ba654dac4ed1-0000/executors/default/runs/b9ec9438-ec55-4667-96ea-62e63e624cf8'
> to user 'mesos'
> I0716 01:32:50.991979 26940 slave.cpp:5748] Launching executor default of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 with resources in work
> directory
> '/tmp/ContentType_MasterAPITest_GetTasks_0_nF2pJL/slaves/2949f69e-5d82-48a7-80da-ba654dac4ed1-S0/frameworks/2949f69e-5d82-48a7-80da-ba654dac4ed1-0000/executors/default/runs/b9ec9438-ec55-4667-96ea-62e63e624cf8'
> I0716 01:32:50.995538 26940 exec.cpp:161] Version: 1.1.0
> I0716 01:32:50.996342 26940 slave.cpp:1914] Queuing task '1' for executor
> 'default' of framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:50.996474 26952 exec.cpp:211] Executor started at:
> executor(147)@172.17.0.8:44669 with pid 26921
> I0716 01:32:50.996603 26940 slave.cpp:922] Successfully attached file
> '/tmp/ContentType_MasterAPITest_GetTasks_0_nF2pJL/slaves/2949f69e-5d82-48a7-80da-ba654dac4ed1-S0/frameworks/2949f69e-5d82-48a7-80da-ba654dac4ed1-0000/executors/default/runs/b9ec9438-ec55-4667-96ea-62e63e624cf8'
> I0716 01:32:50.996870 26940 slave.cpp:2902] Got registration for executor
> 'default' of framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 from
> executor(147)@172.17.0.8:44669
> I0716 01:32:50.997639 26952 exec.cpp:236] Executor registered on agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0
> I0716 01:32:50.997742 26952 exec.cpp:248] Executor::registered took 84319ns
> I0716 01:32:50.997860 26940 slave.cpp:2079] Sending queued task '1' to
> executor 'default' of framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 at
> executor(147)@172.17.0.8:44669
> I0716 01:32:50.998267 26940 exec.cpp:323] Executor asked to run task '1'
> I0716 01:32:50.998633 26940 exec.cpp:332] Executor::launchTask took 244810ns
> I0716 01:32:50.998847 26940 exec.cpp:549] Executor sending status update
> TASK_RUNNING (UUID: 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887) for task 1 of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:50.999171 26940 slave.cpp:3285] Handling status update
> TASK_RUNNING (UUID: 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887) for task 1 of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 from
> executor(147)@172.17.0.8:44669
> I0716 01:32:51.000075 26940 status_update_manager.cpp:320] Received status
> update TASK_RUNNING (UUID: 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887) for task 1
> of framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.000264 26940 status_update_manager.cpp:497] Creating
> StatusUpdate stream for task 1 of framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.000880 26940 status_update_manager.cpp:374] Forwarding update
> TASK_RUNNING (UUID: 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887) for task 1 of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 to the agent
> I0716 01:32:51.001377 26940 slave.cpp:3678] Forwarding the update
> TASK_RUNNING (UUID: 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887) for task 1 of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 to [email protected]:44669
> I0716 01:32:51.001960 26945 master.cpp:5273] Status update TASK_RUNNING
> (UUID: 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887) for task 1 of framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 from agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at slave(443)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.002070 26945 master.cpp:5321] Forwarding status update
> TASK_RUNNING (UUID: 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887) for task 1 of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.002312 26945 master.cpp:6959] Updating the state of task 1 of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (latest state:
> TASK_RUNNING, status update state: TASK_RUNNING)
> I0716 01:32:51.002723 26941 sched.cpp:1025] Scheduler::statusUpdate took
> 156806ns
> I0716 01:32:51.003517 26941 master.cpp:4388] Processing ACKNOWLEDGE call
> 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887 for task 1 of framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (default) at
> [email protected]:44669 on agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0
> I0716 01:32:51.007225 26950 process.cpp:3354] Handling HTTP event for process
> 'master' with path: '/master/api/v1'
> I0716 01:32:51.008761 26950 http.cpp:381] HTTP POST for /master/api/v1 from
> 172.17.0.8:40837
> I0716 01:32:51.008914 26950 http.cpp:484] Processing call GET_TASKS
> I0716 01:32:51.013517 26939 leveldb.cpp:341] Persisting action (16 bytes) to
> leveldb took 46.510882ms
> I0716 01:32:51.013581 26939 replica.cpp:712] Persisted action at 4
> I0716 01:32:51.014714 26951 replica.cpp:691] Replica received learned notice
> for position 4 from @0.0.0.0:0
> I0716 01:32:51.016996 26949 exec.cpp:549] Executor sending status update
> TASK_FINISHED (UUID: f78d241c-6845-4b08-b16d-9156d226bc3d) for task 1 of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.017482 26940 slave.cpp:3572] Status update manager
> successfully handled status update TASK_RUNNING (UUID:
> 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887) for task 1 of framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.017599 26940 slave.cpp:3588] Sending acknowledgement for
> status update TASK_RUNNING (UUID: 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887) for
> task 1 of framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 to
> executor(147)@172.17.0.8:44669
> I0716 01:32:51.017900 26945 exec.cpp:372] Executor received status update
> acknowledgement 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887 for task 1 of framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.018393 26941 status_update_manager.cpp:392] Received status
> update acknowledgement (UUID: 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887) for task
> 1 of framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.018950 26940 slave.cpp:3285] Handling status update
> TASK_FINISHED (UUID: f78d241c-6845-4b08-b16d-9156d226bc3d) for task 1 of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 from
> executor(147)@172.17.0.8:44669
> I0716 01:32:51.019373 26940 slave.cpp:2671] Status update manager
> successfully handled status update acknowledgement (UUID:
> 97f0a1e3-0d3f-4a91-b9c7-04e7f3560887) for task 1 of framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.019595 26940 slave.cpp:6088] Terminating task 1
> I0716 01:32:51.020350 26949 status_update_manager.cpp:320] Received status
> update TASK_FINISHED (UUID: f78d241c-6845-4b08-b16d-9156d226bc3d) for task 1
> of framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.020614 26949 status_update_manager.cpp:374] Forwarding update
> TASK_FINISHED (UUID: f78d241c-6845-4b08-b16d-9156d226bc3d) for task 1 of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 to the agent
> I0716 01:32:51.021210 26940 slave.cpp:3678] Forwarding the update
> TASK_FINISHED (UUID: f78d241c-6845-4b08-b16d-9156d226bc3d) for task 1 of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 to [email protected]:44669
> I0716 01:32:51.021719 26953 master.cpp:5273] Status update TASK_FINISHED
> (UUID: f78d241c-6845-4b08-b16d-9156d226bc3d) for task 1 of framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 from agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at slave(443)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.021829 26953 master.cpp:5321] Forwarding status update
> TASK_FINISHED (UUID: f78d241c-6845-4b08-b16d-9156d226bc3d) for task 1 of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.022313 26953 master.cpp:6959] Updating the state of task 1 of
> framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (latest state:
> TASK_FINISHED, status update state: TASK_FINISHED)
> I0716 01:32:51.022878 26948 sched.cpp:1025] Scheduler::statusUpdate took
> 187419ns
> I0716 01:32:51.024267 26944 hierarchical.cpp:924] Recovered cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: ) on agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 from framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.028446 26942 process.cpp:3354] Handling HTTP event for process
> 'master' with path: '/master/api/v1'
> I0716 01:32:51.029857 26942 http.cpp:381] HTTP POST for /master/api/v1 from
> 172.17.0.8:40838
> I0716 01:32:51.029990 26942 http.cpp:484] Processing call GET_TASKS
> ../../src/tests/api_tests.cpp:690: Failure
> Value of: v1Response.get().get_tasks().tasks().size()
> Actual: 1
> Expected: 0
> I0716 01:32:51.036751 26948 master.cpp:4388] Processing ACKNOWLEDGE call
> f78d241c-6845-4b08-b16d-9156d226bc3d for task 1 of framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (default) at
> [email protected]:44669 on agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0
> I0716 01:32:51.038859 26948 master.cpp:7025] Removing task 1 with resources
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 on agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at slave(443)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.039563 26948 master.cpp:1410] Framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (default) at
> [email protected]:44669 disconnected
> I0716 01:32:51.039683 26948 master.cpp:2851] Disconnecting framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (default) at
> [email protected]:44669
> I0716 01:32:51.039808 26948 master.cpp:2875] Deactivating framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (default) at
> [email protected]:44669
> I0716 01:32:51.040135 26941 hierarchical.cpp:382] Deactivated framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.040253 26948 master.cpp:1423] Giving framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (default) at
> [email protected]:44669 0ns to
> failover
> I0716 01:32:51.040637 26940 slave.cpp:841] Agent terminating
> I0716 01:32:51.040760 26940 slave.cpp:2292] Asked to shut down framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 by @0.0.0.0:0
> I0716 01:32:51.040865 26940 slave.cpp:2317] Shutting down framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.040992 26940 slave.cpp:4481] Shutting down executor 'default'
> of framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 at
> executor(147)@172.17.0.8:44669
> I0716 01:32:51.041618 26947 master.cpp:1371] Agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at slave(443)@172.17.0.8:44669
> (f1ca07e700ef) disconnected
> I0716 01:32:51.041784 26947 master.cpp:2910] Disconnecting agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at slave(443)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.042137 26947 master.cpp:2929] Deactivating agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at slave(443)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.044621 26947 master.cpp:1390] Removing framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (default) at
> [email protected]:44669 from
> disconnected agent 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at
> slave(443)@172.17.0.8:44669 (f1ca07e700ef) because the framework is not
> checkpointing
> I0716 01:32:51.044756 26945 hierarchical.cpp:571] Agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 deactivated
> I0716 01:32:51.044912 26947 master.cpp:6574] Removing framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (default) at
> [email protected]:44669 from agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at slave(443)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.045184 26947 master.cpp:7054] Removing executor 'default' with
> resources of framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 on agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0 at slave(443)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.045604 26947 master.cpp:5687] Framework failover timeout,
> removing framework 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (default) at
> [email protected]:44669
> I0716 01:32:51.045850 26947 master.cpp:6422] Removing framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000 (default) at
> [email protected]:44669
> I0716 01:32:51.046778 26953 hierarchical.cpp:333] Removed framework
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-0000
> I0716 01:32:51.054568 26921 master.cpp:1218] Master terminating
> I0716 01:32:51.054965 26945 hierarchical.cpp:510] Removed agent
> 2949f69e-5d82-48a7-80da-ba654dac4ed1-S0
> I0716 01:32:51.063762 26951 leveldb.cpp:341] Persisting action (18 bytes) to
> leveldb took 48.811786ms
> I0716 01:32:51.063956 26951 leveldb.cpp:399] Deleting ~2 keys from leveldb
> took 83527ns
> I0716 01:32:51.064023 26951 replica.cpp:712] Persisted action at 4
> I0716 01:32:51.064111 26951 replica.cpp:697] Replica learned TRUNCATE action
> at position 4
> [ FAILED ] ContentType/MasterAPITest.GetTasks/0, where GetParam() =
> application/x-protobuf (654 ms)
> {code}
> A success run
> {code}
> [ RUN ] ContentType/MasterAPITest.GetTasks/1
> I0716 01:32:51.098104 26921 cluster.cpp:155] Creating default 'local'
> authorizer
> I0716 01:32:51.264447 26921 leveldb.cpp:174] Opened db in 164.735275ms
> I0716 01:32:51.331194 26921 leveldb.cpp:181] Compacted db in 66.341913ms
> I0716 01:32:51.331606 26921 leveldb.cpp:196] Created db iterator in 70027ns
> I0716 01:32:51.331733 26921 leveldb.cpp:202] Seeked to beginning of db in
> 16516ns
> I0716 01:32:51.331825 26921 leveldb.cpp:271] Iterated through 0 keys in the
> db in 12801ns
> I0716 01:32:51.331959 26921 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0716 01:32:51.333200 26949 recover.cpp:451] Starting replica recovery
> I0716 01:32:51.333560 26949 recover.cpp:477] Replica is in EMPTY status
> I0716 01:32:51.335213 26949 replica.cpp:673] Replica in EMPTY status received
> a broadcasted recover request from (16006)@172.17.0.8:44669
> I0716 01:32:51.335657 26949 recover.cpp:197] Received a recover response from
> a replica in EMPTY status
> I0716 01:32:51.336303 26949 recover.cpp:568] Updating replica status to
> STARTING
> I0716 01:32:51.343477 26952 master.cpp:382] Master
> 1f4b1971-a098-4ced-be7a-b26d4c06983c (f1ca07e700ef) started on
> 172.17.0.8:44669
> I0716 01:32:51.343580 26952 master.cpp:384] Flags at startup: --acls=""
> --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate_agents="true" --authenticate_frameworks="true"
> --authenticate_http="true" --authenticate_http_frameworks="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/PD9O7I/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_agent_ping_timeouts="5" --max_completed_frameworks="50"
> --max_completed_tasks_per_framework="1000" --quiet="false"
> --recovery_agent_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="100secs"
> --registry_strict="true" --root_submissions="true" --user_sorter="drf"
> --version="false" --webui_dir="/mesos/mesos-1.1.0/_inst/share/mesos/webui"
> --work_dir="/tmp/PD9O7I/master" --zk_session_timeout="10secs"
> I0716 01:32:51.344064 26952 master.cpp:434] Master only allowing
> authenticated frameworks to register
> I0716 01:32:51.344149 26952 master.cpp:448] Master only allowing
> authenticated agents to register
> I0716 01:32:51.344214 26952 master.cpp:461] Master only allowing
> authenticated HTTP frameworks to register
> I0716 01:32:51.344279 26952 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/PD9O7I/credentials'
> I0716 01:32:51.344698 26952 master.cpp:506] Using default 'crammd5'
> authenticator
> I0716 01:32:51.344935 26952 master.cpp:578] Using default 'basic' HTTP
> authenticator
> I0716 01:32:51.345160 26952 master.cpp:658] Using default 'basic' HTTP
> framework authenticator
> I0716 01:32:51.345499 26952 master.cpp:705] Authorization enabled
> I0716 01:32:51.346536 26943 hierarchical.cpp:151] Initialized hierarchical
> allocator process
> I0716 01:32:51.346608 26953 whitelist_watcher.cpp:77] No whitelist given
> I0716 01:32:51.351202 26952 master.cpp:1973] The newly elected leader is
> [email protected]:44669 with id 1f4b1971-a098-4ced-be7a-b26d4c06983c
> I0716 01:32:51.351379 26952 master.cpp:1986] Elected as the leading master!
> I0716 01:32:51.351469 26952 master.cpp:1673] Recovering from registrar
> I0716 01:32:51.351775 26952 registrar.cpp:332] Recovering registrar
> I0716 01:32:51.386600 26949 leveldb.cpp:304] Persisting metadata (8 bytes) to
> leveldb took 50.035837ms
> I0716 01:32:51.386680 26949 replica.cpp:320] Persisted replica status to
> STARTING
> I0716 01:32:51.386975 26949 recover.cpp:477] Replica is in STARTING status
> I0716 01:32:51.389536 26950 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (16010)@172.17.0.8:44669
> I0716 01:32:51.390117 26941 recover.cpp:197] Received a recover response from
> a replica in STARTING status
> I0716 01:32:51.390676 26941 recover.cpp:568] Updating replica status to VOTING
> I0716 01:32:51.431485 26941 leveldb.cpp:304] Persisting metadata (8 bytes) to
> leveldb took 40.608222ms
> I0716 01:32:51.431571 26941 replica.cpp:320] Persisted replica status to
> VOTING
> I0716 01:32:51.431807 26941 recover.cpp:582] Successfully joined the Paxos
> group
> I0716 01:32:51.432003 26941 recover.cpp:466] Recover process terminated
> I0716 01:32:51.432876 26947 log.cpp:553] Attempting to start the writer
> I0716 01:32:51.434335 26951 replica.cpp:493] Replica received implicit
> promise request from (16011)@172.17.0.8:44669 with proposal 1
> I0716 01:32:51.474196 26951 leveldb.cpp:304] Persisting metadata (8 bytes) to
> leveldb took 39.855836ms
> I0716 01:32:51.474290 26951 replica.cpp:342] Persisted promised to 1
> I0716 01:32:51.475812 26951 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0716 01:32:51.477309 26945 replica.cpp:388] Replica received explicit
> promise request from (16012)@172.17.0.8:44669 for position 0 with proposal 2
> I0716 01:32:51.515359 26945 leveldb.cpp:341] Persisting action (8 bytes) to
> leveldb took 38.033709ms
> I0716 01:32:51.515458 26945 replica.cpp:712] Persisted action at 0
> I0716 01:32:51.517084 26944 replica.cpp:537] Replica received write request
> for position 0 from (16013)@172.17.0.8:44669
> I0716 01:32:51.517196 26944 leveldb.cpp:436] Reading position from leveldb
> took 56620ns
> I0716 01:32:51.558805 26944 leveldb.cpp:341] Persisting action (14 bytes) to
> leveldb took 41.493767ms
> I0716 01:32:51.558882 26944 replica.cpp:712] Persisted action at 0
> I0716 01:32:51.559965 26951 replica.cpp:691] Replica received learned notice
> for position 0 from @0.0.0.0:0
> I0716 01:32:51.584096 26951 leveldb.cpp:341] Persisting action (16 bytes) to
> leveldb took 23.543826ms
> I0716 01:32:51.584297 26951 replica.cpp:712] Persisted action at 0
> I0716 01:32:51.584491 26951 replica.cpp:697] Replica learned NOP action at
> position 0
> I0716 01:32:51.585485 26951 log.cpp:569] Writer started with ending position 0
> I0716 01:32:51.587004 26954 leveldb.cpp:436] Reading position from leveldb
> took 98945ns
> I0716 01:32:51.588127 26950 registrar.cpp:365] Successfully fetched the
> registry (0B) in 236.073984ms
> I0716 01:32:51.588337 26950 registrar.cpp:464] Applied 1 operations in
> 131037ns; attempting to update the 'registry'
> I0716 01:32:51.589709 26939 log.cpp:577] Attempting to append 168 bytes to
> the log
> I0716 01:32:51.589882 26948 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0716 01:32:51.590795 26942 replica.cpp:537] Replica received write request
> for position 1 from (16014)@172.17.0.8:44669
> I0716 01:32:51.610009 26942 leveldb.cpp:341] Persisting action (187 bytes) to
> leveldb took 19.202954ms
> I0716 01:32:51.610101 26942 replica.cpp:712] Persisted action at 1
> I0716 01:32:51.611517 26942 replica.cpp:691] Replica received learned notice
> for position 1 from @0.0.0.0:0
> I0716 01:32:51.635295 26942 leveldb.cpp:341] Persisting action (189 bytes) to
> leveldb took 23.774987ms
> I0716 01:32:51.635390 26942 replica.cpp:712] Persisted action at 1
> I0716 01:32:51.635447 26942 replica.cpp:697] Replica learned APPEND action at
> position 1
> I0716 01:32:51.637537 26949 registrar.cpp:509] Successfully updated the
> 'registry' in 48.957952ms
> I0716 01:32:51.637552 26943 log.cpp:596] Attempting to truncate the log to 1
> I0716 01:32:51.638185 26949 registrar.cpp:395] Successfully recovered
> registrar
> I0716 01:32:51.638221 26943 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0716 01:32:51.638700 26944 master.cpp:1781] Recovered 0 agents from the
> Registry (129B) ; allowing 10mins for agents to re-register
> I0716 01:32:51.638813 26949 hierarchical.cpp:178] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0716 01:32:51.639576 26949 replica.cpp:537] Replica received write request
> for position 2 from (16015)@172.17.0.8:44669
> I0716 01:32:51.668931 26949 leveldb.cpp:341] Persisting action (16 bytes) to
> leveldb took 29.277183ms
> I0716 01:32:51.669129 26949 replica.cpp:712] Persisted action at 2
> I0716 01:32:51.670639 26946 replica.cpp:691] Replica received learned notice
> for position 2 from @0.0.0.0:0
> I0716 01:32:51.699235 26946 leveldb.cpp:341] Persisting action (18 bytes) to
> leveldb took 28.588884ms
> I0716 01:32:51.699571 26946 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 109168ns
> I0716 01:32:51.699676 26946 replica.cpp:712] Persisted action at 2
> I0716 01:32:51.699805 26946 replica.cpp:697] Replica learned TRUNCATE action
> at position 2
> I0716 01:32:51.711055 26921 cluster.cpp:432] Creating default 'local'
> authorizer
> I0716 01:32:51.721844 26945 slave.cpp:205] Agent started on
> 444)@172.17.0.8:44669
> I0716 01:32:51.721902 26945 slave.cpp:206] Flags at startup: --acls=""
> --appc_simple_discovery_uri_prefix="http://";
> --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http="true"
> --authenticatee="crammd5" --authentication_backoff_factor="1secs"
> --authorizer="local" --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/ContentType_MasterAPITest_GetTasks_1_B16J9J/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"
> --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
> --enforce_container_disk_quota="false"
> --executor_registration_timeout="1mins"
> --executor_shutdown_grace_period="5secs"
> --fetcher_cache_dir="/tmp/ContentType_MasterAPITest_GetTasks_1_B16J9J/fetch"
> --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks"
> --gc_disk_headroom="0.1" --hadoop_home="" --help="false"
> --hostname_lookup="true" --http_authenticators="basic"
> --http_command_executor="false"
> --http_credentials="/tmp/ContentType_MasterAPITest_GetTasks_1_B16J9J/http_credentials"
> --image_provisioner_backend="copy" --initialize_driver_logging="true"
> --isolation="posix/cpu,posix/mem"
> --launcher_dir="/mesos/mesos-1.1.0/_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;gpus:0;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/ContentType_MasterAPITest_GetTasks_1_B16J9J"
> I0716 01:32:51.723016 26945 credentials.hpp:86] Loading credential for
> authentication from
> '/tmp/ContentType_MasterAPITest_GetTasks_1_B16J9J/credential'
> I0716 01:32:51.723567 26945 slave.cpp:343] Agent using credential for:
> test-principal
> I0716 01:32:51.723621 26945 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_MasterAPITest_GetTasks_1_B16J9J/http_credentials'
> I0716 01:32:51.724102 26945 slave.cpp:395] Using default 'basic' HTTP
> authenticator
> I0716 01:32:51.724607 26945 resources.cpp:572] Parsing resources as JSON
> failed: cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]
> Trying semicolon-delimited string format instead
> I0716 01:32:51.725282 26945 resources.cpp:572] Parsing resources as JSON
> failed: cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]
> Trying semicolon-delimited string format instead
> I0716 01:32:51.726402 26945 slave.cpp:594] Agent resources: cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0716 01:32:51.726598 26945 slave.cpp:602] Agent attributes: [ ]
> I0716 01:32:51.726624 26945 slave.cpp:607] Agent hostname: f1ca07e700ef
> I0716 01:32:51.729462 26952 state.cpp:57] Recovering state from
> '/tmp/ContentType_MasterAPITest_GetTasks_1_B16J9J/meta'
> I0716 01:32:51.730470 26953 status_update_manager.cpp:200] Recovering status
> update manager
> I0716 01:32:51.730996 26942 slave.cpp:4856] Finished recovery
> I0716 01:32:51.733889 26921 sched.cpp:226] Version: 1.1.0
> I0716 01:32:51.734863 26948 sched.cpp:330] New master detected at
> [email protected]:44669
> I0716 01:32:51.735283 26948 sched.cpp:396] Authenticating with master
> [email protected]:44669
> I0716 01:32:51.735611 26948 sched.cpp:403] Using default CRAM-MD5
> authenticatee
> I0716 01:32:51.736273 26948 authenticatee.cpp:121] Creating new client SASL
> connection
> I0716 01:32:51.737021 26948 master.cpp:6006] Authenticating
> [email protected]:44669
> I0716 01:32:51.737483 26946 authenticator.cpp:414] Starting authentication
> session for crammd5_authenticatee(918)@172.17.0.8:44669
> I0716 01:32:51.738174 26948 authenticator.cpp:98] Creating new server SASL
> connection
> I0716 01:32:51.739084 26948 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> I0716 01:32:51.739521 26948 authenticatee.cpp:239] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0716 01:32:51.740059 26948 authenticator.cpp:204] Received SASL
> authentication start
> I0716 01:32:51.740506 26948 authenticator.cpp:326] Authentication requires
> more steps
> I0716 01:32:51.741026 26948 authenticatee.cpp:259] Received SASL
> authentication step
> I0716 01:32:51.741559 26948 authenticator.cpp:232] Received SASL
> authentication step
> I0716 01:32:51.742002 26948 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'f1ca07e700ef' server FQDN: 'f1ca07e700ef'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> I0716 01:32:51.742313 26948 auxprop.cpp:181] Looking up auxiliary property
> '*userPassword'
> I0716 01:32:51.743170 26942 slave.cpp:5028] Querying resource estimator for
> oversubscribable resources
> I0716 01:32:51.743639 26948 auxprop.cpp:181] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0716 01:32:51.744184 26948 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'f1ca07e700ef' server FQDN: 'f1ca07e700ef'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> I0716 01:32:51.744524 26948 auxprop.cpp:131] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0716 01:32:51.744845 26948 auxprop.cpp:131] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0716 01:32:51.745173 26948 authenticator.cpp:318] Authentication success
> I0716 01:32:51.745687 26949 authenticatee.cpp:299] Authentication success
> I0716 01:32:51.746353 26939 sched.cpp:502] Successfully authenticated with
> master [email protected]:44669
> I0716 01:32:51.746675 26939 sched.cpp:820] Sending SUBSCRIBE call to
> [email protected]:44669
> I0716 01:32:51.747166 26939 sched.cpp:853] Will retry registration in
> 1.572936764secs if necessary
> I0716 01:32:51.747802 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.748358 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.748917 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.749441 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.749965 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.750463 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.751009 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.751515 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.752041 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.752570 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.753093 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.753612 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.754137 26939 master.cpp:2486] Queuing up SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669 because
> authentication is still in progress
> I0716 01:32:51.754494 26939 master.cpp:6036] Successfully authenticated
> principal 'test-principal' at
> [email protected]:44669
> I0716 01:32:51.754542 26947 authenticator.cpp:432] Authentication session
> cleanup for crammd5_authenticatee(918)@172.17.0.8:44669
> I0716 01:32:51.754624 26939 master.cpp:2550] Received SUBSCRIBE call for
> framework 'default' at
> [email protected]:44669
> I0716 01:32:51.754645 26939 master.cpp:2012] Authorizing framework principal
> 'test-principal' to receive offers for role '*'
> I0716 01:32:51.755347 26939 master.cpp:2626] Subscribing framework default
> with checkpointing disabled and capabilities [ ]
> I0716 01:32:51.755751 26942 slave.cpp:969] New master detected at
> [email protected]:44669
> I0716 01:32:51.755772 26940 status_update_manager.cpp:174] Pausing sending
> status updates
> I0716 01:32:51.756310 26942 slave.cpp:1028] Authenticating with master
> [email protected]:44669
> I0716 01:32:51.756665 26942 slave.cpp:1039] Using default CRAM-MD5
> authenticatee
> I0716 01:32:51.756948 26948 authenticatee.cpp:121] Creating new client SASL
> connection
> I0716 01:32:51.756994 26942 slave.cpp:1001] Detecting new master
> I0716 01:32:51.757282 26942 slave.cpp:5042] Received oversubscribable
> resources from the resource estimator
> I0716 01:32:51.757871 26952 hierarchical.cpp:271] Added framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.758533 26952 hierarchical.cpp:1537] No allocations performed
> I0716 01:32:51.758572 26952 hierarchical.cpp:1632] No inverse offers to send
> out!
> I0716 01:32:51.758621 26943 sched.cpp:743] Framework registered with
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.758636 26952 hierarchical.cpp:1172] Performed allocation for 0
> agents in 177317ns
> I0716 01:32:51.758898 26939 master.cpp:6006] Authenticating
> slave(444)@172.17.0.8:44669
> I0716 01:32:51.759042 26954 authenticator.cpp:414] Starting authentication
> session for crammd5_authenticatee(919)@172.17.0.8:44669
> I0716 01:32:51.758776 26943 sched.cpp:757] Scheduler::registered took 36064ns
> I0716 01:32:51.759495 26939 authenticator.cpp:98] Creating new server SASL
> connection
> I0716 01:32:51.759745 26954 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> I0716 01:32:51.759863 26954 authenticatee.cpp:239] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0716 01:32:51.760135 26939 authenticator.cpp:204] Received SASL
> authentication start
> I0716 01:32:51.760263 26939 authenticator.cpp:326] Authentication requires
> more steps
> I0716 01:32:51.760511 26939 authenticatee.cpp:259] Received SASL
> authentication step
> I0716 01:32:51.760748 26939 authenticator.cpp:232] Received SASL
> authentication step
> I0716 01:32:51.760790 26939 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'f1ca07e700ef' server FQDN: 'f1ca07e700ef'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> I0716 01:32:51.760807 26939 auxprop.cpp:181] Looking up auxiliary property
> '*userPassword'
> I0716 01:32:51.760846 26939 auxprop.cpp:181] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0716 01:32:51.760869 26939 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'f1ca07e700ef' server FQDN: 'f1ca07e700ef'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> I0716 01:32:51.760882 26939 auxprop.cpp:131] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0716 01:32:51.760892 26939 auxprop.cpp:131] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0716 01:32:51.760910 26939 authenticator.cpp:318] Authentication success
> I0716 01:32:51.760990 26954 authenticatee.cpp:299] Authentication success
> I0716 01:32:51.761041 26948 master.cpp:6036] Successfully authenticated
> principal 'test-principal' at slave(444)@172.17.0.8:44669
> I0716 01:32:51.761131 26939 authenticator.cpp:432] Authentication session
> cleanup for crammd5_authenticatee(919)@172.17.0.8:44669
> I0716 01:32:51.761523 26948 slave.cpp:1123] Successfully authenticated with
> master [email protected]:44669
> I0716 01:32:51.761792 26948 slave.cpp:1529] Will retry registration in
> 2.587517ms if necessary
> I0716 01:32:51.762087 26941 master.cpp:4676] Registering agent at
> slave(444)@172.17.0.8:44669 (f1ca07e700ef) with id
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0
> I0716 01:32:51.762835 26939 registrar.cpp:464] Applied 1 operations in
> 105778ns; attempting to update the 'registry'
> I0716 01:32:51.763700 26949 log.cpp:577] Attempting to append 337 bytes to
> the log
> I0716 01:32:51.763993 26949 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 3
> I0716 01:32:51.766073 26949 replica.cpp:537] Replica received write request
> for position 3 from (16021)@172.17.0.8:44669
> I0716 01:32:51.766551 26952 slave.cpp:1529] Will retry registration in
> 37.839637ms if necessary
> I0716 01:32:51.766891 26952 master.cpp:4664] Ignoring register agent message
> from slave(444)@172.17.0.8:44669 (f1ca07e700ef) as admission is already in
> progress
> I0716 01:32:51.783509 26949 leveldb.cpp:341] Persisting action (356 bytes) to
> leveldb took 17.419693ms
> I0716 01:32:51.783599 26949 replica.cpp:712] Persisted action at 3
> I0716 01:32:51.785138 26943 replica.cpp:691] Replica received learned notice
> for position 3 from @0.0.0.0:0
> I0716 01:32:51.805289 26954 slave.cpp:1529] Will retry registration in
> 45.42709ms if necessary
> I0716 01:32:51.805660 26950 master.cpp:4664] Ignoring register agent message
> from slave(444)@172.17.0.8:44669 (f1ca07e700ef) as admission is already in
> progress
> I0716 01:32:51.826437 26943 leveldb.cpp:341] Persisting action (358 bytes) to
> leveldb took 41.233028ms
> I0716 01:32:51.826530 26943 replica.cpp:712] Persisted action at 3
> I0716 01:32:51.826565 26943 replica.cpp:697] Replica learned APPEND action at
> position 3
> I0716 01:32:51.830235 26943 registrar.cpp:509] Successfully updated the
> 'registry' in 67.3152ms
> I0716 01:32:51.830464 26947 log.cpp:596] Attempting to truncate the log to 3
> I0716 01:32:51.830680 26947 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 4
> I0716 01:32:51.832795 26947 replica.cpp:537] Replica received write request
> for position 4 from (16022)@172.17.0.8:44669
> I0716 01:32:51.833925 26943 master.cpp:4745] Registered agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 at slave(444)@172.17.0.8:44669
> (f1ca07e700ef) with cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000]
> I0716 01:32:51.834278 26943 hierarchical.cpp:478] Added agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 (f1ca07e700ef) with cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
> I0716 01:32:51.834508 26941 slave.cpp:1169] Registered with master
> [email protected]:44669; given agent ID
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0
> I0716 01:32:51.834538 26941 fetcher.cpp:86] Clearing fetcher cache
> I0716 01:32:51.834947 26941 slave.cpp:1192] Checkpointing SlaveInfo to
> '/tmp/ContentType_MasterAPITest_GetTasks_1_B16J9J/meta/slaves/1f4b1971-a098-4ced-be7a-b26d4c06983c-S0/slave.info'
> I0716 01:32:51.835355 26941 slave.cpp:1229] Forwarding total oversubscribed
> resources
> I0716 01:32:51.836475 26941 slave.cpp:3760] Received ping from
> slave-observer(412)@172.17.0.8:44669
> I0716 01:32:51.836596 26941 status_update_manager.cpp:181] Resuming sending
> status updates
> I0716 01:32:51.836719 26941 master.cpp:5128] Received update of agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 at slave(444)@172.17.0.8:44669
> (f1ca07e700ef) with total oversubscribed resources
> I0716 01:32:51.837754 26943 hierarchical.cpp:1632] No inverse offers to send
> out!
> I0716 01:32:51.837838 26943 hierarchical.cpp:1195] Performed allocation for
> agent 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 in 3.522957ms
> I0716 01:32:51.837980 26943 hierarchical.cpp:542] Agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 (f1ca07e700ef) updated with
> oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000])
> I0716 01:32:51.838125 26943 hierarchical.cpp:1537] No allocations performed
> I0716 01:32:51.838160 26943 hierarchical.cpp:1632] No inverse offers to send
> out!
> I0716 01:32:51.838204 26943 hierarchical.cpp:1195] Performed allocation for
> agent 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 in 176669ns
> I0716 01:32:51.838714 26943 master.cpp:5835] Sending 1 offers to framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 (default) at
> [email protected]:44669
> I0716 01:32:51.839205 26943 sched.cpp:917] Scheduler::resourceOffers took
> 123086ns
> I0716 01:32:51.843250 26944 master.cpp:3468] Processing ACCEPT call for
> offers: [ 1f4b1971-a098-4ced-be7a-b26d4c06983c-O0 ] on agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 at slave(444)@172.17.0.8:44669
> (f1ca07e700ef) for framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> (default) at [email protected]:44669
> I0716 01:32:51.843369 26944 master.cpp:3106] Authorizing framework principal
> 'test-principal' to launch task 1
> W0716 01:32:51.848954 26944 validation.cpp:650] Executor default 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.
> W0716 01:32:51.849031 26944 validation.cpp:662] Executor default for task 1
> uses less memory (None) than the minimum required (32MB). Please update your
> executor, as this will be mandatory in future releases.
> I0716 01:32:51.851603 26944 master.cpp:7565] Adding task 1 with resources
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 (f1ca07e700ef)
> I0716 01:32:51.851825 26944 master.cpp:3957] Launching task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 (default) at
> [email protected]:44669 with
> resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> agent 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 at slave(444)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.852354 26944 slave.cpp:1569] Got assigned task 1 for framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.854076 26944 slave.cpp:1688] Launching task 1 for framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.868922 26944 paths.cpp:528] Trying to chown
> '/tmp/ContentType_MasterAPITest_GetTasks_1_B16J9J/slaves/1f4b1971-a098-4ced-be7a-b26d4c06983c-S0/frameworks/1f4b1971-a098-4ced-be7a-b26d4c06983c-0000/executors/default/runs/dfe27d79-8e51-4553-a3fd-80f28f0729ac'
> to user 'mesos'
> I0716 01:32:51.877212 26947 leveldb.cpp:341] Persisting action (16 bytes) to
> leveldb took 44.394669ms
> I0716 01:32:51.877305 26947 replica.cpp:712] Persisted action at 4
> I0716 01:32:51.879119 26947 replica.cpp:691] Replica received learned notice
> for position 4 from @0.0.0.0:0
> I0716 01:32:51.907600 26944 slave.cpp:5748] Launching executor default of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 with resources in work
> directory
> '/tmp/ContentType_MasterAPITest_GetTasks_1_B16J9J/slaves/1f4b1971-a098-4ced-be7a-b26d4c06983c-S0/frameworks/1f4b1971-a098-4ced-be7a-b26d4c06983c-0000/executors/default/runs/dfe27d79-8e51-4553-a3fd-80f28f0729ac'
> I0716 01:32:51.911151 26944 exec.cpp:161] Version: 1.1.0
> I0716 01:32:51.911532 26947 leveldb.cpp:341] Persisting action (18 bytes) to
> leveldb took 32.396128ms
> I0716 01:32:51.911641 26947 leveldb.cpp:399] Deleting ~2 keys from leveldb
> took 78972ns
> I0716 01:32:51.911666 26947 replica.cpp:712] Persisted action at 4
> I0716 01:32:51.911700 26947 replica.cpp:697] Replica learned TRUNCATE action
> at position 4
> I0716 01:32:51.911787 26949 exec.cpp:211] Executor started at:
> executor(148)@172.17.0.8:44669 with pid 26921
> I0716 01:32:51.912528 26944 slave.cpp:1914] Queuing task '1' for executor
> 'default' of framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.912909 26944 slave.cpp:922] Successfully attached file
> '/tmp/ContentType_MasterAPITest_GetTasks_1_B16J9J/slaves/1f4b1971-a098-4ced-be7a-b26d4c06983c-S0/frameworks/1f4b1971-a098-4ced-be7a-b26d4c06983c-0000/executors/default/runs/dfe27d79-8e51-4553-a3fd-80f28f0729ac'
> I0716 01:32:51.913069 26944 slave.cpp:2902] Got registration for executor
> 'default' of framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 from
> executor(148)@172.17.0.8:44669
> I0716 01:32:51.914299 26944 slave.cpp:2079] Sending queued task '1' to
> executor 'default' of framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 at
> executor(148)@172.17.0.8:44669
> I0716 01:32:51.914625 26951 exec.cpp:236] Executor registered on agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0
> I0716 01:32:51.914728 26951 exec.cpp:248] Executor::registered took 83014ns
> I0716 01:32:51.914926 26951 exec.cpp:323] Executor asked to run task '1'
> I0716 01:32:51.915531 26951 exec.cpp:332] Executor::launchTask took 593333ns
> I0716 01:32:51.915666 26951 exec.cpp:549] Executor sending status update
> TASK_RUNNING (UUID: 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0) for task 1 of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.916096 26951 slave.cpp:3285] Handling status update
> TASK_RUNNING (UUID: 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0) for task 1 of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 from
> executor(148)@172.17.0.8:44669
> I0716 01:32:51.917110 26951 status_update_manager.cpp:320] Received status
> update TASK_RUNNING (UUID: 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0) for task 1
> of framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.917264 26951 status_update_manager.cpp:497] Creating
> StatusUpdate stream for task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.918076 26951 status_update_manager.cpp:374] Forwarding update
> TASK_RUNNING (UUID: 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0) for task 1 of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 to the agent
> I0716 01:32:51.918742 26951 slave.cpp:3678] Forwarding the update
> TASK_RUNNING (UUID: 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0) for task 1 of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 to [email protected]:44669
> I0716 01:32:51.919379 26940 master.cpp:5273] Status update TASK_RUNNING
> (UUID: 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0) for task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 from agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 at slave(444)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.919546 26940 master.cpp:5321] Forwarding status update
> TASK_RUNNING (UUID: 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0) for task 1 of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.919955 26940 master.cpp:6959] Updating the state of task 1 of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 (latest state:
> TASK_RUNNING, status update state: TASK_RUNNING)
> I0716 01:32:51.920382 26953 sched.cpp:1025] Scheduler::statusUpdate took
> 157615ns
> I0716 01:32:51.920500 26951 slave.cpp:3572] Status update manager
> successfully handled status update TASK_RUNNING (UUID:
> 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0) for task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.921047 26951 slave.cpp:3588] Sending acknowledgement for
> status update TASK_RUNNING (UUID: 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0) for
> task 1 of framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 to
> executor(148)@172.17.0.8:44669
> I0716 01:32:51.921084 26942 master.cpp:4388] Processing ACKNOWLEDGE call
> 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0 for task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 (default) at
> [email protected]:44669 on agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0
> I0716 01:32:51.921303 26951 exec.cpp:372] Executor received status update
> acknowledgement 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0 for task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.921558 26951 status_update_manager.cpp:392] Received status
> update acknowledgement (UUID: 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0) for task
> 1 of framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.922010 26942 slave.cpp:2671] Status update manager
> successfully handled status update acknowledgement (UUID:
> 0c8c5ace-ba3e-46e4-ab46-0ef515474cb0) for task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.923655 26943 process.cpp:3354] Handling HTTP event for process
> 'master' with path: '/master/api/v1'
> I0716 01:32:51.924752 26953 http.cpp:381] HTTP POST for /master/api/v1 from
> 172.17.0.8:40839
> I0716 01:32:51.925014 26953 http.cpp:484] Processing call GET_TASKS
> I0716 01:32:51.931498 26954 exec.cpp:549] Executor sending status update
> TASK_FINISHED (UUID: 486d5b5d-1684-4256-9f8f-22ae671f5cbe) for task 1 of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.931794 26954 slave.cpp:3285] Handling status update
> TASK_FINISHED (UUID: 486d5b5d-1684-4256-9f8f-22ae671f5cbe) for task 1 of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 from
> executor(148)@172.17.0.8:44669
> I0716 01:32:51.932232 26954 slave.cpp:6088] Terminating task 1
> I0716 01:32:51.932971 26954 status_update_manager.cpp:320] Received status
> update TASK_FINISHED (UUID: 486d5b5d-1684-4256-9f8f-22ae671f5cbe) for task 1
> of framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.933166 26954 status_update_manager.cpp:374] Forwarding update
> TASK_FINISHED (UUID: 486d5b5d-1684-4256-9f8f-22ae671f5cbe) for task 1 of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 to the agent
> I0716 01:32:51.933600 26954 slave.cpp:3678] Forwarding the update
> TASK_FINISHED (UUID: 486d5b5d-1684-4256-9f8f-22ae671f5cbe) for task 1 of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 to [email protected]:44669
> I0716 01:32:51.933760 26954 slave.cpp:3572] Status update manager
> successfully handled status update TASK_FINISHED (UUID:
> 486d5b5d-1684-4256-9f8f-22ae671f5cbe) for task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.933806 26954 slave.cpp:3588] Sending acknowledgement for
> status update TASK_FINISHED (UUID: 486d5b5d-1684-4256-9f8f-22ae671f5cbe) for
> task 1 of framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 to
> executor(148)@172.17.0.8:44669
> I0716 01:32:51.934041 26954 master.cpp:5273] Status update TASK_FINISHED
> (UUID: 486d5b5d-1684-4256-9f8f-22ae671f5cbe) for task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 from agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 at slave(444)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.934087 26954 master.cpp:5321] Forwarding status update
> TASK_FINISHED (UUID: 486d5b5d-1684-4256-9f8f-22ae671f5cbe) for task 1 of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.934242 26954 master.cpp:6959] Updating the state of task 1 of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 (latest state:
> TASK_FINISHED, status update state: TASK_FINISHED)
> I0716 01:32:51.934748 26954 exec.cpp:372] Executor received status update
> acknowledgement 486d5b5d-1684-4256-9f8f-22ae671f5cbe for task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.935006 26954 sched.cpp:1025] Scheduler::statusUpdate took
> 96207ns
> I0716 01:32:51.935586 26941 master.cpp:4388] Processing ACKNOWLEDGE call
> 486d5b5d-1684-4256-9f8f-22ae671f5cbe for task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 (default) at
> [email protected]:44669 on agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0
> I0716 01:32:51.935650 26941 master.cpp:7025] Removing task 1 with resources
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 on agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 at slave(444)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.936885 26954 hierarchical.cpp:924] Recovered cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: ) on agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 from framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.936180 26941 status_update_manager.cpp:392] Received status
> update acknowledgement (UUID: 486d5b5d-1684-4256-9f8f-22ae671f5cbe) for task
> 1 of framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.937144 26941 status_update_manager.cpp:528] Cleaning up status
> update stream for task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.937614 26946 slave.cpp:2671] Status update manager
> successfully handled status update acknowledgement (UUID:
> 486d5b5d-1684-4256-9f8f-22ae671f5cbe) for task 1 of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.937662 26946 slave.cpp:6129] Completing task 1
> I0716 01:32:51.940557 26940 process.cpp:3354] Handling HTTP event for process
> 'master' with path: '/master/api/v1'
> I0716 01:32:51.941504 26939 http.cpp:381] HTTP POST for /master/api/v1 from
> 172.17.0.8:40840
> I0716 01:32:51.941634 26939 http.cpp:484] Processing call GET_TASKS
> I0716 01:32:51.948716 26921 sched.cpp:1987] Asked to stop the driver
> I0716 01:32:51.948840 26949 sched.cpp:1187] Stopping framework
> '1f4b1971-a098-4ced-be7a-b26d4c06983c-0000'
> I0716 01:32:51.949188 26949 master.cpp:6410] Processing TEARDOWN call for
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 (default) at
> [email protected]:44669
> I0716 01:32:51.949229 26949 master.cpp:6422] Removing framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 (default) at
> [email protected]:44669
> I0716 01:32:51.949489 26949 master.cpp:7054] Removing executor 'default' with
> resources of framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 on agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 at slave(444)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.949704 26951 hierarchical.cpp:382] Deactivated framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.949873 26948 slave.cpp:2292] Asked to shut down framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 by [email protected]:44669
> I0716 01:32:51.950013 26948 slave.cpp:2317] Shutting down framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.950204 26948 slave.cpp:4481] Shutting down executor 'default'
> of framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 at
> executor(148)@172.17.0.8:44669
> I0716 01:32:51.950700 26948 hierarchical.cpp:333] Removed framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.950405 26951 exec.cpp:413] Executor asked to shutdown
> I0716 01:32:51.950829 26951 exec.cpp:428] Executor::shutdown took 27614ns
> I0716 01:32:51.951040 26951 slave.cpp:3806] executor(148)@172.17.0.8:44669
> exited
> I0716 01:32:51.951364 26951 slave.cpp:4163] Executor 'default' of framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 exited with status 0
> I0716 01:32:51.951730 26951 slave.cpp:4267] Cleaning up executor 'default' of
> framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 at
> executor(148)@172.17.0.8:44669
> W0716 01:32:51.951848 26940 master.cpp:5369] Ignoring unknown exited executor
> 'default' of framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000 on agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 at slave(444)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.953620 26953 gc.cpp:55] Scheduling
> '/tmp/ContentType_MasterAPITest_GetTasks_1_B16J9J/slaves/1f4b1971-a098-4ced-be7a-b26d4c06983c-S0/frameworks/1f4b1971-a098-4ced-be7a-b26d4c06983c-0000/executors/default/runs/dfe27d79-8e51-4553-a3fd-80f28f0729ac'
> for gc 6.99998897096days in the future
> I0716 01:32:51.953934 26951 slave.cpp:4355] Cleaning up framework
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.953948 26939 gc.cpp:55] Scheduling
> '/tmp/ContentType_MasterAPITest_GetTasks_1_B16J9J/slaves/1f4b1971-a098-4ced-be7a-b26d4c06983c-S0/frameworks/1f4b1971-a098-4ced-be7a-b26d4c06983c-0000/executors/default'
> for gc 6.99998895978963days in the future
> I0716 01:32:51.954439 26950 status_update_manager.cpp:282] Closing status
> update streams for framework 1f4b1971-a098-4ced-be7a-b26d4c06983c-0000
> I0716 01:32:51.954684 26951 slave.cpp:841] Agent terminating
> I0716 01:32:51.954877 26954 gc.cpp:55] Scheduling
> '/tmp/ContentType_MasterAPITest_GetTasks_1_B16J9J/slaves/1f4b1971-a098-4ced-be7a-b26d4c06983c-S0/frameworks/1f4b1971-a098-4ced-be7a-b26d4c06983c-0000'
> for gc 6.99998895301037days in the future
> I0716 01:32:51.955643 26951 master.cpp:1371] Agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 at slave(444)@172.17.0.8:44669
> (f1ca07e700ef) disconnected
> I0716 01:32:51.956079 26951 master.cpp:2910] Disconnecting agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 at slave(444)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.956404 26951 master.cpp:2929] Deactivating agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 at slave(444)@172.17.0.8:44669
> (f1ca07e700ef)
> I0716 01:32:51.956712 26946 hierarchical.cpp:571] Agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0 deactivated
> I0716 01:32:51.959475 26921 master.cpp:1218] Master terminating
> I0716 01:32:51.959877 26940 hierarchical.cpp:510] Removed agent
> 1f4b1971-a098-4ced-be7a-b26d4c06983c-S0
> [ OK ] ContentType/MasterAPITest.GetTasks/1 (882 ms)
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
