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 2019/09/05 02:41:05 UTC
Build failed in Jenkins: Mesos-Reviewbot-Linux #3506
See <https://builds.apache.org/job/Mesos-Reviewbot-Linux/3506/display/redirect>
------------------------------------------
[...truncated 14.45 MB...]
I0905 02:40:57.477695 18938 authenticatee.cpp:299] Authentication success
I0905 02:40:57.477883 18952 master.cpp:10605] Successfully authenticated principal 'test-principal' at slave(152)@172.17.0.2:44946
I0905 02:40:57.477973 18945 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(333)@172.17.0.2:44946
I0905 02:40:57.478339 18937 slave.cpp:1543] Successfully authenticated with master master@172.17.0.2:44946
I0905 02:40:57.478968 18937 slave.cpp:1993] Will retry registration in 5.408974ms if necessary
I0905 02:40:57.479233 18939 master.cpp:7066] Received register agent message from slave(152)@172.17.0.2:44946 (3595603fae6f)
I0905 02:40:57.479743 18939 master.cpp:4191] Authorizing agent providing resources 'cpus:0.5; mem:100; disk:10; ports:[6-10]' with principal 'test-principal'
I0905 02:40:57.480734 18934 master.cpp:7133] Authorized registration of agent at slave(152)@172.17.0.2:44946 (3595603fae6f)
I0905 02:40:57.480891 18934 master.cpp:7245] Registering agent at slave(152)@172.17.0.2:44946 (3595603fae6f) with id 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S1
I0905 02:40:57.481863 18942 registrar.cpp:487] Applied 1 operations in 355026ns; attempting to update the registry
I0905 02:40:57.482856 18942 registrar.cpp:544] Successfully updated the registry in 0ns
I0905 02:40:57.483114 18949 master.cpp:7293] Admitted agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S1 at slave(152)@172.17.0.2:44946 (3595603fae6f)
I0905 02:40:57.484181 18949 master.cpp:7338] Registered agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S1 at slave(152)@172.17.0.2:44946 (3595603fae6f) with cpus:0.5; mem:100; disk:10; ports:[6-10]
I0905 02:40:57.484338 18951 slave.cpp:1576] Registered with master master@172.17.0.2:44946; given agent ID 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S1
I0905 02:40:57.484499 18947 task_status_update_manager.cpp:188] Resuming sending task status updates
I0905 02:40:57.484474 18955 hierarchical.cpp:854] Added agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S1 (3595603fae6f) with cpus:0.5; mem:100; disk:10; ports:[6-10] (offered or allocated: {})
I0905 02:40:57.484916 18951 slave.cpp:1611] Checkpointing SlaveInfo to '/tmp/MasterAllocatorTest_1_MinAllocatableResources_fb8xnK/meta/slaves/00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S1/slave.info'
I0905 02:40:57.484953 18955 hierarchical.cpp:1726] Performed allocation for 1 agents in 190103ns
I0905 02:40:57.485007 18952 status_update_manager_process.hpp:385] Resuming operation status update manager
I0905 02:40:57.486416 18951 slave.cpp:1663] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"VjyHDvjcQAKmaTPYZKRqPg=="},"slave_id":{"value":"00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S1"},"update_oversubscribed_resources":false}
I0905 02:40:57.487260 18937 master.cpp:8459] Ignoring update on agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S1 at slave(152)@172.17.0.2:44946 (3595603fae6f) as it reports no changes
W0905 02:40:59.802559 18932 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:44946
I0905 02:40:59.804361 18932 containerizer.cpp:318] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0905 02:40:59.805143 18932 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0905 02:40:59.805184 18932 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0905 02:40:59.805371 18932 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0905 02:40:59.805426 18932 provisioner.cpp:300] Using default backend 'copy'
I0905 02:40:59.808742 18932 cluster.cpp:518] Creating default 'local' authorizer
I0905 02:40:59.812063 18943 slave.cpp:267] Mesos agent started on (153)@172.17.0.2:44946
I0905 02:40:59.812108 18943 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/OIpBqD/qjru31/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/OIpBqD/qjru31/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --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/OIpBqD/qjru31/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/OIpBqD/qjru31/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/OIpBqD/qjru31/frameworks" --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/OIpBqD/qjru31/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.10.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --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" --resources="cpus:0.5;mem:200;disk:10;ports:[11-15]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MasterAllocatorTest_1_MinAllocatableResources_nEnw2m" --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/MasterAllocatorTest_1_MinAllocatableResources_YmFz1H" --zk_session_timeout="10secs"
I0905 02:40:59.812762 18943 credentials.hpp:86] Loading credential for authentication from '/tmp/OIpBqD/qjru31/credential'
I0905 02:40:59.813000 18943 slave.cpp:300] Agent using credential for: test-principal
I0905 02:40:59.813035 18943 credentials.hpp:37] Loading credentials for authentication from '/tmp/OIpBqD/qjru31/http_credentials'
I0905 02:40:59.813329 18943 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0905 02:40:59.813907 18943 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0905 02:40:59.815641 18943 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":0.5},"type":"SCALAR"},{"name":"mem","scalar":{"value":200.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":10.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":11,"end":15}]},"type":"RANGES"}]
I0905 02:40:59.815912 18943 slave.cpp:623] Agent attributes: [ ]
I0905 02:40:59.815932 18943 slave.cpp:632] Agent hostname: 3595603fae6f
I0905 02:40:59.816210 18942 task_status_update_manager.cpp:181] Pausing sending task status updates
I0905 02:40:59.816198 18949 status_update_manager_process.hpp:379] Pausing operation status update manager
I0905 02:40:59.818563 18955 state.cpp:67] Recovering state from '/tmp/MasterAllocatorTest_1_MinAllocatableResources_YmFz1H/meta'
I0905 02:40:59.818945 18952 slave.cpp:7491] Finished recovering checkpointed state from '/tmp/MasterAllocatorTest_1_MinAllocatableResources_YmFz1H/meta', beginning agent recovery
I0905 02:40:59.820067 18938 task_status_update_manager.cpp:207] Recovering task status update manager
I0905 02:40:59.821138 18946 containerizer.cpp:821] Recovering Mesos containers
I0905 02:40:59.821797 18946 containerizer.cpp:1161] Recovering isolators
I0905 02:40:59.823187 18950 containerizer.cpp:1200] Recovering provisioner
I0905 02:40:59.824371 18942 provisioner.cpp:500] Provisioner recovery complete
I0905 02:40:59.825552 18933 composing.cpp:339] Finished recovering all containerizers
I0905 02:40:59.826010 18953 slave.cpp:7972] Recovering executors
I0905 02:40:59.826186 18953 slave.cpp:8125] Finished recovery
I0905 02:40:59.827571 18937 task_status_update_manager.cpp:181] Pausing sending task status updates
I0905 02:40:59.827630 18939 status_update_manager_process.hpp:379] Pausing operation status update manager
I0905 02:40:59.827677 18953 slave.cpp:1351] New master detected at master@172.17.0.2:44946
I0905 02:40:59.827949 18953 slave.cpp:1416] Detecting new master
I0905 02:40:59.829310 18940 slave.cpp:1443] Authenticating with master master@172.17.0.2:44946
I0905 02:40:59.829437 18940 slave.cpp:1452] Using default CRAM-MD5 authenticatee
I0905 02:40:59.829829 18944 authenticatee.cpp:121] Creating new client SASL connection
I0905 02:40:59.830255 18936 master.cpp:10573] Authenticating slave(153)@172.17.0.2:44946
I0905 02:40:59.830428 18950 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(334)@172.17.0.2:44946
I0905 02:40:59.830863 18956 authenticator.cpp:98] Creating new server SASL connection
I0905 02:40:59.831215 18948 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0905 02:40:59.831256 18948 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0905 02:40:59.831419 18943 authenticator.cpp:204] Received SASL authentication start
I0905 02:40:59.831542 18943 authenticator.cpp:326] Authentication requires more steps
I0905 02:40:59.831708 18949 authenticatee.cpp:259] Received SASL authentication step
I0905 02:40:59.831950 18942 authenticator.cpp:232] Received SASL authentication step
I0905 02:40:59.832026 18942 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3595603fae6f' server FQDN: '3595603fae6f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0905 02:40:59.832059 18942 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0905 02:40:59.832130 18942 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0905 02:40:59.832181 18942 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3595603fae6f' server FQDN: '3595603fae6f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0905 02:40:59.832206 18942 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0905 02:40:59.832219 18942 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0905 02:40:59.832252 18942 authenticator.cpp:318] Authentication success
I0905 02:40:59.832432 18947 authenticatee.cpp:299] Authentication success
I0905 02:40:59.832595 18954 master.cpp:10605] Successfully authenticated principal 'test-principal' at slave(153)@172.17.0.2:44946
I0905 02:40:59.832737 18955 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(334)@172.17.0.2:44946
I0905 02:40:59.833148 18938 slave.cpp:1543] Successfully authenticated with master master@172.17.0.2:44946
I0905 02:40:59.833770 18938 slave.cpp:1993] Will retry registration in 5.032292ms if necessary
I0905 02:40:59.834079 18951 master.cpp:7066] Received register agent message from slave(153)@172.17.0.2:44946 (3595603fae6f)
I0905 02:40:59.834600 18951 master.cpp:4191] Authorizing agent providing resources 'cpus:0.5; mem:200; disk:10; ports:[11-15]' with principal 'test-principal'
I0905 02:40:59.835652 18939 master.cpp:7133] Authorized registration of agent at slave(153)@172.17.0.2:44946 (3595603fae6f)
I0905 02:40:59.835790 18939 master.cpp:7245] Registering agent at slave(153)@172.17.0.2:44946 (3595603fae6f) with id 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S2
I0905 02:40:59.836697 18953 registrar.cpp:487] Applied 1 operations in 336920ns; attempting to update the registry
I0905 02:40:59.837618 18953 registrar.cpp:544] Successfully updated the registry in 0ns
I0905 02:40:59.837970 18939 master.cpp:7293] Admitted agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S2 at slave(153)@172.17.0.2:44946 (3595603fae6f)
I0905 02:40:59.838887 18939 master.cpp:7338] Registered agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S2 at slave(153)@172.17.0.2:44946 (3595603fae6f) with cpus:0.5; mem:200; disk:10; ports:[11-15]
I0905 02:40:59.839061 18956 slave.cpp:1576] Registered with master master@172.17.0.2:44946; given agent ID 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S2
I0905 02:40:59.839061 18948 hierarchical.cpp:854] Added agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S2 (3595603fae6f) with cpus:0.5; mem:200; disk:10; ports:[11-15] (offered or allocated: {})
I0905 02:40:59.839210 18949 task_status_update_manager.cpp:188] Resuming sending task status updates
I0905 02:40:59.839593 18948 hierarchical.cpp:1726] Performed allocation for 1 agents in 265084ns
I0905 02:40:59.839684 18956 slave.cpp:1611] Checkpointing SlaveInfo to '/tmp/MasterAllocatorTest_1_MinAllocatableResources_YmFz1H/meta/slaves/00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S2/slave.info'
I0905 02:40:59.839790 18942 status_update_manager_process.hpp:385] Resuming operation status update manager
I0905 02:40:59.841272 18956 slave.cpp:1663] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"3s/Q4oLhSnuSw2fS6StAkw=="},"slave_id":{"value":"00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S2"},"update_oversubscribed_resources":false}
I0905 02:40:59.842178 18955 master.cpp:8459] Ignoring update on agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S2 at slave(153)@172.17.0.2:44946 (3595603fae6f) as it reports no changes
W0905 02:41:01.549103 18932 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:44946
I0905 02:41:01.550681 18932 containerizer.cpp:318] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0905 02:41:01.551333 18932 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0905 02:41:01.551365 18932 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0905 02:41:01.551542 18932 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0905 02:41:01.551589 18932 provisioner.cpp:300] Using default backend 'copy'
I0905 02:41:01.554250 18932 cluster.cpp:518] Creating default 'local' authorizer
I0905 02:41:01.556852 18941 slave.cpp:267] Mesos agent started on (154)@172.17.0.2:44946
I0905 02:41:01.556880 18941 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/OIpBqD/C75cjx/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/OIpBqD/C75cjx/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --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/OIpBqD/C75cjx/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/OIpBqD/C75cjx/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/OIpBqD/C75cjx/frameworks" --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/OIpBqD/C75cjx/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.10.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --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" --resources="cpus:0.5;mem:10;disk:50;ports:[16-20]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MasterAllocatorTest_1_MinAllocatableResources_DRBShO" --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/MasterAllocatorTest_1_MinAllocatableResources_6r0yg5" --zk_session_timeout="10secs"
I0905 02:41:01.557415 18941 credentials.hpp:86] Loading credential for authentication from '/tmp/OIpBqD/C75cjx/credential'
I0905 02:41:01.557641 18941 slave.cpp:300] Agent using credential for: test-principal
I0905 02:41:01.557667 18941 credentials.hpp:37] Loading credentials for authentication from '/tmp/OIpBqD/C75cjx/http_credentials'
I0905 02:41:01.557929 18941 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0905 02:41:01.558516 18941 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0905 02:41:01.559985 18941 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":0.5},"type":"SCALAR"},{"name":"mem","scalar":{"value":10.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":50.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":16,"end":20}]},"type":"RANGES"}]
I0905 02:41:01.560211 18941 slave.cpp:623] Agent attributes: [ ]
I0905 02:41:01.560236 18941 slave.cpp:632] Agent hostname: 3595603fae6f
I0905 02:41:01.560420 18936 task_status_update_manager.cpp:181] Pausing sending task status updates
I0905 02:41:01.560470 18950 status_update_manager_process.hpp:379] Pausing operation status update manager
I0905 02:41:01.562454 18948 state.cpp:67] Recovering state from '/tmp/MasterAllocatorTest_1_MinAllocatableResources_6r0yg5/meta'
I0905 02:41:01.562716 18942 slave.cpp:7491] Finished recovering checkpointed state from '/tmp/MasterAllocatorTest_1_MinAllocatableResources_6r0yg5/meta', beginning agent recovery
I0905 02:41:01.563406 18934 task_status_update_manager.cpp:207] Recovering task status update manager
I0905 02:41:01.563948 18947 containerizer.cpp:821] Recovering Mesos containers
I0905 02:41:01.564391 18947 containerizer.cpp:1161] Recovering isolators
I0905 02:41:01.565512 18954 containerizer.cpp:1200] Recovering provisioner
I0905 02:41:01.566310 18943 provisioner.cpp:500] Provisioner recovery complete
I0905 02:41:01.567155 18934 composing.cpp:339] Finished recovering all containerizers
I0905 02:41:01.567499 18933 slave.cpp:7972] Recovering executors
I0905 02:41:01.567625 18933 slave.cpp:8125] Finished recovery
I0905 02:41:01.568634 18955 task_status_update_manager.cpp:181] Pausing sending task status updates
I0905 02:41:01.568768 18946 status_update_manager_process.hpp:379] Pausing operation status update manager
I0905 02:41:01.568773 18944 slave.cpp:1351] New master detected at master@172.17.0.2:44946
I0905 02:41:01.569002 18944 slave.cpp:1416] Detecting new master
I0905 02:41:01.570367 18935 slave.cpp:1443] Authenticating with master master@172.17.0.2:44946
I0905 02:41:01.570508 18935 slave.cpp:1452] Using default CRAM-MD5 authenticatee
I0905 02:41:01.570991 18947 authenticatee.cpp:121] Creating new client SASL connection
I0905 02:41:01.571532 18953 master.cpp:10573] Authenticating slave(154)@172.17.0.2:44946
I0905 02:41:01.571704 18954 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(335)@172.17.0.2:44946
I0905 02:41:01.572072 18950 authenticator.cpp:98] Creating new server SASL connection
I0905 02:41:01.572373 18949 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0905 02:41:01.572408 18949 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0905 02:41:01.572553 18939 authenticator.cpp:204] Received SASL authentication start
I0905 02:41:01.572629 18939 authenticator.cpp:326] Authentication requires more steps
I0905 02:41:01.572759 18948 authenticatee.cpp:259] Received SASL authentication step
I0905 02:41:01.572896 18948 authenticator.cpp:232] Received SASL authentication step
I0905 02:41:01.572929 18948 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3595603fae6f' server FQDN: '3595603fae6f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0905 02:41:01.572945 18948 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0905 02:41:01.572993 18948 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0905 02:41:01.573022 18948 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3595603fae6f' server FQDN: '3595603fae6f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0905 02:41:01.573036 18948 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0905 02:41:01.573046 18948 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0905 02:41:01.573065 18948 authenticator.cpp:318] Authentication success
I0905 02:41:01.573185 18952 authenticatee.cpp:299] Authentication success
I0905 02:41:01.573269 18942 master.cpp:10605] Successfully authenticated principal 'test-principal' at slave(154)@172.17.0.2:44946
I0905 02:41:01.573319 18945 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(335)@172.17.0.2:44946
I0905 02:41:01.575740 18948 slave.cpp:1543] Successfully authenticated with master master@172.17.0.2:44946
I0905 02:41:01.576151 18948 slave.cpp:1993] Will retry registration in 13.812885ms if necessary
I0905 02:41:01.576362 18937 master.cpp:7066] Received register agent message from slave(154)@172.17.0.2:44946 (3595603fae6f)
I0905 02:41:01.576665 18937 master.cpp:4191] Authorizing agent providing resources 'cpus:0.5; mem:10; disk:50; ports:[16-20]' with principal 'test-principal'
I0905 02:41:01.577615 18951 master.cpp:7133] Authorized registration of agent at slave(154)@172.17.0.2:44946 (3595603fae6f)
I0905 02:41:01.577811 18951 master.cpp:7245] Registering agent at slave(154)@172.17.0.2:44946 (3595603fae6f) with id 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S3
I0905 02:41:01.578824 18935 registrar.cpp:487] Applied 1 operations in 376840ns; attempting to update the registry
I0905 02:41:01.579936 18935 registrar.cpp:544] Successfully updated the registry in 0ns
I0905 02:41:01.580138 18949 master.cpp:7293] Admitted agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S3 at slave(154)@172.17.0.2:44946 (3595603fae6f)
I0905 02:41:01.580983 18949 master.cpp:7338] Registered agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S3 at slave(154)@172.17.0.2:44946 (3595603fae6f) with cpus:0.5; mem:10; disk:50; ports:[16-20]
I0905 02:41:01.581126 18941 slave.cpp:1576] Registered with master master@172.17.0.2:44946; given agent ID 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S3
I0905 02:41:01.581122 18943 hierarchical.cpp:854] Added agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S3 (3595603fae6f) with cpus:0.5; mem:10; disk:50; ports:[16-20] (offered or allocated: {})
I0905 02:41:01.581460 18940 task_status_update_manager.cpp:188] Resuming sending task status updates
I0905 02:41:01.581488 18943 hierarchical.cpp:1726] Performed allocation for 1 agents in 172929ns
I0905 02:41:01.581606 18941 slave.cpp:1611] Checkpointing SlaveInfo to '/tmp/MasterAllocatorTest_1_MinAllocatableResources_6r0yg5/meta/slaves/00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S3/slave.info'
I0905 02:41:01.581688 18956 status_update_manager_process.hpp:385] Resuming operation status update manager
I0905 02:41:01.582855 18941 slave.cpp:1663] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"CTPkS8TtQV6UdPb3tQkS+g=="},"slave_id":{"value":"00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S3"},"update_oversubscribed_resources":false}
I0905 02:41:01.583534 18948 master.cpp:8459] Ignoring update on agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S3 at slave(154)@172.17.0.2:44946 (3595603fae6f) as it reports no changes
W0905 02:41:04.012708 18932 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:44946
I0905 02:41:04.015535 18932 containerizer.cpp:318] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0905 02:41:04.016549 18932 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0905 02:41:04.016607 18932 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0905 02:41:04.016866 18932 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0905 02:41:04.016963 18932 provisioner.cpp:300] Using default backend 'copy'
I0905 02:41:04.020783 18932 cluster.cpp:518] Creating default 'local' authorizer
I0905 02:41:04.024608 18936 slave.cpp:267] Mesos agent started on (155)@172.17.0.2:44946
I0905 02:41:04.024688 18936 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/OIpBqD/x4nstr/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/OIpBqD/x4nstr/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --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/OIpBqD/x4nstr/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/OIpBqD/x4nstr/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/OIpBqD/x4nstr/frameworks" --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/OIpBqD/x4nstr/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.10.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --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" --resources="cpus:1;mem:100;disk:0;ports:[1-5]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MasterAllocatorTest_1_MinAllocatableResources_05ThOC" --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/MasterAllocatorTest_1_MinAllocatableResources_yEK88N" --zk_session_timeout="10secs"
I0905 02:41:04.025588 18936 credentials.hpp:86] Loading credential for authentication from '/tmp/OIpBqD/x4nstr/credential'
I0905 02:41:04.026062 18936 slave.cpp:300] Agent using credential for: test-principal
I0905 02:41:04.026108 18936 credentials.hpp:37] Loading credentials for authentication from '/tmp/OIpBqD/x4nstr/http_credentials'
I0905 02:41:04.026547 18936 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0905 02:41:04.027400 18936 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0905 02:41:04.029377 18936 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":100.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":1,"end":5}]},"type":"RANGES"}]
I0905 02:41:04.029860 18936 slave.cpp:623] Agent attributes: [ ]
I0905 02:41:04.029894 18936 slave.cpp:632] Agent hostname: 3595603fae6f
I0905 02:41:04.030182 18939 status_update_manager_process.hpp:379] Pausing operation status update manager
I0905 02:41:04.030236 18935 task_status_update_manager.cpp:181] Pausing sending task status updates
I0905 02:41:04.033041 18943 state.cpp:67] Recovering state from '/tmp/MasterAllocatorTest_1_MinAllocatableResources_yEK88N/meta'
I0905 02:41:04.033465 18956 slave.cpp:7491] Finished recovering checkpointed state from '/tmp/MasterAllocatorTest_1_MinAllocatableResources_yEK88N/meta', beginning agent recovery
I0905 02:41:04.034518 18938 task_status_update_manager.cpp:207] Recovering task status update manager
I0905 02:41:04.035245 18941 containerizer.cpp:821] Recovering Mesos containers
I0905 02:41:04.035904 18941 containerizer.cpp:1161] Recovering isolators
I0905 02:41:04.037513 18950 containerizer.cpp:1200] Recovering provisioner
I0905 02:41:04.038611 18949 provisioner.cpp:500] Provisioner recovery complete
I0905 02:41:04.039832 18943 composing.cpp:339] Finished recovering all containerizers
I0905 02:41:04.040347 18948 slave.cpp:7972] Recovering executors
I0905 02:41:04.040549 18948 slave.cpp:8125] Finished recovery
I0905 02:41:04.041822 18934 task_status_update_manager.cpp:181] Pausing sending task status updates
I0905 02:41:04.041874 18955 status_update_manager_process.hpp:379] Pausing operation status update manager
I0905 02:41:04.041929 18947 slave.cpp:1351] New master detected at master@172.17.0.2:44946
I0905 02:41:04.042181 18947 slave.cpp:1416] Detecting new master
I0905 02:41:04.043635 18946 slave.cpp:1443] Authenticating with master master@172.17.0.2:44946
I0905 02:41:04.043772 18946 slave.cpp:1452] Using default CRAM-MD5 authenticatee
I0905 02:41:04.044188 18941 authenticatee.cpp:121] Creating new client SASL connection
I0905 02:41:04.044765 18935 master.cpp:10573] Authenticating slave(155)@172.17.0.2:44946
I0905 02:41:04.044955 18950 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(336)@172.17.0.2:44946
I0905 02:41:04.045351 18951 authenticator.cpp:98] Creating new server SASL connection
I0905 02:41:04.045720 18940 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0905 02:41:04.045776 18940 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0905 02:41:04.045967 18949 authenticator.cpp:204] Received SASL authentication start
I0905 02:41:04.046058 18949 authenticator.cpp:326] Authentication requires more steps
I0905 02:41:04.046257 18942 authenticatee.cpp:259] Received SASL authentication step
I0905 02:41:04.046501 18956 authenticator.cpp:232] Received SASL authentication step
I0905 02:41:04.046553 18956 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3595603fae6f' server FQDN: '3595603fae6f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0905 02:41:04.046577 18956 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0905 02:41:04.046638 18956 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0905 02:41:04.046670 18956 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3595603fae6f' server FQDN: '3595603fae6f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0905 02:41:04.046686 18956 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0905 02:41:04.046700 18956 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0905 02:41:04.046722 18956 authenticator.cpp:318] Authentication success
I0905 02:41:04.046876 18945 authenticatee.cpp:299] Authentication success
I0905 02:41:04.047044 18938 master.cpp:10605] Successfully authenticated principal 'test-principal' at slave(155)@172.17.0.2:44946
I0905 02:41:04.047358 18952 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(336)@172.17.0.2:44946
I0905 02:41:04.047449 18936 slave.cpp:1543] Successfully authenticated with master master@172.17.0.2:44946
I0905 02:41:04.048310 18936 slave.cpp:1993] Will retry registration in 11.728812ms if necessary
I0905 02:41:04.048542 18953 master.cpp:7066] Received register agent message from slave(155)@172.17.0.2:44946 (3595603fae6f)
I0905 02:41:04.049090 18953 master.cpp:4191] Authorizing agent providing resources 'cpus:1; mem:100; ports:[1-5]' with principal 'test-principal'
I0905 02:41:04.050436 18954 master.cpp:7133] Authorized registration of agent at slave(155)@172.17.0.2:44946 (3595603fae6f)
I0905 02:41:04.050624 18954 master.cpp:7245] Registering agent at slave(155)@172.17.0.2:44946 (3595603fae6f) with id 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S4
I0905 02:41:04.051966 18939 registrar.cpp:487] Applied 1 operations in 529569ns; attempting to update the registry
I0905 02:41:04.053304 18939 registrar.cpp:544] Successfully updated the registry in 0ns
I0905 02:41:04.053573 18951 master.cpp:7293] Admitted agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S4 at slave(155)@172.17.0.2:44946 (3595603fae6f)
I0905 02:41:04.054721 18951 master.cpp:7338] Registered agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S4 at slave(155)@172.17.0.2:44946 (3595603fae6f) with cpus:1; mem:100; ports:[1-5]
I0905 02:41:04.054854 18949 slave.cpp:1576] Registered with master master@172.17.0.2:44946; given agent ID 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S4
I0905 02:41:04.054916 18942 hierarchical.cpp:854] Added agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S4 (3595603fae6f) with cpus:1; mem:100; ports:[1-5] (offered or allocated: {})
I0905 02:41:04.055009 18956 task_status_update_manager.cpp:188] Resuming sending task status updates
I0905 02:41:04.055449 18942 hierarchical.cpp:1726] Performed allocation for 1 agents in 260045ns
I0905 02:41:04.055485 18949 slave.cpp:1611] Checkpointing SlaveInfo to '/tmp/MasterAllocatorTest_1_MinAllocatableResources_yEK88N/meta/slaves/00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S4/slave.info'
I0905 02:41:04.055575 18945 status_update_manager_process.hpp:385] Resuming operation status update manager
I0905 02:41:04.057032 18949 slave.cpp:1663] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"r8/PEmqmQE+GHCC6EOlBvA=="},"slave_id":{"value":"00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S4"},"update_oversubscribed_resources":false}
I0905 02:41:04.058269 18934 master.cpp:8459] Ignoring update on agent 00ffc8b6-bc75-4e8f-bc13-31a62a85f125-S4 at slave(155)@172.17.0.2:44946 (3595603fae6f) as it reports no changes
Build timed out (after 240 minutes). Marking the build as failed.
W0905 02:41:05.862651 18932 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:44946
I0905 02:41:05.865223 18932 containerizer.cpp:318] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0905 02:41:05.866355 18932 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0905 02:41:05.866410 18932 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0905 02:41:05.866649 18932 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0905 02:41:05.866722 18932 provisioner.cpp:300] Using default backend 'copy'
I0905 02:41:05.871124 18932 cluster.cpp:518] Creating default 'local' authorizer
Build was aborted
Jenkins build is back to normal : Mesos-Reviewbot-Linux #3507
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot-Linux/3507/display/redirect?page=changes>