You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2018/10/17 04:11:19 UTC
Build failed in Jenkins: Mesos-Reviewbot #23484
See <https://builds.apache.org/job/Mesos-Reviewbot/23484/display/redirect>
------------------------------------------
[...truncated 39.49 MB...]
I1017 04:11:13.624073 22572 hierarchical.cpp:359] Removed framework 8e8bb7f3-94e1-43da-b937-0a90a48597ee-0000
I1017 04:11:13.630888 22573 master.cpp:1108] Master terminating
I1017 04:11:13.631685 22563 hierarchical.cpp:645] Removed agent 8e8bb7f3-94e1-43da-b937-0a90a48597ee-S0
[ OK ] ContentType/AgentResourceProviderConfigApiTest.Remove/1 (501 ms)
[ RUN ] ContentType/AgentResourceProviderConfigApiTest.IdempotentRemove/0
I1017 04:11:13.641767 22559 cluster.cpp:173] Creating default 'local' authorizer
I1017 04:11:13.644424 22579 master.cpp:413] Master 7a15d6e6-2ba4-49cb-8b90-cb00e4daad18 (2ed4de034bf5) started on 172.17.0.3:42237
I1017 04:11:13.644450 22579 master.cpp:416] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/MxXPvs/credentials" --filter_gpu_resources="true" --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" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/tmp/SRC/build/mesos-1.8.0/_inst/share/mesos/webui" --work_dir="/tmp/MxXPvs/master" --zk_session_timeout="10secs"
I1017 04:11:13.644775 22579 master.cpp:465] Master only allowing authenticated frameworks to register
I1017 04:11:13.644790 22579 master.cpp:471] Master only allowing authenticated agents to register
I1017 04:11:13.644798 22579 master.cpp:477] Master only allowing authenticated HTTP frameworks to register
I1017 04:11:13.644807 22579 credentials.hpp:37] Loading credentials for authentication from '/tmp/MxXPvs/credentials'
I1017 04:11:13.645078 22579 master.cpp:521] Using default 'crammd5' authenticator
I1017 04:11:13.645265 22579 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I1017 04:11:13.645489 22579 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I1017 04:11:13.645630 22579 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I1017 04:11:13.645800 22579 master.cpp:602] Authorization enabled
I1017 04:11:13.646273 22571 hierarchical.cpp:182] Initialized hierarchical allocator process
I1017 04:11:13.646289 22578 whitelist_watcher.cpp:77] No whitelist given
I1017 04:11:13.648903 22576 master.cpp:2098] Elected as the leading master!
I1017 04:11:13.648941 22576 master.cpp:1653] Recovering from registrar
I1017 04:11:13.649116 22574 registrar.cpp:339] Recovering registrar
I1017 04:11:13.649787 22574 registrar.cpp:383] Successfully fetched the registry (0B) in 630016ns
I1017 04:11:13.649927 22574 registrar.cpp:487] Applied 1 operations in 42326ns; attempting to update the registry
I1017 04:11:13.650499 22574 registrar.cpp:544] Successfully updated the registry in 515072ns
I1017 04:11:13.650636 22574 registrar.cpp:416] Successfully recovered registrar
I1017 04:11:13.651249 22581 hierarchical.cpp:220] Skipping recovery of hierarchical allocator: nothing to recover
I1017 04:11:13.651331 22583 master.cpp:1767] Recovered 0 agents from the registry (135B); allowing 10mins for agents to reregister
W1017 04:11:13.656265 22559 process.cpp:2810] Attempted to spawn already running process files@172.17.0.3:42237
I1017 04:11:13.657665 22559 containerizer.cpp:305] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1017 04:11:13.658257 22559 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1017 04:11:13.658291 22559 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1017 04:11:13.658329 22559 provisioner.cpp:298] Using default backend 'copy'
I1017 04:11:13.660652 22559 cluster.cpp:485] Creating default 'local' authorizer
I1017 04:11:13.662572 22583 slave.cpp:267] Mesos agent started on (1059)@172.17.0.3:42237
I1017 04:11:13.662603 22583 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_i2Rp2C/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --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_AgentResourceProviderConfigApiTest_IdempotentRemove_0_i2Rp2C/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --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/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_i2Rp2C/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_i2Rp2C/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_i2Rp2C/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/tmp/SRC/build/mesos-1.8.0/_build/sub/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_provider_config_dir="/tmp/MxXPvs/resource_provider_configs" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_i2Rp2C" --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_AgentResourceProviderConfigApiTest_IdempotentRemove_0_Toj7L2" --zk_session_timeout="10secs"
I1017 04:11:13.663292 22583 credentials.hpp:86] Loading credential for authentication from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_i2Rp2C/credential'
I1017 04:11:13.663539 22583 slave.cpp:300] Agent using credential for: test-principal
I1017 04:11:13.663571 22583 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_i2Rp2C/http_credentials'
I1017 04:11:13.663884 22583 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1017 04:11:13.664338 22583 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I1017 04:11:13.666281 22583 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I1017 04:11:13.666642 22583 slave.cpp:623] Agent attributes: [ ]
I1017 04:11:13.666672 22583 slave.cpp:632] Agent hostname: 2ed4de034bf5
I1017 04:11:13.666820 22570 task_status_update_manager.cpp:181] Pausing sending task status updates
I1017 04:11:13.668727 22567 state.cpp:66] Recovering state from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_Toj7L2/meta'
I1017 04:11:13.668936 22569 slave.cpp:6915] Finished recovering checkpointed state from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_Toj7L2/meta', beginning agent recovery
I1017 04:11:13.669087 22567 task_status_update_manager.cpp:207] Recovering task status update manager
I1017 04:11:13.669368 22574 containerizer.cpp:727] Recovering Mesos containers
I1017 04:11:13.669689 22574 containerizer.cpp:1053] Recovering isolators
I1017 04:11:13.670339 22571 containerizer.cpp:1092] Recovering provisioner
I1017 04:11:13.670941 22576 provisioner.cpp:494] Provisioner recovery complete
I1017 04:11:13.671602 22566 composing.cpp:339] Finished recovering all containerizers
I1017 04:11:13.671756 22560 slave.cpp:7144] Recovering executors
I1017 04:11:13.671869 22560 slave.cpp:7297] Finished recovery
I1017 04:11:13.672668 22581 task_status_update_manager.cpp:181] Pausing sending task status updates
I1017 04:11:13.672729 22572 slave.cpp:1260] New master detected at master@172.17.0.3:42237
I1017 04:11:13.672894 22572 slave.cpp:1325] Detecting new master
I1017 04:11:13.680217 22573 slave.cpp:1352] Authenticating with master master@172.17.0.3:42237
I1017 04:11:13.680342 22573 slave.cpp:1361] Using default CRAM-MD5 authenticatee
I1017 04:11:13.680675 22579 authenticatee.cpp:121] Creating new client SASL connection
I1017 04:11:13.680996 22568 master.cpp:9668] Authenticating slave(1059)@172.17.0.3:42237
I1017 04:11:13.681141 22577 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1844)@172.17.0.3:42237
I1017 04:11:13.681433 22571 authenticator.cpp:98] Creating new server SASL connection
I1017 04:11:13.681664 22563 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1017 04:11:13.681691 22563 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1017 04:11:13.681804 22564 authenticator.cpp:204] Received SASL authentication start
I1017 04:11:13.681869 22564 authenticator.cpp:326] Authentication requires more steps
I1017 04:11:13.681974 22564 authenticatee.cpp:259] Received SASL authentication step
I1017 04:11:13.682142 22570 authenticator.cpp:232] Received SASL authentication step
I1017 04:11:13.682174 22570 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2ed4de034bf5' server FQDN: '2ed4de034bf5' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1017 04:11:13.682189 22570 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1017 04:11:13.682242 22570 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1017 04:11:13.682282 22570 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2ed4de034bf5' server FQDN: '2ed4de034bf5' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1017 04:11:13.682298 22570 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1017 04:11:13.682308 22570 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1017 04:11:13.682327 22570 authenticator.cpp:318] Authentication success
I1017 04:11:13.682435 22575 authenticatee.cpp:299] Authentication success
I1017 04:11:13.682548 22583 master.cpp:9700] Successfully authenticated principal 'test-principal' at slave(1059)@172.17.0.3:42237
I1017 04:11:13.682556 22569 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1844)@172.17.0.3:42237
I1017 04:11:13.682818 22570 slave.cpp:1452] Successfully authenticated with master master@172.17.0.3:42237
I1017 04:11:13.683276 22570 slave.cpp:1883] Will retry registration in 874193ns if necessary
I1017 04:11:13.683482 22560 master.cpp:6620] Received register agent message from slave(1059)@172.17.0.3:42237 (2ed4de034bf5)
I1017 04:11:13.683831 22560 master.cpp:3979] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I1017 04:11:13.684417 22572 master.cpp:6687] Authorized registration of agent at slave(1059)@172.17.0.3:42237 (2ed4de034bf5)
I1017 04:11:13.684528 22572 master.cpp:6802] Registering agent at slave(1059)@172.17.0.3:42237 (2ed4de034bf5) with id 7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0
I1017 04:11:13.684942 22574 slave.cpp:1883] Will retry registration in 37.300091ms if necessary
I1017 04:11:13.685056 22579 master.cpp:6613] Ignoring register agent message from slave(1059)@172.17.0.3:42237 (2ed4de034bf5) as registration is already in progress
I1017 04:11:13.685164 22573 registrar.cpp:487] Applied 1 operations in 233713ns; attempting to update the registry
I1017 04:11:13.685801 22573 registrar.cpp:544] Successfully updated the registry in 567040ns
I1017 04:11:13.685953 22576 master.cpp:6850] Admitted agent 7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0 at slave(1059)@172.17.0.3:42237 (2ed4de034bf5)
I1017 04:11:13.686599 22576 master.cpp:6895] Registered agent 7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0 at slave(1059)@172.17.0.3:42237 (2ed4de034bf5) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1017 04:11:13.686772 22583 slave.cpp:1485] Registered with master master@172.17.0.3:42237; given agent ID 7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0
I1017 04:11:13.686949 22565 task_status_update_manager.cpp:188] Resuming sending task status updates
I1017 04:11:13.686934 22564 hierarchical.cpp:605] Added agent 7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0 (2ed4de034bf5) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I1017 04:11:13.687219 22564 hierarchical.cpp:1568] Performed allocation for 1 agents in 88330ns
I1017 04:11:13.687227 22583 slave.cpp:1505] Checkpointing SlaveInfo to '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_Toj7L2/meta/slaves/7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0/slave.info'
I1017 04:11:13.688350 22583 slave.cpp:1554] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"nyERYEeaSgORYIwomS4FlA=="},"slave_id":{"value":"7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0"},"update_oversubscribed_resources":false}
I1017 04:11:13.688980 22574 master.cpp:7954] Ignoring update on agent 7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0 at slave(1059)@172.17.0.3:42237 (2ed4de034bf5) as it reports no changes
I1017 04:11:13.690317 22571 process.cpp:3569] Handling HTTP event for process 'slave(1059)' with path: '/slave(1059)/api/v1'
I1017 04:11:13.691272 22567 http.cpp:1178] HTTP POST for /slave(1059)/api/v1 from 172.17.0.3:52534
I1017 04:11:13.692353 22580 http.cpp:3297] Processing REMOVE_RESOURCE_PROVIDER_CONFIG call with type 'org.apache.mesos.rp.local.storage' and name 'test'
I1017 04:11:13.693848 22571 slave.cpp:915] Agent terminating
I1017 04:11:13.696981 22564 hierarchical.cpp:1568] Performed allocation for 1 agents in 102092ns
I1017 04:11:13.748778 22569 hierarchical.cpp:1568] Performed allocation for 1 agents in 111363ns
I1017 04:11:13.799834 22581 hierarchical.cpp:1568] Performed allocation for 1 agents in 114459ns
I1017 04:11:13.815263 22583 master.cpp:1266] Agent 7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0 at slave(1059)@172.17.0.3:42237 (2ed4de034bf5) disconnected
I1017 04:11:13.815302 22583 master.cpp:3282] Disconnecting agent 7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0 at slave(1059)@172.17.0.3:42237 (2ed4de034bf5)
I1017 04:11:13.815389 22583 master.cpp:3301] Deactivating agent 7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0 at slave(1059)@172.17.0.3:42237 (2ed4de034bf5)
I1017 04:11:13.815544 22563 hierarchical.cpp:803] Agent 7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0 deactivated
I1017 04:11:13.822098 22571 master.cpp:1108] Master terminating
I1017 04:11:13.822893 22574 hierarchical.cpp:645] Removed agent 7a15d6e6-2ba4-49cb-8b90-cb00e4daad18-S0
[ OK ] ContentType/AgentResourceProviderConfigApiTest.IdempotentRemove/0 (187 ms)
[ RUN ] ContentType/AgentResourceProviderConfigApiTest.IdempotentRemove/1
I1017 04:11:13.830597 22559 cluster.cpp:173] Creating default 'local' authorizer
I1017 04:11:13.833315 22574 master.cpp:413] Master 5d440900-f821-4942-88ca-2750dcf933a3 (2ed4de034bf5) started on 172.17.0.3:42237
I1017 04:11:13.833338 22574 master.cpp:416] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/dsFSmo/credentials" --filter_gpu_resources="true" --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" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/tmp/SRC/build/mesos-1.8.0/_inst/share/mesos/webui" --work_dir="/tmp/dsFSmo/master" --zk_session_timeout="10secs"
I1017 04:11:13.833650 22574 master.cpp:465] Master only allowing authenticated frameworks to register
I1017 04:11:13.833674 22574 master.cpp:471] Master only allowing authenticated agents to register
I1017 04:11:13.833691 22574 master.cpp:477] Master only allowing authenticated HTTP frameworks to register
I1017 04:11:13.833708 22574 credentials.hpp:37] Loading credentials for authentication from '/tmp/dsFSmo/credentials'
I1017 04:11:13.833957 22574 master.cpp:521] Using default 'crammd5' authenticator
I1017 04:11:13.834125 22574 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I1017 04:11:13.834305 22574 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I1017 04:11:13.834456 22574 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I1017 04:11:13.834615 22574 master.cpp:602] Authorization enabled
I1017 04:11:13.835000 22560 hierarchical.cpp:182] Initialized hierarchical allocator process
I1017 04:11:13.835048 22572 whitelist_watcher.cpp:77] No whitelist given
I1017 04:11:13.837627 22579 master.cpp:2098] Elected as the leading master!
I1017 04:11:13.837661 22579 master.cpp:1653] Recovering from registrar
I1017 04:11:13.837826 22582 registrar.cpp:339] Recovering registrar
I1017 04:11:13.838470 22582 registrar.cpp:383] Successfully fetched the registry (0B) in 604928ns
I1017 04:11:13.838599 22582 registrar.cpp:487] Applied 1 operations in 36897ns; attempting to update the registry
I1017 04:11:13.839339 22564 registrar.cpp:544] Successfully updated the registry in 640us
I1017 04:11:13.839535 22564 registrar.cpp:416] Successfully recovered registrar
I1017 04:11:13.840085 22578 hierarchical.cpp:220] Skipping recovery of hierarchical allocator: nothing to recover
I1017 04:11:13.840087 22562 master.cpp:1767] Recovered 0 agents from the registry (135B); allowing 10mins for agents to reregister
W1017 04:11:13.844748 22559 process.cpp:2810] Attempted to spawn already running process files@172.17.0.3:42237
I1017 04:11:13.845928 22559 containerizer.cpp:305] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1017 04:11:13.846499 22559 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1017 04:11:13.846527 22559 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1017 04:11:13.846566 22559 provisioner.cpp:298] Using default backend 'copy'
I1017 04:11:13.848906 22559 cluster.cpp:485] Creating default 'local' authorizer
I1017 04:11:13.850987 22562 slave.cpp:267] Mesos agent started on (1060)@172.17.0.3:42237
I1017 04:11:13.851027 22562 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_VUWCNz/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --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_AgentResourceProviderConfigApiTest_IdempotentRemove_1_VUWCNz/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --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/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_VUWCNz/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_VUWCNz/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_VUWCNz/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/tmp/SRC/build/mesos-1.8.0/_build/sub/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_provider_config_dir="/tmp/dsFSmo/resource_provider_configs" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_VUWCNz" --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_AgentResourceProviderConfigApiTest_IdempotentRemove_1_Yugf5Y" --zk_session_timeout="10secs"
I1017 04:11:13.851660 22562 credentials.hpp:86] Loading credential for authentication from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_VUWCNz/credential'
I1017 04:11:13.851955 22562 slave.cpp:300] Agent using credential for: test-principal
I1017 04:11:13.851981 22562 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_VUWCNz/http_credentials'
I1017 04:11:13.852259 22562 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1017 04:11:13.852748 22562 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I1017 04:11:13.854121 22562 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I1017 04:11:13.854354 22562 slave.cpp:623] Agent attributes: [ ]
I1017 04:11:13.854382 22562 slave.cpp:632] Agent hostname: 2ed4de034bf5
I1017 04:11:13.854568 22567 task_status_update_manager.cpp:181] Pausing sending task status updates
I1017 04:11:13.856323 22573 state.cpp:66] Recovering state from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_Yugf5Y/meta'
I1017 04:11:13.856542 22565 slave.cpp:6915] Finished recovering checkpointed state from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_Yugf5Y/meta', beginning agent recovery
I1017 04:11:13.856724 22582 task_status_update_manager.cpp:207] Recovering task status update manager
I1017 04:11:13.857034 22561 containerizer.cpp:727] Recovering Mesos containers
I1017 04:11:13.857353 22561 containerizer.cpp:1053] Recovering isolators
I1017 04:11:13.858070 22575 containerizer.cpp:1092] Recovering provisioner
I1017 04:11:13.858814 22579 provisioner.cpp:494] Provisioner recovery complete
I1017 04:11:13.859444 22565 composing.cpp:339] Finished recovering all containerizers
I1017 04:11:13.859575 22582 slave.cpp:7144] Recovering executors
I1017 04:11:13.859733 22582 slave.cpp:7297] Finished recovery
I1017 04:11:13.860744 22570 task_status_update_manager.cpp:181] Pausing sending task status updates
I1017 04:11:13.860774 22578 slave.cpp:1260] New master detected at master@172.17.0.3:42237
I1017 04:11:13.860980 22578 slave.cpp:1325] Detecting new master
I1017 04:11:13.871428 22568 slave.cpp:1352] Authenticating with master master@172.17.0.3:42237
I1017 04:11:13.871589 22568 slave.cpp:1361] Using default CRAM-MD5 authenticatee
I1017 04:11:13.871949 22574 authenticatee.cpp:121] Creating new client SASL connection
I1017 04:11:13.872373 22560 master.cpp:9668] Authenticating slave(1060)@172.17.0.3:42237
I1017 04:11:13.872577 22571 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1845)@172.17.0.3:42237
I1017 04:11:13.872994 22575 authenticator.cpp:98] Creating new server SASL connection
I1017 04:11:13.873318 22576 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1017 04:11:13.873361 22576 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1017 04:11:13.873509 22563 authenticator.cpp:204] Received SASL authentication start
I1017 04:11:13.873581 22563 authenticator.cpp:326] Authentication requires more steps
I1017 04:11:13.873728 22579 authenticatee.cpp:259] Received SASL authentication step
I1017 04:11:13.873863 22567 authenticator.cpp:232] Received SASL authentication step
I1017 04:11:13.873901 22567 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2ed4de034bf5' server FQDN: '2ed4de034bf5' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1017 04:11:13.873917 22567 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1017 04:11:13.873965 22567 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1017 04:11:13.873996 22567 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2ed4de034bf5' server FQDN: '2ed4de034bf5' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1017 04:11:13.874011 22567 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1017 04:11:13.874028 22567 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1017 04:11:13.874047 22567 authenticator.cpp:318] Authentication success
I1017 04:11:13.874155 22583 authenticatee.cpp:299] Authentication success
I1017 04:11:13.874258 22562 master.cpp:9700] Successfully authenticated principal 'test-principal' at slave(1060)@172.17.0.3:42237
I1017 04:11:13.874280 22573 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1845)@172.17.0.3:42237
I1017 04:11:13.874629 22569 slave.cpp:1452] Successfully authenticated with master master@172.17.0.3:42237
I1017 04:11:13.875037 22569 slave.cpp:1883] Will retry registration in 10.150029ms if necessary
I1017 04:11:13.875236 22582 master.cpp:6620] Received register agent message from slave(1060)@172.17.0.3:42237 (2ed4de034bf5)
I1017 04:11:13.875648 22582 master.cpp:3979] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I1017 04:11:13.876428 22570 master.cpp:6687] Authorized registration of agent at slave(1060)@172.17.0.3:42237 (2ed4de034bf5)
I1017 04:11:13.876528 22570 master.cpp:6802] Registering agent at slave(1060)@172.17.0.3:42237 (2ed4de034bf5) with id 5d440900-f821-4942-88ca-2750dcf933a3-S0
I1017 04:11:13.877213 22572 registrar.cpp:487] Applied 1 operations in 236982ns; attempting to update the registry
I1017 04:11:13.877964 22572 registrar.cpp:544] Successfully updated the registry in 679936ns
I1017 04:11:13.878129 22571 master.cpp:6850] Admitted agent 5d440900-f821-4942-88ca-2750dcf933a3-S0 at slave(1060)@172.17.0.3:42237 (2ed4de034bf5)
I1017 04:11:13.878901 22571 master.cpp:6895] Registered agent 5d440900-f821-4942-88ca-2750dcf933a3-S0 at slave(1060)@172.17.0.3:42237 (2ed4de034bf5) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1017 04:11:13.879091 22576 slave.cpp:1485] Registered with master master@172.17.0.3:42237; given agent ID 5d440900-f821-4942-88ca-2750dcf933a3-S0
I1017 04:11:13.879168 22563 hierarchical.cpp:605] Added agent 5d440900-f821-4942-88ca-2750dcf933a3-S0 (2ed4de034bf5) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I1017 04:11:13.879202 22580 task_status_update_manager.cpp:188] Resuming sending task status updates
I1017 04:11:13.879470 22576 slave.cpp:1505] Checkpointing SlaveInfo to '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_Yugf5Y/meta/slaves/5d440900-f821-4942-88ca-2750dcf933a3-S0/slave.info'
I1017 04:11:13.879483 22563 hierarchical.cpp:1568] Performed allocation for 1 agents in 105053ns
I1017 04:11:13.880496 22576 slave.cpp:1554] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"e6JC9NwGSsmCuFX3DTLS0Q=="},"slave_id":{"value":"5d440900-f821-4942-88ca-2750dcf933a3-S0"},"update_oversubscribed_resources":false}
I1017 04:11:13.881175 22582 master.cpp:7954] Ignoring update on agent 5d440900-f821-4942-88ca-2750dcf933a3-S0 at slave(1060)@172.17.0.3:42237 (2ed4de034bf5) as it reports no changes
I1017 04:11:13.883067 22574 process.cpp:3569] Handling HTTP event for process 'slave(1060)' with path: '/slave(1060)/api/v1'
I1017 04:11:13.884068 22565 http.cpp:1178] HTTP POST for /slave(1060)/api/v1 from 172.17.0.3:52538
I1017 04:11:13.885434 22577 http.cpp:3297] Processing REMOVE_RESOURCE_PROVIDER_CONFIG call with type 'org.apache.mesos.rp.local.storage' and name 'test'
I1017 04:11:13.886181 22573 hierarchical.cpp:1568] Performed allocation for 1 agents in 127570ns
I1017 04:11:13.887182 22575 slave.cpp:915] Agent terminating
I1017 04:11:13.937096 22563 hierarchical.cpp:1568] Performed allocation for 1 agents in 108439ns
I1017 04:11:13.988139 22562 hierarchical.cpp:1568] Performed allocation for 1 agents in 118006ns
I1017 04:11:14.008635 22573 master.cpp:1266] Agent 5d440900-f821-4942-88ca-2750dcf933a3-S0 at slave(1060)@172.17.0.3:42237 (2ed4de034bf5) disconnected
I1017 04:11:14.008728 22573 master.cpp:3282] Disconnecting agent 5d440900-f821-4942-88ca-2750dcf933a3-S0 at slave(1060)@172.17.0.3:42237 (2ed4de034bf5)
I1017 04:11:14.008862 22573 master.cpp:3301] Deactivating agent 5d440900-f821-4942-88ca-2750dcf933a3-S0 at slave(1060)@172.17.0.3:42237 (2ed4de034bf5)
I1017 04:11:14.009080 22570 hierarchical.cpp:803] Agent 5d440900-f821-4942-88ca-2750dcf933a3-S0 deactivated
I1017 04:11:14.017004 22570 master.cpp:1108] Master terminating
I1017 04:11:14.017861 22568 hierarchical.cpp:645] Removed agent 5d440900-f821-4942-88ca-2750dcf933a3-S0
[ OK ] ContentType/AgentResourceProviderConfigApiTest.IdempotentRemove/1 (194 ms)
[----------] 20 tests from ContentType/AgentResourceProviderConfigApiTest (9514 ms total)
[----------] Global test environment tear-down
[==========] 2043 tests from 207 test cases ran. (1038929 ms total)
[ PASSED ] 2041 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] PersistentVolumeEndpointsTest.EndpointCreateThenOfferRemove
[ FAILED ] StorageLocalResourceProviderTest.RetryOperationStatusUpdateToScheduler
2 FAILED TESTS
YOU HAVE 25 DISABLED TESTS
I1017 04:11:14.080456 22584 process.cpp:926] Stopped the socket accept loop
Makefile:14837: recipe for target 'check-local' failed
make[4]: *** [check-local] Error 1
make[4]: Leaving directory '/tmp/SRC/build/mesos-1.8.0/_build/sub/src'
Makefile:13979: recipe for target 'check-am' failed
make[3]: *** [check-am] Error 2
make[3]: Leaving directory '/tmp/SRC/build/mesos-1.8.0/_build/sub/src'
Makefile:13983: recipe for target 'check' failed
make[2]: *** [check] Error 2
make[2]: Leaving directory '/tmp/SRC/build/mesos-1.8.0/_build/sub/src'
Makefile:786: recipe for target 'check-recursive' failed
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory '/tmp/SRC/build/mesos-1.8.0/_build/sub'
Makefile:992: recipe for target 'distcheck' failed
make: *** [distcheck] Error 1
Error response from daemon: conflict: unable to delete 03de0cadaa0a (cannot be forced) - image is being used by running container d9cb5c1ba9d7
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos-Reviewbot #23486
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot/23486/display/redirect?page=changes>
Build failed in Jenkins: Mesos-Reviewbot #23485
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot/23485/display/redirect?page=changes>
Changes:
[klueska] Added `get_container_id` to util functions for the new CLI.
------------------------------------------
[...truncated 39.51 MB...]
I1017 12:20:16.673987 22561 master.cpp:10212] Removing framework 4873ce30-6fe6-4449-8fe4-636168ffe3f8-0000 (default) at scheduler-77fb0feb-4671-491a-a3e7-1bf75be3f05e@172.17.0.3:43389
I1017 12:20:16.674871 22570 hierarchical.cpp:359] Removed framework 4873ce30-6fe6-4449-8fe4-636168ffe3f8-0000
I1017 12:20:16.683439 22557 master.cpp:1108] Master terminating
I1017 12:20:16.683496 22578 hierarchical.cpp:1568] Performed allocation for 1 agents in 95369ns
I1017 12:20:16.684420 22578 hierarchical.cpp:645] Removed agent 4873ce30-6fe6-4449-8fe4-636168ffe3f8-S0
[ OK ] ContentType/AgentResourceProviderConfigApiTest.Remove/1 (692 ms)
[ RUN ] ContentType/AgentResourceProviderConfigApiTest.IdempotentRemove/0
I1017 12:20:16.694531 22557 cluster.cpp:173] Creating default 'local' authorizer
I1017 12:20:16.697297 22578 master.cpp:413] Master a65ea1bf-c58f-4ed5-9728-725ba5b6bc37 (afc8d1d244c6) started on 172.17.0.3:43389
I1017 12:20:16.697330 22578 master.cpp:416] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/g69vAQ/credentials" --filter_gpu_resources="true" --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" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/tmp/SRC/build/mesos-1.8.0/_inst/share/mesos/webui" --work_dir="/tmp/g69vAQ/master" --zk_session_timeout="10secs"
I1017 12:20:16.697651 22578 master.cpp:465] Master only allowing authenticated frameworks to register
I1017 12:20:16.697666 22578 master.cpp:471] Master only allowing authenticated agents to register
I1017 12:20:16.697674 22578 master.cpp:477] Master only allowing authenticated HTTP frameworks to register
I1017 12:20:16.697683 22578 credentials.hpp:37] Loading credentials for authentication from '/tmp/g69vAQ/credentials'
I1017 12:20:16.697953 22578 master.cpp:521] Using default 'crammd5' authenticator
I1017 12:20:16.698143 22578 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I1017 12:20:16.698344 22578 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I1017 12:20:16.698516 22578 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I1017 12:20:16.698693 22578 master.cpp:602] Authorization enabled
I1017 12:20:16.699146 22562 whitelist_watcher.cpp:77] No whitelist given
I1017 12:20:16.699157 22572 hierarchical.cpp:182] Initialized hierarchical allocator process
I1017 12:20:16.701838 22568 master.cpp:2098] Elected as the leading master!
I1017 12:20:16.701874 22568 master.cpp:1653] Recovering from registrar
I1017 12:20:16.702030 22565 registrar.cpp:339] Recovering registrar
I1017 12:20:16.702715 22565 registrar.cpp:383] Successfully fetched the registry (0B) in 641024ns
I1017 12:20:16.702849 22565 registrar.cpp:487] Applied 1 operations in 41509ns; attempting to update the registry
I1017 12:20:16.703481 22565 registrar.cpp:544] Successfully updated the registry in 576us
I1017 12:20:16.703624 22565 registrar.cpp:416] Successfully recovered registrar
I1017 12:20:16.704118 22579 master.cpp:1767] Recovered 0 agents from the registry (135B); allowing 10mins for agents to reregister
I1017 12:20:16.704138 22577 hierarchical.cpp:220] Skipping recovery of hierarchical allocator: nothing to recover
W1017 12:20:16.709117 22557 process.cpp:2810] Attempted to spawn already running process files@172.17.0.3:43389
I1017 12:20:16.710383 22557 containerizer.cpp:305] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1017 12:20:16.710994 22557 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1017 12:20:16.711025 22557 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1017 12:20:16.711060 22557 provisioner.cpp:298] Using default backend 'copy'
I1017 12:20:16.713498 22557 cluster.cpp:485] Creating default 'local' authorizer
I1017 12:20:16.715559 22577 slave.cpp:267] Mesos agent started on (1059)@172.17.0.3:43389
I1017 12:20:16.715591 22577 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_wlvPup/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --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_AgentResourceProviderConfigApiTest_IdempotentRemove_0_wlvPup/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --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/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_wlvPup/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_wlvPup/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_wlvPup/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/tmp/SRC/build/mesos-1.8.0/_build/sub/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_provider_config_dir="/tmp/g69vAQ/resource_provider_configs" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_wlvPup" --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_AgentResourceProviderConfigApiTest_IdempotentRemove_0_bkkF27" --zk_session_timeout="10secs"
I1017 12:20:16.716006 22577 credentials.hpp:86] Loading credential for authentication from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_wlvPup/credential'
I1017 12:20:16.716158 22577 slave.cpp:300] Agent using credential for: test-principal
I1017 12:20:16.716183 22577 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_wlvPup/http_credentials'
I1017 12:20:16.716373 22577 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1017 12:20:16.716711 22577 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I1017 12:20:16.717950 22577 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I1017 12:20:16.718174 22577 slave.cpp:623] Agent attributes: [ ]
I1017 12:20:16.718192 22577 slave.cpp:632] Agent hostname: afc8d1d244c6
I1017 12:20:16.718343 22568 task_status_update_manager.cpp:181] Pausing sending task status updates
I1017 12:20:16.719789 22559 state.cpp:66] Recovering state from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_bkkF27/meta'
I1017 12:20:16.719987 22564 slave.cpp:6915] Finished recovering checkpointed state from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_bkkF27/meta', beginning agent recovery
I1017 12:20:16.720130 22559 task_status_update_manager.cpp:207] Recovering task status update manager
I1017 12:20:16.720482 22560 containerizer.cpp:727] Recovering Mesos containers
I1017 12:20:16.720865 22560 containerizer.cpp:1053] Recovering isolators
I1017 12:20:16.721563 22572 containerizer.cpp:1092] Recovering provisioner
I1017 12:20:16.722259 22578 provisioner.cpp:494] Provisioner recovery complete
I1017 12:20:16.722990 22564 composing.cpp:339] Finished recovering all containerizers
I1017 12:20:16.723160 22559 slave.cpp:7144] Recovering executors
I1017 12:20:16.723299 22559 slave.cpp:7297] Finished recovery
I1017 12:20:16.724321 22574 slave.cpp:1260] New master detected at master@172.17.0.3:43389
I1017 12:20:16.724328 22581 task_status_update_manager.cpp:181] Pausing sending task status updates
I1017 12:20:16.724438 22574 slave.cpp:1325] Detecting new master
I1017 12:20:16.725772 22565 slave.cpp:1352] Authenticating with master master@172.17.0.3:43389
I1017 12:20:16.725862 22565 slave.cpp:1361] Using default CRAM-MD5 authenticatee
I1017 12:20:16.726156 22561 authenticatee.cpp:121] Creating new client SASL connection
I1017 12:20:16.726454 22562 master.cpp:9668] Authenticating slave(1059)@172.17.0.3:43389
I1017 12:20:16.726609 22572 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1844)@172.17.0.3:43389
I1017 12:20:16.726917 22575 authenticator.cpp:98] Creating new server SASL connection
I1017 12:20:16.727140 22573 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1017 12:20:16.727174 22573 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1017 12:20:16.727310 22568 authenticator.cpp:204] Received SASL authentication start
I1017 12:20:16.727401 22568 authenticator.cpp:326] Authentication requires more steps
I1017 12:20:16.727529 22578 authenticatee.cpp:259] Received SASL authentication step
I1017 12:20:16.727702 22576 authenticator.cpp:232] Received SASL authentication step
I1017 12:20:16.727738 22576 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'afc8d1d244c6' server FQDN: 'afc8d1d244c6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1017 12:20:16.727756 22576 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1017 12:20:16.727798 22576 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1017 12:20:16.727825 22576 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'afc8d1d244c6' server FQDN: 'afc8d1d244c6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1017 12:20:16.727840 22576 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1017 12:20:16.727852 22576 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1017 12:20:16.727871 22576 authenticator.cpp:318] Authentication success
I1017 12:20:16.727967 22563 authenticatee.cpp:299] Authentication success
I1017 12:20:16.728049 22566 master.cpp:9700] Successfully authenticated principal 'test-principal' at slave(1059)@172.17.0.3:43389
I1017 12:20:16.728082 22571 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1844)@172.17.0.3:43389
I1017 12:20:16.728395 22567 slave.cpp:1452] Successfully authenticated with master master@172.17.0.3:43389
I1017 12:20:16.728792 22567 slave.cpp:1883] Will retry registration in 7.182942ms if necessary
I1017 12:20:16.728976 22570 master.cpp:6620] Received register agent message from slave(1059)@172.17.0.3:43389 (afc8d1d244c6)
I1017 12:20:16.729440 22570 master.cpp:3979] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I1017 12:20:16.730065 22574 master.cpp:6687] Authorized registration of agent at slave(1059)@172.17.0.3:43389 (afc8d1d244c6)
I1017 12:20:16.730154 22574 master.cpp:6802] Registering agent at slave(1059)@172.17.0.3:43389 (afc8d1d244c6) with id a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0
I1017 12:20:16.730888 22560 registrar.cpp:487] Applied 1 operations in 328283ns; attempting to update the registry
I1017 12:20:16.731591 22560 registrar.cpp:544] Successfully updated the registry in 606976ns
I1017 12:20:16.731760 22575 master.cpp:6850] Admitted agent a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0 at slave(1059)@172.17.0.3:43389 (afc8d1d244c6)
I1017 12:20:16.732465 22575 master.cpp:6895] Registered agent a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0 at slave(1059)@172.17.0.3:43389 (afc8d1d244c6) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1017 12:20:16.732671 22568 slave.cpp:1485] Registered with master master@172.17.0.3:43389; given agent ID a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0
I1017 12:20:16.732800 22564 task_status_update_manager.cpp:188] Resuming sending task status updates
I1017 12:20:16.732806 22578 hierarchical.cpp:605] Added agent a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0 (afc8d1d244c6) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I1017 12:20:16.733043 22568 slave.cpp:1505] Checkpointing SlaveInfo to '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_bkkF27/meta/slaves/a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0/slave.info'
I1017 12:20:16.733093 22578 hierarchical.cpp:1568] Performed allocation for 1 agents in 102476ns
I1017 12:20:16.734099 22568 slave.cpp:1554] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"Z8NsCODlSkmsck+wi5gefw=="},"slave_id":{"value":"a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0"},"update_oversubscribed_resources":false}
I1017 12:20:16.734766 22581 master.cpp:7954] Ignoring update on agent a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0 at slave(1059)@172.17.0.3:43389 (afc8d1d244c6) as it reports no changes
I1017 12:20:16.736368 22572 process.cpp:3569] Handling HTTP event for process 'slave(1059)' with path: '/slave(1059)/api/v1'
I1017 12:20:16.737371 22566 http.cpp:1178] HTTP POST for /slave(1059)/api/v1 from 172.17.0.3:34588
I1017 12:20:16.738476 22559 http.cpp:3297] Processing REMOVE_RESOURCE_PROVIDER_CONFIG call with type 'org.apache.mesos.rp.local.storage' and name 'test'
I1017 12:20:16.740104 22560 slave.cpp:915] Agent terminating
I1017 12:20:16.750214 22564 hierarchical.cpp:1568] Performed allocation for 1 agents in 76113ns
I1017 12:20:16.800853 22563 hierarchical.cpp:1568] Performed allocation for 1 agents in 72580ns
I1017 12:20:16.851806 22559 hierarchical.cpp:1568] Performed allocation for 1 agents in 114005ns
I1017 12:20:16.861711 22570 master.cpp:1266] Agent a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0 at slave(1059)@172.17.0.3:43389 (afc8d1d244c6) disconnected
I1017 12:20:16.861774 22570 master.cpp:3282] Disconnecting agent a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0 at slave(1059)@172.17.0.3:43389 (afc8d1d244c6)
I1017 12:20:16.861865 22570 master.cpp:3301] Deactivating agent a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0 at slave(1059)@172.17.0.3:43389 (afc8d1d244c6)
I1017 12:20:16.861975 22579 hierarchical.cpp:803] Agent a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0 deactivated
I1017 12:20:16.874925 22557 master.cpp:1108] Master terminating
I1017 12:20:16.875825 22580 hierarchical.cpp:645] Removed agent a65ea1bf-c58f-4ed5-9728-725ba5b6bc37-S0
[ OK ] ContentType/AgentResourceProviderConfigApiTest.IdempotentRemove/0 (189 ms)
[ RUN ] ContentType/AgentResourceProviderConfigApiTest.IdempotentRemove/1
I1017 12:20:16.884898 22557 cluster.cpp:173] Creating default 'local' authorizer
I1017 12:20:16.888198 22580 master.cpp:413] Master 80ad07eb-b9f4-4b11-b2b8-6a399f618bfb (afc8d1d244c6) started on 172.17.0.3:43389
I1017 12:20:16.888236 22580 master.cpp:416] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/wcqLng/credentials" --filter_gpu_resources="true" --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" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/tmp/SRC/build/mesos-1.8.0/_inst/share/mesos/webui" --work_dir="/tmp/wcqLng/master" --zk_session_timeout="10secs"
I1017 12:20:16.888600 22580 master.cpp:465] Master only allowing authenticated frameworks to register
I1017 12:20:16.888622 22580 master.cpp:471] Master only allowing authenticated agents to register
I1017 12:20:16.888643 22580 master.cpp:477] Master only allowing authenticated HTTP frameworks to register
I1017 12:20:16.888661 22580 credentials.hpp:37] Loading credentials for authentication from '/tmp/wcqLng/credentials'
I1017 12:20:16.888975 22580 master.cpp:521] Using default 'crammd5' authenticator
I1017 12:20:16.889192 22580 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I1017 12:20:16.889415 22580 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I1017 12:20:16.889623 22580 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I1017 12:20:16.889830 22580 master.cpp:602] Authorization enabled
I1017 12:20:16.890324 22568 hierarchical.cpp:182] Initialized hierarchical allocator process
I1017 12:20:16.890353 22570 whitelist_watcher.cpp:77] No whitelist given
I1017 12:20:16.893159 22561 master.cpp:2098] Elected as the leading master!
I1017 12:20:16.893226 22561 master.cpp:1653] Recovering from registrar
I1017 12:20:16.893508 22579 registrar.cpp:339] Recovering registrar
I1017 12:20:16.894362 22579 registrar.cpp:383] Successfully fetched the registry (0B) in 793088ns
I1017 12:20:16.894531 22579 registrar.cpp:487] Applied 1 operations in 47928ns; attempting to update the registry
I1017 12:20:16.895256 22579 registrar.cpp:544] Successfully updated the registry in 666112ns
I1017 12:20:16.895407 22579 registrar.cpp:416] Successfully recovered registrar
I1017 12:20:16.895972 22581 master.cpp:1767] Recovered 0 agents from the registry (135B); allowing 10mins for agents to reregister
I1017 12:20:16.896010 22565 hierarchical.cpp:220] Skipping recovery of hierarchical allocator: nothing to recover
W1017 12:20:16.901193 22557 process.cpp:2810] Attempted to spawn already running process files@172.17.0.3:43389
I1017 12:20:16.902529 22557 containerizer.cpp:305] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1017 12:20:16.903156 22557 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1017 12:20:16.903194 22557 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1017 12:20:16.903239 22557 provisioner.cpp:298] Using default backend 'copy'
I1017 12:20:16.905563 22557 cluster.cpp:485] Creating default 'local' authorizer
I1017 12:20:16.907532 22581 slave.cpp:267] Mesos agent started on (1060)@172.17.0.3:43389
I1017 12:20:16.907564 22581 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_OshfdQ/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --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_AgentResourceProviderConfigApiTest_IdempotentRemove_1_OshfdQ/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --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/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_OshfdQ/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_OshfdQ/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_OshfdQ/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/tmp/SRC/build/mesos-1.8.0/_build/sub/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_provider_config_dir="/tmp/wcqLng/resource_provider_configs" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_OshfdQ" --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_AgentResourceProviderConfigApiTest_IdempotentRemove_1_H6Quiy" --zk_session_timeout="10secs"
I1017 12:20:16.908048 22581 credentials.hpp:86] Loading credential for authentication from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_OshfdQ/credential'
I1017 12:20:16.908237 22581 slave.cpp:300] Agent using credential for: test-principal
I1017 12:20:16.908282 22581 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_OshfdQ/http_credentials'
I1017 12:20:16.908579 22581 http.cpp:1038] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1017 12:20:16.909029 22581 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I1017 12:20:16.911224 22581 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I1017 12:20:16.911622 22581 slave.cpp:623] Agent attributes: [ ]
I1017 12:20:16.911661 22581 slave.cpp:632] Agent hostname: afc8d1d244c6
I1017 12:20:16.911857 22561 task_status_update_manager.cpp:181] Pausing sending task status updates
I1017 12:20:16.913563 22560 state.cpp:66] Recovering state from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_H6Quiy/meta'
I1017 12:20:16.913895 22572 slave.cpp:6915] Finished recovering checkpointed state from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_H6Quiy/meta', beginning agent recovery
I1017 12:20:16.914077 22575 task_status_update_manager.cpp:207] Recovering task status update manager
I1017 12:20:16.914422 22566 containerizer.cpp:727] Recovering Mesos containers
I1017 12:20:16.914819 22566 containerizer.cpp:1053] Recovering isolators
I1017 12:20:16.915494 22558 containerizer.cpp:1092] Recovering provisioner
I1017 12:20:16.916165 22562 provisioner.cpp:494] Provisioner recovery complete
I1017 12:20:16.917018 22567 composing.cpp:339] Finished recovering all containerizers
I1017 12:20:16.917176 22575 slave.cpp:7144] Recovering executors
I1017 12:20:16.917292 22575 slave.cpp:7297] Finished recovery
I1017 12:20:16.918153 22568 task_status_update_manager.cpp:181] Pausing sending task status updates
I1017 12:20:16.918195 22559 slave.cpp:1260] New master detected at master@172.17.0.3:43389
I1017 12:20:16.918359 22559 slave.cpp:1325] Detecting new master
I1017 12:20:16.919637 22569 slave.cpp:1352] Authenticating with master master@172.17.0.3:43389
I1017 12:20:16.919745 22569 slave.cpp:1361] Using default CRAM-MD5 authenticatee
I1017 12:20:16.920054 22578 authenticatee.cpp:121] Creating new client SASL connection
I1017 12:20:16.920341 22576 master.cpp:9668] Authenticating slave(1060)@172.17.0.3:43389
I1017 12:20:16.920480 22570 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1845)@172.17.0.3:43389
I1017 12:20:16.920753 22558 authenticator.cpp:98] Creating new server SASL connection
I1017 12:20:16.920965 22580 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1017 12:20:16.920995 22580 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1017 12:20:16.921130 22563 authenticator.cpp:204] Received SASL authentication start
I1017 12:20:16.921247 22563 authenticator.cpp:326] Authentication requires more steps
I1017 12:20:16.921402 22562 authenticatee.cpp:259] Received SASL authentication step
I1017 12:20:16.921558 22561 authenticator.cpp:232] Received SASL authentication step
I1017 12:20:16.921602 22561 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'afc8d1d244c6' server FQDN: 'afc8d1d244c6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1017 12:20:16.921631 22561 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1017 12:20:16.921682 22561 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1017 12:20:16.921716 22561 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'afc8d1d244c6' server FQDN: 'afc8d1d244c6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1017 12:20:16.921732 22561 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1017 12:20:16.921748 22561 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1017 12:20:16.921779 22561 authenticator.cpp:318] Authentication success
I1017 12:20:16.921885 22574 authenticatee.cpp:299] Authentication success
I1017 12:20:16.921969 22560 master.cpp:9700] Successfully authenticated principal 'test-principal' at slave(1060)@172.17.0.3:43389
I1017 12:20:16.922039 22564 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1845)@172.17.0.3:43389
I1017 12:20:16.922291 22581 slave.cpp:1452] Successfully authenticated with master master@172.17.0.3:43389
I1017 12:20:16.922740 22581 slave.cpp:1883] Will retry registration in 3.37506ms if necessary
I1017 12:20:16.922906 22575 master.cpp:6620] Received register agent message from slave(1060)@172.17.0.3:43389 (afc8d1d244c6)
I1017 12:20:16.923230 22575 master.cpp:3979] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I1017 12:20:16.923799 22568 master.cpp:6687] Authorized registration of agent at slave(1060)@172.17.0.3:43389 (afc8d1d244c6)
I1017 12:20:16.923907 22568 master.cpp:6802] Registering agent at slave(1060)@172.17.0.3:43389 (afc8d1d244c6) with id 80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0
I1017 12:20:16.924513 22565 registrar.cpp:487] Applied 1 operations in 232129ns; attempting to update the registry
I1017 12:20:16.925352 22565 registrar.cpp:544] Successfully updated the registry in 749056ns
I1017 12:20:16.925585 22570 master.cpp:6850] Admitted agent 80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0 at slave(1060)@172.17.0.3:43389 (afc8d1d244c6)
I1017 12:20:16.926264 22570 master.cpp:6895] Registered agent 80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0 at slave(1060)@172.17.0.3:43389 (afc8d1d244c6) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1017 12:20:16.926466 22580 slave.cpp:1485] Registered with master master@172.17.0.3:43389; given agent ID 80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0
I1017 12:20:16.926581 22572 task_status_update_manager.cpp:188] Resuming sending task status updates
I1017 12:20:16.926587 22558 hierarchical.cpp:605] Added agent 80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0 (afc8d1d244c6) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I1017 12:20:16.926826 22580 slave.cpp:1505] Checkpointing SlaveInfo to '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_H6Quiy/meta/slaves/80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0/slave.info'
I1017 12:20:16.926870 22558 hierarchical.cpp:1568] Performed allocation for 1 agents in 92854ns
I1017 12:20:16.927839 22580 slave.cpp:1554] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"Yp9zf92BSVOfANCUbPpPGA=="},"slave_id":{"value":"80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0"},"update_oversubscribed_resources":false}
I1017 12:20:16.928524 22575 master.cpp:7954] Ignoring update on agent 80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0 at slave(1060)@172.17.0.3:43389 (afc8d1d244c6) as it reports no changes
I1017 12:20:16.930266 22578 process.cpp:3569] Handling HTTP event for process 'slave(1060)' with path: '/slave(1060)/api/v1'
I1017 12:20:16.931334 22567 http.cpp:1178] HTTP POST for /slave(1060)/api/v1 from 172.17.0.3:34590
I1017 12:20:16.932554 22577 http.cpp:3297] Processing REMOVE_RESOURCE_PROVIDER_CONFIG call with type 'org.apache.mesos.rp.local.storage' and name 'test'
I1017 12:20:16.934212 22565 slave.cpp:915] Agent terminating
I1017 12:20:16.941407 22561 hierarchical.cpp:1568] Performed allocation for 1 agents in 119645ns
I1017 12:20:16.993326 22573 hierarchical.cpp:1568] Performed allocation for 1 agents in 134570ns
I1017 12:20:17.044533 22564 hierarchical.cpp:1568] Performed allocation for 1 agents in 119600ns
I1017 12:20:17.066637 22581 master.cpp:1266] Agent 80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0 at slave(1060)@172.17.0.3:43389 (afc8d1d244c6) disconnected
I1017 12:20:17.066704 22581 master.cpp:3282] Disconnecting agent 80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0 at slave(1060)@172.17.0.3:43389 (afc8d1d244c6)
I1017 12:20:17.066820 22581 master.cpp:3301] Deactivating agent 80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0 at slave(1060)@172.17.0.3:43389 (afc8d1d244c6)
I1017 12:20:17.067018 22579 hierarchical.cpp:803] Agent 80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0 deactivated
I1017 12:20:17.079227 22557 master.cpp:1108] Master terminating
I1017 12:20:17.080205 22575 hierarchical.cpp:645] Removed agent 80ad07eb-b9f4-4b11-b2b8-6a399f618bfb-S0
[ OK ] ContentType/AgentResourceProviderConfigApiTest.IdempotentRemove/1 (203 ms)
[----------] 20 tests from ContentType/AgentResourceProviderConfigApiTest (10558 ms total)
[----------] Global test environment tear-down
[==========] 2043 tests from 207 test cases ran. (1094687 ms total)
[ PASSED ] 2041 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] FetcherCacheHttpTest.HttpCachedSerialized
[ FAILED ] StorageLocalResourceProviderTest.RetryOperationStatusUpdateToScheduler
2 FAILED TESTS
YOU HAVE 25 DISABLED TESTS
I1017 12:20:17.160428 22582 process.cpp:926] Stopped the socket accept loop
Makefile:14837: recipe for target 'check-local' failed
make[4]: *** [check-local] Error 1
make[4]: Leaving directory '/tmp/SRC/build/mesos-1.8.0/_build/sub/src'
Makefile:13979: recipe for target 'check-am' failed
make[3]: *** [check-am] Error 2
make[3]: Leaving directory '/tmp/SRC/build/mesos-1.8.0/_build/sub/src'
Makefile:13983: recipe for target 'check' failed
make[2]: *** [check] Error 2
make[2]: Leaving directory '/tmp/SRC/build/mesos-1.8.0/_build/sub/src'
Makefile:786: recipe for target 'check-recursive' failed
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory '/tmp/SRC/build/mesos-1.8.0/_build/sub'
Makefile:992: recipe for target 'distcheck' failed
make: *** [distcheck] Error 1
Error response from daemon: conflict: unable to delete 03de0cadaa0a (cannot be forced) - image is being used by running container 2bb4598831d8
Build step 'Execute shell' marked build as failure