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 2017/11/23 08:17:53 UTC
Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4494
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4494/display/redirect>
------------------------------------------
[...truncated 31.53 MB...]
3: I1123 08:17:40.990464 26954 slave.cpp:3594] Updated checkpointed resources from disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_rABoak/disk1,id1:path1]<SHARED>:2048<1>; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_rABoak/disk2,id2:path2]<SHARED>:2048<1> to {}
3: I1123 08:17:40.990635 26954 slave.cpp:3270] Asked to shut down framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0000 by master@172.17.0.2:36060
3: I1123 08:17:40.990677 26954 slave.cpp:3295] Shutting down framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0000
3: I1123 08:17:40.990725 26954 slave.cpp:5923] Shutting down executor 'c04964f2-df3b-4277-bc39-5245faee9f1e' of framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0000
3: W1123 08:17:40.990746 26954 slave.hpp:786] Unable to send event to executor 'c04964f2-df3b-4277-bc39-5245faee9f1e' of framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0000: unknown connection type
3: I1123 08:17:40.990885 26954 slave.cpp:3270] Asked to shut down framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0001 by master@172.17.0.2:36060
3: I1123 08:17:40.990916 26954 slave.cpp:3285] Cannot shut down unknown framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0001
3: I1123 08:17:40.995671 26937 hierarchical.cpp:856] Updated allocation of framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0001 on agent 7bd27e34-da9e-48b3-9967-b514eff8f259-S0 from cpus(allocated: default-role):1; mem(allocated: default-role):1920; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_rABoak/disk1,id1:path1]<SHARED>:2048<1>; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_rABoak/disk2,id2:path2]<SHARED>:2048<1> to cpus(allocated: default-role):1; mem(allocated: default-role):1920; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_rABoak/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_rABoak/disk2]:2048
3: I1123 08:17:40.997436 26937 hierarchical.cpp:1132] Recovered cpus(allocated: default-role):1; mem(allocated: default-role):1920; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_rABoak/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_rABoak/disk2]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_rABoak/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_rABoak/disk2]:2048, allocated: {}) on agent 7bd27e34-da9e-48b3-9967-b514eff8f259-S0 from framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0001
3: I1123 08:17:40.997638 26937 hierarchical.cpp:419] Deactivated framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0000
3: I1123 08:17:40.997797 26937 hierarchical.cpp:358] Removed framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0000
3: I1123 08:17:40.997889 26937 hierarchical.cpp:419] Deactivated framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0001
3: I1123 08:17:40.998174 26937 hierarchical.cpp:358] Removed framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0001
3: I1123 08:17:41.074843 26940 containerizer.cpp:2773] Container 2bde6325-f931-40dc-813b-61e35b8f61e0 has exited
3: I1123 08:17:41.077930 26937 provisioner.cpp:557] Ignoring destroy request for unknown container 2bde6325-f931-40dc-813b-61e35b8f61e0
3: I1123 08:17:41.078908 26939 slave.cpp:5588] Executor 'c04964f2-df3b-4277-bc39-5245faee9f1e' of framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0000 terminated with signal Killed
3: I1123 08:17:41.078966 26939 slave.cpp:5692] Cleaning up executor 'c04964f2-df3b-4277-bc39-5245faee9f1e' of framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0000
3: I1123 08:17:41.079342 26945 gc.cpp:90] Scheduling '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_E12ojt/slaves/7bd27e34-da9e-48b3-9967-b514eff8f259-S0/frameworks/7bd27e34-da9e-48b3-9967-b514eff8f259-0000/executors/c04964f2-df3b-4277-bc39-5245faee9f1e/runs/2bde6325-f931-40dc-813b-61e35b8f61e0' for gc 6.99999908336889days in the future
3: I1123 08:17:41.079668 26939 slave.cpp:5799] Cleaning up framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0000
3: I1123 08:17:41.079679 26946 gc.cpp:90] Scheduling '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_E12ojt/slaves/7bd27e34-da9e-48b3-9967-b514eff8f259-S0/frameworks/7bd27e34-da9e-48b3-9967-b514eff8f259-0000/executors/c04964f2-df3b-4277-bc39-5245faee9f1e' for gc 6.99999907967704days in the future
3: I1123 08:17:41.079826 26936 task_status_update_manager.cpp:289] Closing task status update streams for framework 7bd27e34-da9e-48b3-9967-b514eff8f259-0000
3: I1123 08:17:41.080029 26941 gc.cpp:90] Scheduling '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_2_E12ojt/slaves/7bd27e34-da9e-48b3-9967-b514eff8f259-S0/frameworks/7bd27e34-da9e-48b3-9967-b514eff8f259-0000' for gc 6.99999907557926days in the future
3: I1123 08:17:41.080284 26949 slave.cpp:883] Agent terminating
3: I1123 08:17:41.080557 26954 master.cpp:1311] Agent 7bd27e34-da9e-48b3-9967-b514eff8f259-S0 at slave(863)@172.17.0.2:36060 (d0a244847e88) disconnected
3: I1123 08:17:41.080593 26954 master.cpp:3370] Disconnecting agent 7bd27e34-da9e-48b3-9967-b514eff8f259-S0 at slave(863)@172.17.0.2:36060 (d0a244847e88)
3: I1123 08:17:41.080673 26954 master.cpp:3389] Deactivating agent 7bd27e34-da9e-48b3-9967-b514eff8f259-S0 at slave(863)@172.17.0.2:36060 (d0a244847e88)
3: I1123 08:17:41.080857 26937 hierarchical.cpp:697] Agent 7bd27e34-da9e-48b3-9967-b514eff8f259-S0 deactivated
3: I1123 08:17:41.091192 18294 master.cpp:1153] Master terminating
3: I1123 08:17:41.093129 26939 hierarchical.cpp:633] Removed agent 7bd27e34-da9e-48b3-9967-b514eff8f259-S0
3: [ OK ] DiskResource/PersistentVolumeTest.SharedPersistentVolumeRescindOnDestroy/2 (247 ms)
3: [ RUN ] DiskResource/PersistentVolumeTest.SharedPersistentVolumeRescindOnDestroy/3
3: I1123 08:17:41.103196 18294 cluster.cpp:162] Creating default 'local' authorizer
3: I1123 08:17:41.107646 26937 master.cpp:448] Master d69481e2-58e3-4a24-99d1-ea6daefdc65d (d0a244847e88) started on 172.17.0.2:36060
3: I1123 08:17:41.107673 26937 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/MHQFbP/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" --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" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/MHQFbP/master" --zk_session_timeout="10secs"
3: I1123 08:17:41.108042 26937 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1123 08:17:41.108055 26937 master.cpp:505] Master only allowing authenticated agents to register
3: I1123 08:17:41.108062 26937 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1123 08:17:41.108067 26937 credentials.hpp:37] Loading credentials for authentication from '/tmp/MHQFbP/credentials'
3: I1123 08:17:41.108423 26937 master.cpp:555] Using default 'crammd5' authenticator
3: I1123 08:17:41.108615 26937 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1123 08:17:41.108844 26937 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1123 08:17:41.109035 26937 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1123 08:17:41.109213 26937 master.cpp:634] Authorization enabled
3: I1123 08:17:41.109411 26933 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1123 08:17:41.109489 26952 whitelist_watcher.cpp:77] No whitelist given
3: I1123 08:17:41.112992 26936 master.cpp:2215] Elected as the leading master!
3: I1123 08:17:41.113024 26936 master.cpp:1695] Recovering from registrar
3: I1123 08:17:41.113194 26941 registrar.cpp:347] Recovering registrar
3: I1123 08:17:41.113894 26941 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1123 08:17:41.114007 26941 registrar.cpp:495] Applied 1 operations in 32406ns; attempting to update the registry
3: I1123 08:17:41.114652 26941 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1123 08:17:41.114807 26941 registrar.cpp:424] Successfully recovered registrar
3: I1123 08:17:41.115231 26940 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1123 08:17:41.115265 26931 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1123 08:17:41.121618 18294 process.cpp:2756] Attempted to spawn already running process files@172.17.0.2:36060
3: I1123 08:17:41.122611 18294 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1123 08:17:41.123158 18294 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1123 08:17:41.123291 18294 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1123 08:17:41.123324 18294 provisioner.cpp:259] Using default backend 'copy'
3: I1123 08:17:41.125432 18294 cluster.cpp:448] Creating default 'local' authorizer
3: I1123 08:17:41.127908 26931 slave.cpp:262] Mesos agent started on (864)@172.17.0.2:36060
3: I1123 08:17:41.127931 26931 slave.cpp:263] Flags at startup: --acls="" --agent_features="capabilities {
3: type: MULTI_ROLE
3: }
3: capabilities {
3: type: HIERARCHICAL_ROLE
3: }
3: capabilities {
3: type: RESERVATION_REFINEMENT
3: }
3: capabilities {
3: type: RESOURCE_PROVIDER
3: }
3: " --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_lhv8ii/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_lhv8ii/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/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_lhv8ii/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_secret_key="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_lhv8ii/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_lhv8ii/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_lhv8ii/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY\/disk1"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY\/disk2"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_lhv8ii" --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/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8" --zk_session_timeout="10secs"
3: I1123 08:17:41.128422 26931 credentials.hpp:86] Loading credential for authentication from '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_lhv8ii/credential'
3: I1123 08:17:41.128582 26931 slave.cpp:295] Agent using credential for: test-principal
3: I1123 08:17:41.128602 26931 credentials.hpp:37] Loading credentials for authentication from '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_lhv8ii/http_credentials'
3: I1123 08:17:41.128878 26931 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1123 08:17:41.129014 26931 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1123 08:17:41.129261 26931 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1123 08:17:41.129375 26931 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1123 08:17:41.129611 26931 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1123 08:17:41.129731 26931 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1123 08:17:41.133374 26931 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY\/disk1"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY\/disk2"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1123 08:17:41.133842 26931 slave.cpp:601] Agent attributes: [ ]
3: I1123 08:17:41.133854 26931 slave.cpp:610] Agent hostname: d0a244847e88
3: I1123 08:17:41.134027 26949 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1123 08:17:41.135881 26938 state.cpp:64] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8/meta'
3: I1123 08:17:41.136157 26953 task_status_update_manager.cpp:207] Recovering task status update manager
3: I1123 08:17:41.136363 26942 containerizer.cpp:668] Recovering containerizer
3: I1123 08:17:41.137920 26947 provisioner.cpp:455] Provisioner recovery complete
3: I1123 08:17:41.138273 26949 slave.cpp:6493] Finished recovery
3: I1123 08:17:41.138981 26931 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1123 08:17:41.138986 26954 slave.cpp:1007] New master detected at master@172.17.0.2:36060
3: I1123 08:17:41.139066 26954 slave.cpp:1042] Detecting new master
3: I1123 08:17:41.139299 26954 slave.cpp:1069] Authenticating with master master@172.17.0.2:36060
3: I1123 08:17:41.139386 26954 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1123 08:17:41.139637 26941 authenticatee.cpp:121] Creating new client SASL connection
3: I1123 08:17:41.139925 26940 master.cpp:8312] Authenticating slave(864)@172.17.0.2:36060
3: I1123 08:17:41.140031 26953 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1542)@172.17.0.2:36060
3: I1123 08:17:41.140276 26935 authenticator.cpp:98] Creating new server SASL connection
3: I1123 08:17:41.140506 26945 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1123 08:17:41.140529 26945 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1123 08:17:41.140652 26952 authenticator.cpp:204] Received SASL authentication start
3: I1123 08:17:41.140718 26952 authenticator.cpp:326] Authentication requires more steps
3: I1123 08:17:41.140841 26950 authenticatee.cpp:259] Received SASL authentication step
3: I1123 08:17:41.140985 26937 authenticator.cpp:232] Received SASL authentication step
3: I1123 08:17:41.141014 26937 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd0a244847e88' server FQDN: 'd0a244847e88' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1123 08:17:41.141026 26937 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1123 08:17:41.141057 26937 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1123 08:17:41.141075 26937 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd0a244847e88' server FQDN: 'd0a244847e88' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1123 08:17:41.141083 26937 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1123 08:17:41.141088 26937 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1123 08:17:41.141103 26937 authenticator.cpp:318] Authentication success
3: I1123 08:17:41.141186 26933 authenticatee.cpp:299] Authentication success
3: I1123 08:17:41.141273 26932 master.cpp:8342] Successfully authenticated principal 'test-principal' at slave(864)@172.17.0.2:36060
3: I1123 08:17:41.141329 26933 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1542)@172.17.0.2:36060
3: I1123 08:17:41.141482 26942 slave.cpp:1161] Successfully authenticated with master master@172.17.0.2:36060
3: I1123 08:17:41.141726 26942 slave.cpp:1685] Will retry registration in 16.611488ms if necessary
3: I1123 08:17:41.141996 26947 master.cpp:6036] Received register agent message from slave(864)@172.17.0.2:36060 (d0a244847e88)
3: I1123 08:17:41.142150 26947 master.cpp:3872] Authorizing agent with principal 'test-principal'
3: I1123 08:17:41.142572 26949 master.cpp:6098] Authorized registration of agent at slave(864)@172.17.0.2:36060 (d0a244847e88)
3: I1123 08:17:41.142685 26949 master.cpp:6191] Registering agent at slave(864)@172.17.0.2:36060 (d0a244847e88) with id d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0
3: I1123 08:17:41.143213 26951 registrar.cpp:495] Applied 1 operations in 63483ns; attempting to update the registry
3: I1123 08:17:41.143749 26951 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1123 08:17:41.143942 26941 master.cpp:6240] Admitted agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 at slave(864)@172.17.0.2:36060 (d0a244847e88)
3: I1123 08:17:41.144754 26953 slave.cpp:1207] Registered with master master@172.17.0.2:36060; given agent ID d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0
3: I1123 08:17:41.144775 26941 master.cpp:6276] Registered agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 at slave(864)@172.17.0.2:36060 (d0a244847e88) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk2]:2048; ports:[31000-32000]
3: I1123 08:17:41.144851 26952 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1123 08:17:41.145036 26953 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8/meta/slaves/d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0/slave.info'
3: I1123 08:17:41.145310 26935 hierarchical.cpp:600] Added agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 (d0a244847e88) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk2]:2048; ports:[31000-32000] (allocated: {})
3: I1123 08:17:41.145468 26953 slave.cpp:1288] Forwarding total resources cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk2]:2048; ports:[31000-32000]
3: I1123 08:17:41.145572 26953 slave.cpp:1298] Forwarding total oversubscribed resources {}
3: I1123 08:17:41.145668 26935 hierarchical.cpp:1457] Performed allocation for 1 agents in 175868ns
3: I1123 08:17:41.146276 26944 master.cpp:7078] Received update of agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 at slave(864)@172.17.0.2:36060 (d0a244847e88) with total resources cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk2]:2048; ports:[31000-32000]
3: I1123 08:17:41.146379 26944 master.cpp:7091] Received update of agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 at slave(864)@172.17.0.2:36060 (d0a244847e88) with total oversubscribed resources {}
3: I1123 08:17:41.146651 26944 master.cpp:7109] Ignoring update on agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 at slave(864)@172.17.0.2:36060 (d0a244847e88) as it reports no changes
3: W1123 08:17:41.147161 18294 process.cpp:2756] Attempted to spawn already running process version@172.17.0.2:36060
3: I1123 08:17:41.148020 18294 sched.cpp:232] Version: 1.5.0
3: I1123 08:17:41.148620 26942 sched.cpp:336] New master detected at master@172.17.0.2:36060
3: I1123 08:17:41.148710 26942 sched.cpp:396] Authenticating with master master@172.17.0.2:36060
3: I1123 08:17:41.148725 26942 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1123 08:17:41.148897 26947 hierarchical.cpp:1457] Performed allocation for 1 agents in 145272ns
3: I1123 08:17:41.148959 26948 authenticatee.cpp:121] Creating new client SASL connection
3: I1123 08:17:41.149211 26931 master.cpp:8312] Authenticating scheduler-c7a14adc-7520-4d11-b6fb-541c36350441@172.17.0.2:36060
3: I1123 08:17:41.149317 26939 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1543)@172.17.0.2:36060
3: I1123 08:17:41.149528 26938 authenticator.cpp:98] Creating new server SASL connection
3: I1123 08:17:41.149714 26954 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1123 08:17:41.149734 26954 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1123 08:17:41.149838 26951 authenticator.cpp:204] Received SASL authentication start
3: I1123 08:17:41.149889 26951 authenticator.cpp:326] Authentication requires more steps
3: I1123 08:17:41.150002 26940 authenticatee.cpp:259] Received SASL authentication step
3: I1123 08:17:41.150113 26945 authenticator.cpp:232] Received SASL authentication step
3: I1123 08:17:41.150148 26945 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd0a244847e88' server FQDN: 'd0a244847e88' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1123 08:17:41.150161 26945 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1123 08:17:41.150184 26945 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1123 08:17:41.150202 26945 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd0a244847e88' server FQDN: 'd0a244847e88' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1123 08:17:41.150216 26945 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1123 08:17:41.150228 26945 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1123 08:17:41.150240 26945 authenticator.cpp:318] Authentication success
3: I1123 08:17:41.150323 26952 authenticatee.cpp:299] Authentication success
3: I1123 08:17:41.150374 26941 master.cpp:8342] Successfully authenticated principal 'test-principal' at scheduler-c7a14adc-7520-4d11-b6fb-541c36350441@172.17.0.2:36060
3: I1123 08:17:41.150419 26950 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1543)@172.17.0.2:36060
3: I1123 08:17:41.150584 26953 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:36060
3: I1123 08:17:41.150602 26953 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:36060
3: I1123 08:17:41.150707 26953 sched.cpp:857] Will retry registration in 1.696350764secs if necessary
3: I1123 08:17:41.150879 26934 master.cpp:2963] Received SUBSCRIBE call for framework 'default' at scheduler-c7a14adc-7520-4d11-b6fb-541c36350441@172.17.0.2:36060
3: I1123 08:17:41.150957 26934 master.cpp:2280] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1123 08:17:41.151365 26936 master.cpp:3043] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT, SHARED_RESOURCES ]
3: I1123 08:17:41.152007 26947 sched.cpp:751] Framework registered with d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000
3: I1123 08:17:41.152047 26947 sched.cpp:765] Scheduler::registered took 19889ns
3: I1123 08:17:41.152149 26943 hierarchical.cpp:306] Added framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000
3: I1123 08:17:41.153762 26943 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.495669ms
3: I1123 08:17:41.154492 26949 master.cpp:8142] Sending 1 offers to framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000 (default) at scheduler-c7a14adc-7520-4d11-b6fb-541c36350441@172.17.0.2:36060
3: I1123 08:17:41.155017 26931 sched.cpp:921] Scheduler::resourceOffers took 99621ns
3: I1123 08:17:41.158841 26938 master.cpp:10063] Removing offer d69481e2-58e3-4a24-99d1-ea6daefdc65d-O0
3: I1123 08:17:41.159191 26938 master.cpp:4230] Processing ACCEPT call for offers: [ d69481e2-58e3-4a24-99d1-ea6daefdc65d-O0 ] on agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 at slave(864)@172.17.0.2:36060 (d0a244847e88) for framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000 (default) at scheduler-c7a14adc-7520-4d11-b6fb-541c36350441@172.17.0.2:36060
3: I1123 08:17:41.159340 26938 master.cpp:3792] Authorizing principal 'test-principal' to create volumes '[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id2","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY\/disk2"},"type":"PATH"},"volume":{"container_path":"path2","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]'
3: I1123 08:17:41.160018 26938 master.cpp:3599] Authorizing framework principal 'test-principal' to launch task 337a244c-6f50-4509-9168-cbd3c287fd08
3: I1123 08:17:41.162003 26941 master.cpp:4706] Applying CREATE operation for volumes [{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id2","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY\/disk2"},"type":"PATH"},"volume":{"container_path":"path2","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}] from framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000 (default) at scheduler-c7a14adc-7520-4d11-b6fb-541c36350441@172.17.0.2:36060 to agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 at slave(864)@172.17.0.2:36060 (d0a244847e88)
3: I1123 08:17:41.163398 26941 master.cpp:9945] Sending offer operation '' (uuid: ae62ea8a-6484-4297-bb1e-aff2bce9dc01) to agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 at slave(864)@172.17.0.2:36060 (d0a244847e88)
3: I1123 08:17:41.164685 26941 master.cpp:10814] Adding task 337a244c-6f50-4509-9168-cbd3c287fd08 with resources cpus(allocated: default-role):1; mem(allocated: default-role):128 on agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 at slave(864)@172.17.0.2:36060 (d0a244847e88)
3: I1123 08:17:41.165019 26941 master.cpp:4978] Launching task 337a244c-6f50-4509-9168-cbd3c287fd08 of framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000 (default) at scheduler-c7a14adc-7520-4d11-b6fb-541c36350441@172.17.0.2:36060 with resources [{"allocation_info":{"role":"default-role"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","scalar":{"value":128.0},"type":"SCALAR"}] on agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 at slave(864)@172.17.0.2:36060 (d0a244847e88)
3: I1123 08:17:41.166293 26937 slave.cpp:3594] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk1,id1:path1]<SHARED>:2048<1>; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk2,id2:path2]<SHARED>:2048<1>
3: I1123 08:17:41.166436 26937 slave.cpp:6989] Updating the state of offer operation '' (uuid: ae62ea8a-6484-4297-bb1e-aff2bce9dc01) of framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000 (latest state: OFFER_OPERATION_FINISHED, status update state: OFFER_OPERATION_FINISHED)
3: I1123 08:17:41.166746 26932 master.cpp:9731] Updating the state of offer operation '' (uuid: ae62ea8a-6484-4297-bb1e-aff2bce9dc01) of framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000 (latest state: OFFER_OPERATION_FINISHED, status update state: OFFER_OPERATION_FINISHED)
3: I1123 08:17:41.167444 26937 slave.cpp:1806] Got assigned task '337a244c-6f50-4509-9168-cbd3c287fd08' for framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000
3: I1123 08:17:41.168284 26937 slave.cpp:2074] Authorizing task '337a244c-6f50-4509-9168-cbd3c287fd08' for framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000
3: I1123 08:17:41.168344 26937 slave.cpp:7349] Authorizing framework principal 'test-principal' to launch task 337a244c-6f50-4509-9168-cbd3c287fd08
3: I1123 08:17:41.169117 26946 slave.cpp:2242] Launching task '337a244c-6f50-4509-9168-cbd3c287fd08' for framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000
3: I1123 08:17:41.169701 26946 paths.cpp:621] Trying to chown '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8/slaves/d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0/frameworks/d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000/executors/337a244c-6f50-4509-9168-cbd3c287fd08/runs/891bc82a-d2e0-4b21-acb4-697277c79427' to user 'mesos'
3: I1123 08:17:41.169975 26946 slave.cpp:7823] Launching executor '337a244c-6f50-4509-9168-cbd3c287fd08' of framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000 with resources [{"allocation_info":{"role":"default-role"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] in work directory '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8/slaves/d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0/frameworks/d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000/executors/337a244c-6f50-4509-9168-cbd3c287fd08/runs/891bc82a-d2e0-4b21-acb4-697277c79427'
3: I1123 08:17:41.170807 26944 hierarchical.cpp:856] Updated allocation of framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000 on agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 from cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk2]:2048; ports(allocated: default-role):[31000-32000] to cpus(allocated: default-role):2; mem(allocated: default-role):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk1,id1:path1]<SHARED>:2048<1>; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk2,id2:path2]<SHARED>:2048<1>
3: I1123 08:17:41.171052 26946 slave.cpp:2470] Queued task '337a244c-6f50-4509-9168-cbd3c287fd08' for executor '337a244c-6f50-4509-9168-cbd3c287fd08' of framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000
3: I1123 08:17:41.171183 26946 slave.cpp:958] Successfully attached '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8/slaves/d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0/frameworks/d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000/executors/337a244c-6f50-4509-9168-cbd3c287fd08/runs/891bc82a-d2e0-4b21-acb4-697277c79427' to virtual path '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8/slaves/d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0/frameworks/d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000/executors/337a244c-6f50-4509-9168-cbd3c287fd08/runs/latest'
3: I1123 08:17:41.171238 26946 slave.cpp:958] Successfully attached '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8/slaves/d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0/frameworks/d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000/executors/337a244c-6f50-4509-9168-cbd3c287fd08/runs/891bc82a-d2e0-4b21-acb4-697277c79427' to virtual path '/frameworks/d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000/executors/337a244c-6f50-4509-9168-cbd3c287fd08/runs/latest'
3: I1123 08:17:41.171288 26946 slave.cpp:958] Successfully attached '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8/slaves/d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0/frameworks/d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000/executors/337a244c-6f50-4509-9168-cbd3c287fd08/runs/891bc82a-d2e0-4b21-acb4-697277c79427' to virtual path '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8/slaves/d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0/frameworks/d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000/executors/337a244c-6f50-4509-9168-cbd3c287fd08/runs/891bc82a-d2e0-4b21-acb4-697277c79427'
3: I1123 08:17:41.171571 26946 slave.cpp:2933] Launching container 891bc82a-d2e0-4b21-acb4-697277c79427 for executor '337a244c-6f50-4509-9168-cbd3c287fd08' of framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000
3: I1123 08:17:41.171831 26942 containerizer.cpp:1195] Starting container 891bc82a-d2e0-4b21-acb4-697277c79427
3: I1123 08:17:41.172581 26942 containerizer.cpp:1367] Checkpointed ContainerConfig at '/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_lhv8ii/containers/891bc82a-d2e0-4b21-acb4-697277c79427/config'
3: I1123 08:17:41.172610 26942 containerizer.cpp:2919] Transitioning the state of container 891bc82a-d2e0-4b21-acb4-697277c79427 from PROVISIONING to PREPARING
3: I1123 08:17:41.173017 26944 hierarchical.cpp:1132] Recovered cpus(allocated: default-role):1; mem(allocated: default-role):1920; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk1,id1:path1]<SHARED>:2048<1>; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk2,id2:path2]<SHARED>:2048<1> (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk1,id1:path1]<SHARED>:2048<1>; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_zoPNRY/disk2,id2:path2]<SHARED>:2048<1>, allocated: cpus(allocated: default-role):1; mem(allocated: default-role):128) on agent d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0 from framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000
3: I1123 08:17:41.177094 26940 containerizer.cpp:1836] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/build\/src"],"shell":false,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:36060"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8\/slaves\/d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0\/frameworks\/d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000\/executors\/337a244c-6f50-4509-9168-cbd3c287fd08\/runs\/891bc82a-d2e0-4b21-acb4-697277c79427"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiI4OTFiYzgyYS1kMmUwLTRiMjEtYWNiNC02OTcyNzdjNzk0MjciLCJlaWQiOiIzMzdhMjQ0Yy02ZjUwLTQ1MDktOTE2OC1jYmQzYzI4N2ZkMDgiLCJmaWQiOiJkNjk0ODFlMi01OGUzLTRhMjQtOTlkMS1lYTZkYWVmZGM2NWQtMDAwMCJ9.a9XY4UyJTldNCI7KrfKg_ISgUqsyvAE3x1T4lb5px5k"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"337a244c-6f50-4509-9168-cbd3c287fd08"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(864)@172.17.0.2:36060"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8\/slaves\/d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0\/frameworks\/d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000\/executors\/337a244c-6f50-4509-9168-cbd3c287fd08\/runs\/891bc82a-d2e0-4b21-acb4-697277c79427"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8\/slaves\/d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0\/frameworks\/d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000\/executors\/337a244c-6f50-4509-9168-cbd3c287fd08\/runs\/891bc82a-d2e0-4b21-acb4-697277c79427"}" --pipe_read="14" --pipe_write="15" --runtime_directory="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_lhv8ii/containers/891bc82a-d2e0-4b21-acb4-697277c79427" --unshare_namespace_mnt="false"'
3: I1123 08:17:41.181572 26940 launcher.cpp:140] Forked child with pid '27353' for container '891bc82a-d2e0-4b21-acb4-697277c79427'
3: I1123 08:17:41.182274 26940 containerizer.cpp:2919] Transitioning the state of container 891bc82a-d2e0-4b21-acb4-697277c79427 from PREPARING to ISOLATING
3: I1123 08:17:41.184236 26947 containerizer.cpp:2919] Transitioning the state of container 891bc82a-d2e0-4b21-acb4-697277c79427 from ISOLATING to FETCHING
3: I1123 08:17:41.184520 26948 fetcher.cpp:379] Starting to fetch URIs for container: 891bc82a-d2e0-4b21-acb4-697277c79427, directory: /tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_3_jMCsA8/slaves/d69481e2-58e3-4a24-99d1-ea6daefdc65d-S0/frameworks/d69481e2-58e3-4a24-99d1-ea6daefdc65d-0000/executors/337a244c-6f50-4509-9168-cbd3c287fd08/runs/891bc82a-d2e0-4b21-acb4-697277c79427
3: I1123 08:17:41.185595 26942 containerizer.cpp:2919] Transitioning the state of container 891bc82a-d2e0-4b21-acb4-697277c79427 from FETCHING to RUNNING
3: W1123 08:17:41.186625 18294 process.cpp:2756] Attempted to spawn already running process version@172.17.0.2:36060
3: I1123 08:17:41.187512 18294 sched.cpp:232] Version: 1.5.0
3: I1123 08:17:41.188325 26945 sched.cpp:336] New master detected at master@172.17.0.2:36060
3: I1123 08:17:41.188472 26945 sched.cpp:396] Authenticating with master master@172.17.0.2:36060
3: I1123 08:17:41.188490 26945 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1123 08:17:41.188805 26938 authenticatee.cpp:121] Creating new client SASL connection
3: I1123 08:17:41.189146 26935 master.cpp:8312] Authenticating scheduler-1c15d972-dcc9-4707-ab38-47dc2512f2ab@172.17.0.2:36060
3: I1123 08:17:41.189313 26941 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1544)@172.17.0.2:36060
3: I1123 08:17:41.189591 26936 authenticator.cpp:98] Creating new server SASL connection
3: I1123 08:17:41.189857 26950 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1123 08:17:41.189882 26950 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1123 08:17:41.190027 26934 authenticator.cpp:204] Received SASL authentication start
3: I1123 08:17:41.190079 26934 authenticator.cpp:326] Authentication requires more steps
3: I1123 08:17:41.190196 26932 authenticatee.cpp:259] Received SASL authentication step
3: I1123 08:17:41.190349 26953 authenticator.cpp:232] Received SASL authentication step
3: I1123 08:17:41.190394 26953 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd0a244847e88' server FQDN: 'd0a244847e88' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1123 08:17:41.190413 26953 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1123 08:17:41.190461 26953 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1123 08:17:41.190492 26953 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd0a244847e88' server FQDN: 'd0a244847e88' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1123 08:17:41.190508 26953 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1123 08:17:41.190518 26953 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1123 08:17:41.190536 26953 authenticator.cpp:318] Authentication success
3: I1123 08:17:41.190649 26933 authenticatee.cpp:299] Authentication success
3: I1123 08:17:41.190735 26937 master.cpp:8342] Successfully authenticated principal 'test-principal' at scheduler-1c15d972-dcc9-4707-ab38-47dc2512f2ab@172.17.0.2:36060
3: I1123 08:17:41.190778 26933 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1544)@172.17.0.2:36060
3: I1123 08:17:41.190974 26940 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:36060
3: I1123 08:17:41.190999 26940 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:36060
3: I1123 08:17:41.191184 26940 sched.cpp:857] Will retry registration in 707.48858ms if necessary
3: I1123 08:17:41.191526 26943 master.cpp:2963] Received SUBSCRIBE call for framework 'default' at scheduler-1c15d972-dcc9-4707-ab38-47dc2512f2ab@172.17.0.2:36060
3: I1123 08:17:41.191655 26943 master.cpp:2280] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1123 08:17:41.192522 26931 master.cpp:3043] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT, SHARED_RESOURCES ]
3: I1123 08:17:41.193323 26939 hierarchical.cpp:306] Added framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0001
3: I1123 08:17:41.193367 26951 sched.cpp:751] Framework registered with d69481e2-58e3-4a24-99d1-ea6daefdc65d-0001
3: I1123 08:17:41.193431 26951 sched.cpp:765] Scheduler::registered took 32973ns
3: I1123 08:17:41.196863 26939 hierarchical.cpp:1457] Performed allocation for 1 agents in 3.280875ms
3: I1123 08:17:41.197823 26954 master.cpp:8142] Sending 1 offers to framework d69481e2-58e3-4a24-99d1-ea6daefdc65d-0001 (default) at scheduler-1c15d972-dcc9-4707-ab38-47dc2512f2ab@172.17.0.2:36060
3: I1123 08:17:41.198580 26945 sched.cpp:921] Scheduler::resourceOffers took 150951ns
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1511422079-8473
Process leaked file descriptors. See https://jenkins.io/redirect/troubleshooting/process-leaked-file-descriptors for more information
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4495
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4495/display/redirect?page=changes>