See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4520/display/redirect?page=changes>
Changes: [bbannier] Made sure only non-terminal operations use resources. [bbannier] Allowed removing non-terminal offer operations. [bbannier] Reconciled pending resource provider operations in agent. [bbannier] Introduced an allocator helper function to track used resources. [bbannier] Added a new allocator method to add resources to agents. [bbannier] Reconciled offer operations between agent and master. [bbannier] Removed currently unneeded 'AWAIT_READY's in 'MockResourceProvider'. [bbannier] Implemented a test of offer operation reconcilation. [yujie.jay] Terminated the Slave first before cleaning up its dependencies. ------------------------------------------ [...truncated 5.76 MB...] 3: I1130 23:14:59.420709 17337 master.cpp:7092] Ignoring update on agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) as it reports no changes 3: W1130 23:14:59.421332 17323 process.cpp:2756] Attempted to spawn already running process [email protected]:47218 3: I1130 23:14:59.422236 17323 sched.cpp:232] Version: 1.5.0 3: I1130 23:14:59.422910 17324 sched.cpp:336] New master detected at [email protected]:47218 3: I1130 23:14:59.423004 17324 sched.cpp:396] Authenticating with master [email protected]:47218 3: I1130 23:14:59.423020 17324 sched.cpp:403] Using default CRAM-MD5 authenticatee 3: I1130 23:14:59.423398 17324 authenticatee.cpp:121] Creating new client SASL connection 3: I1130 23:14:59.423799 17324 master.cpp:8593] Authenticating [email protected]:47218 3: I1130 23:14:59.423979 17324 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(258)@172.17.0.4:47218 3: I1130 23:14:59.424350 17324 authenticator.cpp:98] Creating new server SASL connection 3: I1130 23:14:59.424562 17331 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1130 23:14:59.424589 17331 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1130 23:14:59.424718 17331 authenticator.cpp:204] Received SASL authentication start 3: I1130 23:14:59.424769 17331 authenticator.cpp:326] Authentication requires more steps 3: I1130 23:14:59.424926 17329 authenticatee.cpp:259] Received SASL authentication step 3: I1130 23:14:59.425194 17329 authenticator.cpp:232] Received SASL authentication step 3: I1130 23:14:59.425223 17329 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c8a6051e98c' server FQDN: '1c8a6051e98c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1130 23:14:59.425379 17329 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1130 23:14:59.425495 17329 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1130 23:14:59.425642 17329 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c8a6051e98c' server FQDN: '1c8a6051e98c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1130 23:14:59.425731 17329 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1130 23:14:59.425861 17329 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1130 23:14:59.425951 17329 authenticator.cpp:318] Authentication success 3: I1130 23:14:59.426126 17337 authenticatee.cpp:299] Authentication success 3: I1130 23:14:59.426321 17337 master.cpp:8623] Successfully authenticated principal 'test-principal' at [email protected]:47218 3: I1130 23:14:59.426393 17330 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(258)@172.17.0.4:47218 3: I1130 23:14:59.426514 17338 sched.cpp:502] Successfully authenticated with master [email protected]:47218 3: I1130 23:14:59.426594 17338 sched.cpp:824] Sending SUBSCRIBE call to [email protected]:47218 3: I1130 23:14:59.426757 17338 sched.cpp:857] Will retry registration in 188.532928ms if necessary 3: I1130 23:14:59.426911 17330 master.cpp:2969] Received SUBSCRIBE call for framework 'default' at [email protected]:47218 3: I1130 23:14:59.426991 17330 master.cpp:2286] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1130 23:14:59.427481 17327 master.cpp:3049] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ] 3: I1130 23:14:59.428246 17327 sched.cpp:751] Framework registered with f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 3: I1130 23:14:59.428292 17331 hierarchical.cpp:293] Added framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 3: I1130 23:14:59.428303 17327 sched.cpp:765] Scheduler::registered took 33982ns 3: I1130 23:14:59.430084 17331 hierarchical.cpp:1431] Performed allocation for 1 agents in 1.592794ms 3: I1130 23:14:59.430765 17329 master.cpp:8423] Sending 1 offers to framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 (default) at [email protected]:47218 3: I1130 23:14:59.431335 17325 sched.cpp:921] Scheduler::resourceOffers took 21497ns 3: I1130 23:14:59.433698 17334 hierarchical.cpp:1431] Performed allocation for 1 agents in 144397ns 3: I1130 23:14:59.435890 17327 hierarchical.cpp:1431] Performed allocation for 1 agents in 125568ns 3: I1130 23:14:59.437587 17324 hierarchical.cpp:1431] Performed allocation for 1 agents in 123250ns 3: I1130 23:14:59.439575 17336 slave.cpp:6130] Current disk usage 17.80%. Max allowed age: 5.053986125464561days 3: I1130 23:14:59.439623 17334 hierarchical.cpp:1431] Performed allocation for 1 agents in 245684ns 3: I1130 23:14:59.441366 17325 slave.cpp:5192] No pings from master received within 75secs 3: I1130 23:14:59.441720 17331 hierarchical.cpp:1431] Performed allocation for 1 agents in 300489ns 3: I1130 23:14:59.441774 17327 slave.cpp:988] Re-detecting master 3: I1130 23:14:59.441792 17327 slave.cpp:1034] Detecting new master 3: I1130 23:14:59.441781 17325 master.cpp:7879] Marking agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) unreachable: health check timed out 3: I1130 23:14:59.441926 17331 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1130 23:14:59.442466 17326 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1130 23:14:59.442466 17330 slave.cpp:999] New master detected at [email protected]:47218 3: I1130 23:14:59.442520 17330 slave.cpp:1034] Detecting new master 3: I1130 23:14:59.442626 17328 registrar.cpp:495] Applied 1 operations in 174531ns; attempting to update the registry 3: I1130 23:14:59.443560 17328 registrar.cpp:552] Successfully updated the registry in 0ns 3: I1130 23:14:59.443814 17339 master.cpp:7927] Marked agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) unreachable: health check timed out 3: I1130 23:14:59.444572 17339 master.cpp:10374] Removing offer f5d4df97-cd11-4ca5-801a-2526e5d580d1-O0 3: I1130 23:14:59.445065 17339 master.cpp:2138] Notifying framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 (default) at [email protected]:47218 of lost agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 (1c8a6051e98c) 3: I1130 23:14:59.445253 17324 hierarchical.cpp:586] Removed agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 3: I1130 23:14:59.444739 17332 sched.cpp:947] Rescinded offer f5d4df97-cd11-4ca5-801a-2526e5d580d1-O0 3: I1130 23:14:59.445396 17332 sched.cpp:958] Scheduler::offerRescinded took 23865ns 3: I1130 23:14:59.445539 17332 sched.cpp:1091] Lost agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 3: I1130 23:14:59.445639 17332 sched.cpp:1102] Scheduler::slaveLost took 48675ns 3: I1130 23:14:59.447504 17325 slave.cpp:1061] Authenticating with master [email protected]:47218 3: I1130 23:14:59.447568 17325 slave.cpp:1070] Using default CRAM-MD5 authenticatee 3: I1130 23:14:59.447885 17329 authenticatee.cpp:121] Creating new client SASL connection 3: I1130 23:14:59.450142 17336 process.cpp:3503] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' 3: I1130 23:14:59.450965 17333 http.cpp:851] Authorizing principal 'ANY' to GET the endpoint '/metrics/snapshot' 3: W1130 23:14:59.481016 17335 master.cpp:7529] Ignoring status update TASK_RUNNING (UUID: cfbab597-df2a-4786-9e00-d02936281354) for task task_id1 of framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 from removed agent slave(114)@172.17.0.4:47218 with id f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 3: W1130 23:14:59.483095 17337 slave.cpp:1172] Authentication timed out 3: I1130 23:14:59.483240 17326 hierarchical.cpp:1431] Performed allocation for 0 agents in 111139ns 3: W1130 23:14:59.483558 17337 slave.cpp:1117] Failed to authenticate with master [email protected]:47218: Authentication discarded 3: I1130 23:14:59.485056 17328 slave.cpp:1061] Authenticating with master [email protected]:47218 3: I1130 23:14:59.485201 17328 slave.cpp:1070] Using default CRAM-MD5 authenticatee 3: I1130 23:14:59.485266 17338 hierarchical.cpp:1431] Performed allocation for 0 agents in 67050ns 3: I1130 23:14:59.485527 17329 authenticatee.cpp:121] Creating new client SASL connection 3: I1130 23:14:59.485883 17325 master.cpp:8593] Authenticating slave(114)@172.17.0.4:47218 3: I1130 23:14:59.486111 17330 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(260)@172.17.0.4:47218 3: I1130 23:14:59.486495 17335 authenticator.cpp:98] Creating new server SASL connection 3: I1130 23:14:59.486729 17336 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1130 23:14:59.486749 17336 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1130 23:14:59.486845 17336 authenticator.cpp:204] Received SASL authentication start 3: I1130 23:14:59.486891 17336 authenticator.cpp:326] Authentication requires more steps 3: I1130 23:14:59.487102 17331 authenticatee.cpp:259] Received SASL authentication step 3: I1130 23:14:59.487344 17331 authenticator.cpp:232] Received SASL authentication step 3: I1130 23:14:59.487423 17331 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c8a6051e98c' server FQDN: '1c8a6051e98c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1130 23:14:59.487576 17331 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1130 23:14:59.487679 17331 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1130 23:14:59.487756 17331 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c8a6051e98c' server FQDN: '1c8a6051e98c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1130 23:14:59.487825 17331 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1130 23:14:59.487835 17331 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1130 23:14:59.487978 17331 authenticator.cpp:318] Authentication success 3: I1130 23:14:59.488118 17326 authenticatee.cpp:299] Authentication success 3: I1130 23:14:59.488250 17337 master.cpp:8623] Successfully authenticated principal 'test-principal' at slave(114)@172.17.0.4:47218 3: I1130 23:14:59.488415 17333 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(260)@172.17.0.4:47218 3: I1130 23:14:59.488582 17334 slave.cpp:1153] Successfully authenticated with master [email protected]:47218 3: I1130 23:14:59.488958 17334 slave.cpp:1696] Will retry registration in 9.823369ms if necessary 3: I1130 23:14:59.489373 17328 master.cpp:6371] Received re-register agent message from agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) 3: I1130 23:14:59.489579 17328 master.cpp:3878] Authorizing agent with principal 'test-principal' 3: I1130 23:14:59.490144 17330 master.cpp:6442] Authorized re-registration of agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) 3: I1130 23:14:59.490348 17330 master.cpp:6624] Re-registering agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) 3: I1130 23:14:59.491125 17335 registrar.cpp:495] Applied 1 operations in 101287ns; attempting to update the registry 3: I1130 23:14:59.491818 17335 registrar.cpp:552] Successfully updated the registry in 0ns 3: I1130 23:14:59.492097 17338 master.cpp:6696] Re-admitted agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) 3: I1130 23:14:59.493038 17338 master.cpp:6849] Re-registered agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] 3: I1130 23:14:59.493235 17333 slave.cpp:1343] Re-registered with master [email protected]:47218 3: I1130 23:14:59.493422 17334 task_status_update_manager.cpp:188] Resuming sending task status updates 3: I1130 23:14:59.493593 17333 slave.cpp:1411] Forwarding total oversubscribed resources {} 3: I1130 23:14:59.493921 17337 master.cpp:7049] Received update of agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) with total oversubscribed resources {} 3: I1130 23:14:59.494041 17331 hierarchical.cpp:553] Added agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 (1c8a6051e98c) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) 3: I1130 23:14:59.494154 17337 master.cpp:7092] Ignoring update on agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) as it reports no changes 3: I1130 23:14:59.495798 17331 hierarchical.cpp:1431] Performed allocation for 1 agents in 1.352746ms 3: I1130 23:14:59.496292 17328 master.cpp:8423] Sending 1 offers to framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 (default) at [email protected]:47218 3: I1130 23:14:59.496788 17328 sched.cpp:921] Scheduler::resourceOffers took 22479ns 3: I1130 23:14:59.498657 17330 hierarchical.cpp:1431] Performed allocation for 1 agents in 190808ns 3: I1130 23:14:59.498814 17332 slave.cpp:6130] Current disk usage 17.80%. Max allowed age: 5.053985882005058days 3: I1130 23:14:59.500732 17329 hierarchical.cpp:1431] Performed allocation for 1 agents in 144520ns 3: I1130 23:14:59.502748 17339 hierarchical.cpp:1431] Performed allocation for 1 agents in 160092ns 3: I1130 23:14:59.503469 17338 master.cpp:7555] Status update TASK_RUNNING (UUID: c4fe5031-d5d6-48e0-a30e-5dcf52742b7a) for task task_id2 of framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 from agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) 3: I1130 23:14:59.503603 17338 master.cpp:7617] Forwarding status update TASK_RUNNING (UUID: c4fe5031-d5d6-48e0-a30e-5dcf52742b7a) for task task_id2 of framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 3: W1130 23:14:59.503742 17338 master.cpp:7585] Could not lookup task for status update TASK_RUNNING (UUID: c4fe5031-d5d6-48e0-a30e-5dcf52742b7a) for task task_id2 of framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 from agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) 3: I1130 23:14:59.504142 17323 sched.cpp:2009] Asked to stop the driver 3: I1130 23:14:59.504245 17330 sched.cpp:1191] Stopping framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 3: I1130 23:14:59.504580 17334 master.cpp:9100] Processing TEARDOWN call for framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 (default) at [email protected]:47218 3: I1130 23:14:59.504611 17334 master.cpp:9112] Removing framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 (default) at [email protected]:47218 3: I1130 23:14:59.504624 17334 master.cpp:3339] Deactivating framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 (default) at [email protected]:47218 3: I1130 23:14:59.504763 17328 hierarchical.cpp:406] Deactivated framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 3: I1130 23:14:59.505347 17334 master.cpp:10374] Removing offer f5d4df97-cd11-4ca5-801a-2526e5d580d1-O1 3: I1130 23:14:59.505619 17336 slave.cpp:3281] Asked to shut down framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 by [email protected]:47218 3: I1130 23:14:59.505647 17336 slave.cpp:3296] Cannot shut down unknown framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 3: I1130 23:14:59.505753 17323 slave.cpp:875] Agent terminating 3: I1130 23:14:59.506131 17334 master.cpp:1317] Agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) disconnected 3: I1130 23:14:59.506186 17334 master.cpp:3376] Disconnecting agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) 3: I1130 23:14:59.506273 17334 master.cpp:3395] Deactivating agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 at slave(114)@172.17.0.4:47218 (1c8a6051e98c) 3: I1130 23:14:59.506714 17333 hierarchical.cpp:1106] Recovered cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 from framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 3: I1130 23:14:59.507100 17333 hierarchical.cpp:345] Removed framework f5d4df97-cd11-4ca5-801a-2526e5d580d1-0000 3: I1130 23:14:59.507143 17333 hierarchical.cpp:671] Agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 deactivated 3: I1130 23:14:59.510390 17323 master.cpp:1159] Master terminating 3: I1130 23:14:59.511154 17330 hierarchical.cpp:586] Removed agent f5d4df97-cd11-4ca5-801a-2526e5d580d1-S0 3: [ OK ] PartitionTest.PartitionedSlaveStatusUpdates (137 ms) 3: [ RUN ] PartitionTest.PartitionedSlaveExitedExecutor 3: I1130 23:14:59.517951 17323 cluster.cpp:170] Creating default 'local' authorizer 3: I1130 23:14:59.520377 17325 master.cpp:454] Master 14b9980a-ed30-46f6-a27c-1e70395f82c2 (1c8a6051e98c) started on 172.17.0.4:47218 3: I1130 23:14:59.520396 17325 master.cpp:456] 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/yrFfKV/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/yrFfKV/master" --zk_session_timeout="10secs" 3: I1130 23:14:59.520718 17325 master.cpp:505] Master only allowing authenticated frameworks to register 3: I1130 23:14:59.520725 17325 master.cpp:511] Master only allowing authenticated agents to register 3: I1130 23:14:59.520730 17325 master.cpp:517] Master only allowing authenticated HTTP frameworks to register 3: I1130 23:14:59.520735 17325 credentials.hpp:37] Loading credentials for authentication from '/tmp/yrFfKV/credentials' 3: I1130 23:14:59.520972 17325 master.cpp:561] Using default 'crammd5' authenticator 3: I1130 23:14:59.521136 17325 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1130 23:14:59.521298 17325 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1130 23:14:59.521419 17325 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1130 23:14:59.521533 17325 master.cpp:640] Authorization enabled 3: I1130 23:14:59.521683 17326 hierarchical.cpp:173] Initialized hierarchical allocator process 3: I1130 23:14:59.521778 17326 whitelist_watcher.cpp:77] No whitelist given 3: I1130 23:14:59.524284 17336 master.cpp:2221] Elected as the leading master! 3: I1130 23:14:59.524309 17336 master.cpp:1701] Recovering from registrar 3: I1130 23:14:59.524570 17336 registrar.cpp:347] Recovering registrar 3: I1130 23:14:59.525483 17336 registrar.cpp:391] Successfully fetched the registry (0B) in 877056ns 3: I1130 23:14:59.525599 17336 registrar.cpp:495] Applied 1 operations in 35089ns; attempting to update the registry 3: I1130 23:14:59.526259 17336 registrar.cpp:552] Successfully updated the registry in 565760ns 3: I1130 23:14:59.526461 17336 registrar.cpp:424] Successfully recovered registrar 3: I1130 23:14:59.526962 17336 master.cpp:1814] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register 3: I1130 23:14:59.527248 17336 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover 3: W1130 23:14:59.533944 17323 process.cpp:2756] Attempted to spawn already running process [email protected]:47218 3: I1130 23:14:59.534433 17323 cluster.cpp:458] Creating default 'local' authorizer 3: I1130 23:14:59.537304 17336 slave.cpp:253] Mesos agent started on (115)@172.17.0.4:47218 3: I1130 23:14:59.537322 17336 slave.cpp:254] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/PartitionTest_PartitionedSlaveExitedExecutor_F4fdiC/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/PartitionTest_PartitionedSlaveExitedExecutor_F4fdiC/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/PartitionTest_PartitionedSlaveExitedExecutor_F4fdiC/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/PartitionTest_PartitionedSlaveExitedExecutor_F4fdiC/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/PartitionTest_PartitionedSlaveExitedExecutor_F4fdiC/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="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/PartitionTest_PartitionedSlaveExitedExecutor_F4fdiC" --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/PartitionTest_PartitionedSlaveExitedExecutor_oJpd1L" --zk_session_timeout="10secs" 3: I1130 23:14:59.537809 17336 credentials.hpp:86] Loading credential for authentication from '/tmp/PartitionTest_PartitionedSlaveExitedExecutor_F4fdiC/credential' 3: I1130 23:14:59.538027 17336 slave.cpp:286] Agent using credential for: test-principal 3: I1130 23:14:59.538046 17336 credentials.hpp:37] Loading credentials for authentication from '/tmp/PartitionTest_PartitionedSlaveExitedExecutor_F4fdiC/http_credentials' 3: I1130 23:14:59.538332 17336 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1130 23:14:59.538516 17336 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: W1130 23:14:59.539386 17323 process.cpp:2756] Attempted to spawn already running process [email protected]:47218 3: I1130 23:14:59.540544 17323 sched.cpp:232] Version: 1.5.0 3: I1130 23:14:59.540367 17336 slave.cpp:585] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] 3: I1130 23:14:59.540829 17336 slave.cpp:593] Agent attributes: [ ] 3: I1130 23:14:59.540843 17336 slave.cpp:602] Agent hostname: 1c8a6051e98c 3: I1130 23:14:59.541007 17327 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1130 23:14:59.541570 17331 sched.cpp:336] New master detected at [email protected]:47218 3: I1130 23:14:59.541662 17331 sched.cpp:396] Authenticating with master [email protected]:47218 3: I1130 23:14:59.541676 17331 sched.cpp:403] Using default CRAM-MD5 authenticatee 3: I1130 23:14:59.542027 17325 authenticatee.cpp:121] Creating new client SASL connection 3: I1130 23:14:59.542359 17325 master.cpp:8593] Authenticating [email protected]:47218 3: I1130 23:14:59.542551 17325 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(261)@172.17.0.4:47218 3: I1130 23:14:59.542840 17338 authenticator.cpp:98] Creating new server SASL connection 3: I1130 23:14:59.543231 17338 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1130 23:14:59.543256 17338 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1130 23:14:59.543361 17338 authenticator.cpp:204] Received SASL authentication start 3: I1130 23:14:59.543414 17338 authenticator.cpp:326] Authentication requires more steps 3: I1130 23:14:59.543517 17338 authenticatee.cpp:259] Received SASL authentication step 3: I1130 23:14:59.543633 17326 authenticator.cpp:232] Received SASL authentication step 3: I1130 23:14:59.543660 17326 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c8a6051e98c' server FQDN: '1c8a6051e98c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1130 23:14:59.543671 17326 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1130 23:14:59.543714 17326 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1130 23:14:59.543735 17326 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c8a6051e98c' server FQDN: '1c8a6051e98c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1130 23:14:59.543743 17326 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1130 23:14:59.543751 17326 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1130 23:14:59.543766 17326 authenticator.cpp:318] Authentication success 3: I1130 23:14:59.543939 17327 master.cpp:8623] Successfully authenticated principal 'test-principal' at [email protected]:47218 3: I1130 23:14:59.543983 17338 authenticatee.cpp:299] Authentication success 3: I1130 23:14:59.544176 17331 state.cpp:64] Recovering state from '/tmp/PartitionTest_PartitionedSlaveExitedExecutor_oJpd1L/meta' 3: I1130 23:14:59.544198 17328 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(261)@172.17.0.4:47218 3: I1130 23:14:59.544358 17330 sched.cpp:502] Successfully authenticated with master [email protected]:47218 3: I1130 23:14:59.544379 17330 sched.cpp:824] Sending SUBSCRIBE call to [email protected]:47218 3: I1130 23:14:59.544533 17330 sched.cpp:857] Will retry registration in 1.212820585secs if necessary 3: I1130 23:14:59.544728 17328 master.cpp:2969] Received SUBSCRIBE call for framework 'default' at [email protected]:47218 3: I1130 23:14:59.544776 17329 task_status_update_manager.cpp:207] Recovering task status update manager 3: I1130 23:14:59.544816 17328 master.cpp:2286] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1130 23:14:59.545169 17327 slave.cpp:6513] Finished recovery 3: I1130 23:14:59.545367 17332 master.cpp:3049] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ] 3: I1130 23:14:59.546105 17332 sched.cpp:751] Framework registered with 14b9980a-ed30-46f6-a27c-1e70395f82c2-0000 3: I1130 23:14:59.546162 17337 hierarchical.cpp:293] Added framework 14b9980a-ed30-46f6-a27c-1e70395f82c2-0000 3: I1130 23:14:59.546380 17337 hierarchical.cpp:1431] Performed allocation for 0 agents in 81994ns 3: I1130 23:14:59.551998 17332 sched.cpp:765] Scheduler::registered took 5.866806ms 3: I1130 23:14:59.552206 17326 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1130 23:14:59.552268 17327 slave.cpp:999] New master detected at [email protected]:47218 3: I1130 23:14:59.552412 17327 slave.cpp:1034] Detecting new master 3: I1130 23:14:59.556793 17337 slave.cpp:1061] Authenticating with master [email protected]:47218 3: I1130 23:14:59.556869 17337 slave.cpp:1070] Using default CRAM-MD5 authenticatee 3: I1130 23:14:59.557268 17333 authenticatee.cpp:121] Creating new client SASL connection 3: I1130 23:14:59.557665 17329 master.cpp:8593] Authenticating slave(115)@172.17.0.4:47218 3: I1130 23:14:59.557776 17336 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(262)@172.17.0.4:47218 3: I1130 23:14:59.558054 17334 authenticator.cpp:98] Creating new server SASL connection 3: I1130 23:14:59.558312 17332 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1130 23:14:59.558338 17332 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1130 23:14:59.558468 17325 authenticator.cpp:204] Received SASL authentication start 3: I1130 23:14:59.558527 17325 authenticator.cpp:326] Authentication requires more steps 3: I1130 23:14:59.558643 17339 authenticatee.cpp:259] Received SASL authentication step 3: I1130 23:14:59.558794 17331 authenticator.cpp:232] Received SASL authentication step 3: I1130 23:14:59.558823 17331 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c8a6051e98c' server FQDN: '1c8a6051e98c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1130 23:14:59.558838 17331 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1130 23:14:59.558887 17331 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1130 23:14:59.558913 17331 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c8a6051e98c' server FQDN: '1c8a6051e98c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1130 23:14:59.558923 17331 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1130 23:14:59.558930 17331 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1130 23:14:59.558945 17331 authenticator.cpp:318] Authentication success 3: I1130 23:14:59.559087 17326 authenticatee.cpp:299] Authentication success 3: I1130 23:14:59.559216 17328 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(262)@172.17.0.4:47218 3: I1130 23:14:59.559326 17331 master.cpp:8623] Successfully authenticated principal 'test-principal' at slave(115)@172.17.0.4:47218 3: I1130 23:14:59.561213 17335 slave.cpp:1153] Successfully authenticated with master [email protected]:47218 3: I1130 23:14:59.561465 17335 slave.cpp:1696] Will retry registration in 18.844669ms if necessary 3: I1130 23:14:59.561784 17333 master.cpp:6042] Received register agent message from slave(115)@172.17.0.4:47218 (1c8a6051e98c) 3: I1130 23:14:59.561950 17333 master.cpp:3878] Authorizing agent with principal 'test-principal' write /dev/stdout: resource temporarily unavailable + docker rmi mesos-1512079003-9826 Error response from daemon: conflict: unable to remove repository reference "mesos-1512079003-9826" (must force) - container 1c8a6051e98c is using its referenced image e5d4a933f526 Build step 'Execute shell' marked build as failure Not sending mail to unregistered user [email protected] Not sending mail to unregistered user [email protected]
