See <https://builds.apache.org/job/Mesos-Reviewbot/23244/display/redirect>
------------------------------------------ [...truncated 38.80 MB...] I0903 20:04:37.791805 29434 whitelist_watcher.cpp:77] No whitelist given I0903 20:04:37.795444 29433 master.cpp:2083] Elected as the leading master! I0903 20:04:37.795506 29433 master.cpp:1638] Recovering from registrar I0903 20:04:37.795763 29439 registrar.cpp:339] Recovering registrar I0903 20:04:37.796814 29439 registrar.cpp:383] Successfully fetched the registry (0B) in 971008ns I0903 20:04:37.797044 29439 registrar.cpp:487] Applied 1 operations in 52077ns; attempting to update the registry I0903 20:04:37.798130 29439 registrar.cpp:544] Successfully updated the registry in 985856ns I0903 20:04:37.798390 29439 registrar.cpp:416] Successfully recovered registrar I0903 20:04:37.799185 29430 master.cpp:1752] Recovered 0 agents from the registry (135B); allowing 10mins for agents to reregister I0903 20:04:37.799238 29448 hierarchical.cpp:220] Skipping recovery of hierarchical allocator: nothing to recover W0903 20:04:37.807231 29426 process.cpp:2810] Attempted to spawn already running process [email protected]:44366 I0903 20:04:37.808727 29426 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } W0903 20:04:37.809615 29426 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges W0903 20:04:37.809656 29426 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges I0903 20:04:37.809700 29426 provisioner.cpp:298] Using default backend 'copy' I0903 20:04:37.812937 29426 cluster.cpp:479] Creating default 'local' authorizer I0903 20:04:37.816084 29448 slave.cpp:267] Mesos agent started on (1037)@172.17.0.2:44366 I0903 20:04:37.816117 29448 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_YRJ5zg/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_YRJ5zg/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_YRJ5zg/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_YRJ5zg/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_YRJ5zg/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/Wnpuah/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_YRJ5zg" --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_KorhSg" --zk_session_timeout="10secs" I0903 20:04:37.816645 29448 credentials.hpp:86] Loading credential for authentication from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_YRJ5zg/credential' I0903 20:04:37.816813 29448 slave.cpp:300] Agent using credential for: test-principal I0903 20:04:37.816854 29448 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_YRJ5zg/http_credentials' I0903 20:04:37.817093 29448 http.cpp:1037] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0903 20:04:37.817497 29448 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module I0903 20:04:37.819185 29448 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"}] I0903 20:04:37.819589 29448 slave.cpp:623] Agent attributes: [ ] I0903 20:04:37.819617 29448 slave.cpp:632] Agent hostname: 44d958e7b613 I0903 20:04:37.819918 29433 task_status_update_manager.cpp:181] Pausing sending task status updates I0903 20:04:37.822074 29449 state.cpp:66] Recovering state from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_KorhSg/meta' I0903 20:04:37.822474 29428 slave.cpp:6909] Finished recovering checkpointed state from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_KorhSg/meta', beginning agent recovery I0903 20:04:37.822955 29449 task_status_update_manager.cpp:207] Recovering task status update manager I0903 20:04:37.823578 29429 containerizer.cpp:720] Recovering Mesos containers I0903 20:04:37.823968 29429 containerizer.cpp:1027] Recovering isolators I0903 20:04:37.824769 29437 containerizer.cpp:1066] Recovering provisioner I0903 20:04:37.825584 29450 provisioner.cpp:494] Provisioner recovery complete I0903 20:04:37.826478 29447 composing.cpp:339] Finished recovering all containerizers I0903 20:04:37.826663 29449 slave.cpp:7138] Recovering executors I0903 20:04:37.826867 29449 slave.cpp:7291] Finished recovery I0903 20:04:37.828058 29436 task_status_update_manager.cpp:181] Pausing sending task status updates I0903 20:04:37.828112 29441 slave.cpp:1254] New master detected at [email protected]:44366 I0903 20:04:37.828348 29441 slave.cpp:1319] Detecting new master I0903 20:04:37.829782 29429 slave.cpp:1346] Authenticating with master [email protected]:44366 I0903 20:04:37.829897 29429 slave.cpp:1355] Using default CRAM-MD5 authenticatee I0903 20:04:37.830317 29430 authenticatee.cpp:121] Creating new client SASL connection I0903 20:04:37.830899 29427 master.cpp:9600] Authenticating slave(1037)@172.17.0.2:44366 I0903 20:04:37.831171 29437 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1804)@172.17.0.2:44366 I0903 20:04:37.831462 29434 authenticator.cpp:98] Creating new server SASL connection I0903 20:04:37.831748 29431 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0903 20:04:37.831807 29431 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0903 20:04:37.831975 29433 authenticator.cpp:204] Received SASL authentication start I0903 20:04:37.832070 29433 authenticator.cpp:326] Authentication requires more steps I0903 20:04:37.832237 29450 authenticatee.cpp:259] Received SASL authentication step I0903 20:04:37.832427 29450 authenticator.cpp:232] Received SASL authentication step I0903 20:04:37.832485 29450 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '44d958e7b613' server FQDN: '44d958e7b613' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0903 20:04:37.832509 29450 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0903 20:04:37.832564 29450 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0903 20:04:37.832604 29450 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '44d958e7b613' server FQDN: '44d958e7b613' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0903 20:04:37.832638 29450 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0903 20:04:37.832660 29450 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0903 20:04:37.832708 29450 authenticator.cpp:318] Authentication success I0903 20:04:37.832857 29443 authenticatee.cpp:299] Authentication success I0903 20:04:37.832998 29448 master.cpp:9632] Successfully authenticated principal 'test-principal' at slave(1037)@172.17.0.2:44366 I0903 20:04:37.833029 29446 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1804)@172.17.0.2:44366 I0903 20:04:37.833372 29428 slave.cpp:1446] Successfully authenticated with master [email protected]:44366 I0903 20:04:37.833906 29428 slave.cpp:1877] Will retry registration in 11.242307ms if necessary I0903 20:04:37.834091 29432 master.cpp:6562] Received register agent message from slave(1037)@172.17.0.2:44366 (44d958e7b613) I0903 20:04:37.834461 29432 master.cpp:3921] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal' I0903 20:04:37.835132 29436 master.cpp:6629] Authorized registration of agent at slave(1037)@172.17.0.2:44366 (44d958e7b613) I0903 20:04:37.835224 29436 master.cpp:6744] Registering agent at slave(1037)@172.17.0.2:44366 (44d958e7b613) with id d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0 I0903 20:04:37.836155 29439 registrar.cpp:487] Applied 1 operations in 384680ns; attempting to update the registry I0903 20:04:37.837220 29439 registrar.cpp:544] Successfully updated the registry in 942848ns I0903 20:04:37.837492 29437 master.cpp:6792] Admitted agent d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0 at slave(1037)@172.17.0.2:44366 (44d958e7b613) I0903 20:04:37.838186 29437 master.cpp:6837] Registered agent d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0 at slave(1037)@172.17.0.2:44366 (44d958e7b613) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0903 20:04:37.838374 29431 slave.cpp:1479] Registered with master [email protected]:44366; given agent ID d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0 I0903 20:04:37.838531 29445 task_status_update_manager.cpp:188] Resuming sending task status updates I0903 20:04:37.838743 29431 slave.cpp:1499] Checkpointing SlaveInfo to '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_0_KorhSg/meta/slaves/d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0/slave.info' I0903 20:04:37.838886 29433 hierarchical.cpp:601] Added agent d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0 (44d958e7b613) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) I0903 20:04:37.839176 29433 hierarchical.cpp:1564] Performed allocation for 1 agents in 111208ns I0903 20:04:37.839761 29431 slave.cpp:1548] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"/CXZkyPPSwGbsRJyh4NiqA=="},"slave_id":{"value":"d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0"},"update_oversubscribed_resources":false} I0903 20:04:37.840493 29438 master.cpp:7896] Ignoring update on agent d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0 at slave(1037)@172.17.0.2:44366 (44d958e7b613) as it reports no changes I0903 20:04:37.842866 29444 hierarchical.cpp:1564] Performed allocation for 1 agents in 148560ns I0903 20:04:37.843266 29439 process.cpp:3569] Handling HTTP event for process 'slave(1037)' with path: '/slave(1037)/api/v1' I0903 20:04:37.844768 29442 http.cpp:1177] HTTP POST for /slave(1037)/api/v1 from 172.17.0.2:34470 I0903 20:04:37.846321 29428 http.cpp:3304] Processing REMOVE_RESOURCE_PROVIDER_CONFIG call with type 'org.apache.mesos.rp.local.storage' and name 'test' I0903 20:04:37.848783 29427 slave.cpp:909] Agent terminating I0903 20:04:37.894196 29445 hierarchical.cpp:1564] Performed allocation for 1 agents in 109633ns I0903 20:04:37.945418 29433 hierarchical.cpp:1564] Performed allocation for 1 agents in 168802ns I0903 20:04:37.995461 29432 master.cpp:1251] Agent d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0 at slave(1037)@172.17.0.2:44366 (44d958e7b613) disconnected I0903 20:04:37.995529 29432 master.cpp:3267] Disconnecting agent d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0 at slave(1037)@172.17.0.2:44366 (44d958e7b613) I0903 20:04:37.995621 29432 master.cpp:3286] Deactivating agent d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0 at slave(1037)@172.17.0.2:44366 (44d958e7b613) I0903 20:04:37.995699 29438 hierarchical.cpp:795] Agent d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0 deactivated I0903 20:04:37.997153 29445 hierarchical.cpp:1564] Performed allocation for 1 agents in 108577ns I0903 20:04:38.008523 29426 master.cpp:1093] Master terminating I0903 20:04:38.009281 29440 hierarchical.cpp:637] Removed agent d7e4336f-3651-46d9-9ead-13eaf6b20ce4-S0 [ OK ] ContentType/AgentResourceProviderConfigApiTest.IdempotentRemove/0 (234 ms) [ RUN ] ContentType/AgentResourceProviderConfigApiTest.IdempotentRemove/1 I0903 20:04:38.021361 29426 cluster.cpp:173] Creating default 'local' authorizer I0903 20:04:38.026475 29440 master.cpp:413] Master 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be (44d958e7b613) started on 172.17.0.2:44366 I0903 20:04:38.026520 29440 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/sAScmg/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/sAScmg/master" --zk_session_timeout="10secs" I0903 20:04:38.027146 29440 master.cpp:465] Master only allowing authenticated frameworks to register I0903 20:04:38.027170 29440 master.cpp:471] Master only allowing authenticated agents to register I0903 20:04:38.027184 29440 master.cpp:477] Master only allowing authenticated HTTP frameworks to register I0903 20:04:38.027207 29440 credentials.hpp:37] Loading credentials for authentication from '/tmp/sAScmg/credentials' I0903 20:04:38.027581 29440 master.cpp:521] Using default 'crammd5' authenticator I0903 20:04:38.027792 29440 http.cpp:1037] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0903 20:04:38.028048 29440 http.cpp:1037] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0903 20:04:38.028244 29440 http.cpp:1037] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0903 20:04:38.028455 29440 master.cpp:602] Authorization enabled I0903 20:04:38.029064 29434 hierarchical.cpp:182] Initialized hierarchical allocator process I0903 20:04:38.029156 29439 whitelist_watcher.cpp:77] No whitelist given I0903 20:04:38.032969 29437 master.cpp:2083] Elected as the leading master! I0903 20:04:38.033010 29437 master.cpp:1638] Recovering from registrar I0903 20:04:38.033195 29431 registrar.cpp:339] Recovering registrar I0903 20:04:38.034154 29431 registrar.cpp:383] Successfully fetched the registry (0B) in 910848ns I0903 20:04:38.034320 29431 registrar.cpp:487] Applied 1 operations in 50588ns; attempting to update the registry I0903 20:04:38.035291 29431 registrar.cpp:544] Successfully updated the registry in 882944ns I0903 20:04:38.035488 29431 registrar.cpp:416] Successfully recovered registrar I0903 20:04:38.036118 29445 master.cpp:1752] Recovered 0 agents from the registry (135B); allowing 10mins for agents to reregister I0903 20:04:38.036310 29428 hierarchical.cpp:220] Skipping recovery of hierarchical allocator: nothing to recover W0903 20:04:38.045079 29426 process.cpp:2810] Attempted to spawn already running process [email protected]:44366 I0903 20:04:38.046699 29426 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } W0903 20:04:38.047650 29426 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges W0903 20:04:38.047700 29426 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges I0903 20:04:38.047749 29426 provisioner.cpp:298] Using default backend 'copy' I0903 20:04:38.051570 29426 cluster.cpp:479] Creating default 'local' authorizer I0903 20:04:38.054726 29428 slave.cpp:267] Mesos agent started on (1038)@172.17.0.2:44366 I0903 20:04:38.054774 29428 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_WgrsUg/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_WgrsUg/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_WgrsUg/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_WgrsUg/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_WgrsUg/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/sAScmg/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_WgrsUg" --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_QKXjDg" --zk_session_timeout="10secs" I0903 20:04:38.055464 29428 credentials.hpp:86] Loading credential for authentication from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_WgrsUg/credential' I0903 20:04:38.055702 29428 slave.cpp:300] Agent using credential for: test-principal I0903 20:04:38.055740 29428 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_WgrsUg/http_credentials' I0903 20:04:38.056047 29428 http.cpp:1037] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0903 20:04:38.056568 29428 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module I0903 20:04:38.058502 29428 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"}] I0903 20:04:38.058874 29428 slave.cpp:623] Agent attributes: [ ] I0903 20:04:38.058897 29428 slave.cpp:632] Agent hostname: 44d958e7b613 I0903 20:04:38.059131 29437 task_status_update_manager.cpp:181] Pausing sending task status updates I0903 20:04:38.061039 29429 state.cpp:66] Recovering state from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_QKXjDg/meta' I0903 20:04:38.061391 29450 slave.cpp:6909] Finished recovering checkpointed state from '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_QKXjDg/meta', beginning agent recovery I0903 20:04:38.061708 29448 task_status_update_manager.cpp:207] Recovering task status update manager I0903 20:04:38.062391 29442 containerizer.cpp:720] Recovering Mesos containers I0903 20:04:38.062974 29442 containerizer.cpp:1027] Recovering isolators I0903 20:04:38.064057 29440 containerizer.cpp:1066] Recovering provisioner I0903 20:04:38.064987 29443 provisioner.cpp:494] Provisioner recovery complete I0903 20:04:38.066331 29448 composing.cpp:339] Finished recovering all containerizers I0903 20:04:38.066574 29433 slave.cpp:7138] Recovering executors I0903 20:04:38.066792 29433 slave.cpp:7291] Finished recovery I0903 20:04:38.067806 29433 task_status_update_manager.cpp:181] Pausing sending task status updates I0903 20:04:38.067873 29449 slave.cpp:1254] New master detected at [email protected]:44366 I0903 20:04:38.068094 29449 slave.cpp:1319] Detecting new master I0903 20:04:38.073650 29427 slave.cpp:1346] Authenticating with master [email protected]:44366 I0903 20:04:38.073786 29427 slave.cpp:1355] Using default CRAM-MD5 authenticatee I0903 20:04:38.074223 29435 authenticatee.cpp:121] Creating new client SASL connection I0903 20:04:38.074787 29440 master.cpp:9600] Authenticating slave(1038)@172.17.0.2:44366 I0903 20:04:38.075001 29439 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1805)@172.17.0.2:44366 I0903 20:04:38.075470 29432 authenticator.cpp:98] Creating new server SASL connection I0903 20:04:38.075886 29436 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0903 20:04:38.075948 29436 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0903 20:04:38.076202 29436 authenticator.cpp:204] Received SASL authentication start I0903 20:04:38.076333 29436 authenticator.cpp:326] Authentication requires more steps I0903 20:04:38.076594 29436 authenticatee.cpp:259] Received SASL authentication step I0903 20:04:38.076855 29436 authenticator.cpp:232] Received SASL authentication step I0903 20:04:38.076939 29436 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '44d958e7b613' server FQDN: '44d958e7b613' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0903 20:04:38.076973 29436 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0903 20:04:38.077064 29436 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0903 20:04:38.077127 29436 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '44d958e7b613' server FQDN: '44d958e7b613' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0903 20:04:38.077168 29436 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0903 20:04:38.077196 29436 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0903 20:04:38.077260 29436 authenticator.cpp:318] Authentication success I0903 20:04:38.077422 29428 authenticatee.cpp:299] Authentication success I0903 20:04:38.077750 29444 master.cpp:9632] Successfully authenticated principal 'test-principal' at slave(1038)@172.17.0.2:44366 I0903 20:04:38.077934 29450 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1805)@172.17.0.2:44366 I0903 20:04:38.078073 29447 slave.cpp:1446] Successfully authenticated with master [email protected]:44366 I0903 20:04:38.078554 29447 slave.cpp:1877] Will retry registration in 3.616666ms if necessary I0903 20:04:38.078856 29434 master.cpp:6562] Received register agent message from slave(1038)@172.17.0.2:44366 (44d958e7b613) I0903 20:04:38.079290 29434 master.cpp:3921] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal' I0903 20:04:38.080140 29427 master.cpp:6629] Authorized registration of agent at slave(1038)@172.17.0.2:44366 (44d958e7b613) I0903 20:04:38.080178 29445 hierarchical.cpp:1564] Performed allocation for 0 agents in 54832ns I0903 20:04:38.080250 29427 master.cpp:6744] Registering agent at slave(1038)@172.17.0.2:44366 (44d958e7b613) with id 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 I0903 20:04:38.081382 29440 registrar.cpp:487] Applied 1 operations in 446557ns; attempting to update the registry I0903 20:04:38.082506 29440 registrar.cpp:544] Successfully updated the registry in 1.006848ms I0903 20:04:38.082875 29437 master.cpp:6792] Admitted agent 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 at slave(1038)@172.17.0.2:44366 (44d958e7b613) I0903 20:04:38.083647 29437 master.cpp:6837] Registered agent 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 at slave(1038)@172.17.0.2:44366 (44d958e7b613) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0903 20:04:38.083828 29436 slave.cpp:1877] Will retry registration in 36.37047ms if necessary I0903 20:04:38.084026 29431 master.cpp:6562] Received register agent message from slave(1038)@172.17.0.2:44366 (44d958e7b613) I0903 20:04:38.084192 29448 hierarchical.cpp:601] Added agent 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 (44d958e7b613) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) I0903 20:04:38.084372 29436 slave.cpp:1479] Registered with master [email protected]:44366; given agent ID 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 I0903 20:04:38.084440 29431 master.cpp:3921] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal' I0903 20:04:38.084527 29446 task_status_update_manager.cpp:188] Resuming sending task status updates I0903 20:04:38.084666 29448 hierarchical.cpp:1564] Performed allocation for 1 agents in 146788ns I0903 20:04:38.084897 29436 slave.cpp:1499] Checkpointing SlaveInfo to '/tmp/ContentType_AgentResourceProviderConfigApiTest_IdempotentRemove_1_QKXjDg/meta/slaves/5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0/slave.info' I0903 20:04:38.085047 29434 master.cpp:6629] Authorized registration of agent at slave(1038)@172.17.0.2:44366 (44d958e7b613) I0903 20:04:38.085165 29434 master.cpp:6723] Agent 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 at slave(1038)@172.17.0.2:44366 (44d958e7b613) already registered, resending acknowledgement I0903 20:04:38.086203 29436 slave.cpp:1548] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"hOE6DPtJT2yRQlr7kr6eNA=="},"slave_id":{"value":"5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0"},"update_oversubscribed_resources":false} W0903 20:04:38.086426 29436 slave.cpp:1530] Already registered with master [email protected]:44366 I0903 20:04:38.086546 29436 slave.cpp:1548] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"hOE6DPtJT2yRQlr7kr6eNA=="},"slave_id":{"value":"5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0"},"update_oversubscribed_resources":false} I0903 20:04:38.087280 29443 master.cpp:7896] Ignoring update on agent 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 at slave(1038)@172.17.0.2:44366 (44d958e7b613) as it reports no changes I0903 20:04:38.088089 29443 master.cpp:7896] Ignoring update on agent 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 at slave(1038)@172.17.0.2:44366 (44d958e7b613) as it reports no changes I0903 20:04:38.089026 29441 process.cpp:3569] Handling HTTP event for process 'slave(1038)' with path: '/slave(1038)/api/v1' I0903 20:04:38.090631 29447 http.cpp:1177] HTTP POST for /slave(1038)/api/v1 from 172.17.0.2:34472 I0903 20:04:38.092319 29442 http.cpp:3304] Processing REMOVE_RESOURCE_PROVIDER_CONFIG call with type 'org.apache.mesos.rp.local.storage' and name 'test' I0903 20:04:38.095314 29426 slave.cpp:909] Agent terminating I0903 20:04:38.131189 29433 hierarchical.cpp:1564] Performed allocation for 1 agents in 149040ns I0903 20:04:38.182343 29442 hierarchical.cpp:1564] Performed allocation for 1 agents in 166208ns I0903 20:04:38.233521 29432 master.cpp:1251] Agent 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 at slave(1038)@172.17.0.2:44366 (44d958e7b613) disconnected I0903 20:04:38.233584 29432 master.cpp:3267] Disconnecting agent 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 at slave(1038)@172.17.0.2:44366 (44d958e7b613) I0903 20:04:38.233693 29432 master.cpp:3286] Deactivating agent 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 at slave(1038)@172.17.0.2:44366 (44d958e7b613) I0903 20:04:38.233839 29439 hierarchical.cpp:795] Agent 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 deactivated I0903 20:04:38.234328 29439 hierarchical.cpp:1564] Performed allocation for 1 agents in 106674ns I0903 20:04:38.244123 29426 master.cpp:1093] Master terminating I0903 20:04:38.244910 29449 hierarchical.cpp:637] Removed agent 5a025ced-b5f3-4ce9-9dcd-be9e8f6980be-S0 [ OK ] ContentType/AgentResourceProviderConfigApiTest.IdempotentRemove/1 (232 ms) [----------] 4 tests from ContentType/AgentResourceProviderConfigApiTest (953 ms total) [----------] Global test environment tear-down [==========] 2019 tests from 206 test cases ran. (918448 ms total) [ PASSED ] 2018 tests. [ FAILED ] 1 test, listed below: [ FAILED ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization 1 FAILED TEST YOU HAVE 24 DISABLED TESTS I0903 20:04:38.344470 29451 process.cpp:926] Stopped the socket accept loop Makefile:14846: 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:13956: 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:13960: 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:779: 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:985: recipe for target 'distcheck' failed make: *** [distcheck] Error 1 Untagged: mesos/mesos-build:ubuntu-16.04 Untagged: mesos/mesos-build@sha256:8685ea3c3e17663e4a1764d08df701102b4e9286c6c1a7116afccbe382777290 Deleted: sha256:4ecb5a128921ae9aad805a57a0e4d24dbcfbe84b09304997c7e2798819aa155a Deleted: sha256:91a3c8a13a99414ff67baa2d1c6a6a82b43c237327a78d7f815414e155578ac1 Deleted: sha256:d05373b7ffe6961840e0962d4b16df22a14b1bbba3416f5aee58b579f08a2bcd Deleted: sha256:db96690681268d3c4fdd48cd5edc2ca128c6b2493c67333983b63119622cc485 Deleted: sha256:70f40beaddd4e8dc15479d4f78d75b121fd4428c7bb29319a0fae0babd257e37 Deleted: sha256:77e6ddba346d8ad1e436256f6373dede5af4002006981b7d4116c561c759cefa Deleted: sha256:8db758ab2fdb54da0aec53aeac876934337e6170f5a8c8872b3d4171e3d465b7 Deleted: sha256:a7fc6b405fe8ef71edfa6163d1dc9f1cb1df426049eefaa7d388e9df21a061ad Deleted: sha256:5a3e35538f7f2e2727c8ac92f08c30002b9e8a77737de0dab91244344d59f69b Deleted: sha256:ff986b10a018b48074e6d3a68b39aad8ccc002cdad912d4148c0f92b3729323e Build step 'Execute shell' marked build as failure
