See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)/4105/display/redirect>
------------------------------------------ [...truncated 17.64 MB...] I0812 10:50:15.286759 31553 process.cpp:3933] Handling HTTP event for process 'master' with path: '/master/reserve' I0812 10:50:15.287777 31565 slave.cpp:1194] Checkpointing SlaveInfo to '/tmp/PersistentVolumeEndpointsTest_DynamicReservationRoleMismatch_Up7Gpp/meta/slaves/25e97175-d615-492a-890b-b6e1d1c1184a-S0/slave.info' I0812 10:50:15.288151 31555 http.cpp:1166] HTTP POST for /master/reserve from 172.17.0.2:33925 I0812 10:50:15.288163 31565 slave.cpp:1232] Forwarding total oversubscribed resources {} I0812 10:50:15.288615 31555 master.cpp:3588] Authorizing principal 'test-principal' to reserve resources '[{"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":1024.0},"type":"SCALAR"}]' I0812 10:50:15.289216 31555 master.cpp:6688] Received update of agent 25e97175-d615-492a-890b-b6e1d1c1184a-S0 at slave(447)@172.17.0.2:49532 (4c851870f6a8) with total oversubscribed resources {} I0812 10:50:15.289680 31557 hierarchical.cpp:660] Agent 25e97175-d615-492a-890b-b6e1d1c1184a-S0 (4c851870f6a8) updated with total resources disk:1024; cpus:16; mem:47270; ports:[31000-32000] I0812 10:50:15.291615 31566 master.cpp:9110] Sending updated checkpointed resources disk(reservations: [(DYNAMIC,role1,test-principal)]):1024 to agent 25e97175-d615-492a-890b-b6e1d1c1184a-S0 at slave(447)@172.17.0.2:49532 (4c851870f6a8) I0812 10:50:15.292546 31558 slave.cpp:3449] Updated checkpointed resources from {} to disk(reservations: [(DYNAMIC,role1,test-principal)]):1024 I0812 10:50:15.293223 31552 process.cpp:3228] Attempting to spawn already spawned process version@172.17.0.2:49532 I0812 10:50:15.294324 31552 sched.cpp:232] Version: 1.4.0 I0812 10:50:15.294970 31554 sched.cpp:336] New master detected at master@172.17.0.2:49532 I0812 10:50:15.295096 31554 sched.cpp:407] Authenticating with master master@172.17.0.2:49532 I0812 10:50:15.295120 31554 sched.cpp:414] Using default CRAM-MD5 authenticatee I0812 10:50:15.295346 31558 authenticatee.cpp:121] Creating new client SASL connection I0812 10:50:15.295624 31561 master.cpp:7837] Authenticating scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532 I0812 10:50:15.295730 31563 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(932)@172.17.0.2:49532 I0812 10:50:15.296037 31564 authenticator.cpp:98] Creating new server SASL connection I0812 10:50:15.296284 31560 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0812 10:50:15.296314 31560 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0812 10:50:15.296439 31555 authenticator.cpp:204] Received SASL authentication start I0812 10:50:15.296497 31555 authenticator.cpp:326] Authentication requires more steps I0812 10:50:15.296591 31555 authenticatee.cpp:259] Received SASL authentication step I0812 10:50:15.296697 31555 authenticator.cpp:232] Received SASL authentication step I0812 10:50:15.296725 31555 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4c851870f6a8' server FQDN: '4c851870f6a8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0812 10:50:15.296736 31555 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0812 10:50:15.296772 31555 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0812 10:50:15.296794 31555 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4c851870f6a8' server FQDN: '4c851870f6a8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0812 10:50:15.296808 31555 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0812 10:50:15.296814 31555 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0812 10:50:15.296831 31555 authenticator.cpp:318] Authentication success I0812 10:50:15.296933 31553 authenticatee.cpp:299] Authentication success I0812 10:50:15.297046 31562 master.cpp:7867] Successfully authenticated principal 'test-principal' at scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532 I0812 10:50:15.297134 31555 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(932)@172.17.0.2:49532 I0812 10:50:15.297267 31553 sched.cpp:513] Successfully authenticated with master master@172.17.0.2:49532 I0812 10:50:15.297343 31553 sched.cpp:836] Sending SUBSCRIBE call to master@172.17.0.2:49532 I0812 10:50:15.297526 31553 sched.cpp:869] Will retry registration in 1.772875033secs if necessary I0812 10:50:15.297758 31558 master.cpp:2894] Received SUBSCRIBE call for framework 'default' at scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532 I0812 10:50:15.297855 31558 master.cpp:2228] Authorizing framework principal 'test-principal' to receive offers for roles '{ role1 }' I0812 10:50:15.298414 31559 master.cpp:2974] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ] I0812 10:50:15.299057 31567 sched.cpp:759] Framework registered with 25e97175-d615-492a-890b-b6e1d1c1184a-0000 I0812 10:50:15.299116 31567 sched.cpp:773] Scheduler::registered took 29294ns I0812 10:50:15.299151 31564 hierarchical.cpp:303] Added framework 25e97175-d615-492a-890b-b6e1d1c1184a-0000 I0812 10:50:15.300492 31564 hierarchical.cpp:2015] No inverse offers to send out! I0812 10:50:15.300546 31564 hierarchical.cpp:1468] Performed allocation for 1 agents in 1.251655ms I0812 10:50:15.301221 31565 master.cpp:7667] Sending 1 offers to framework 25e97175-d615-492a-890b-b6e1d1c1184a-0000 (default) at scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532 I0812 10:50:15.301880 31554 sched.cpp:933] Scheduler::resourceOffers took 135959ns I0812 10:50:15.305358 31562 process.cpp:3933] Handling HTTP event for process 'master' with path: '/master/create-volumes' I0812 10:50:15.306957 31568 http.cpp:1166] HTTP POST for /master/create-volumes from 172.17.0.2:33926 I0812 10:50:15.307756 31568 master.cpp:3723] Authorizing principal 'test-principal' to create volumes '[{"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"principal":"test-principal","role":"role2","type":"DYNAMIC"}],"scalar":{"value":64.0},"type":"SCALAR"}]' I0812 10:50:15.310726 31552 sched.cpp:2021] Asked to stop the driver I0812 10:50:15.310895 31558 sched.cpp:1203] Stopping framework 25e97175-d615-492a-890b-b6e1d1c1184a-0000 I0812 10:50:15.311168 31559 master.cpp:8348] Processing TEARDOWN call for framework 25e97175-d615-492a-890b-b6e1d1c1184a-0000 (default) at scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532 I0812 10:50:15.311203 31559 master.cpp:8360] Removing framework 25e97175-d615-492a-890b-b6e1d1c1184a-0000 (default) at scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532 I0812 10:50:15.311234 31559 master.cpp:3264] Deactivating framework 25e97175-d615-492a-890b-b6e1d1c1184a-0000 (default) at scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532 I0812 10:50:15.311426 31557 hierarchical.cpp:412] Deactivated framework 25e97175-d615-492a-890b-b6e1d1c1184a-0000 I0812 10:50:15.312113 31559 master.cpp:9164] Removing offer 25e97175-d615-492a-890b-b6e1d1c1184a-O0 I0812 10:50:15.312326 31564 slave.cpp:3159] Asked to shut down framework 25e97175-d615-492a-890b-b6e1d1c1184a-0000 by master@172.17.0.2:49532 I0812 10:50:15.312358 31564 slave.cpp:3174] Cannot shut down unknown framework 25e97175-d615-492a-890b-b6e1d1c1184a-0000 I0812 10:50:15.312834 31557 hierarchical.cpp:1152] Recovered ports(allocated: role1):[31000-32000]; cpus(allocated: role1):16; mem(allocated: role1):47270; disk(allocated: role1)(reservations: [(DYNAMIC,role1,test-principal)]):1024 (total: ports:[31000-32000]; cpus:16; mem:47270; disk(reservations: [(DYNAMIC,role1,test-principal)]):1024, allocated: {}) on agent 25e97175-d615-492a-890b-b6e1d1c1184a-S0 from framework 25e97175-d615-492a-890b-b6e1d1c1184a-0000 I0812 10:50:15.312978 31564 slave.cpp:843] Agent terminating I0812 10:50:15.313161 31562 master.cpp:1318] Agent 25e97175-d615-492a-890b-b6e1d1c1184a-S0 at slave(447)@172.17.0.2:49532 (4c851870f6a8) disconnected I0812 10:50:15.313190 31562 master.cpp:3301] Disconnecting agent 25e97175-d615-492a-890b-b6e1d1c1184a-S0 at slave(447)@172.17.0.2:49532 (4c851870f6a8) I0812 10:50:15.313285 31557 hierarchical.cpp:355] Removed framework 25e97175-d615-492a-890b-b6e1d1c1184a-0000 I0812 10:50:15.313336 31562 master.cpp:3320] Deactivating agent 25e97175-d615-492a-890b-b6e1d1c1184a-S0 at slave(447)@172.17.0.2:49532 (4c851870f6a8) I0812 10:50:15.313454 31561 hierarchical.cpp:690] Agent 25e97175-d615-492a-890b-b6e1d1c1184a-S0 deactivated I0812 10:50:15.320636 31552 master.cpp:1160] Master terminating I0812 10:50:15.321581 31568 hierarchical.cpp:626] Removed agent 25e97175-d615-492a-890b-b6e1d1c1184a-S0 [ OK ] PersistentVolumeEndpointsTest.DynamicReservationRoleMismatch (108 ms) [ RUN ] PersistentVolumeEndpointsTest.UnreserveVolumeResources I0812 10:50:15.332918 31552 cluster.cpp:162] Creating default 'local' authorizer I0812 10:50:15.336380 31554 master.cpp:442] Master 2aac1248-9bc8-462f-9550-019f6c85fe93 (4c851870f6a8) started on 172.17.0.2:49532 I0812 10:50:15.336442 31554 master.cpp:444] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --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/gYSykE/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" --roles="role1" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/gYSykE/master" --zk_session_timeout="10secs" I0812 10:50:15.336943 31554 master.cpp:494] Master only allowing authenticated frameworks to register I0812 10:50:15.336962 31554 master.cpp:508] Master only allowing authenticated agents to register I0812 10:50:15.336973 31554 master.cpp:521] Master only allowing authenticated HTTP frameworks to register I0812 10:50:15.336988 31554 credentials.hpp:37] Loading credentials for authentication from '/tmp/gYSykE/credentials' I0812 10:50:15.337393 31554 master.cpp:566] Using default 'crammd5' authenticator I0812 10:50:15.337664 31554 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0812 10:50:15.337880 31554 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0812 10:50:15.338042 31554 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0812 10:50:15.338181 31554 master.cpp:646] Authorization enabled W0812 10:50:15.338198 31554 master.cpp:709] The '--roles' flag is deprecated. This flag will be removed in the future. See the Mesos 0.27 upgrade notes for more information I0812 10:50:15.338424 31558 whitelist_watcher.cpp:77] No whitelist given I0812 10:50:15.338429 31567 hierarchical.cpp:171] Initialized hierarchical allocator process I0812 10:50:15.341552 31565 master.cpp:2163] Elected as the leading master! I0812 10:50:15.341583 31565 master.cpp:1702] Recovering from registrar I0812 10:50:15.341743 31559 registrar.cpp:347] Recovering registrar I0812 10:50:15.342370 31559 registrar.cpp:391] Successfully fetched the registry (0B) in 585728ns I0812 10:50:15.342470 31559 registrar.cpp:495] Applied 1 operations in 25748ns; attempting to update the registry I0812 10:50:15.343053 31559 registrar.cpp:552] Successfully updated the registry in 527104ns I0812 10:50:15.343170 31559 registrar.cpp:424] Successfully recovered registrar I0812 10:50:15.343515 31566 master.cpp:1801] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register I0812 10:50:15.343569 31560 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover I0812 10:50:15.349115 31552 process.cpp:3228] Attempting to spawn already spawned process files@172.17.0.2:49532 I0812 10:50:15.350283 31552 containerizer.cpp:246] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret W0812 10:50:15.361397 31552 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges W0812 10:50:15.361493 31552 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges I0812 10:50:15.361536 31552 provisioner.cpp:255] Using default backend 'copy' I0812 10:50:15.363253 31552 cluster.cpp:448] Creating default 'local' authorizer I0812 10:50:15.364934 31558 slave.cpp:250] Mesos agent started on (448)@172.17.0.2:49532 I0812 10:50:15.364953 31558 slave.cpp:251] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl/store/appc" --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/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl/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/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl/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/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl/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="disk(*):1024" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl" --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/PersistentVolumeEndpointsTest_UnreserveVolumeResources_sA254u" I0812 10:50:15.365350 31558 credentials.hpp:86] Loading credential for authentication from '/tmp/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl/credential' I0812 10:50:15.365557 31558 slave.cpp:283] Agent using credential for: test-principal I0812 10:50:15.365583 31558 credentials.hpp:37] Loading credentials for authentication from '/tmp/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl/http_credentials' I0812 10:50:15.365785 31558 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0812 10:50:15.365922 31558 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' I0812 10:50:15.366816 31558 slave.cpp:565] Agent resources: [{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"cpus","scalar":{"value":16.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":47270.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] I0812 10:50:15.366987 31558 slave.cpp:573] Agent attributes: [ ] I0812 10:50:15.366997 31558 slave.cpp:582] Agent hostname: 4c851870f6a8 I0812 10:50:15.367117 31555 status_update_manager.cpp:177] Pausing sending status updates I0812 10:50:15.368404 31567 state.cpp:64] Recovering state from '/tmp/PersistentVolumeEndpointsTest_UnreserveVolumeResources_sA254u/meta' I0812 10:50:15.368666 31567 status_update_manager.cpp:203] Recovering status update manager I0812 10:50:15.368826 31561 containerizer.cpp:598] Recovering containerizer I0812 10:50:15.370106 31567 provisioner.cpp:416] Provisioner recovery complete I0812 10:50:15.370445 31554 slave.cpp:6210] Finished recovery I0812 10:50:15.370851 31554 slave.cpp:6392] Querying resource estimator for oversubscribable resources I0812 10:50:15.371069 31563 status_update_manager.cpp:177] Pausing sending status updates I0812 10:50:15.371067 31554 slave.cpp:971] New master detected at master@172.17.0.2:49532 I0812 10:50:15.371176 31554 slave.cpp:1006] Detecting new master I0812 10:50:15.371311 31554 slave.cpp:6406] Received oversubscribable resources {} from the resource estimator I0812 10:50:15.376595 31561 slave.cpp:1033] Authenticating with master master@172.17.0.2:49532 I0812 10:50:15.376654 31561 slave.cpp:1044] Using default CRAM-MD5 authenticatee I0812 10:50:15.376889 31565 authenticatee.cpp:121] Creating new client SASL connection I0812 10:50:15.377162 31564 master.cpp:7837] Authenticating slave(448)@172.17.0.2:49532 I0812 10:50:15.377265 31568 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(933)@172.17.0.2:49532 I0812 10:50:15.377522 31566 authenticator.cpp:98] Creating new server SASL connection I0812 10:50:15.377704 31562 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0812 10:50:15.377725 31562 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0812 10:50:15.377820 31562 authenticator.cpp:204] Received SASL authentication start I0812 10:50:15.377878 31562 authenticator.cpp:326] Authentication requires more steps I0812 10:50:15.377974 31560 authenticatee.cpp:259] Received SASL authentication step I0812 10:50:15.378082 31567 authenticator.cpp:232] Received SASL authentication step I0812 10:50:15.378113 31567 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4c851870f6a8' server FQDN: '4c851870f6a8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0812 10:50:15.378129 31567 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0812 10:50:15.378170 31567 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0812 10:50:15.378197 31567 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4c851870f6a8' server FQDN: '4c851870f6a8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0812 10:50:15.378211 31567 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0812 10:50:15.378222 31567 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0812 10:50:15.378243 31567 authenticator.cpp:318] Authentication success I0812 10:50:15.378427 31556 authenticatee.cpp:299] Authentication success I0812 10:50:15.378429 31553 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(933)@172.17.0.2:49532 I0812 10:50:15.378466 31557 master.cpp:7867] Successfully authenticated principal 'test-principal' at slave(448)@172.17.0.2:49532 I0812 10:50:15.378671 31559 slave.cpp:1128] Successfully authenticated with master master@172.17.0.2:49532 I0812 10:50:15.378856 31559 slave.cpp:1572] Will retry registration in 3.247352ms if necessary I0812 10:50:15.379014 31561 master.cpp:5712] Received register agent message from slave(448)@172.17.0.2:49532 (4c851870f6a8) I0812 10:50:15.379133 31561 master.cpp:3803] Authorizing agent with principal 'test-principal' I0812 10:50:15.379509 31564 master.cpp:5772] Authorized registration of agent at slave(448)@172.17.0.2:49532 (4c851870f6a8) I0812 10:50:15.379613 31564 master.cpp:5865] Registering agent at slave(448)@172.17.0.2:49532 (4c851870f6a8) with id 2aac1248-9bc8-462f-9550-019f6c85fe93-S0 I0812 10:50:15.380024 31568 registrar.cpp:495] Applied 1 operations in 54207ns; attempting to update the registry I0812 10:50:15.380596 31568 registrar.cpp:552] Successfully updated the registry in 516352ns I0812 10:50:15.380772 31555 master.cpp:5912] Admitted agent 2aac1248-9bc8-462f-9550-019f6c85fe93-S0 at slave(448)@172.17.0.2:49532 (4c851870f6a8) I0812 10:50:15.381369 31556 slave.cpp:4887] Received ping from slave-observer(444)@172.17.0.2:49532 I0812 10:50:15.381294 31555 master.cpp:5943] Registered agent 2aac1248-9bc8-462f-9550-019f6c85fe93-S0 at slave(448)@172.17.0.2:49532 (4c851870f6a8) with [{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"cpus","scalar":{"value":16.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":47270.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] I0812 10:50:15.381644 31556 slave.cpp:1174] Registered with master master@172.17.0.2:49532; given agent ID 2aac1248-9bc8-462f-9550-019f6c85fe93-S0 I0812 10:50:15.381810 31554 hierarchical.cpp:593] Added agent 2aac1248-9bc8-462f-9550-019f6c85fe93-S0 (4c851870f6a8) with disk:1024; cpus:16; mem:47270; ports:[31000-32000] (allocated: {}) I0812 10:50:15.381929 31561 status_update_manager.cpp:184] Resuming sending status updates I0812 10:50:15.382164 31554 hierarchical.cpp:1925] No allocations performed I0812 10:50:15.382213 31554 hierarchical.cpp:1468] Performed allocation for 1 agents in 191822ns I0812 10:50:15.384657 31555 process.cpp:3933] Handling HTTP event for process 'master' with path: '/master/reserve' I0812 10:50:15.385956 31567 http.cpp:1166] HTTP POST for /master/reserve from 172.17.0.2:33927 I0812 10:50:15.386456 31567 master.cpp:3588] Authorizing principal 'test-principal' to reserve resources '[{"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":1024.0},"type":"SCALAR"}]' I0812 10:50:15.388746 31555 master.cpp:9110] Sending updated checkpointed resources disk(reservations: [(DYNAMIC,role1,test-principal)]):1024 to agent 2aac1248-9bc8-462f-9550-019f6c85fe93-S0 at slave(448)@172.17.0.2:49532 (4c851870f6a8) I0812 10:50:15.389120 31561 hierarchical.cpp:1925] No allocations performed I0812 10:50:15.389171 31561 hierarchical.cpp:1468] Performed allocation for 1 agents in 170198ns I0812 10:50:15.391633 31561 process.cpp:3933] Handling HTTP event for process 'master' with path: '/master/create-volumes' I0812 10:50:15.393113 31563 http.cpp:1166] HTTP POST for /master/create-volumes from 172.17.0.2:33928 I0812 10:50:15.393800 31563 master.cpp:3723] Authorizing principal 'test-principal' to create volumes '[{"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":64.0},"type":"SCALAR"}]' I0812 10:50:15.394937 31556 slave.cpp:1194] Checkpointing SlaveInfo to '/tmp/PersistentVolumeEndpointsTest_UnreserveVolumeResources_sA254u/meta/slaves/2aac1248-9bc8-462f-9550-019f6c85fe93-S0/slave.info' I0812 10:50:15.395274 31556 slave.cpp:1232] Forwarding total oversubscribed resources {} I0812 10:50:15.395429 31561 master.cpp:6688] Received update of agent 2aac1248-9bc8-462f-9550-019f6c85fe93-S0 at slave(448)@172.17.0.2:49532 (4c851870f6a8) with total oversubscribed resources {} I0812 10:50:15.395826 31556 slave.cpp:3449] Updated checkpointed resources from {} to disk(reservations: [(DYNAMIC,role1,test-principal)]):1024 I0812 10:50:15.396389 31560 master.cpp:9110] Sending updated checkpointed resources disk(reservations: [(DYNAMIC,role1,test-principal)]):960; disk(reservations: [(DYNAMIC,role1,test-principal)])[id1:path1]:64 to agent 2aac1248-9bc8-462f-9550-019f6c85fe93-S0 at slave(448)@172.17.0.2:49532 (4c851870f6a8) I0812 10:50:15.397297 31554 hierarchical.cpp:660] Agent 2aac1248-9bc8-462f-9550-019f6c85fe93-S0 (4c851870f6a8) updated with total resources ports:[31000-32000]; cpus:16; mem:47270; disk(reservations: [(DYNAMIC,role1,test-principal)]):1024 I0812 10:50:15.397505 31554 hierarchical.cpp:1925] No allocations performed I0812 10:50:15.397608 31554 hierarchical.cpp:1468] Performed allocation for 1 agents in 190554ns I0812 10:50:15.399036 31557 process.cpp:3933] Handling HTTP event for process 'master' with path: '/master/unreserve' I0812 10:50:15.400270 31556 http.cpp:1166] HTTP POST for /master/unreserve from 172.17.0.2:33929 I0812 10:50:15.400807 31556 master.cpp:3656] Authorizing principal 'test-principal' to unreserve resources '[{"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":1024.0},"type":"SCALAR"}]' F0812 10:50:15.402957 31557 master.cpp:9860] CHECK_SOME(resources): Invalid UNRESERVE Operation: ports:[31000-32000]; cpus:16; mem:47270; disk(reservations: [(DYNAMIC,role1,test-principal)]):960; disk(reservations: [(DYNAMIC,role1,test-principal)])[id1:path1]:64 does not contain disk(reservations: [(DYNAMIC,role1,test-principal)]):1024 *** Check failure stack trace: *** @ 0x7f3f97bb984d google::LogMessage::Fail() /mesos/src/tests/persistent_volume_endpoints_tests.cpp:458: Failure Value of: (response).get().status Actual: "202 Accepted" Expected: Conflict().status Which is: "409 Conflict" @ 0x7f3f97bbb61c google::LogMessage::SendToLog() @ 0x7f3f97bb943c google::LogMessage::Flush() @ 0x7f3f97bbbf2e google::LogMessageFatal::~LogMessageFatal() @ 0x26556dc _CheckFatal::~_CheckFatal() @ 0x7f3f9fe00b96 mesos::internal::master::Slave::apply() @ 0x7f3f9fdfa57e mesos::internal::master::Master::_apply() I0812 10:50:15.440655 31564 hierarchical.cpp:1925] No allocations performed I0812 10:50:15.440714 31564 hierarchical.cpp:1468] Performed allocation for 1 agents in 211887ns @ 0x7f3f9fe626d6 _ZZN7process8dispatchIN5mesos8internal6master6MasterEPNS3_5SlaveERKNS1_15Offer_OperationERS6_S9_EEvRKNS_3PIDIT_EEMSC_FvT0_T1_EOT2_OT3_ENKUlSA_RS7_PNS_11ProcessBaseEE_clESA_SO_SQ_ I0812 10:50:15.445353 31568 slave.cpp:3449] Updated checkpointed resources from disk(reservations: [(DYNAMIC,role1,test-principal)]):1024 to disk(reservations: [(DYNAMIC,role1,test-principal)]):960; disk(reservations: [(DYNAMIC,role1,test-principal)])[id1:path1]:64 I0812 10:50:15.445456 31568 slave.cpp:843] Agent terminating @ 0x7f3f9fefa660 _ZNSt5_BindIFZN7process8dispatchIN5mesos8internal6master6MasterEPNS4_5SlaveERKNS2_15Offer_OperationERS7_SA_EEvRKNS0_3PIDIT_EEMSD_FvT0_T1_EOT2_OT3_EUlSB_RS8_PNS0_11ProcessBaseEE_S7_S8_St12_PlaceholderILi1EEEE6__callIvJOSR_EJLm0ELm1ELm2EEEET_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE @ 0x7f3f9fee777b _ZNSt5_BindIFZN7process8dispatchIN5mesos8internal6master6MasterEPNS4_5SlaveERKNS2_15Offer_OperationERS7_SA_EEvRKNS0_3PIDIT_EEMSD_FvT0_T1_EOT2_OT3_EUlSB_RS8_PNS0_11ProcessBaseEE_S7_S8_St12_PlaceholderILi1EEEEclIISR_EvEET0_DpOT_ @ 0x7f3f9fec4593 _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEESt5_BindIFZNS0_8dispatchIN5mesos8internal6master6MasterEPNS8_5SlaveERKNS6_15Offer_OperationERSB_SE_EEvRKNS0_3PIDIT_EEMSH_FvT0_T1_EOT2_OT3_EUlSF_RSC_S2_E_SB_SC_St12_PlaceholderILi1EEEEE9_M_invokeERKSt9_Any_dataS2_ @ 0x7f3f9a5f50d7 std::function<>::operator()() @ 0x7f3f9a5cf0e1 process::ProcessBase::visit() @ 0x7f3f9a5dc0e8 process::DispatchEvent::visit() @ 0x266f6c0 process::ProcessBase::serve() @ 0x7f3f9a5cc94b process::ProcessManager::resume() @ 0x7f3f9a5c8e14 _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv @ 0x7f3f9a5da06a _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE @ 0x7f3f9a5d9fc1 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv @ 0x7f3f9a5d9f5a _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv @ 0x7f3f95ffe230 (unknown) @ 0x7f3f96259dc5 start_thread @ 0x7f3f9576776d __clone make[3]: *** [CMakeFiles/check] Aborted make[3]: Leaving directory `/mesos/build' make[2]: *** [CMakeFiles/check.dir/all] Error 2 make[2]: Leaving directory `/mesos/build' make[1]: *** [CMakeFiles/check.dir/rule] Error 2 make[1]: Leaving directory `/mesos/build' make: *** [check] Error 2 + docker rmi mesos-1502532088-24659 Untagged: mesos-1502532088-24659:latest Deleted: sha256:06c3651dd0a68f28f6cebe156bb64c81f1d9b2d1eb3c1be05e89be8a87aa90c8 Deleted: sha256:0837295442dc607f572dac56c37f6f9ae74d0c3bbccd4e5d58e09c73c7c32136 Deleted: sha256:1b21cb6be001ee7c1ba1dfdfb4bb361c249166017aedb60fad05bfd798925da9 Deleted: sha256:53b316238071c12e1fe00f6fb3f79dc7f9766f37a2e01bc99be2946208cbdc24 Deleted: sha256:ab029e46e504befba4de407ed49ad6bd44e3b742990089c8894f3a79d24f9f43 Deleted: sha256:22303ed8807b00cf99106c05e7c9393a18be0f19f0879ec33f274f0789ec5323 Deleted: sha256:531b01991274a2e7f092748e34387688a647edad7de37197a799630ecbca73f3 Deleted: sha256:8e910f2bb5ebfc3719b49953e19f42d235f3fac9fdc0036517660780825b7b6b Deleted: sha256:371c7e7254bf4e340014f554903cbf7157941f10582ac34869071dd72b464b5c Deleted: sha256:68de8c7d844d2f65a05353d2a189be0ebcfb8a600410e7d3db73e216029f1943 Deleted: sha256:d45dc78d1b6b3cc5bb9e47bb641a1318f5f471ba3c34cda6bab6f4b839d3c31a Deleted: sha256:9b061858b9d6cc58aa5812db586f0d526ecb4ec8705da9ea32e8551bebf6dcf9 Deleted: sha256:1de498076926400efd15178d36fe656fb2800dbb53aaccbce65b284a3789b597 Deleted: sha256:903441215bafa59cd84a942131ca5f79d21e50c346a4e9ee01c9ff3ff13cf4e4 Deleted: sha256:4d01daacac8119b571f8abae5516df2936a942c960393c8017fa17deaa1d648a Deleted: sha256:3a8ef37c5d7f0823e9826effdfe9b2870749d3805899f34b1fc4148da95e4bb2 Deleted: sha256:afc2776ac115dc10617625e212fde350176e4aec8ecc952028c77099c54c8d4a Deleted: sha256:3dd52f44230317162ea079c33b65eae3115aa58b6879a080dee1438cc01fe7ae Deleted: sha256:c0b04f1cbf8d04479a646ea3c661d5740d0ee0f1885130d2d080efb1b302febd Deleted: sha256:b7edf56393dff656fb927abf2369ff7b89247991b436bd1d618b4f42ae10120e Deleted: sha256:6500160dee675c6d107702a667bf7563cbc6ad03de935e763c2e468d781f0876 Deleted: sha256:e5d9d80a6694079314ceede6899738110414a50aa73d5ec3da9b7863f3a32523 Deleted: sha256:aa94f362a25480697cc9545f8f0229fbbbf683d6d4bed9bca1cd5dfe1dc342f9 Deleted: sha256:21d6a0e6da43ec99ade4fffef8f61948ef2dfdb5846da5907306dc6d5f1d4e1c Deleted: sha256:0588f6f6a0ed29b6fb37dbd0d266fca37a1d3c34bdddaf98177fc63915a0f413 Build step 'Execute shell' marked build as failure Not sending mail to unregistered user gregorywm...@gmail.com