See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4492/display/redirect?page=changes>
Changes: [bmahler] Optimized resources logging in master. ------------------------------------------ [...truncated 7.27 MB...] 3: I1122 22:04:01.680599 20043 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1122 22:04:01.680635 20043 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1122 22:04:01.680655 20043 auxprop.cpp:109] Request to lookup properties for user: 'test-principal-2' realm: '987dffa45d9c' server FQDN: '987dffa45d9c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1122 22:04:01.680665 20043 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1122 22:04:01.680671 20043 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1122 22:04:01.680685 20043 authenticator.cpp:318] Authentication success 3: I1122 22:04:01.680800 20044 authenticatee.cpp:299] Authentication success 3: I1122 22:04:01.680860 20046 master.cpp:8342] Successfully authenticated principal 'test-principal-2' at [email protected]:35264 3: I1122 22:04:01.680910 20037 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(347)@172.17.0.2:35264 3: I1122 22:04:01.681049 20042 sched.cpp:502] Successfully authenticated with master [email protected]:35264 3: I1122 22:04:01.681074 20042 sched.cpp:824] Sending SUBSCRIBE call to [email protected]:35264 3: I1122 22:04:01.681176 20042 sched.cpp:857] Will retry registration in 585.236252ms if necessary 3: I1122 22:04:01.681437 20047 master.cpp:2963] Received SUBSCRIBE call for framework 'framework-muggle' at [email protected]:35264 3: I1122 22:04:01.681563 20047 master.cpp:2280] Authorizing framework principal 'test-principal-2' to receive offers for roles '{ muggle }' 3: I1122 22:04:01.682106 20040 master.cpp:3043] Subscribing framework framework-muggle with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ] 3: I1122 22:04:01.682896 20050 sched.cpp:751] Framework registered with 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.683037 20050 sched.cpp:765] Scheduler::registered took 97982ns 3: I1122 22:04:01.683230 20038 hierarchical.cpp:306] Added framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.685714 20038 hierarchical.cpp:1457] Performed allocation for 1 agents in 2.239995ms 3: I1122 22:04:01.686143 20052 master.cpp:8142] Sending 1 offers to framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 (framework-muggle) at [email protected]:35264 3: I1122 22:04:01.686646 20043 sched.cpp:921] Scheduler::resourceOffers took 103630ns 3: I1122 22:04:01.688982 20042 master.cpp:10057] Removing offer 1a5b1511-a9f5-49cb-8824-470a109f5b8b-O1 3: I1122 22:04:01.689254 20042 master.cpp:4230] Processing ACCEPT call for offers: [ 1a5b1511-a9f5-49cb-8824-470a109f5b8b-O1 ] on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) for framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 (framework-muggle) at [email protected]:35264 3: I1122 22:04:01.689452 20042 master.cpp:3599] Authorizing framework principal 'test-principal-2' to launch task 2 3: W1122 22:04:01.691474 20040 validation.cpp:1391] Executor 'test-executor-muggle' for task '2' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases. 3: W1122 22:04:01.691514 20040 validation.cpp:1403] Executor 'test-executor-muggle' for task '2' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases. 3: I1122 22:04:01.692132 20040 master.cpp:10808] Adding task 2 with resources mem(allocated: muggle)(reservations: [(STATIC,muggle)]):1024; cpus(allocated: muggle)(reservations: [(STATIC,muggle)]):3 on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) 3: I1122 22:04:01.692472 20040 master.cpp:4978] Launching task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 (framework-muggle) at [email protected]:35264 with resources [{"allocation_info":{"role":"muggle"},"name":"mem","reservations":[{"role":"muggle","type":"STATIC"}],"scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"muggle"},"name":"cpus","reservations":[{"role":"muggle","type":"STATIC"}],"scalar":{"value":3.0},"type":"SCALAR"}] on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) 3: I1122 22:04:01.693156 20045 slave.cpp:1806] Got assigned task '2' for framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.693817 20045 slave.cpp:2074] Authorizing task '2' for framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.693881 20045 slave.cpp:7270] Authorizing framework principal 'test-principal-2' to launch task 2 3: I1122 22:04:01.695022 20053 slave.cpp:2242] Launching task '2' for framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.695809 20053 paths.cpp:621] Trying to chown '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001/executors/test-executor-muggle/runs/23df3b2f-27ae-46bc-b0de-e51d78a2406c' to user 'foo' 3: W1122 22:04:01.695936 20053 paths.cpp:629] Failed to chown executor directory '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001/executors/test-executor-muggle/runs/23df3b2f-27ae-46bc-b0de-e51d78a2406c'. This may be due to attempting to run the executor as a nonexistent user on the agent; see the description for the `--switch_user` flag for more information: Failed to get user information for 'foo': Success 3: I1122 22:04:01.696086 20053 slave.cpp:7744] Launching executor 'test-executor-muggle' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 with resources [] in work directory '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001/executors/test-executor-muggle/runs/23df3b2f-27ae-46bc-b0de-e51d78a2406c' 3: I1122 22:04:01.697371 20053 slave.cpp:2470] Queued task '2' for executor 'test-executor-muggle' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.697484 20053 slave.cpp:958] Successfully attached '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001/executors/test-executor-muggle/runs/23df3b2f-27ae-46bc-b0de-e51d78a2406c' to virtual path '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001/executors/test-executor-muggle/runs/latest' 3: I1122 22:04:01.697536 20053 slave.cpp:958] Successfully attached '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001/executors/test-executor-muggle/runs/23df3b2f-27ae-46bc-b0de-e51d78a2406c' to virtual path '/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001/executors/test-executor-muggle/runs/latest' 3: I1122 22:04:01.697579 20053 slave.cpp:958] Successfully attached '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001/executors/test-executor-muggle/runs/23df3b2f-27ae-46bc-b0de-e51d78a2406c' to virtual path '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001/executors/test-executor-muggle/runs/23df3b2f-27ae-46bc-b0de-e51d78a2406c' 3: I1122 22:04:01.697963 20053 slave.cpp:2933] Launching container 23df3b2f-27ae-46bc-b0de-e51d78a2406c for executor 'test-executor-muggle' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: W1122 22:04:01.701584 20057 process.cpp:2756] Attempted to spawn already running process [email protected]:35264 3: I1122 22:04:01.701843 20057 exec.cpp:162] Version: 1.5.0 3: I1122 22:04:01.702199 20038 exec.cpp:212] Executor started at: executor(42)@172.17.0.2:35264 with pid 20035 3: I1122 22:04:01.702453 20052 slave.cpp:4066] Got registration for executor 'test-executor-muggle' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 from executor(42)@172.17.0.2:35264 3: I1122 22:04:01.702927 20043 exec.cpp:237] Executor registered on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 3: I1122 22:04:01.702975 20043 exec.cpp:249] Executor::registered took 22363ns 3: I1122 22:04:01.703369 20052 slave.cpp:2672] Sending queued task '2' to executor 'test-executor-muggle' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 at executor(42)@172.17.0.2:35264 3: I1122 22:04:01.703861 20044 exec.cpp:331] Executor asked to run task '2' 3: I1122 22:04:01.703990 20044 exec.cpp:340] Executor::launchTask took 88373ns 3: I1122 22:04:01.704128 20044 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID: ac65aa56-73ff-40c1-9b52-ce8396b1a6b9) for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.704511 20044 slave.cpp:4520] Handling status update TASK_RUNNING (UUID: ac65aa56-73ff-40c1-9b52-ce8396b1a6b9) for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 from executor(42)@172.17.0.2:35264 3: I1122 22:04:01.705251 20039 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (UUID: ac65aa56-73ff-40c1-9b52-ce8396b1a6b9) for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.705301 20039 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.705816 20039 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (UUID: ac65aa56-73ff-40c1-9b52-ce8396b1a6b9) for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 to the agent 3: I1122 22:04:01.706118 20059 slave.cpp:5003] Forwarding the update TASK_RUNNING (UUID: ac65aa56-73ff-40c1-9b52-ce8396b1a6b9) for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 to [email protected]:35264 3: I1122 22:04:01.706424 20059 slave.cpp:4896] Task status update manager successfully handled status update TASK_RUNNING (UUID: ac65aa56-73ff-40c1-9b52-ce8396b1a6b9) for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.706490 20059 slave.cpp:4912] Sending acknowledgement for status update TASK_RUNNING (UUID: ac65aa56-73ff-40c1-9b52-ce8396b1a6b9) for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 to executor(42)@172.17.0.2:35264 3: I1122 22:04:01.706656 20047 master.cpp:7274] Status update TASK_RUNNING (UUID: ac65aa56-73ff-40c1-9b52-ce8396b1a6b9) for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 from agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) 3: I1122 22:04:01.706717 20042 exec.cpp:388] Executor received status update acknowledgement ac65aa56-73ff-40c1-9b52-ce8396b1a6b9 for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.706732 20047 master.cpp:7336] Forwarding status update TASK_RUNNING (UUID: ac65aa56-73ff-40c1-9b52-ce8396b1a6b9) for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.706996 20047 master.cpp:9529] Updating the state of task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 (latest state: TASK_RUNNING, status update state: TASK_RUNNING) 3: I1122 22:04:01.707346 20051 sched.cpp:1029] Scheduler::statusUpdate took 114320ns 3: I1122 22:04:01.707759 20051 master.cpp:5793] Processing ACKNOWLEDGE call ac65aa56-73ff-40c1-9b52-ce8396b1a6b9 for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 (framework-muggle) at [email protected]:35264 on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 3: I1122 22:04:01.708210 20056 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: ac65aa56-73ff-40c1-9b52-ce8396b1a6b9) for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.708566 20049 slave.cpp:3804] Task status update manager successfully handled status update acknowledgement (UUID: ac65aa56-73ff-40c1-9b52-ce8396b1a6b9) for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.710278 20043 process.cpp:3503] Handling HTTP event for process 'slave(146)' with path: '/slave(146)/state' 3: I1122 22:04:01.712779 20047 http.cpp:1185] HTTP GET for /slave(146)/state from 172.17.0.2:57064 3: I1122 22:04:01.730600 20042 process.cpp:3503] Handling HTTP event for process 'slave(146)' with path: '/slave(146)/state' 3: I1122 22:04:01.732993 20036 http.cpp:1185] HTTP GET for /slave(146)/state from 172.17.0.2:57066 3: I1122 22:04:01.740792 20035 sched.cpp:2009] Asked to stop the driver 3: I1122 22:04:01.740924 20037 sched.cpp:1191] Stopping framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 3: I1122 22:04:01.741214 20035 sched.cpp:2009] Asked to stop the driver 3: I1122 22:04:01.741204 20042 master.cpp:8819] Processing TEARDOWN call for framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 (framework-superhero) at [email protected]:35264 3: I1122 22:04:01.741247 20042 master.cpp:8831] Removing framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 (framework-superhero) at [email protected]:35264 3: I1122 22:04:01.741266 20042 master.cpp:3333] Deactivating framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 (framework-superhero) at [email protected]:35264 3: I1122 22:04:01.741413 20040 sched.cpp:1191] Stopping framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.741542 20047 hierarchical.cpp:419] Deactivated framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 3: I1122 22:04:01.741638 20048 slave.cpp:3270] Asked to shut down framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 by [email protected]:35264 3: I1122 22:04:01.741653 20042 master.cpp:9529] Updating the state of task 1 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED) 3: I1122 22:04:01.741701 20048 slave.cpp:3295] Shutting down framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 3: I1122 22:04:01.741770 20048 slave.cpp:5879] Shutting down executor 'test-executor-superhero' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 at executor(41)@172.17.0.2:35264 3: I1122 22:04:01.741961 20036 exec.cpp:435] Executor asked to shutdown 3: I1122 22:04:01.742020 20036 exec.cpp:450] Executor::shutdown took 29883ns 3: I1122 22:04:01.742316 20051 slave.cpp:5135] Got exited event for executor(41)@172.17.0.2:35264 3: I1122 22:04:01.743155 20042 master.cpp:9629] Removing task 1 with resources cpus(allocated: superhero)(reservations: [(STATIC,superhero)]):2; mem(allocated: superhero)(reservations: [(STATIC,superhero)]):512; disk(allocated: superhero):367463; ports(allocated: superhero):[31000-32000] of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) 3: I1122 22:04:01.743644 20042 master.cpp:9658] Removing executor 'test-executor-superhero' with resources [] of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) 3: I1122 22:04:01.743654 20041 hierarchical.cpp:1132] Recovered cpus(allocated: superhero)(reservations: [(STATIC,superhero)]):2; mem(allocated: superhero)(reservations: [(STATIC,superhero)]):512; disk(allocated: superhero):367463; ports(allocated: superhero):[31000-32000] (total: cpus(reservations: [(STATIC,superhero)]):2; cpus(reservations: [(STATIC,muggle)]):3; mem(reservations: [(STATIC,superhero)]):512; mem(reservations: [(STATIC,muggle)]):1024; disk:367463; ports:[31000-32000], allocated: cpus(allocated: muggle)(reservations: [(STATIC,muggle)]):3; mem(allocated: muggle)(reservations: [(STATIC,muggle)]):1024) on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 from framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 3: I1122 22:04:01.744751 20042 master.cpp:8819] Processing TEARDOWN call for framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 (framework-muggle) at [email protected]:35264 3: I1122 22:04:01.744777 20053 hierarchical.cpp:358] Removed framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 3: I1122 22:04:01.744794 20042 master.cpp:8831] Removing framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 (framework-muggle) at [email protected]:35264 3: I1122 22:04:01.744814 20042 master.cpp:3333] Deactivating framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 (framework-muggle) at [email protected]:35264 3: I1122 22:04:01.744961 20045 slave.cpp:5544] Executor 'test-executor-superhero' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 exited with status 0 3: I1122 22:04:01.745028 20042 master.cpp:9529] Updating the state of task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 (latest state: TASK_KILLED, status update state: TASK_KILLED) 3: I1122 22:04:01.745126 20043 hierarchical.cpp:419] Deactivated framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.745112 20045 slave.cpp:5648] Cleaning up executor 'test-executor-superhero' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 at executor(41)@172.17.0.2:35264 3: I1122 22:04:01.745643 20040 gc.cpp:90] Scheduling '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000/executors/test-executor-superhero/runs/0a961748-aeb5-41b7-aeef-641cdbb34022' for gc 6.99999137191111days in the future 3: I1122 22:04:01.745832 20045 slave.cpp:5755] Cleaning up framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 3: I1122 22:04:01.745839 20042 master.cpp:9629] Removing task 2 with resources mem(allocated: muggle)(reservations: [(STATIC,muggle)]):1024; cpus(allocated: muggle)(reservations: [(STATIC,muggle)]):3 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) 3: I1122 22:04:01.745879 20040 gc.cpp:90] Scheduling '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000/executors/test-executor-superhero' for gc 6.99999136895704days in the future 3: I1122 22:04:01.746035 20057 task_status_update_manager.cpp:289] Closing task status update streams for framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 3: I1122 22:04:01.746110 20057 task_status_update_manager.cpp:538] Cleaning up status update stream for task 1 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 3: I1122 22:04:01.746150 20040 gc.cpp:90] Scheduling '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000' for gc 6.99999136548741days in the future 3: I1122 22:04:01.746204 20042 master.cpp:9658] Removing executor 'test-executor-muggle' with resources [] of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) 3: I1122 22:04:01.746274 20045 slave.cpp:3270] Asked to shut down framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 by [email protected]:35264 3: I1122 22:04:01.746335 20045 slave.cpp:3295] Shutting down framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.746388 20045 slave.cpp:5879] Shutting down executor 'test-executor-muggle' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 at executor(42)@172.17.0.2:35264 3: I1122 22:04:01.746385 20048 hierarchical.cpp:1132] Recovered mem(allocated: muggle)(reservations: [(STATIC,muggle)]):1024; cpus(allocated: muggle)(reservations: [(STATIC,muggle)]):3 (total: cpus(reservations: [(STATIC,superhero)]):2; cpus(reservations: [(STATIC,muggle)]):3; mem(reservations: [(STATIC,superhero)]):512; mem(reservations: [(STATIC,muggle)]):1024; disk:367463; ports:[31000-32000], allocated: {}) on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 from framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.746613 20045 slave.cpp:5135] Got exited event for executor(42)@172.17.0.2:35264 3: I1122 22:04:01.746726 20045 slave.cpp:5544] Executor 'test-executor-muggle' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 exited with status 0 3: I1122 22:04:01.746836 20045 slave.cpp:5648] Cleaning up executor 'test-executor-muggle' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 at executor(42)@172.17.0.2:35264 3: I1122 22:04:01.747208 20050 gc.cpp:90] Scheduling '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001/executors/test-executor-muggle/runs/23df3b2f-27ae-46bc-b0de-e51d78a2406c' for gc 6.99999135381926days in the future 3: W1122 22:04:01.747257 20042 master.cpp:7480] Ignoring unknown exited executor 'test-executor-superhero' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0000 on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) 3: I1122 22:04:01.747368 20045 slave.cpp:5755] Cleaning up framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.747398 20050 gc.cpp:90] Scheduling '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001/executors/test-executor-muggle' for gc 6.99999135101926days in the future 3: W1122 22:04:01.747409 20042 master.cpp:7480] Ignoring unknown exited executor 'test-executor-muggle' of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 on agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) 3: I1122 22:04:01.747473 20036 hierarchical.cpp:358] Removed framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.747579 20054 task_status_update_manager.cpp:289] Closing task status update streams for framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.747640 20054 task_status_update_manager.cpp:538] Cleaning up status update stream for task 2 of framework 1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001 3: I1122 22:04:01.747684 20046 gc.cpp:90] Scheduling '/tmp/SlaveAuthorizerTest_0_FilterStateEndpoint_vnHdq0/slaves/1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0/frameworks/1a5b1511-a9f5-49cb-8824-470a109f5b8b-0001' for gc 6.99999134785778days in the future 3: I1122 22:04:01.747704 20045 slave.cpp:883] Agent terminating 3: I1122 22:04:01.747967 20040 master.cpp:1311] Agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) disconnected 3: I1122 22:04:01.747997 20040 master.cpp:3370] Disconnecting agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) 3: I1122 22:04:01.748060 20040 master.cpp:3389] Deactivating agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 at slave(146)@172.17.0.2:35264 (987dffa45d9c) 3: I1122 22:04:01.748212 20052 hierarchical.cpp:697] Agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 deactivated 3: I1122 22:04:01.752887 20041 master.cpp:1153] Master terminating 3: I1122 22:04:01.754263 20037 hierarchical.cpp:633] Removed agent 1a5b1511-a9f5-49cb-8824-470a109f5b8b-S0 3: [ OK ] SlaveAuthorizerTest/0.FilterStateEndpoint (152 ms) 3: [ RUN ] SlaveAuthorizerTest/0.ViewFlags 3: I1122 22:04:01.768858 20035 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } 3: W1122 22:04:01.769572 20035 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges 3: W1122 22:04:01.769727 20035 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges 3: I1122 22:04:01.769768 20035 provisioner.cpp:259] Using default backend 'copy' 3: I1122 22:04:01.774929 20043 slave.cpp:262] Mesos agent started on (147)@172.17.0.2:35264 3: I1122 22:04:01.774957 20043 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/SlaveAuthorizerTest_0_ViewFlags_sYhgZo/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SlaveAuthorizerTest_0_ViewFlags_sYhgZo/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/SlaveAuthorizerTest_0_ViewFlags_sYhgZo/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/SlaveAuthorizerTest_0_ViewFlags_sYhgZo/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveAuthorizerTest_0_ViewFlags_sYhgZo/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/SlaveAuthorizerTest_0_ViewFlags_sYhgZo/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/SlaveAuthorizerTest_0_ViewFlags_sYhgZo" --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/SlaveAuthorizerTest_0_ViewFlags_89YpKP" --zk_session_timeout="10secs" 3: I1122 22:04:01.775563 20043 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveAuthorizerTest_0_ViewFlags_sYhgZo/credential' 3: I1122 22:04:01.775807 20043 slave.cpp:295] Agent using credential for: test-principal 3: I1122 22:04:01.775833 20043 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveAuthorizerTest_0_ViewFlags_sYhgZo/http_credentials' 3: I1122 22:04:01.776240 20043 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' 3: I1122 22:04:01.776432 20043 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' 3: I1122 22:04:01.776732 20043 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1122 22:04:01.776868 20043 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1122 22:04:01.777113 20043 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1122 22:04:01.777246 20043 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1122 22:04:01.779431 20043 slave.cpp:593] 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: I1122 22:04:01.779765 20043 slave.cpp:601] Agent attributes: [ ] 3: I1122 22:04:01.779778 20043 slave.cpp:610] Agent hostname: 987dffa45d9c 3: I1122 22:04:01.780023 20048 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1122 22:04:01.782361 20051 state.cpp:64] Recovering state from '/tmp/SlaveAuthorizerTest_0_ViewFlags_89YpKP/meta' 3: I1122 22:04:01.782852 20053 task_status_update_manager.cpp:207] Recovering task status update manager 3: I1122 22:04:01.783140 20042 containerizer.cpp:668] Recovering containerizer 3: I1122 22:04:01.785105 20044 provisioner.cpp:455] Provisioner recovery complete 3: I1122 22:04:01.785637 20048 slave.cpp:6449] Finished recovery 3: I1122 22:04:01.789158 20041 process.cpp:3503] Handling HTTP event for process 'slave(147)' with path: '/slave(147)/flags' 3: I1122 22:04:01.791847 20044 http.cpp:1185] HTTP GET for /slave(147)/flags from 172.17.0.2:57070 3: I1122 22:04:01.797747 20036 process.cpp:3503] Handling HTTP event for process 'slave(147)' with path: '/slave(147)/state' 3: I1122 22:04:01.799968 20047 http.cpp:1185] HTTP GET for /slave(147)/state from 172.17.0.2:57074 3: I1122 22:04:01.808104 20036 process.cpp:3503] Handling HTTP event for process 'slave(147)' with path: '/slave(147)/flags' 3: I1122 22:04:01.810194 20049 http.cpp:1185] HTTP GET for /slave(147)/flags from 172.17.0.2:57080 3: I1122 22:04:01.813923 20055 process.cpp:3503] Handling HTTP event for process 'slave(147)' with path: '/slave(147)/state' 3: I1122 22:04:01.816609 20047 http.cpp:1185] HTTP GET for /slave(147)/state from 172.17.0.2:57082 3: I1122 22:04:01.821602 20048 slave.cpp:883] Agent terminating 3: [ OK ] SlaveAuthorizerTest/0.ViewFlags (71 ms) 3: [ RUN ] SlaveAuthorizerTest/0.AuthorizeRunTaskOnAgent 3: I1122 22:04:01.835062 20035 cluster.cpp:162] Creating default 'local' authorizer 3: I1122 22:04:01.839287 20038 master.cpp:448] Master 981fdab6-e821-4209-9386-3e530021d411 (987dffa45d9c) started on 172.17.0.2:35264 3: I1122 22:04:01.839316 20038 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/dIluFx/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/dIluFx/master" --zk_session_timeout="10secs" 3: I1122 22:04:01.839694 20038 master.cpp:499] Master only allowing authenticated frameworks to register 3: I1122 22:04:01.839705 20038 master.cpp:505] Master only allowing authenticated agents to register 3: I1122 22:04:01.839712 20038 master.cpp:511] Master only allowing authenticated HTTP frameworks to register 3: I1122 22:04:01.839720 20038 credentials.hpp:37] Loading credentials for authentication from '/tmp/dIluFx/credentials' 3: I1122 22:04:01.840078 20038 master.cpp:555] Using default 'crammd5' authenticator 3: I1122 22:04:01.840289 20038 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1122 22:04:01.840474 20038 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1122 22:04:01.840652 20038 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1122 22:04:01.840816 20038 master.cpp:634] Authorization enabled 3: I1122 22:04:01.841027 20048 hierarchical.cpp:173] Initialized hierarchical allocator process 3: I1122 22:04:01.841035 20037 whitelist_watcher.cpp:77] No whitelist given 3: I1122 22:04:01.845016 20043 master.cpp:2215] Elected as the leading master! 3: I1122 22:04:01.845064 20043 master.cpp:1695] Recovering from registrar 3: I1122 22:04:01.845254 20040 registrar.cpp:347] Recovering registrar 3: I1122 22:04:01.846112 20040 registrar.cpp:391] Successfully fetched the registry (0B) in 801024ns 3: I1122 22:04:01.846261 20040 registrar.cpp:495] Applied 1 operations in 43908ns; attempting to update the registry 3: I1122 22:04:01.847060 20040 registrar.cpp:552] Successfully updated the registry in 724224ns 3: I1122 22:04:01.847223 20040 registrar.cpp:424] Successfully recovered registrar 3: I1122 22:04:01.847756 20059 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register 3: I1122 22:04:01.847841 20039 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover 3: W1122 22:04:01.853865 20035 process.cpp:2756] Attempted to spawn already running process [email protected]:35264 3: I1122 22:04:01.854928 20035 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } 3: W1122 22:04:01.855526 20035 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges 3: W1122 22:04:01.855656 20035 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges 3: I1122 22:04:01.855691 20035 provisioner.cpp:259] Using default backend 'copy' 3: I1122 22:04:01.858007 20035 cluster.cpp:448] Creating default 'local' authorizer 3: I1122 22:04:01.860788 20039 slave.cpp:262] Mesos agent started on (148)@172.17.0.2:35264 3: I1122 22:04:01.860816 20039 slave.cpp:263] Flags at startup: --acls="permissive: false 3: run_tasks { 3: principals { 3: type: ANY 3: } 3: users { 3: values: "bar" 3: values: "mesos" 3: } 3: } 3: " --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_t51yxG/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_t51yxG/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/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_t51yxG/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_t51yxG/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_t51yxG/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/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_t51yxG/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/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_t51yxG" --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/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_qsUv66" --zk_session_timeout="10secs" 3: I1122 22:04:01.861531 20039 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_t51yxG/credential' 3: W1122 22:04:01.861563 20035 process.cpp:2756] Attempted to spawn already running process [email protected]:35264 3: I1122 22:04:01.861717 20039 slave.cpp:295] Agent using credential for: test-principal 3: I1122 22:04:01.861744 20039 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_t51yxG/http_credentials' 3: I1122 22:04:01.862084 20039 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' 3: I1122 22:04:01.862223 20039 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' 3: I1122 22:04:01.862464 20039 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1122 22:04:01.862584 20039 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1122 22:04:01.862679 20035 sched.cpp:232] Version: 1.5.0 3: I1122 22:04:01.862807 20039 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1122 22:04:01.862924 20039 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1122 22:04:01.863360 20051 sched.cpp:336] New master detected at [email protected]:35264 3: I1122 22:04:01.863474 20051 sched.cpp:396] Authenticating with master [email protected]:35264 3: I1122 22:04:01.863492 20051 sched.cpp:403] Using default CRAM-MD5 authenticatee 3: I1122 22:04:01.863790 20059 authenticatee.cpp:121] Creating new client SASL connection 3: I1122 22:04:01.864130 20047 master.cpp:8312] Authenticating [email protected]:35264 3: I1122 22:04:01.864279 20048 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(348)@172.17.0.2:35264 3: I1122 22:04:01.864575 20050 authenticator.cpp:98] Creating new server SASL connection 3: I1122 22:04:01.864914 20038 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1122 22:04:01.864953 20038 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1122 22:04:01.864783 20039 slave.cpp:593] 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: I1122 22:04:01.865077 20039 slave.cpp:601] Agent attributes: [ ] 3: I1122 22:04:01.865083 20043 authenticator.cpp:204] Received SASL authentication start 3: I1122 22:04:01.865092 20039 slave.cpp:610] Agent hostname: 987dffa45d9c 3: I1122 22:04:01.865147 20043 authenticator.cpp:326] Authentication requires more steps 3: I1122 22:04:01.865278 20042 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1122 22:04:01.865346 20045 authenticatee.cpp:259] Received SASL authentication step 3: I1122 22:04:01.865516 20055 authenticator.cpp:232] Received SASL authentication step 3: I1122 22:04:01.865556 20055 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '987dffa45d9c' server FQDN: '987dffa45d9c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1122 22:04:01.865569 20055 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1122 22:04:01.865607 20055 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1122 22:04:01.865631 20055 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '987dffa45d9c' server FQDN: '987dffa45d9c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1122 22:04:01.865640 20055 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1122 22:04:01.865648 20055 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1122 22:04:01.865665 20055 authenticator.cpp:318] Authentication success 3: I1122 22:04:01.865777 20036 authenticatee.cpp:299] Authentication success 3: I1122 22:04:01.865854 20054 master.cpp:8342] Successfully authenticated principal 'test-principal' at [email protected]:35264 3: I1122 22:04:01.865918 20041 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(348)@172.17.0.2:35264 3: I1122 22:04:01.866268 20057 sched.cpp:502] Successfully authenticated with master [email protected]:35264 3: I1122 22:04:01.866295 20057 sched.cpp:824] Sending SUBSCRIBE call to [email protected]:35264 3: I1122 22:04:01.866452 20057 sched.cpp:857] Will retry registration in 1.782519472secs if necessary 3: I1122 22:04:01.866654 20049 master.cpp:2963] Received SUBSCRIBE call for framework 'default' at [email protected]:35264 write /dev/stdout: resource temporarily unavailable + docker rmi mesos-1511385564-13051 Build step 'Execute shell' marked build as failure
