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)/4555/display/redirect?page=changes>
Changes: [gregorywmann] Updated master ACCEPT handler to disallow offer operation feedback. [gregorywmann] Made master acknowledge offer operation updates when 'id' isn't set. [gregorywmann] Added ACKNOWLEDGE event to the resource provider API. [gregorywmann] Added offer operation update acknowledgement to the agent. [gregorywmann] Added status update acknowledgement to resource provider manager. [gregorywmann] Added plumbing for master to reconcile offer operations with agent. ------------------------------------------ [...truncated 13.44 MB...] 3: I1207 21:08:16.810310 17411 master.cpp:8815] Authenticating [email protected]:44498 3: I1207 21:08:16.810410 17410 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1207 21:08:16.810505 17419 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(617)@172.17.0.3:44498 3: I1207 21:08:16.810853 17420 authenticator.cpp:98] Creating new server SASL connection 3: I1207 21:08:16.811203 17426 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1207 21:08:16.811236 17426 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1207 21:08:16.811401 17425 authenticator.cpp:204] Received SASL authentication start 3: I1207 21:08:16.811491 17425 authenticator.cpp:326] Authentication requires more steps 3: I1207 21:08:16.811635 17430 authenticatee.cpp:259] Received SASL authentication step 3: I1207 21:08:16.811816 17429 authenticator.cpp:232] Received SASL authentication step 3: I1207 21:08:16.811862 17429 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'fc6ea3cde502' server FQDN: 'fc6ea3cde502' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1207 21:08:16.811880 17429 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1207 21:08:16.811925 17429 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1207 21:08:16.811954 17429 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'fc6ea3cde502' server FQDN: 'fc6ea3cde502' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1207 21:08:16.811964 17429 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1207 21:08:16.811972 17429 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1207 21:08:16.811991 17429 authenticator.cpp:318] Authentication success 3: I1207 21:08:16.812139 17412 authenticatee.cpp:299] Authentication success 3: I1207 21:08:16.812263 17433 master.cpp:8845] Successfully authenticated principal 'test-principal' at [email protected]:44498 3: I1207 21:08:16.812326 17418 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(617)@172.17.0.3:44498 3: I1207 21:08:16.812561 17415 sched.cpp:502] Successfully authenticated with master [email protected]:44498 3: I1207 21:08:16.812584 17415 sched.cpp:824] Sending SUBSCRIBE call to [email protected]:44498 3: I1207 21:08:16.812702 17422 state.cpp:66] Recovering state from '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_loxcSW/meta' 3: I1207 21:08:16.812741 17415 sched.cpp:857] Will retry registration in 1.001115464secs if necessary 3: I1207 21:08:16.813060 17431 master.cpp:2960] Received SUBSCRIBE call for framework 'default' at [email protected]:44498 3: I1207 21:08:16.813127 17413 task_status_update_manager.cpp:207] Recovering task status update manager 3: I1207 21:08:16.813168 17431 master.cpp:2277] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1207 21:08:16.813724 17411 slave.cpp:6679] Finished recovery 3: I1207 21:08:16.813966 17419 master.cpp:3040] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] 3: I1207 21:08:16.814225 17419 master.cpp:9036] Adding framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 (default) at [email protected]:44498 with roles { } suppressed 3: I1207 21:08:16.814903 17425 sched.cpp:751] Framework registered with 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.814913 17428 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1207 21:08:16.814918 17416 slave.cpp:1031] New master detected at [email protected]:44498 3: I1207 21:08:16.814965 17425 sched.cpp:765] Scheduler::registered took 26251ns 3: I1207 21:08:16.815089 17416 slave.cpp:1086] Detecting new master 3: I1207 21:08:16.815130 17426 hierarchical.cpp:297] Added framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.815493 17426 hierarchical.cpp:1527] Performed allocation for 0 agents in 106341ns 3: I1207 21:08:16.824501 17427 slave.cpp:1113] Authenticating with master [email protected]:44498 3: I1207 21:08:16.824580 17427 slave.cpp:1122] Using default CRAM-MD5 authenticatee 3: I1207 21:08:16.824852 17418 authenticatee.cpp:121] Creating new client SASL connection 3: I1207 21:08:16.825191 17421 master.cpp:8815] Authenticating slave(312)@172.17.0.3:44498 3: I1207 21:08:16.825361 17415 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(618)@172.17.0.3:44498 3: I1207 21:08:16.825655 17422 authenticator.cpp:98] Creating new server SASL connection 3: I1207 21:08:16.825920 17414 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1207 21:08:16.825951 17414 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1207 21:08:16.826083 17424 authenticator.cpp:204] Received SASL authentication start 3: I1207 21:08:16.826151 17424 authenticator.cpp:326] Authentication requires more steps 3: I1207 21:08:16.826288 17413 authenticatee.cpp:259] Received SASL authentication step 3: I1207 21:08:16.826442 17410 authenticator.cpp:232] Received SASL authentication step 3: I1207 21:08:16.826481 17410 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'fc6ea3cde502' server FQDN: 'fc6ea3cde502' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1207 21:08:16.826499 17410 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1207 21:08:16.826536 17410 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1207 21:08:16.826565 17410 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'fc6ea3cde502' server FQDN: 'fc6ea3cde502' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1207 21:08:16.826578 17410 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1207 21:08:16.826586 17410 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1207 21:08:16.826606 17410 authenticator.cpp:318] Authentication success 3: I1207 21:08:16.826712 17417 authenticatee.cpp:299] Authentication success 3: I1207 21:08:16.826823 17431 master.cpp:8845] Successfully authenticated principal 'test-principal' at slave(312)@172.17.0.3:44498 3: I1207 21:08:16.826867 17411 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(618)@172.17.0.3:44498 3: I1207 21:08:16.827118 17423 slave.cpp:1205] Successfully authenticated with master [email protected]:44498 3: I1207 21:08:16.827415 17423 slave.cpp:1748] Will retry registration in 10.836693ms if necessary 3: I1207 21:08:16.827697 17412 master.cpp:6082] Received register agent message from slave(312)@172.17.0.3:44498 (fc6ea3cde502) 3: I1207 21:08:16.827906 17412 master.cpp:3869] Authorizing agent with principal 'test-principal' 3: I1207 21:08:16.828474 17425 master.cpp:6158] Authorized registration of agent at slave(312)@172.17.0.3:44498 (fc6ea3cde502) 3: I1207 21:08:16.828611 17425 master.cpp:6251] Registering agent at slave(312)@172.17.0.3:44498 (fc6ea3cde502) with id 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 3: I1207 21:08:16.829247 17428 registrar.cpp:495] Applied 1 operations in 112524ns; attempting to update the registry 3: I1207 21:08:16.830049 17428 registrar.cpp:552] Successfully updated the registry in 727808ns 3: I1207 21:08:16.830328 17418 master.cpp:6300] Admitted agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) 3: I1207 21:08:16.831223 17418 master.cpp:6336] Registered agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) with cpus:2; mem:1024; disk:367463; ports:[31000-32000] 3: I1207 21:08:16.831305 17415 slave.cpp:1251] Registered with master [email protected]:44498; given agent ID 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 3: I1207 21:08:16.831468 17424 task_status_update_manager.cpp:188] Resuming sending task status updates 3: I1207 21:08:16.831593 17422 hierarchical.cpp:577] Added agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 (fc6ea3cde502) with cpus:2; mem:1024; disk:367463; ports:[31000-32000] (allocated: {}) 3: I1207 21:08:16.831665 17415 slave.cpp:1271] Checkpointing SlaveInfo to '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_loxcSW/meta/slaves/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0/slave.info' 3: I1207 21:08:16.832170 17415 slave.cpp:1350] Forwarding total oversubscribed resources {} 3: I1207 21:08:16.832396 17417 master.cpp:7230] Received update of agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) with total oversubscribed resources {} 3: I1207 21:08:16.832633 17417 master.cpp:7273] Ignoring update on agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) as it reports no changes 3: I1207 21:08:16.833160 17422 hierarchical.cpp:1527] Performed allocation for 1 agents in 1.368949ms 3: I1207 21:08:16.833782 17410 master.cpp:8645] Sending 1 offers to framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 (default) at [email protected]:44498 3: I1207 21:08:16.835302 17429 sched.cpp:921] Scheduler::resourceOffers took 1.014719ms 3: I1207 21:08:16.836758 17431 master.cpp:10565] Removing offer 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-O0 3: I1207 21:08:16.836936 17431 master.cpp:4276] Processing ACCEPT call for offers: [ 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-O0 ] on agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) for framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 (default) at [email protected]:44498 3: I1207 21:08:16.837074 17431 master.cpp:3596] Authorizing framework principal 'test-principal' to launch task 0 3: W1207 21:08:16.839011 17430 validation.cpp:1388] Executor 'default' for task '0' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases. 3: W1207 21:08:16.839052 17430 validation.cpp:1400] Executor 'default' for task '0' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases. 3: I1207 21:08:16.839560 17430 master.cpp:11317] Adding task 0 with resources cpus(allocated: *):1; mem(allocated: *):500 on agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) 3: I1207 21:08:16.839821 17430 master.cpp:5024] Launching task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 (default) at [email protected]:44498 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":500.0},"type":"SCALAR"}] on agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) 3: I1207 21:08:16.840468 17423 slave.cpp:1869] Got assigned task '0' for framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.841178 17423 slave.cpp:2137] Authorizing task '0' for framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.841248 17423 slave.cpp:7573] Authorizing framework principal 'test-principal' to launch task 0 3: I1207 21:08:16.841356 17412 hierarchical.cpp:1202] Recovered cpus(allocated: *):1; mem(allocated: *):524; disk(allocated: *):367463; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:367463; ports:[31000-32000], allocated: cpus(allocated: *):1; mem(allocated: *):500) on agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 from framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.841459 17412 hierarchical.cpp:1248] Framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 filtered agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 for 5secs 3: I1207 21:08:16.842104 17416 slave.cpp:2305] Launching task '0' for framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.842736 17416 paths.cpp:702] Trying to chown '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_loxcSW/slaves/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0/frameworks/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000/executors/default/runs/9bf74b42-bc85-47bb-b4ee-14a1033c61fd' to user 'mesos' 3: I1207 21:08:16.843017 17416 slave.cpp:8047] Launching executor 'default' of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 with resources [] in work directory '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_loxcSW/slaves/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0/frameworks/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000/executors/default/runs/9bf74b42-bc85-47bb-b4ee-14a1033c61fd' 3: I1207 21:08:16.843592 17416 slave.cpp:2996] Launching container 9bf74b42-bc85-47bb-b4ee-14a1033c61fd for executor 'default' of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.843940 17416 slave.cpp:2533] Queued task '0' for executor 'default' of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.844039 17416 slave.cpp:982] Successfully attached '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_loxcSW/slaves/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0/frameworks/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000/executors/default/runs/9bf74b42-bc85-47bb-b4ee-14a1033c61fd' to virtual path '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_loxcSW/slaves/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0/frameworks/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000/executors/default/runs/latest' 3: I1207 21:08:16.844092 17416 slave.cpp:982] Successfully attached '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_loxcSW/slaves/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0/frameworks/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000/executors/default/runs/9bf74b42-bc85-47bb-b4ee-14a1033c61fd' to virtual path '/frameworks/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000/executors/default/runs/latest' 3: I1207 21:08:16.844135 17416 slave.cpp:982] Successfully attached '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_loxcSW/slaves/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0/frameworks/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000/executors/default/runs/9bf74b42-bc85-47bb-b4ee-14a1033c61fd' to virtual path '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_loxcSW/slaves/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0/frameworks/02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000/executors/default/runs/9bf74b42-bc85-47bb-b4ee-14a1033c61fd' 3: W1207 21:08:16.846381 17428 process.cpp:2756] Attempted to spawn already running process [email protected]:44498 3: I1207 21:08:16.846587 17428 exec.cpp:162] Version: 1.5.0 3: I1207 21:08:16.846896 17414 exec.cpp:212] Executor started at: executor(112)@172.17.0.3:44498 with pid 17409 3: I1207 21:08:16.847138 17414 slave.cpp:4230] Got registration for executor 'default' of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 from executor(112)@172.17.0.3:44498 3: I1207 21:08:16.847525 17424 exec.cpp:237] Executor registered on agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 3: I1207 21:08:16.847573 17424 exec.cpp:249] Executor::registered took 24891ns 3: I1207 21:08:16.848037 17414 slave.cpp:2735] Sending queued task '0' to executor 'default' of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 at executor(112)@172.17.0.3:44498 3: I1207 21:08:16.848417 17415 exec.cpp:331] Executor asked to run task '0' 3: I1207 21:08:16.848515 17415 exec.cpp:340] Executor::launchTask took 76597ns 3: I1207 21:08:16.848631 17415 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID: 0737dcf2-32ff-4862-b5e3-e1b7c844468d) for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.848964 17417 slave.cpp:4684] Handling status update TASK_RUNNING (UUID: 0737dcf2-32ff-4862-b5e3-e1b7c844468d) for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 from executor(112)@172.17.0.3:44498 3: I1207 21:08:16.849673 17429 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (UUID: 0737dcf2-32ff-4862-b5e3-e1b7c844468d) for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.849725 17429 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.850134 17429 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (UUID: 0737dcf2-32ff-4862-b5e3-e1b7c844468d) for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 to the agent 3: I1207 21:08:16.850337 17419 slave.cpp:5167] Forwarding the update TASK_RUNNING (UUID: 0737dcf2-32ff-4862-b5e3-e1b7c844468d) for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 to [email protected]:44498 3: I1207 21:08:16.850594 17419 slave.cpp:5060] Task status update manager successfully handled status update TASK_RUNNING (UUID: 0737dcf2-32ff-4862-b5e3-e1b7c844468d) for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.850662 17419 slave.cpp:5076] Sending acknowledgement for status update TASK_RUNNING (UUID: 0737dcf2-32ff-4862-b5e3-e1b7c844468d) for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 to executor(112)@172.17.0.3:44498 3: I1207 21:08:16.850814 17431 master.cpp:7738] Status update TASK_RUNNING (UUID: 0737dcf2-32ff-4862-b5e3-e1b7c844468d) for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 from agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) 3: I1207 21:08:16.850865 17420 exec.cpp:388] Executor received status update acknowledgement 0737dcf2-32ff-4862-b5e3-e1b7c844468d for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.850879 17431 master.cpp:7794] Forwarding status update TASK_RUNNING (UUID: 0737dcf2-32ff-4862-b5e3-e1b7c844468d) for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.851094 17431 master.cpp:10041] Updating the state of task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING) 3: I1207 21:08:16.851361 17411 sched.cpp:1029] Scheduler::statusUpdate took 95850ns 3: I1207 21:08:16.851730 17412 master.cpp:5839] Processing ACKNOWLEDGE call 0737dcf2-32ff-4862-b5e3-e1b7c844468d for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 (default) at [email protected]:44498 on agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 3: I1207 21:08:16.852104 17421 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 0737dcf2-32ff-4862-b5e3-e1b7c844468d) for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.852408 17418 slave.cpp:3968] Task status update manager successfully handled status update acknowledgement (UUID: 0737dcf2-32ff-4862-b5e3-e1b7c844468d) for task 0 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.853000 17409 master.cpp:1150] Master terminating 3: W1207 21:08:16.853163 17409 master.cpp:10131] Removing task 0 with resources cpus(allocated: *):1; mem(allocated: *):500 of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 on agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) in non-removable state TASK_RUNNING 3: I1207 21:08:16.853652 17409 master.cpp:10176] Removing executor 'default' with resources [] of framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 on agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) 3: I1207 21:08:16.853687 17429 hierarchical.cpp:610] Removed agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 3: I1207 21:08:16.854481 17429 hierarchical.cpp:349] Removed framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.854617 17426 slave.cpp:5299] Got exited event for [email protected]:44498 3: W1207 21:08:16.854645 17426 slave.cpp:5304] Master disconnected! Waiting for a new master to be elected 3: I1207 21:08:16.860826 17409 cluster.cpp:172] Creating default 'local' authorizer 3: I1207 21:08:16.863589 17412 master.cpp:454] Master 1832d98a-28a5-46c1-b80c-e4d9ddf32004 (fc6ea3cde502) started on 172.17.0.3:44498 3: I1207 21:08:16.863615 17412 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/LcnGxR/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/LcnGxR/master" --zk_session_timeout="10secs" 3: I1207 21:08:16.864076 17412 master.cpp:505] Master only allowing authenticated frameworks to register 3: I1207 21:08:16.864092 17412 master.cpp:511] Master only allowing authenticated agents to register 3: I1207 21:08:16.864101 17412 master.cpp:517] Master only allowing authenticated HTTP frameworks to register 3: I1207 21:08:16.864110 17412 credentials.hpp:37] Loading credentials for authentication from '/tmp/LcnGxR/credentials' 3: I1207 21:08:16.864495 17412 master.cpp:561] Using default 'crammd5' authenticator 3: I1207 21:08:16.864673 17412 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1207 21:08:16.864876 17412 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1207 21:08:16.865054 17412 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1207 21:08:16.865226 17412 master.cpp:640] Authorization enabled 3: I1207 21:08:16.865475 17420 whitelist_watcher.cpp:77] No whitelist given 3: I1207 21:08:16.865481 17419 hierarchical.cpp:175] Initialized hierarchical allocator process 3: I1207 21:08:16.869366 17431 master.cpp:2212] Elected as the leading master! 3: I1207 21:08:16.869392 17431 master.cpp:1692] Recovering from registrar 3: I1207 21:08:16.869530 17429 registrar.cpp:347] Recovering registrar 3: I1207 21:08:16.870172 17429 registrar.cpp:391] Successfully fetched the registry (0B) in 605184ns 3: I1207 21:08:16.870272 17429 registrar.cpp:495] Applied 1 operations in 30570ns; attempting to update the registry 3: I1207 21:08:16.870807 17429 registrar.cpp:552] Successfully updated the registry in 487168ns 3: I1207 21:08:16.870925 17429 registrar.cpp:424] Successfully recovered registrar 3: I1207 21:08:16.871373 17418 master.cpp:1805] Recovered 0 agents from the registry (135B); allowing 10mins for agents to re-register 3: I1207 21:08:16.871383 17417 hierarchical.cpp:213] Skipping recovery of hierarchical allocator: nothing to recover 3: I1207 21:08:16.871948 17411 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1207 21:08:16.871960 17423 slave.cpp:1031] New master detected at [email protected]:44498 3: I1207 21:08:16.872054 17423 slave.cpp:1086] Detecting new master 3: I1207 21:08:16.881315 17425 slave.cpp:1113] Authenticating with master [email protected]:44498 3: I1207 21:08:16.881371 17425 slave.cpp:1122] Using default CRAM-MD5 authenticatee 3: I1207 21:08:16.881590 17431 authenticatee.cpp:121] Creating new client SASL connection 3: I1207 21:08:16.881850 17432 master.cpp:8815] Authenticating slave(312)@172.17.0.3:44498 3: I1207 21:08:16.881960 17427 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(619)@172.17.0.3:44498 3: I1207 21:08:16.882187 17430 authenticator.cpp:98] Creating new server SASL connection 3: I1207 21:08:16.882386 17426 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1207 21:08:16.882407 17426 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1207 21:08:16.882508 17416 authenticator.cpp:204] Received SASL authentication start 3: I1207 21:08:16.882557 17416 authenticator.cpp:326] Authentication requires more steps 3: I1207 21:08:16.882648 17424 authenticatee.cpp:259] Received SASL authentication step 3: I1207 21:08:16.882764 17421 authenticator.cpp:232] Received SASL authentication step 3: I1207 21:08:16.882794 17421 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'fc6ea3cde502' server FQDN: 'fc6ea3cde502' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1207 21:08:16.882805 17421 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1207 21:08:16.882832 17421 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1207 21:08:16.882856 17421 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'fc6ea3cde502' server FQDN: 'fc6ea3cde502' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1207 21:08:16.882867 17421 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1207 21:08:16.882872 17421 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1207 21:08:16.882885 17421 authenticator.cpp:318] Authentication success 3: I1207 21:08:16.882992 17428 authenticatee.cpp:299] Authentication success 3: I1207 21:08:16.883030 17413 master.cpp:8845] Successfully authenticated principal 'test-principal' at slave(312)@172.17.0.3:44498 3: I1207 21:08:16.883085 17429 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(619)@172.17.0.3:44498 3: I1207 21:08:16.883242 17422 slave.cpp:1205] Successfully authenticated with master [email protected]:44498 3: I1207 21:08:16.883617 17422 slave.cpp:1748] Will retry registration in 11.843015ms if necessary 3: I1207 21:08:16.883962 17418 master.cpp:6415] Received re-register agent message from agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) 3: I1207 21:08:16.884038 17418 master.cpp:3869] Authorizing agent with principal 'test-principal' 3: I1207 21:08:16.884413 17433 master.cpp:6504] Authorized re-registration of agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) 3: I1207 21:08:16.884480 17433 master.cpp:6644] Consulting registry about agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498(fc6ea3cde502) 3: W1207 21:08:16.884827 17419 registry_operations.cpp:185] Allowing UNKNOWN agent to reregister: hostname: "fc6ea3cde502" 3: resources { 3: name: "cpus" 3: type: SCALAR 3: scalar { 3: value: 2 3: } 3: } 3: resources { 3: name: "mem" 3: type: SCALAR 3: scalar { 3: value: 1024 3: } 3: } 3: resources { 3: name: "disk" 3: type: SCALAR 3: scalar { 3: value: 367463 3: } 3: } 3: resources { 3: name: "ports" 3: type: RANGES 3: ranges { 3: range { 3: begin: 31000 3: end: 32000 3: } 3: } 3: } 3: id { 3: value: "02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0" 3: } 3: checkpoint: true 3: port: 44498 3: I1207 21:08:16.885090 17419 registrar.cpp:495] Applied 1 operations in 285284ns; attempting to update the registry 3: I1207 21:08:16.885612 17419 registrar.cpp:552] Successfully updated the registry in 473856ns 3: I1207 21:08:16.885776 17431 master.cpp:6695] Re-admitted agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) 3: I1207 21:08:16.886245 17431 master.cpp:11317] Adding task 0 with resources cpus(allocated: *):1; mem(allocated: *):500 on agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) 3: I1207 21:08:16.886734 17431 master.cpp:6858] Re-registered agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) with cpus:2; mem:1024; disk:367463; ports:[31000-32000] 3: I1207 21:08:16.886780 17424 slave.cpp:1395] Re-registered with master [email protected]:44498 3: I1207 21:08:16.886783 17431 master.cpp:7092] Recovering framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 from re-registering agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) 3: I1207 21:08:16.886879 17414 task_status_update_manager.cpp:188] Resuming sending task status updates 3: I1207 21:08:16.886914 17424 slave.cpp:1463] Forwarding total oversubscribed resources {} 3: I1207 21:08:16.887068 17431 master.cpp:9036] Adding framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 (default) with roles { } suppressed 3: I1207 21:08:16.887110 17430 hierarchical.cpp:577] Added agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 (fc6ea3cde502) with cpus:2; mem:1024; disk:367463; ports:[31000-32000] (allocated: cpus(allocated: *):1; mem(allocated: *):500) 3: I1207 21:08:16.887526 17431 master.cpp:7230] Received update of agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) with total oversubscribed resources {} 3: I1207 21:08:16.887699 17431 master.cpp:7273] Ignoring update on agent 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-S0 at slave(312)@172.17.0.3:44498 (fc6ea3cde502) as it reports no changes 3: I1207 21:08:16.887881 17425 sched.cpp:330] Scheduler::disconnected took 22648ns 3: I1207 21:08:16.887900 17425 sched.cpp:336] New master detected at [email protected]:44498 3: I1207 21:08:16.887958 17430 hierarchical.cpp:297] Added framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.888000 17425 sched.cpp:396] Authenticating with master [email protected]:44498 3: I1207 21:08:16.888002 17430 hierarchical.cpp:410] Deactivated framework 02f7d4fa-f075-4cd3-8025-fe0c47a764fd-0000 3: I1207 21:08:16.888018 17425 sched.cpp:403] Using default CRAM-MD5 authenticatee 3: I1207 21:08:16.888237 17419 authenticatee.cpp:121] Creating new client SASL connection 3: I1207 21:08:16.888304 17430 hierarchical.cpp:1527] Performed allocation for 1 agents in 195905ns 3: I1207 21:08:16.888444 17430 master.cpp:8815] Authenticating [email protected]:44498 3: I1207 21:08:16.888546 17416 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(620)@172.17.0.3:44498 3: I1207 21:08:16.888748 17426 authenticator.cpp:98] Creating new server SASL connection write /dev/stdout: resource temporarily unavailable Build step 'Execute shell' marked build as failure Not sending mail to unregistered user [email protected]
