You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by "Vinod Kone (JIRA)" <ji...@apache.org> on 2013/08/22 07:40:59 UTC
[jira] [Created] (MESOS-656) SlaveRecoveryTest/1.PartitionedSlave
fails with cgroups
Vinod Kone created MESOS-656:
--------------------------------
Summary: SlaveRecoveryTest/1.PartitionedSlave fails with cgroups
Key: MESOS-656
URL: https://issues.apache.org/jira/browse/MESOS-656
Project: Mesos
Issue Type: Bug
Reporter: Vinod Kone
Assignee: Jie Yu
Fix For: 0.14.0
[vinod@smfd-aki-27-sr1 build]$ cat /tmp/anon
[vinod@smfd-aki-27-sr1 build]$ sudo GLOG_v=1 ./bin/mesos-tests.sh --gtest_filter="SlaveRecoveryTest/1.PartitionedSlave" --verbose
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0822 05:32:41.300804 32727 process.cpp:1555] libprocess is initialized on <ip>:40057 for 16 cpus
I0822 05:32:41.301574 32727 logging.cpp:97] Logging to STDERR
Source directory: /home/vinod/mesos
Build directory: /home/vinod/mesos/build
Note: Google Test filter = SlaveRecoveryTest/1.PartitionedSlave-
[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[----------] 1 test from SlaveRecoveryTest/1, where TypeParam = mesos::internal::slave::CgroupsIsolator
[ RUN ] SlaveRecoveryTest/1.PartitionedSlave
I0822 05:32:41.307350 32750 master.cpp:230] Master started on <ip>:40057
I0822 05:32:41.307487 32750 master.cpp:245] Master ID: 201308220532-2081170186-40057-32727
W0822 05:32:41.308032 32742 master.cpp:83] No whitelist given. Advertising offers for all slaves
I0822 05:32:41.308197 32755 hierarchical_allocator_process.hpp:291] Initializing hierarchical allocator process with master : master@<ip>:40057
I0822 05:32:41.309728 32750 master.cpp:613] Elected as master!
I0822 05:32:41.310422 32756 slave.cpp:113] Slave started on 1)@<ip>:40057
I0822 05:32:41.310816 32756 slave.cpp:213] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0822 05:32:41.311655 32752 sched.cpp:178] New master at master@<ip>:40057
I0822 05:32:41.312114 32749 cgroups_isolator.cpp:224] Using /tmp/mesos_test_cgroup as cgroups hierarchy root
I0822 05:32:41.312227 32745 master.cpp:663] Registering framework 201308220532-2081170186-40057-32727-0000 at scheduler(1)@<ip>:40057
I0822 05:32:41.312657 32755 sched.cpp:237] Framework registered with 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.312790 32744 hierarchical_allocator_process.hpp:321] Added framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.312826 32756 slave.cpp:549] New master detected at master@<ip>:40057
I0822 05:32:41.312849 32755 sched.cpp:251] Scheduler::registered took 59.153us
I0822 05:32:41.312840 32744 hierarchical_allocator_process.hpp:687] No resources available to allocate!
I0822 05:32:41.312937 32756 slave.cpp:564] Postponing registration until recovery is complete
I0822 05:32:41.312952 32744 hierarchical_allocator_process.hpp:649] Performed allocation for 0 slaves in 121.203us
I0822 05:32:41.312947 32755 status_update_manager.cpp:157] New master detected at master@<ip>:40057
I0822 05:32:41.317355 32749 cgroups_isolator.cpp:791] Recovering isolator
I0822 05:32:41.318194 32752 slave.cpp:404] Finished recovery
I0822 05:32:41.318797 32741 master.cpp:1032] Attempting to register slave on <hostname> at slave(1)@<ip>:40057
I0822 05:32:41.318831 32741 master.cpp:2042] Adding slave 201308220532-2081170186-40057-32727-0 at <hostname> with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0822 05:32:41.319134 32748 slave.cpp:609] Registered with master master@<ip>:40057; given slave ID 201308220532-2081170186-40057-32727-0
I0822 05:32:41.319362 32748 paths.hpp:369] Created slave directory '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta/slaves/201308220532-2081170186-40057-32727-0'
I0822 05:32:41.319365 32753 hierarchical_allocator_process.hpp:434] Added slave 201308220532-2081170186-40057-32727-0 (<hostname>) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta/slaves/201308220532-2081170186-40057-32727-0/slave.info'
I0822 05:32:41.319573 32753 hierarchical_allocator_process.hpp:712] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201308220532-2081170186-40057-32727-0 to framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.319869 32753 hierarchical_allocator_process.hpp:669] Performed allocation for slave 201308220532-2081170186-40057-32727-0 in 395.454us
I0822 05:32:41.320164 32756 master.hpp:333] Adding offer 201308220532-2081170186-40057-32727-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201308220532-2081170186-40057-32727-0 (<hostname>)
I0822 05:32:41.320273 32756 master.cpp:1403] Sending 1 offers to framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.320667 32756 sched.cpp:340] Scheduler::resourceOffers took 50.907us
I0822 05:32:41.323725 32747 master.cpp:1640] Processing reply for offer 201308220532-2081170186-40057-32727-0 on slave 201308220532-2081170186-40057-32727-0 (<hostname>) for framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.324600 32747 master.hpp:310] Adding task c4dc8b8b-7e95-49d0-ae60-4d716290020c with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201308220532-2081170186-40057-32727-0 (<hostname>)
I0822 05:32:41.324971 32747 master.cpp:1760] Launching task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201308220532-2081170186-40057-32727-0 (<hostname>)
I0822 05:32:41.325589 32745 slave.cpp:771] Got assigned task c4dc8b8b-7e95-49d0-ae60-4d716290020c for framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.325592 32747 master.hpp:343] Removing offer 201308220532-2081170186-40057-32727-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201308220532-2081170186-40057-32727-0 (<hostname>)
Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta/slaves/201308220532-2081170186-40057-32727-0/frameworks/201308220532-2081170186-40057-32727-0000/framework.info'
Checkpointing 'scheduler(1)@<ip>:40057' to '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta/slaves/201308220532-2081170186-40057-32727-0/frameworks/201308220532-2081170186-40057-32727-0000/framework.pid'
I0822 05:32:41.326714 32745 slave.cpp:882] Launching task c4dc8b8b-7e95-49d0-ae60-4d716290020c for framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.328809 32745 paths.hpp:336] Created executor directory '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/slaves/201308220532-2081170186-40057-32727-0/frameworks/201308220532-2081170186-40057-32727-0000/executors/c4dc8b8b-7e95-49d0-ae60-4d716290020c/runs/b76b9d48-64eb-41bd-877f-0f6e83dd5e07'
Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta/slaves/201308220532-2081170186-40057-32727-0/frameworks/201308220532-2081170186-40057-32727-0000/executors/c4dc8b8b-7e95-49d0-ae60-4d716290020c/executor.info'
I0822 05:32:41.329428 32745 paths.hpp:336] Created executor directory '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta/slaves/201308220532-2081170186-40057-32727-0/frameworks/201308220532-2081170186-40057-32727-0000/executors/c4dc8b8b-7e95-49d0-ae60-4d716290020c/runs/b76b9d48-64eb-41bd-877f-0f6e83dd5e07'
Checkpointing Task to '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta/slaves/201308220532-2081170186-40057-32727-0/frameworks/201308220532-2081170186-40057-32727-0000/executors/c4dc8b8b-7e95-49d0-ae60-4d716290020c/runs/b76b9d48-64eb-41bd-877f-0f6e83dd5e07/tasks/c4dc8b8b-7e95-49d0-ae60-4d716290020c/task.info'
I0822 05:32:41.330199 32745 slave.cpp:993] Queuing task 'c4dc8b8b-7e95-49d0-ae60-4d716290020c' for executor c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework '201308220532-2081170186-40057-32727-0000
I0822 05:32:41.330472 32745 slave.cpp:531] Successfully attached file '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/slaves/201308220532-2081170186-40057-32727-0/frameworks/201308220532-2081170186-40057-32727-0000/executors/c4dc8b8b-7e95-49d0-ae60-4d716290020c/runs/b76b9d48-64eb-41bd-877f-0f6e83dd5e07'
I0822 05:32:41.330521 32748 cgroups_isolator.cpp:513] Launching c4dc8b8b-7e95-49d0-ae60-4d716290020c (/home/vinod/mesos/build/src/mesos-executor) in /tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/slaves/201308220532-2081170186-40057-32727-0/frameworks/201308220532-2081170186-40057-32727-0000/executors/c4dc8b8b-7e95-49d0-ae60-4d716290020c/runs/b76b9d48-64eb-41bd-877f-0f6e83dd5e07 with resources for framework 201308220532-2081170186-40057-32727-0000 in cgroup mesos_test/framework_201308220532-2081170186-40057-32727-0000_executor_c4dc8b8b-7e95-49d0-ae60-4d716290020c_tag_b76b9d48-64eb-41bd-877f-0f6e83dd5e07
I0822 05:32:41.331620 32748 cgroups_isolator.cpp:705] Changing cgroup controls for executor c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000 with resources
I0822 05:32:41.332352 32748 cgroups_isolator.cpp:1109] Started listening for OOM events for executor c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000
Checkpointing forked pid 32758
Checkpointing '32758' to '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta/slaves/201308220532-2081170186-40057-32727-0/frameworks/201308220532-2081170186-40057-32727-0000/executors/c4dc8b8b-7e95-49d0-ae60-4d716290020c/runs/b76b9d48-64eb-41bd-877f-0f6e83dd5e07/pids/forked.pid'
I0822 05:32:41.333046 32748 cgroups_isolator.cpp:565] Forked executor at = 32758
Fetching resources into '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/slaves/201308220532-2081170186-40057-32727-0/frameworks/201308220532-2081170186-40057-32727-0000/executors/c4dc8b8b-7e95-49d0-ae60-4d716290020c/runs/b76b9d48-64eb-41bd-877f-0f6e83dd5e07'
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0822 05:32:41.371963 32758 process.cpp:1555] libprocess is initialized on <ip>:60511 for 16 cpus
I0822 05:32:41.373756 32789 exec.cpp:171] Executor started at: executor(1)@<ip>:60511 with pid 32758
I0822 05:32:41.374852 32744 slave.cpp:1437] Got registration for executor 'c4dc8b8b-7e95-49d0-ae60-4d716290020c' of framework 201308220532-2081170186-40057-32727-0000
Checkpointing 'executor(1)@<ip>:60511' to '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta/slaves/201308220532-2081170186-40057-32727-0/frameworks/201308220532-2081170186-40057-32727-0000/executors/c4dc8b8b-7e95-49d0-ae60-4d716290020c/runs/b76b9d48-64eb-41bd-877f-0f6e83dd5e07/pids/libprocess.pid'
I0822 05:32:41.375720 32745 cgroups_isolator.cpp:705] Changing cgroup controls for executor c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0822 05:32:41.376500 32790 process.cpp:986] Socket closed while receiving
I0822 05:32:41.376090 32744 slave.cpp:1556] Flushing queued task c4dc8b8b-7e95-49d0-ae60-4d716290020c for executor 'c4dc8b8b-7e95-49d0-ae60-4d716290020c' of framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.376759 32778 exec.cpp:195] Executor registered on slave 201308220532-2081170186-40057-32727-0
I0822 05:32:41.376984 32778 exec.cpp:206] Executor::registered took 187.692us
Registered executor on <hostname>
I0822 05:32:41.377020 32790 process.cpp:986] Socket closed while receiving
I0822 05:32:41.377291 32778 exec.cpp:278] Executor asked to run task 'c4dc8b8b-7e95-49d0-ae60-4d716290020c'
I0822 05:32:41.377388 32778 exec.cpp:287] Executor::launchTask took 71.082us
Starting task c4dc8b8b-7e95-49d0-ae60-4d716290020c
I0822 05:32:41.376772 32745 cgroups_isolator.cpp:945] Updated 'cpu.shares' to 2048 for executor c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000
sh -c 'sleep 1000'
Forked command at 32791
I0822 05:32:41.378352 32745 cgroups_isolator.cpp:1083] Updated 'memory.soft_limit_in_bytes' to 1073741824 for executor c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.380643 32777 exec.cpp:469] Executor sending status update TASK_RUNNING (UUID: bfe4f003-b97e-4c6e-94d4-4bfa0109fdd8) for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.381350 32755 slave.cpp:1766] Handling status update TASK_RUNNING (UUID: bfe4f003-b97e-4c6e-94d4-4bfa0109fdd8) for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000 from executor(1)@<ip>:60511
I0822 05:32:41.382068 32755 status_update_manager.cpp:300] Received status update TASK_RUNNING (UUID: bfe4f003-b97e-4c6e-94d4-4bfa0109fdd8) for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.382360 32755 status_update_manager.cpp:471] Creating StatusUpdate stream for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.382979 32755 status_update_manager.hpp:337] Checkpointing UPDATE for status update TASK_RUNNING (UUID: bfe4f003-b97e-4c6e-94d4-4bfa0109fdd8) for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.533018 32755 status_update_manager.cpp:351] Forwarding status update TASK_RUNNING (UUID: bfe4f003-b97e-4c6e-94d4-4bfa0109fdd8) for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000 to master@<ip>:40057
I0822 05:32:41.534148 32749 slave.cpp:1885] Status update manager successfully handled status update TASK_RUNNING (UUID: bfe4f003-b97e-4c6e-94d4-4bfa0109fdd8) for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.534137 32741 master.cpp:1169] Status update TASK_RUNNING (UUID: bfe4f003-b97e-4c6e-94d4-4bfa0109fdd8) for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000 from slave(1)@<ip>:40057
I0822 05:32:41.534459 32749 slave.cpp:1891] Sending acknowledgement for status update TASK_RUNNING (UUID: bfe4f003-b97e-4c6e-94d4-4bfa0109fdd8) for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000 to executor(1)@<ip>:60511
I0822 05:32:41.535447 32748 sched.cpp:395] Scheduler::statusUpdate took 24.946us
I0822 05:32:41.535888 32790 process.cpp:986] Socket closed while receiving
I0822 05:32:41.535979 32776 exec.cpp:324] Executor received status update acknowledgement bfe4f003-b97e-4c6e-94d4-4bfa0109fdd8 for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.536345 32743 status_update_manager.cpp:375] Received status update acknowledgement (UUID: bfe4f003-b97e-4c6e-94d4-4bfa0109fdd8) for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.536509 32743 status_update_manager.hpp:337] Checkpointing ACK for status update TASK_RUNNING (UUID: bfe4f003-b97e-4c6e-94d4-4bfa0109fdd8) for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.625432 32756 slave.cpp:1383] Status update manager successfully handled status update acknowledgement (UUID: bfe4f003-b97e-4c6e-94d4-4bfa0109fdd8) for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.628168 32749 hierarchical_allocator_process.hpp:649] Performed allocation for 1 slaves in 116.403us
W0822 05:32:41.628233 32748 master.cpp:83] No whitelist given. Advertising offers for all slaves
I0822 05:32:41.630333 32750 monitor.cpp:180] Publishing resource usage for executor 'c4dc8b8b-7e95-49d0-ae60-4d716290020c' of framework '201308220532-2081170186-40057-32727-0000'
W0822 05:32:41.638368 32747 master.cpp:83] No whitelist given. Advertising offers for all slaves
I0822 05:32:41.638612 32748 hierarchical_allocator_process.hpp:649] Performed allocation for 1 slaves in 81.786us
I0822 05:32:41.639991 32746 monitor.cpp:180] Publishing resource usage for executor 'c4dc8b8b-7e95-49d0-ae60-4d716290020c' of framework '201308220532-2081170186-40057-32727-0000'
W0822 05:32:41.648931 32754 master.cpp:83] No whitelist given. Advertising offers for all slaves
I0822 05:32:41.649000 32755 hierarchical_allocator_process.hpp:649] Performed allocation for 1 slaves in 100.055us
I0822 05:32:41.650557 32745 monitor.cpp:180] Publishing resource usage for executor 'c4dc8b8b-7e95-49d0-ae60-4d716290020c' of framework '201308220532-2081170186-40057-32727-0000'
W0822 05:32:41.659109 32753 master.cpp:83] No whitelist given. Advertising offers for all slaves
I0822 05:32:41.659200 32747 hierarchical_allocator_process.hpp:649] Performed allocation for 1 slaves in 112.024us
I0822 05:32:41.659864 32750 slave.cpp:2596] Current usage 4.72%. Max allowed age: 5.969295237817998days
I0822 05:32:41.660876 32746 monitor.cpp:180] Publishing resource usage for executor 'c4dc8b8b-7e95-49d0-ae60-4d716290020c' of framework '201308220532-2081170186-40057-32727-0000'
W0822 05:32:41.669231 32742 master.cpp:83] No whitelist given. Advertising offers for all slaves
I0822 05:32:41.669329 32756 hierarchical_allocator_process.hpp:649] Performed allocation for 1 slaves in 124.831us
W0822 05:32:41.669500 32751 master.cpp:1306] Removing slave 201308220532-2081170186-40057-32727-0 at slave(1)@<ip>:40057 because it has been deactivated
I0822 05:32:41.669699 32751 master.cpp:2152] Removing slave 201308220532-2081170186-40057-32727-0 (<hostname>)
I0822 05:32:41.669806 32749 slave.cpp:505] Slave asked to shut down by master@<ip>:40057
I0822 05:32:41.670986 32755 monitor.cpp:180] Publishing resource usage for executor 'c4dc8b8b-7e95-49d0-ae60-4d716290020c' of framework '201308220532-2081170186-40057-32727-0000'
I0822 05:32:41.671062 32749 slave.cpp:1166] Asked to shut down framework 201308220532-2081170186-40057-32727-0000 by master@<ip>:40057
I0822 05:32:41.671241 32754 hierarchical_allocator_process.hpp:459] Removed slave 201308220532-2081170186-40057-32727-0
I0822 05:32:41.671298 32749 slave.cpp:1191] Shutting down framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.671574 32749 slave.cpp:2417] Shutting down executor 'c4dc8b8b-7e95-49d0-ae60-4d716290020c' of framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.671906 32790 process.cpp:986] Socket closed while receiving
I0822 05:32:41.671972 32789 exec.cpp:364] Executor asked to shutdown
IShutting down
Killing process tree at pid 32791
0822 05:32:41.672068 32778 exec.cpp:76] Scheduling shutdown of the executor
I0822 05:32:41.672063 32789 exec.cpp:379] Executor::shutdown took 10.908us
I0822 05:32:41.672957 32751 master.cpp:1169] Status update TASK_LOST (UUID: 2da19494-f28c-49f4-bac9-6e16d0d2c10c) for task c4dc8b8b-7e95-49d0-ae60-4d716290020c of framework 201308220532-2081170186-40057-32727-0000 from @0.0.0.0:0
I0822 05:32:41.675581 32751 master.hpp:323] Removing task c4dc8b8b-7e95-49d0-ae60-4d716290020c with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201308220532-2081170186-40057-32727-0 (<hostname>)
I0822 05:32:41.675604 32742 sched.cpp:395] Scheduler::statusUpdate took 48.78us
I0822 05:32:41.676053 32755 sched.cpp:439] Lost slave 201308220532-2081170186-40057-32727-0
I0822 05:32:41.676244 32755 sched.cpp:450] Scheduler::slaveLost took 90.78us
I0822 05:32:41.679101 32727 slave.cpp:459] Slave terminating
I0822 05:32:41.681224 32744 slave.cpp:113] Slave started on 2)@<ip>:40057
I0822 05:32:41.681457 32744 slave.cpp:213] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0822 05:32:41.682106 32743 cgroups_isolator.cpp:224] Using /tmp/mesos_test_cgroup as cgroups hierarchy root
I0822 05:32:41.682374 32744 state.cpp:33] Recovering state from /tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta
I0822 05:32:41.685153 32744 state.cpp:41] Failed to find the latest slave from '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta'
I0822 05:32:41.685586 32744 slave.cpp:549] New master detected at master@<ip>:40057
I0822 05:32:41.685827 32744 slave.cpp:564] Postponing registration until recovery is complete
I0822 05:32:41.685972 32741 status_update_manager.cpp:157] New master detected at master@<ip>:40057
Killed the following process trees:
[
--- 32791 sleep 1000
]
I0822 05:32:41.743227 32743 cgroups_isolator.cpp:791] Recovering isolator
I0822 05:32:41.744333 32743 cgroups_isolator.cpp:880] Removing orphaned cgroup 'mesos_test/framework_201308220532-2081170186-40057-32727-0000_executor_c4dc8b8b-7e95-49d0-ae60-4d716290020c_tag_b76b9d48-64eb-41bd-877f-0f6e83dd5e07'
I0822 05:32:41.746001 32747 slave.cpp:404] Finished recovery
I0822 05:32:41.746359 32747 slave.cpp:424] Garbage collecting old slave 201308220532-2081170186-40057-32727-0
I0822 05:32:41.746901 32750 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/slaves/201308220532-2081170186-40057-32727-0' for removal
I0822 05:32:41.747517 32749 master.cpp:1032] Attempting to register slave on <hostname> at slave(2)@<ip>:40057
I0822 05:32:41.747551 32750 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta/slaves/201308220532-2081170186-40057-32727-0' for removal
I0822 05:32:41.747848 32749 master.cpp:2042] Adding slave 201308220532-2081170186-40057-32727-1 at <hostname> with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0822 05:32:41.748072 32753 sched.cpp:498] Stopping framework '201308220532-2081170186-40057-32727-0000'
I0822 05:32:41.748273 32746 slave.cpp:609] Registered with master master@<ip>:40057; given slave ID 201308220532-2081170186-40057-32727-1
I0822 05:32:41.748483 32749 master.cpp:446] Master terminating
I0822 05:32:41.748559 32746 paths.hpp:369] Created slave directory '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta/slaves/201308220532-2081170186-40057-32727-1'
I0822 05:32:41.748579 32751 hierarchical_allocator_process.hpp:434] Added slave 201308220532-2081170186-40057-32727-1 (<hostname>) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_1_PartitionedSlave_CuQlvb/meta/slaves/201308220532-2081170186-40057-32727-1/slave.info'
I0822 05:32:41.748713 32727 master.cpp:209] Shutting down master
I0822 05:32:41.748860 32751 hierarchical_allocator_process.hpp:712] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201308220532-2081170186-40057-32727-1 to framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.748951 32727 master.cpp:1926] Removing framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.749091 32746 slave.cpp:505] Slave asked to shut down by master@<ip>:40057
I0822 05:32:41.749176 32746 slave.cpp:459] Slave terminating
I0822 05:32:41.749198 32751 hierarchical_allocator_process.hpp:669] Performed allocation for slave 201308220532-2081170186-40057-32727-1 in 430.155us
I0822 05:32:41.749367 32727 master.cpp:2152] Removing slave 201308220532-2081170186-40057-32727-1 (<hostname>)
I0822 05:32:41.749444 32751 hierarchical_allocator_process.hpp:397] Deactivated framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.749683 32751 hierarchical_allocator_process.hpp:352] Removed framework 201308220532-2081170186-40057-32727-0000
I0822 05:32:41.749847 32751 hierarchical_allocator_process.hpp:459] Removed slave 201308220532-2081170186-40057-32727-1
I0822 05:32:41.751276 32757 process.cpp:986] Socket closed while receiving
I0822 05:32:41.752579 32749 cgroups.cpp:1193] Trying to freeze cgroup /tmp/mesos_test_cgroup/mesos_test/framework_201308220532-2081170186-40057-32727-0000_executor_c4dc8b8b-7e95-49d0-ae60-4d716290020c_tag_b76b9d48-64eb-41bd-877f-0f6e83dd5e07
I0822 05:32:41.752755 32749 cgroups.cpp:1232] Successfully froze cgroup /tmp/mesos_test_cgroup/mesos_test/framework_201308220532-2081170186-40057-32727-0000_executor_c4dc8b8b-7e95-49d0-ae60-4d716290020c_tag_b76b9d48-64eb-41bd-877f-0f6e83dd5e07 after 1 attempts
I0822 05:32:41.755101 32747 cgroups.cpp:1208] Trying to thaw cgroup /tmp/mesos_test_cgroup/mesos_test/framework_201308220532-2081170186-40057-32727-0000_executor_c4dc8b8b-7e95-49d0-ae60-4d716290020c_tag_b76b9d48-64eb-41bd-877f-0f6e83dd5e07
I0822 05:32:41.755275 32747 cgroups.cpp:1318] Successfully thawed /tmp/mesos_test_cgroup/mesos_test/framework_201308220532-2081170186-40057-32727-0000_executor_c4dc8b8b-7e95-49d0-ae60-4d716290020c_tag_b76b9d48-64eb-41bd-877f-0f6e83dd5e07
I0822 05:32:41.759117 32756 cgroups.cpp:1193] Trying to freeze cgroup /tmp/mesos_test_cgroup/mesos_test
I0822 05:32:41.759294 32756 cgroups.cpp:1232] Successfully froze cgroup /tmp/mesos_test_cgroup/mesos_test after 1 attempts
../../src/tests/mesos.cpp:223: Failure
(cgroups::destroy(hierarchy, TEST_CGROUPS_ROOT)).failure(): Failed to kill tasks in nested cgroups: Collect failed: 'mesos_test/framework_201308220532-2081170186-40057-32727-0000_executor_c4dc8b8b-7e95-49d0-ae60-4d716290020c_tag_b76b9d48-64eb-41bd-877f-0f6e83dd5e07' is not a valid cgroup
[ FAILED ] SlaveRecoveryTest/1.PartitionedSlave, where TypeParam = mesos::internal::slave::CgroupsIsolator (456 ms)
I0822 05:32:41.762033 32743 cgroups.cpp:1208] Trying to thaw cgroup /tmp/mesos_test_cgroup/mesos_test
I0822 05:32:41.762225 32743 cgroups.cpp:1318] Successfully thawed /tmp/mesos_test_cgroup/mesos_test
[----------] 1 test from SlaveRecoveryTest/1 (456 ms total)
[----------] Global test environment tear-down
[==========] 1 test from 1 test case ran. (1983 ms total)
[ PASSED ] 0 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] SlaveRecoveryTest/1.PartitionedSlave, where TypeParam = mesos::internal::slave::CgroupsIsolator
1 FAILED TEST
[vinod@smfd-aki-27-sr1 build]$
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira