See <https://ci-builds.apache.org/job/Mesos/job/Mesos-Reviewbot-Linux/249/display/redirect?page=changes>
Changes: [gregorywmann] Fixed broken authorization in the CSI server. ------------------------------------------ [...truncated 7.96 MB...] I0831 23:20:20.068832 5640 leveldb.cpp:347] Persisting action (16 bytes) to leveldb took 29.327859ms I0831 23:20:20.068892 5640 replica.cpp:712] Persisted action TRUNCATE at position 4 I0831 23:20:20.069613 5655 replica.cpp:695] Replica received learned notice for position 4 from log-network(1)@172.17.0.4:37375 I0831 23:20:20.078194 5612 process.cpp:935] Stopped the socket accept loop I0831 23:20:20.078203 5613 process.cpp:935] Stopped the socket accept loop I0831 23:20:20.079102 5615 process.cpp:935] Stopped the socket accept loop I0831 23:20:20.079335 5611 process.cpp:935] Stopped the socket accept loop I0831 23:20:20.080948 5619 process.cpp:935] Stopped the socket accept loop I0831 23:20:20.081610 5633 scheduler.cpp:416] Connected with the master at http://172.17.0.4:37375/master/api/v1/scheduler I0831 23:20:20.084144 5634 scheduler.cpp:246] Adding authentication headers to SUBSCRIBE call to http://172.17.0.4:37375/master/api/v1/scheduler I0831 23:20:20.092317 5640 scheduler.cpp:600] Sending SUBSCRIBE call to http://172.17.0.4:37375/master/api/v1/scheduler I0831 23:20:20.095140 5642 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I0831 23:20:20.102371 5632 http.cpp:1436] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:37594 I0831 23:20:20.105744 5632 master.cpp:2666] Received subscription request for HTTP framework 'Event Call Scheduler using libprocess (C++)' I0831 23:20:20.110924 5655 leveldb.cpp:347] Persisting action (18 bytes) to leveldb took 41.262602ms I0831 23:20:20.111069 5655 leveldb.cpp:423] Deleting ~2 keys from leveldb took 75183ns I0831 23:20:20.111104 5655 replica.cpp:712] Persisted action TRUNCATE at position 4 I0831 23:20:20.113168 5640 master.cpp:2751] Subscribing framework 'Event Call Scheduler using libprocess (C++)' with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] I0831 23:20:20.117125 5640 master.cpp:9958] Adding framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) with roles { } suppressed I0831 23:20:20.120321 5654 hierarchical.cpp:774] Added framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.120462 5641 scheduler.cpp:845] Enqueuing event SUBSCRIBED received from http://172.17.0.4:37375/master/api/v1/scheduler I0831 23:20:20.121500 5641 scheduler.cpp:845] Enqueuing event HEARTBEAT received from http://172.17.0.4:37375/master/api/v1/scheduler Received a SUBSCRIBED event Subscribed with ID c9d498db-5640-4b1e-a958-2780891a60f2-0000 Received a HEARTBEAT event I0831 23:20:20.123450 5654 hierarchical.cpp:1935] Performed allocation for 1 agents in 2.830395ms I0831 23:20:20.124379 5646 master.cpp:9536] Sending offers [ c9d498db-5640-4b1e-a958-2780891a60f2-O0 ] to framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) I0831 23:20:20.126494 5650 scheduler.cpp:845] Enqueuing event OFFERS received from http://172.17.0.4:37375/master/api/v1/scheduler Received an OFFERS event Received offer c9d498db-5640-4b1e-a958-2780891a60f2-O0 with ports(allocated: *):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):10240; disk(allocated: *):3748421 Launching task 0 using offer c9d498db-5640-4b1e-a958-2780891a60f2-O0 Launching task 1 using offer c9d498db-5640-4b1e-a958-2780891a60f2-O0 I0831 23:20:20.132601 5633 scheduler.cpp:246] Adding authentication headers to ACCEPT call to http://172.17.0.4:37375/master/api/v1/scheduler I0831 23:20:20.133432 5655 scheduler.cpp:600] Sending ACCEPT call to http://172.17.0.4:37375/master/api/v1/scheduler I0831 23:20:20.134954 5652 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I0831 23:20:20.137490 5654 http.cpp:1436] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:37592 I0831 23:20:20.139808 5654 master.cpp:4314] Processing ACCEPT call for offers: [ c9d498db-5640-4b1e-a958-2780891a60f2-O0 ] on agent c9d498db-5640-4b1e-a958-2780891a60f2-S0 at slave(2)@172.17.0.4:37375 (c8c11e6bf65b) for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) I0831 23:20:20.140702 5654 master.cpp:11834] Removing offer c9d498db-5640-4b1e-a958-2780891a60f2-O0 W0831 23:20:20.143961 5654 validation.cpp:1716] 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. W0831 23:20:20.144022 5654 validation.cpp:1728] 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. I0831 23:20:20.144578 5654 master.cpp:3831] Adding executor 'default' with resources {} of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) on agent c9d498db-5640-4b1e-a958-2780891a60f2-S0 at slave(2)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.145181 5654 master.cpp:3857] Adding task 0 with resources cpus(allocated: *):1; mem(allocated: *):128 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) on agent c9d498db-5640-4b1e-a958-2780891a60f2-S0 at slave(2)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.146402 5654 master.cpp:4993] Launching task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":128.0},"type":"SCALAR"}] on agent c9d498db-5640-4b1e-a958-2780891a60f2-S0 at slave(2)@172.17.0.4:37375 (c8c11e6bf65b) on new executor I0831 23:20:20.148244 5646 slave.cpp:2300] Got assigned task '0' for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 W0831 23:20:20.149063 5654 validation.cpp:1716] Executor 'default' for task '1' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases. W0831 23:20:20.149108 5654 validation.cpp:1728] Executor 'default' for task '1' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases. I0831 23:20:20.149602 5654 master.cpp:3857] Adding task 1 with resources cpus(allocated: *):1; mem(allocated: *):128 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) on agent c9d498db-5640-4b1e-a958-2780891a60f2-S0 at slave(2)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.150291 5654 master.cpp:4993] Launching task 1 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":128.0},"type":"SCALAR"}] on agent c9d498db-5640-4b1e-a958-2780891a60f2-S0 at slave(2)@172.17.0.4:37375 (c8c11e6bf65b) on existing executor I0831 23:20:20.150899 5642 hierarchical.cpp:1859] Allocation paused I0831 23:20:20.151865 5653 hierarchical.cpp:1658] Recovered ports(allocated: *):[31000-32000]; disk(allocated: *):3748421; mem(allocated: *):9984 (total: cpus:2; mem:10240; disk:3748421; ports:[31000-32000], offered or allocated: mem(allocated: *):256; cpus(allocated: *):2) on agent c9d498db-5640-4b1e-a958-2780891a60f2-S0 from framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.153352 5646 slave.cpp:2300] Got assigned task '1' for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.153707 5653 hierarchical.cpp:1707] Framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 filtered agent c9d498db-5640-4b1e-a958-2780891a60f2-S0 for 5secs I0831 23:20:20.155818 5646 slave.cpp:2707] Authorizing task '0' for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.155982 5646 slave.cpp:9715] Authorizing framework principal 'test-principal' to launch task 0 I0831 23:20:20.156028 5653 hierarchical.cpp:1869] Allocation resumed I0831 23:20:20.158577 5646 slave.cpp:2707] Authorizing task '1' for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.158763 5646 slave.cpp:9715] Authorizing framework principal 'test-principal' to launch task 1 I0831 23:20:20.164865 5646 slave.cpp:3181] Launching task '0' for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.166746 5646 paths.cpp:832] Creating sandbox '/tmp/mesos-GKkUkb/agents/1/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S0/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/c213dd8c-e024-4d2d-8acb-7b84c09a6d00' for user 'mesos' I0831 23:20:20.167718 5646 slave.cpp:10379] Launching executor 'default' of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 with resources [] in work directory '/tmp/mesos-GKkUkb/agents/1/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S0/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/c213dd8c-e024-4d2d-8acb-7b84c09a6d00' I0831 23:20:20.170339 5646 slave.cpp:3415] Queued task '0' for executor 'default' of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.170734 5646 slave.cpp:3181] Launching task '1' for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.170892 5646 slave.cpp:3415] Queued task '1' for executor 'default' of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.171036 5646 slave.cpp:1206] Successfully attached '/tmp/mesos-GKkUkb/agents/1/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S0/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/c213dd8c-e024-4d2d-8acb-7b84c09a6d00' to virtual path '/tmp/mesos-GKkUkb/agents/1/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S0/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/latest' I0831 23:20:20.171099 5646 slave.cpp:1206] Successfully attached '/tmp/mesos-GKkUkb/agents/1/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S0/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/c213dd8c-e024-4d2d-8acb-7b84c09a6d00' to virtual path '/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/latest' I0831 23:20:20.171151 5646 slave.cpp:1206] Successfully attached '/tmp/mesos-GKkUkb/agents/1/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S0/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/c213dd8c-e024-4d2d-8acb-7b84c09a6d00' to virtual path '/tmp/mesos-GKkUkb/agents/1/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S0/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/c213dd8c-e024-4d2d-8acb-7b84c09a6d00' I0831 23:20:20.172180 5646 slave.cpp:3876] Launching container c213dd8c-e024-4d2d-8acb-7b84c09a6d00 for executor 'default' of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.172858 5641 containerizer.cpp:1405] Starting container c213dd8c-e024-4d2d-8acb-7b84c09a6d00 I0831 23:20:20.173601 5641 containerizer.cpp:3414] Transitioning the state of container c213dd8c-e024-4d2d-8acb-7b84c09a6d00 from STARTING to PROVISIONING after 414976ns I0831 23:20:20.181059 5641 containerizer.cpp:1584] Checkpointed ContainerConfig at '/tmp/mesos-GKkUkb/agents/1/run/containers/c213dd8c-e024-4d2d-8acb-7b84c09a6d00/config' I0831 23:20:20.181114 5641 containerizer.cpp:3414] Transitioning the state of container c213dd8c-e024-4d2d-8acb-7b84c09a6d00 from PROVISIONING to PREPARING after 7520us I0831 23:20:20.194919 5651 containerizer.cpp:2110] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"shell":true,"value":"/tmp/SRC/build/mesos-1.11.0/_build/sub/src/test-http-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.4:37375"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/mesos-GKkUkb/agents/1/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S0/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/c213dd8c-e024-4d2d-8acb-7b84c09a6d00"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"default"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"c9d498db-5640-4b1e-a958-2780891a60f2-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"c9d498db-5640-4b1e-a958-2780891a60f2-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(2)@172.17.0.4:37375"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/mesos-GKkUkb/agents/1/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S0/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/c213dd8c-e024-4d2d-8acb-7b84c09a6d00"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/mesos-GKkUkb/agents/1/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S0/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/c213dd8c-e024-4d2d-8acb-7b84c09a6d00"}" --pipe_read="20" --pipe_write="21" --runtime_directory="/tmp/mesos-GKkUkb/agents/1/run/containers/c213dd8c-e024-4d2d-8acb-7b84c09a6d00" --unshare_namespace_mnt="false"' I0831 23:20:20.200439 5651 launcher.cpp:145] Forked child with pid '5661' for container 'c213dd8c-e024-4d2d-8acb-7b84c09a6d00' I0831 23:20:20.202102 5651 containerizer.cpp:3414] Transitioning the state of container c213dd8c-e024-4d2d-8acb-7b84c09a6d00 from PREPARING to ISOLATING after 20.979968ms I0831 23:20:20.204627 5651 containerizer.cpp:3414] Transitioning the state of container c213dd8c-e024-4d2d-8acb-7b84c09a6d00 from ISOLATING to FETCHING after 2.514176ms I0831 23:20:20.205022 5645 fetcher.cpp:369] Starting to fetch URIs for container: c213dd8c-e024-4d2d-8acb-7b84c09a6d00, directory: /tmp/mesos-GKkUkb/agents/1/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S0/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/c213dd8c-e024-4d2d-8acb-7b84c09a6d00 I0831 23:20:20.208364 5652 containerizer.cpp:3414] Transitioning the state of container c213dd8c-e024-4d2d-8acb-7b84c09a6d00 from FETCHING to RUNNING after 3.719936ms I0831 23:20:20.254086 5642 slave.cpp:2131] Will retry registration in 806.861086ms if necessary I0831 23:20:20.254417 5654 master.cpp:6221] Received register agent message from slave(3)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.254953 5654 master.cpp:3752] Authorizing ANY principal to perform action REGISTER_AGENT on ANY object I0831 23:20:20.255787 5640 master.cpp:6288] Authorized registration of agent at slave(3)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.255970 5640 master.cpp:6400] Registering agent at slave(3)@172.17.0.4:37375 (c8c11e6bf65b) with id c9d498db-5640-4b1e-a958-2780891a60f2-S1 I0831 23:20:20.257016 5639 registrar.cpp:487] Applied 1 operations in 429783ns; attempting to update the registry I0831 23:20:20.260152 5633 log.cpp:578] Attempting to append 518 bytes to the log I0831 23:20:20.260376 5653 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 5 I0831 23:20:20.261677 5652 replica.cpp:541] Replica received write request for position 5 from __req_res__(10)@172.17.0.4:37375 I0831 23:20:20.295912 5652 leveldb.cpp:347] Persisting action (537 bytes) to leveldb took 34.154977ms I0831 23:20:20.295996 5652 replica.cpp:712] Persisted action APPEND at position 5 I0831 23:20:20.296975 5642 replica.cpp:695] Replica received learned notice for position 5 from log-network(1)@172.17.0.4:37375 I0831 23:20:20.329313 5642 leveldb.cpp:347] Persisting action (539 bytes) to leveldb took 32.287951ms I0831 23:20:20.329358 5642 replica.cpp:712] Persisted action APPEND at position 5 I0831 23:20:20.331255 5643 registrar.cpp:544] Successfully updated the registry in 74.12096ms I0831 23:20:20.331550 5639 master.cpp:6448] Admitted agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 at slave(3)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.331828 5632 log.cpp:597] Attempting to truncate the log to 5 I0831 23:20:20.331980 5650 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 6 I0831 23:20:20.332752 5639 master.cpp:6493] Registered agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 at slave(3)@172.17.0.4:37375 (c8c11e6bf65b) with cpus:2; mem:10240; disk:3748421; ports:[31000-32000] I0831 23:20:20.332854 5634 slave.cpp:1698] Registered with master [email protected]:37375; given agent ID c9d498db-5640-4b1e-a958-2780891a60f2-S1 I0831 23:20:20.333060 5641 task_status_update_manager.cpp:188] Resuming sending task status updates I0831 23:20:20.333087 5651 hierarchical.cpp:1041] Added agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 (c8c11e6bf65b) with cpus:2; mem:10240; disk:3748421; ports:[31000-32000] (offered or allocated: {}) I0831 23:20:20.333186 5648 replica.cpp:541] Replica received write request for position 6 from __req_res__(11)@172.17.0.4:37375 I0831 23:20:20.333493 5634 slave.cpp:1733] Checkpointing SlaveInfo to '/tmp/mesos-GKkUkb/agents/2/work/meta/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S1/slave.info' I0831 23:20:20.333571 5638 status_update_manager_process.hpp:385] Resuming operation status update manager I0831 23:20:20.334923 5651 hierarchical.cpp:1935] Performed allocation for 1 agents in 1.515109ms I0831 23:20:20.335189 5634 slave.cpp:1793] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"+MP+klr5TvWlNCSIRskuqQ=="},"slave_id":{"value":"c9d498db-5640-4b1e-a958-2780891a60f2-S1"},"update_oversubscribed_resources":false} I0831 23:20:20.335485 5640 master.cpp:9536] Sending offers [ c9d498db-5640-4b1e-a958-2780891a60f2-O1 ] to framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) I0831 23:20:20.336647 5640 master.cpp:7635] Ignoring update on agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 at slave(3)@172.17.0.4:37375 (c8c11e6bf65b) as it reports no changes I0831 23:20:20.337771 5655 scheduler.cpp:845] Enqueuing event OFFERS received from http://172.17.0.4:37375/master/api/v1/scheduler Received an OFFERS event Received offer c9d498db-5640-4b1e-a958-2780891a60f2-O1 with ports(allocated: *):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):10240; disk(allocated: *):3748421 Launching task 2 using offer c9d498db-5640-4b1e-a958-2780891a60f2-O1 Launching task 3 using offer c9d498db-5640-4b1e-a958-2780891a60f2-O1 I0831 23:20:20.340698 5636 scheduler.cpp:246] Adding authentication headers to ACCEPT call to http://172.17.0.4:37375/master/api/v1/scheduler I0831 23:20:20.341472 5641 scheduler.cpp:600] Sending ACCEPT call to http://172.17.0.4:37375/master/api/v1/scheduler I0831 23:20:20.342811 5637 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I0831 23:20:20.371352 5648 leveldb.cpp:347] Persisting action (16 bytes) to leveldb took 38.10201ms I0831 23:20:20.371410 5648 replica.cpp:712] Persisted action TRUNCATE at position 6 I0831 23:20:20.372155 5640 replica.cpp:695] Replica received learned notice for position 6 from log-network(1)@172.17.0.4:37375 I0831 23:20:20.386157 5653 http.cpp:1436] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:37592 I0831 23:20:20.387632 5653 master.cpp:4314] Processing ACCEPT call for offers: [ c9d498db-5640-4b1e-a958-2780891a60f2-O1 ] on agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 at slave(3)@172.17.0.4:37375 (c8c11e6bf65b) for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) I0831 23:20:20.388243 5653 master.cpp:11834] Removing offer c9d498db-5640-4b1e-a958-2780891a60f2-O1 W0831 23:20:20.389930 5653 validation.cpp:1716] Executor 'default' 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. W0831 23:20:20.389967 5653 validation.cpp:1728] Executor 'default' for task '2' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases. I0831 23:20:20.390305 5653 master.cpp:3831] Adding executor 'default' with resources {} of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) on agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 at slave(3)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.390569 5653 master.cpp:3857] Adding task 2 with resources cpus(allocated: *):1; mem(allocated: *):128 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) on agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 at slave(3)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.391117 5653 master.cpp:4993] Launching task 2 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":128.0},"type":"SCALAR"}] on agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 at slave(3)@172.17.0.4:37375 (c8c11e6bf65b) on new executor I0831 23:20:20.392318 5639 slave.cpp:2300] Got assigned task '2' for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 W0831 23:20:20.392884 5653 validation.cpp:1716] Executor 'default' for task '3' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases. W0831 23:20:20.392918 5653 validation.cpp:1728] Executor 'default' for task '3' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases. I0831 23:20:20.393270 5653 master.cpp:3857] Adding task 3 with resources cpus(allocated: *):1; mem(allocated: *):128 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) on agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 at slave(3)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.393734 5653 master.cpp:4993] Launching task 3 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":128.0},"type":"SCALAR"}] on agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 at slave(3)@172.17.0.4:37375 (c8c11e6bf65b) on existing executor I0831 23:20:20.394162 5652 hierarchical.cpp:1859] Allocation paused I0831 23:20:20.394249 5639 slave.cpp:2707] Authorizing task '2' for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.394345 5639 slave.cpp:9715] Authorizing framework principal 'test-principal' to launch task 2 I0831 23:20:20.394600 5652 hierarchical.cpp:1658] Recovered ports(allocated: *):[31000-32000]; disk(allocated: *):3748421; mem(allocated: *):9984 (total: cpus:2; mem:10240; disk:3748421; ports:[31000-32000], offered or allocated: mem(allocated: *):256; cpus(allocated: *):2) on agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 from framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.395675 5652 hierarchical.cpp:1707] Framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 filtered agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 for 5secs I0831 23:20:20.396291 5639 slave.cpp:2300] Got assigned task '3' for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.396334 5652 hierarchical.cpp:1869] Allocation resumed I0831 23:20:20.398227 5639 slave.cpp:2707] Authorizing task '3' for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.398315 5639 slave.cpp:9715] Authorizing framework principal 'test-principal' to launch task 3 I0831 23:20:20.400624 5639 slave.cpp:3181] Launching task '2' for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.400719 5639 paths.cpp:832] Creating sandbox '/tmp/mesos-GKkUkb/agents/2/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S1/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/062b6cf4-d7be-4d62-8e7f-caf885bb6556' for user 'mesos' I0831 23:20:20.401505 5639 slave.cpp:10379] Launching executor 'default' of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 with resources [] in work directory '/tmp/mesos-GKkUkb/agents/2/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S1/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/062b6cf4-d7be-4d62-8e7f-caf885bb6556' I0831 23:20:20.402884 5639 slave.cpp:3415] Queued task '2' for executor 'default' of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.403451 5639 slave.cpp:1206] Successfully attached '/tmp/mesos-GKkUkb/agents/2/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S1/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/062b6cf4-d7be-4d62-8e7f-caf885bb6556' to virtual path '/tmp/mesos-GKkUkb/agents/2/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S1/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/latest' I0831 23:20:20.403501 5639 slave.cpp:1206] Successfully attached '/tmp/mesos-GKkUkb/agents/2/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S1/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/062b6cf4-d7be-4d62-8e7f-caf885bb6556' to virtual path '/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/latest' I0831 23:20:20.403537 5639 slave.cpp:1206] Successfully attached '/tmp/mesos-GKkUkb/agents/2/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S1/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/062b6cf4-d7be-4d62-8e7f-caf885bb6556' to virtual path '/tmp/mesos-GKkUkb/agents/2/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S1/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/062b6cf4-d7be-4d62-8e7f-caf885bb6556' I0831 23:20:20.404147 5639 slave.cpp:3181] Launching task '3' for framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.404273 5639 slave.cpp:3415] Queued task '3' for executor 'default' of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.404523 5639 slave.cpp:3876] Launching container 062b6cf4-d7be-4d62-8e7f-caf885bb6556 for executor 'default' of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.404852 5633 containerizer.cpp:1405] Starting container 062b6cf4-d7be-4d62-8e7f-caf885bb6556 I0831 23:20:20.405450 5633 containerizer.cpp:3414] Transitioning the state of container 062b6cf4-d7be-4d62-8e7f-caf885bb6556 from STARTING to PROVISIONING after 308992ns I0831 23:20:20.406333 5633 containerizer.cpp:1584] Checkpointed ContainerConfig at '/tmp/mesos-GKkUkb/agents/2/run/containers/062b6cf4-d7be-4d62-8e7f-caf885bb6556/config' I0831 23:20:20.406394 5633 containerizer.cpp:3414] Transitioning the state of container 062b6cf4-d7be-4d62-8e7f-caf885bb6556 from PROVISIONING to PREPARING after 944128ns I0831 23:20:20.413810 5641 containerizer.cpp:2110] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"shell":true,"value":"/tmp/SRC/build/mesos-1.11.0/_build/sub/src/test-http-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.4:37375"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/mesos-GKkUkb/agents/2/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S1/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/062b6cf4-d7be-4d62-8e7f-caf885bb6556"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"default"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"c9d498db-5640-4b1e-a958-2780891a60f2-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"c9d498db-5640-4b1e-a958-2780891a60f2-S1"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(3)@172.17.0.4:37375"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/mesos-GKkUkb/agents/2/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S1/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/062b6cf4-d7be-4d62-8e7f-caf885bb6556"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/mesos-GKkUkb/agents/2/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S1/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/062b6cf4-d7be-4d62-8e7f-caf885bb6556"}" --pipe_read="24" --pipe_write="25" --runtime_directory="/tmp/mesos-GKkUkb/agents/2/run/containers/062b6cf4-d7be-4d62-8e7f-caf885bb6556" --unshare_namespace_mnt="false"' I0831 23:20:20.416795 5641 launcher.cpp:145] Forked child with pid '5664' for container '062b6cf4-d7be-4d62-8e7f-caf885bb6556' I0831 23:20:20.417619 5648 slave.cpp:2131] Will retry registration in 1.379132501secs if necessary I0831 23:20:20.417858 5641 containerizer.cpp:3414] Transitioning the state of container 062b6cf4-d7be-4d62-8e7f-caf885bb6556 from PREPARING to ISOLATING after 11.452928ms I0831 23:20:20.418030 5649 master.cpp:6221] Received register agent message from slave(1)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.418648 5649 master.cpp:3752] Authorizing ANY principal to perform action REGISTER_AGENT on ANY object I0831 23:20:20.419793 5636 master.cpp:6288] Authorized registration of agent at slave(1)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.419963 5636 master.cpp:6400] Registering agent at slave(1)@172.17.0.4:37375 (c8c11e6bf65b) with id c9d498db-5640-4b1e-a958-2780891a60f2-S2 I0831 23:20:20.420487 5641 containerizer.cpp:3414] Transitioning the state of container 062b6cf4-d7be-4d62-8e7f-caf885bb6556 from ISOLATING to FETCHING after 2.624256ms I0831 23:20:20.420737 5643 fetcher.cpp:369] Starting to fetch URIs for container: 062b6cf4-d7be-4d62-8e7f-caf885bb6556, directory: /tmp/mesos-GKkUkb/agents/2/work/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S1/frameworks/c9d498db-5640-4b1e-a958-2780891a60f2-0000/executors/default/runs/062b6cf4-d7be-4d62-8e7f-caf885bb6556 I0831 23:20:20.421109 5648 registrar.cpp:487] Applied 1 operations in 463444ns; attempting to update the registry I0831 23:20:20.423166 5652 containerizer.cpp:3414] Transitioning the state of container 062b6cf4-d7be-4d62-8e7f-caf885bb6556 from FETCHING to RUNNING after 2.688768ms I0831 23:20:20.458799 5640 leveldb.cpp:347] Persisting action (18 bytes) to leveldb took 86.562404ms I0831 23:20:20.459003 5640 leveldb.cpp:423] Deleting ~2 keys from leveldb took 104391ns I0831 23:20:20.459040 5640 replica.cpp:712] Persisted action TRUNCATE at position 6 I0831 23:20:20.460798 5649 log.cpp:578] Attempting to append 684 bytes to the log I0831 23:20:20.461012 5650 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 7 I0831 23:20:20.462289 5636 replica.cpp:541] Replica received write request for position 7 from __req_res__(12)@172.17.0.4:37375 I0831 23:20:20.522728 5636 leveldb.cpp:347] Persisting action (703 bytes) to leveldb took 60.362812ms I0831 23:20:20.522775 5636 replica.cpp:712] Persisted action APPEND at position 7 I0831 23:20:20.523730 5633 replica.cpp:695] Replica received learned notice for position 7 from log-network(1)@172.17.0.4:37375 I0831 23:20:20.584767 5677 executor.cpp:210] Version: 1.11.0 I0831 23:20:20.585261 5677 executor.cpp:286] Using URL http://172.17.0.4:37375/slave(2)/api/v1/executor for the executor API endpoint I0831 23:20:20.589624 5633 leveldb.cpp:347] Persisting action (705 bytes) to leveldb took 65.849428ms I0831 23:20:20.589668 5633 replica.cpp:712] Persisted action APPEND at position 7 I0831 23:20:20.591289 5647 registrar.cpp:544] Successfully updated the registry in 170.053888ms I0831 23:20:20.591532 5649 master.cpp:6448] Admitted agent c9d498db-5640-4b1e-a958-2780891a60f2-S2 at slave(1)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.591743 5655 log.cpp:597] Attempting to truncate the log to 7 I0831 23:20:20.591909 5650 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 8 I0831 23:20:20.592573 5649 master.cpp:6493] Registered agent c9d498db-5640-4b1e-a958-2780891a60f2-S2 at slave(1)@172.17.0.4:37375 (c8c11e6bf65b) with cpus:2; mem:10240; disk:3748421; ports:[31000-32000] I0831 23:20:20.592660 5646 slave.cpp:1698] Registered with master [email protected]:37375; given agent ID c9d498db-5640-4b1e-a958-2780891a60f2-S2 I0831 23:20:20.592783 5636 task_status_update_manager.cpp:188] Resuming sending task status updates I0831 23:20:20.592876 5637 hierarchical.cpp:1041] Added agent c9d498db-5640-4b1e-a958-2780891a60f2-S2 (c8c11e6bf65b) with cpus:2; mem:10240; disk:3748421; ports:[31000-32000] (offered or allocated: {}) I0831 23:20:20.592989 5654 replica.cpp:541] Replica received write request for position 8 from __req_res__(13)@172.17.0.4:37375 I0831 23:20:20.593212 5646 slave.cpp:1733] Checkpointing SlaveInfo to '/tmp/mesos-GKkUkb/agents/0/work/meta/slaves/c9d498db-5640-4b1e-a958-2780891a60f2-S2/slave.info' I0831 23:20:20.593271 5641 status_update_manager_process.hpp:385] Resuming operation status update manager I0831 23:20:20.594630 5646 slave.cpp:1793] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"pVTpXMU5SnS8xzpTN5UQyQ=="},"slave_id":{"value":"c9d498db-5640-4b1e-a958-2780891a60f2-S2"},"update_oversubscribed_resources":false} I0831 23:20:20.594681 5637 hierarchical.cpp:1935] Performed allocation for 1 agents in 1.52738ms I0831 23:20:20.594756 5646 process.cpp:3671] Handling HTTP event for process 'slave(2)' with path: '/slave(2)/api/v1/executor' I0831 23:20:20.595197 5647 master.cpp:9536] Sending offers [ c9d498db-5640-4b1e-a958-2780891a60f2-O2 ] to framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (Event Call Scheduler using libprocess (C++)) I0831 23:20:20.596398 5647 master.cpp:7635] Ignoring update on agent c9d498db-5640-4b1e-a958-2780891a60f2-S2 at slave(1)@172.17.0.4:37375 (c8c11e6bf65b) as it reports no changes I0831 23:20:20.597440 5634 http.cpp:1436] HTTP POST for /slave(2)/api/v1/executor from 172.17.0.4:37596 I0831 23:20:20.597956 5634 slave.cpp:5251] Received Subscribe request for HTTP executor 'default' of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.598007 5636 scheduler.cpp:845] Enqueuing event OFFERS received from http://172.17.0.4:37375/master/api/v1/scheduler Received an OFFERS event Received offer c9d498db-5640-4b1e-a958-2780891a60f2-O2 with ports(allocated: *):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):10240; disk(allocated: *):3748421 Launching task 4 using offer c9d498db-5640-4b1e-a958-2780891a60f2-O2 I0831 23:20:20.600409 5637 scheduler.cpp:246] Adding authentication headers to ACCEPT call to http://172.17.0.4:37375/master/api/v1/scheduler I0831 23:20:20.601147 5633 scheduler.cpp:600] Sending ACCEPT call to http://172.17.0.4:37375/master/api/v1/scheduler I0831 23:20:20.602365 5639 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I0831 23:20:20.604794 5632 slave.cpp:3641] Sending queued task '0' to executor 'default' of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (via HTTP) I0831 23:20:20.605408 5632 slave.cpp:3641] Sending queued task '1' to executor 'default' of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (via HTTP) Received a SUBSCRIBED event Starting task 0 Finishing task 0 Starting task 1 I0831 23:20:20.610060 5637 process.cpp:3671] Handling HTTP event for process 'slave(2)' with path: '/slave(2)/api/v1/executor' Finishing task 1 I0831 23:20:20.611431 5653 process.cpp:3671] Handling HTTP event for process 'slave(2)' with path: '/slave(2)/api/v1/executor' I0831 23:20:20.612205 5653 http.cpp:1436] HTTP POST for /slave(2)/api/v1/executor from 172.17.0.4:37598 I0831 23:20:20.612607 5653 slave.cpp:5980] Handling status update TASK_RUNNING (Status UUID: ec15da08-798c-499a-8aa7-9ad4525495ad) for task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.613104 5649 hierarchical.cpp:2764] Filtered offer with ports:[31000-32000]; mem:9984; disk:3748421 on agent c9d498db-5640-4b1e-a958-2780891a60f2-S0 for role * of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.613338 5649 hierarchical.cpp:2764] Filtered offer with ports:[31000-32000]; mem:9984; disk:3748421 on agent c9d498db-5640-4b1e-a958-2780891a60f2-S1 for role * of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.613469 5649 hierarchical.cpp:1935] Performed allocation for 3 agents in 909883ns I0831 23:20:20.614552 5653 process.cpp:3671] Handling HTTP event for process 'slave(2)' with path: '/slave(2)/api/v1/executor' I0831 23:20:20.615180 5653 process.cpp:3671] Handling HTTP event for process 'slave(2)' with path: '/slave(2)/api/v1/executor' I0831 23:20:20.616998 5653 http.cpp:1436] HTTP POST for /slave(2)/api/v1/executor from 172.17.0.4:37598 I0831 23:20:20.617225 5653 slave.cpp:5980] Handling status update TASK_FINISHED (Status UUID: b5d6a8eb-fe29-4a31-a6d3-a1c60ed31c54) for task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.618769 5655 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: ec15da08-798c-499a-8aa7-9ad4525495ad) for task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.618861 5655 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.618978 5653 http.cpp:1436] HTTP POST for /slave(2)/api/v1/executor from 172.17.0.4:37598 I0831 23:20:20.619141 5653 slave.cpp:5980] Handling status update TASK_RUNNING (Status UUID: 1d5a8dc7-bcdc-4540-810b-18fe6f3cc370) for task 1 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.620182 5655 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: ec15da08-798c-499a-8aa7-9ad4525495ad) for task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 to the agent I0831 23:20:20.620715 5653 http.cpp:1436] HTTP POST for /slave(2)/api/v1/executor from 172.17.0.4:37598 I0831 23:20:20.620895 5653 slave.cpp:5980] Handling status update TASK_FINISHED (Status UUID: b73fa864-3d3e-4f6f-ba0a-e632eb907ab5) for task 1 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.621533 5653 slave.cpp:6526] Forwarding the update TASK_RUNNING (Status UUID: ec15da08-798c-499a-8aa7-9ad4525495ad) for task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 to [email protected]:37375 I0831 23:20:20.621927 5653 slave.cpp:6410] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: ec15da08-798c-499a-8aa7-9ad4525495ad) for task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.622119 5634 master.cpp:8117] Status update TASK_RUNNING (Status UUID: ec15da08-798c-499a-8aa7-9ad4525495ad) for task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 from agent c9d498db-5640-4b1e-a958-2780891a60f2-S0 at slave(2)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.622212 5634 master.cpp:8174] Forwarding status update TASK_RUNNING (Status UUID: ec15da08-798c-499a-8aa7-9ad4525495ad) for task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.622684 5650 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: 1d5a8dc7-bcdc-4540-810b-18fe6f3cc370) for task 1 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.622809 5650 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 1 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.623170 5634 master.cpp:11151] Updating the state of task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 (latest state: TASK_FINISHED, status update state: TASK_RUNNING) I0831 23:20:20.623538 5650 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: 1d5a8dc7-bcdc-4540-810b-18fe6f3cc370) for task 1 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 to the agent I0831 23:20:20.623769 5648 slave.cpp:6526] Forwarding the update TASK_RUNNING (Status UUID: 1d5a8dc7-bcdc-4540-810b-18fe6f3cc370) for task 1 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 to [email protected]:37375 I0831 23:20:20.623986 5650 task_status_update_manager.cpp:328] Received task status update TASK_FINISHED (Status UUID: b5d6a8eb-fe29-4a31-a6d3-a1c60ed31c54) for task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.624011 5648 slave.cpp:6410] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: 1d5a8dc7-bcdc-4540-810b-18fe6f3cc370) for task 1 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.624184 5641 hierarchical.cpp:1658] Recovered cpus(allocated: *):1; mem(allocated: *):128 (total: cpus:2; mem:10240; disk:3748421; ports:[31000-32000], offered or allocated: mem(allocated: *):128; cpus(allocated: *):1) on agent c9d498db-5640-4b1e-a958-2780891a60f2-S0 from framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 I0831 23:20:20.624209 5638 scheduler.cpp:845] Enqueuing event UPDATE received from http://172.17.0.4:37375/master/api/v1/scheduler I0831 23:20:20.624219 5637 master.cpp:8117] Status update TASK_RUNNING (Status UUID: 1d5a8dc7-bcdc-4540-810b-18fe6f3cc370) for task 1 of framework c9d498db-5640-4b1e-a958-2780891a60f2-0000 from agent c9d498db-5640-4b1e-a958-2780891a60f2-S0 at slave(2)@172.17.0.4:37375 (c8c11e6bf65b) I0831 23:20:20.624296 5648 slave.cpp:6410] Task status update manager successfully handled status update TASK_FINISHED (Status UUID: b5d6a8eb-fe29-4a31-a6d3-a1c60ed31c54) for task 0 of framework c9d498db-5640-4b1e-a958-2780891a60f2-000Build timed out (after 240 minutes). Marking the build as failed. Build was aborted
