See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/2025/changes>
Changes: [benjamin.hindman] Serialize Containerizer::launch,wait invocations. [benjamin.hindman] Added 'bool' return value to Containerizer::launch. [benjamin.hindman] Added composing containerizer and --containerizers flag. [benjamin.hindman] Added a helper for determining the cgroup of particular pid. ------------------------------------------ [...truncated 61378 lines...] I0804 18:45:27.133662 27257 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 23.432629ms I0804 18:45:27.133748 27257 replica.cpp:676] Persisted action at 0 I0804 18:45:27.133955 27257 replica.cpp:655] Replica received learned notice for position 0 I0804 18:45:27.153662 27257 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 19.635239ms I0804 18:45:27.153749 27257 replica.cpp:676] Persisted action at 0 I0804 18:45:27.153806 27257 replica.cpp:661] Replica learned NOP action at position 0 I0804 18:45:27.154067 27257 log.cpp:672] Writer started with ending position 0 I0804 18:45:27.154383 27257 leveldb.cpp:438] Reading position from leveldb took 10735ns I0804 18:45:27.156523 27257 registrar.cpp:346] Successfully fetched the registry (0B) I0804 18:45:27.156610 27257 registrar.cpp:422] Attempting to update the 'registry' I0804 18:45:27.158849 27237 log.cpp:680] Attempting to append 138 bytes to the log I0804 18:45:27.158926 27237 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1 I0804 18:45:27.159185 27237 replica.cpp:508] Replica received write request for position 1 I0804 18:45:27.181671 27237 leveldb.cpp:343] Persisting action (157 bytes) to leveldb took 22.464014ms I0804 18:45:27.181710 27237 replica.cpp:676] Persisted action at 1 I0804 18:45:27.181967 27237 replica.cpp:655] Replica received learned notice for position 1 I0804 18:45:27.201668 27237 leveldb.cpp:343] Persisting action (159 bytes) to leveldb took 19.681537ms I0804 18:45:27.201704 27237 replica.cpp:676] Persisted action at 1 I0804 18:45:27.201714 27237 replica.cpp:661] Replica learned APPEND action at position 1 I0804 18:45:27.202075 27237 registrar.cpp:479] Successfully updated 'registry' I0804 18:45:27.202113 27237 registrar.cpp:372] Successfully recovered registrar I0804 18:45:27.202155 27237 log.cpp:699] Attempting to truncate the log to 1 I0804 18:45:27.202231 27237 master.cpp:987] Recovered 0 slaves from the Registry (100B) ; allowing 10mins for slaves to re-register I0804 18:45:27.202268 27237 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2 I0804 18:45:27.202550 27237 replica.cpp:508] Replica received write request for position 2 I0804 18:45:27.221668 27237 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 19.097017ms I0804 18:45:27.221704 27237 replica.cpp:676] Persisted action at 2 I0804 18:45:27.221956 27237 replica.cpp:655] Replica received learned notice for position 2 I0804 18:45:27.241664 27237 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 19.688201ms I0804 18:45:27.241729 27237 leveldb.cpp:401] Deleting ~1 keys from leveldb took 32578ns I0804 18:45:27.241742 27237 replica.cpp:676] Persisted action at 2 I0804 18:45:27.241752 27237 replica.cpp:661] Replica learned TRUNCATE action at position 2 I0804 18:45:27.250262 25520 containerizer.cpp:124] Using isolation: posix/cpu,posix/mem I0804 18:45:27.253754 27237 slave.cpp:169] Slave started on 197)@140.211.11.27:41719 I0804 18:45:27.253772 27237 credentials.hpp:84] Loading credential for authentication from '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/credential' I0804 18:45:27.253875 27237 slave.cpp:267] Slave using credential for: test-principal I0804 18:45:27.253981 27237 slave.cpp:280] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I0804 18:45:27.254070 27237 slave.cpp:325] Slave hostname: hemera.apache.org I0804 18:45:27.254079 27237 slave.cpp:326] Slave checkpoint: true I0804 18:45:27.254830 27253 state.cpp:33] Recovering state from '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/meta' I0804 18:45:27.257428 25520 sched.cpp:139] Version: 0.20.0 I0804 18:45:27.257617 27237 status_update_manager.cpp:193] Recovering status update manager I0804 18:45:27.257690 27246 sched.cpp:235] New master detected at [email protected]:41719 I0804 18:45:27.257726 27246 sched.cpp:285] Authenticating with master [email protected]:41719 I0804 18:45:27.257846 27246 containerizer.cpp:287] Recovering containerizer I0804 18:45:27.257917 27244 authenticatee.hpp:128] Creating new client SASL connection I0804 18:45:27.258075 27244 master.cpp:3505] Authenticating [email protected]:41719 I0804 18:45:27.258167 27244 authenticator.hpp:156] Creating new server SASL connection I0804 18:45:27.258258 27244 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0804 18:45:27.258275 27244 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0804 18:45:27.258302 27244 authenticator.hpp:262] Received SASL authentication start I0804 18:45:27.258349 27244 authenticator.hpp:384] Authentication requires more steps I0804 18:45:27.258379 27244 authenticatee.hpp:265] Received SASL authentication step I0804 18:45:27.258415 27244 authenticator.hpp:290] Received SASL authentication step I0804 18:45:27.258430 27244 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0804 18:45:27.258437 27244 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0804 18:45:27.258447 27244 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0804 18:45:27.258456 27244 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0804 18:45:27.258462 27244 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0804 18:45:27.258468 27244 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0804 18:45:27.258479 27244 authenticator.hpp:376] Authentication success I0804 18:45:27.258507 27244 authenticatee.hpp:305] Authentication success I0804 18:45:27.258533 27244 master.cpp:3545] Successfully authenticated principal 'test-principal' at [email protected]:41719 I0804 18:45:27.258610 27244 sched.cpp:359] Successfully authenticated with master [email protected]:41719 I0804 18:45:27.258625 27244 sched.cpp:478] Sending registration request to [email protected]:41719 I0804 18:45:27.258668 27244 master.cpp:1248] Received registration request from [email protected]:41719 I0804 18:45:27.258687 27244 master.cpp:1208] Authorizing framework principal 'test-principal' to receive offers for role '*' I0804 18:45:27.258798 27244 master.cpp:1307] Registering framework 20140804-184527-453759884-41719-25520-0000 at [email protected]:41719 I0804 18:45:27.258890 27244 sched.cpp:409] Framework registered with 20140804-184527-453759884-41719-25520-0000 I0804 18:45:27.258913 27244 sched.cpp:423] Scheduler::registered took 9406ns I0804 18:45:27.258949 27244 hierarchical_allocator_process.hpp:331] Added framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:27.258960 27244 hierarchical_allocator_process.hpp:724] No resources available to allocate! I0804 18:45:27.258966 27244 hierarchical_allocator_process.hpp:686] Performed allocation for 0 slaves in 6923ns I0804 18:45:27.259197 27231 slave.cpp:3150] Finished recovery I0804 18:45:27.259404 27231 slave.cpp:601] New master detected at [email protected]:41719 I0804 18:45:27.259425 27231 slave.cpp:677] Authenticating with master [email protected]:41719 I0804 18:45:27.259462 27231 slave.cpp:650] Detecting new master I0804 18:45:27.259495 27231 status_update_manager.cpp:167] New master detected at [email protected]:41719 I0804 18:45:27.259520 27231 authenticatee.hpp:128] Creating new client SASL connection I0804 18:45:27.259621 27231 master.cpp:3505] Authenticating slave(197)@140.211.11.27:41719 I0804 18:45:27.259693 27231 authenticator.hpp:156] Creating new server SASL connection I0804 18:45:27.259767 27231 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0804 18:45:27.259779 27231 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0804 18:45:27.259800 27231 authenticator.hpp:262] Received SASL authentication start I0804 18:45:27.259834 27231 authenticator.hpp:384] Authentication requires more steps I0804 18:45:27.259855 27231 authenticatee.hpp:265] Received SASL authentication step I0804 18:45:27.259881 27231 authenticator.hpp:290] Received SASL authentication step I0804 18:45:27.259894 27231 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0804 18:45:27.259901 27231 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0804 18:45:27.259908 27231 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0804 18:45:27.259917 27231 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0804 18:45:27.259922 27231 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0804 18:45:27.259927 27231 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0804 18:45:27.259937 27231 authenticator.hpp:376] Authentication success I0804 18:45:27.259958 27231 authenticatee.hpp:305] Authentication success I0804 18:45:27.259975 27231 master.cpp:3545] Successfully authenticated principal 'test-principal' at slave(197)@140.211.11.27:41719 I0804 18:45:27.260031 27231 slave.cpp:734] Successfully authenticated with master [email protected]:41719 I0804 18:45:27.260066 27231 slave.cpp:973] Will retry registration in 14.623202ms if necessary I0804 18:45:27.260123 27231 master.cpp:2763] Registering slave at slave(197)@140.211.11.27:41719 (hemera.apache.org) with id 20140804-184527-453759884-41719-25520-0 I0804 18:45:27.260215 27231 registrar.cpp:422] Attempting to update the 'registry' I0804 18:45:27.262416 27231 log.cpp:680] Attempting to append 332 bytes to the log I0804 18:45:27.262471 27231 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3 I0804 18:45:27.262682 27231 replica.cpp:508] Replica received write request for position 3 I0804 18:45:27.277719 27246 slave.cpp:973] Will retry registration in 39.076321ms if necessary I0804 18:45:27.277777 27246 master.cpp:2751] Ignoring register slave message from slave(197)@140.211.11.27:41719 (hemera.apache.org) as admission is already in progress I0804 18:45:27.281662 27231 leveldb.cpp:343] Persisting action (351 bytes) to leveldb took 18.961471ms I0804 18:45:27.281684 27231 replica.cpp:676] Persisted action at 3 I0804 18:45:27.281884 27231 replica.cpp:655] Replica received learned notice for position 3 I0804 18:45:27.301658 27231 leveldb.cpp:343] Persisting action (353 bytes) to leveldb took 19.755979ms I0804 18:45:27.301683 27231 replica.cpp:676] Persisted action at 3 I0804 18:45:27.301692 27231 replica.cpp:661] Replica learned APPEND action at position 3 I0804 18:45:27.302008 27231 registrar.cpp:479] Successfully updated 'registry' I0804 18:45:27.302083 27231 log.cpp:699] Attempting to truncate the log to 3 I0804 18:45:27.302134 27231 master.cpp:2803] Registered slave 20140804-184527-453759884-41719-25520-0 at slave(197)@140.211.11.27:41719 (hemera.apache.org) I0804 18:45:27.302146 27231 master.cpp:3973] Adding slave 20140804-184527-453759884-41719-25520-0 at slave(197)@140.211.11.27:41719 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I0804 18:45:27.302242 27231 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4 I0804 18:45:27.302302 27231 slave.cpp:768] Registered with master [email protected]:41719; given slave ID 20140804-184527-453759884-41719-25520-0 I0804 18:45:27.302435 27231 slave.cpp:781] Checkpointing SlaveInfo to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/meta/slaves/20140804-184527-453759884-41719-25520-0/slave.info' I0804 18:45:27.302570 27231 hierarchical_allocator_process.hpp:444] Added slave 20140804-184527-453759884-41719-25520-0 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I0804 18:45:27.302628 27231 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140804-184527-453759884-41719-25520-0 to framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:27.302736 27231 hierarchical_allocator_process.hpp:706] Performed allocation for slave 20140804-184527-453759884-41719-25520-0 in 133745ns I0804 18:45:27.302786 27231 slave.cpp:2326] Received ping from slave-observer(167)@140.211.11.27:41719 I0804 18:45:27.302841 27231 master.hpp:816] Adding offer 20140804-184527-453759884-41719-25520-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140804-184527-453759884-41719-25520-0 (hemera.apache.org) I0804 18:45:27.302882 27231 master.cpp:3452] Sending 1 offers to framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:27.303009 27231 sched.cpp:546] Scheduler::resourceOffers took 19839ns I0804 18:45:27.303175 27231 replica.cpp:508] Replica received write request for position 4 I0804 18:45:27.305492 27267 master.hpp:826] Removing offer 20140804-184527-453759884-41719-25520-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140804-184527-453759884-41719-25520-0 (hemera.apache.org) I0804 18:45:27.305569 27267 master.cpp:2126] Processing reply for offers: [ 20140804-184527-453759884-41719-25520-0 ] on slave 20140804-184527-453759884-41719-25520-0 at slave(197)@140.211.11.27:41719 (hemera.apache.org) for framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:27.305603 27267 master.cpp:2212] Authorizing framework principal 'test-principal' to launch task e7b05c72-c72b-4201-8d9f-742348d16213 as user 'jenkins' I0804 18:45:27.305969 27267 master.hpp:788] Adding task e7b05c72-c72b-4201-8d9f-742348d16213 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140804-184527-453759884-41719-25520-0 (hemera.apache.org) I0804 18:45:27.306010 27267 master.cpp:2278] Launching task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140804-184527-453759884-41719-25520-0 at slave(197)@140.211.11.27:41719 (hemera.apache.org) I0804 18:45:27.306154 27267 slave.cpp:1004] Got assigned task e7b05c72-c72b-4201-8d9f-742348d16213 for framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:27.306239 27267 slave.cpp:3425] Checkpointing FrameworkInfo to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/meta/slaves/20140804-184527-453759884-41719-25520-0/frameworks/20140804-184527-453759884-41719-25520-0000/framework.info' I0804 18:45:27.306401 27267 slave.cpp:3432] Checkpointing framework pid '[email protected]:41719' to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/meta/slaves/20140804-184527-453759884-41719-25520-0/frameworks/20140804-184527-453759884-41719-25520-0000/framework.pid' I0804 18:45:27.306663 27267 slave.cpp:1114] Launching task e7b05c72-c72b-4201-8d9f-742348d16213 for framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:27.308933 27267 slave.cpp:3739] Checkpointing ExecutorInfo to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/meta/slaves/20140804-184527-453759884-41719-25520-0/frameworks/20140804-184527-453759884-41719-25520-0000/executors/e7b05c72-c72b-4201-8d9f-742348d16213/executor.info' I0804 18:45:27.309355 27267 slave.cpp:3854] Checkpointing TaskInfo to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/meta/slaves/20140804-184527-453759884-41719-25520-0/frameworks/20140804-184527-453759884-41719-25520-0000/executors/e7b05c72-c72b-4201-8d9f-742348d16213/runs/9da0de07-4776-4c37-b961-73ca56c897ba/tasks/e7b05c72-c72b-4201-8d9f-742348d16213/task.info' I0804 18:45:27.309500 27267 slave.cpp:1224] Queuing task 'e7b05c72-c72b-4201-8d9f-742348d16213' for executor e7b05c72-c72b-4201-8d9f-742348d16213 of framework '20140804-184527-453759884-41719-25520-0000 I0804 18:45:27.309628 27267 containerizer.cpp:427] Starting container '9da0de07-4776-4c37-b961-73ca56c897ba' for executor 'e7b05c72-c72b-4201-8d9f-742348d16213' of framework '20140804-184527-453759884-41719-25520-0000' I0804 18:45:27.309820 27266 slave.cpp:562] Successfully attached file '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/slaves/20140804-184527-453759884-41719-25520-0/frameworks/20140804-184527-453759884-41719-25520-0000/executors/e7b05c72-c72b-4201-8d9f-742348d16213/runs/9da0de07-4776-4c37-b961-73ca56c897ba' I0804 18:45:27.313256 27267 launcher.cpp:137] Forked child with pid '22637' for container '9da0de07-4776-4c37-b961-73ca56c897ba' I0804 18:45:27.313335 27267 containerizer.cpp:705] Checkpointing executor's forked pid 22637 to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/meta/slaves/20140804-184527-453759884-41719-25520-0/frameworks/20140804-184527-453759884-41719-25520-0000/executors/e7b05c72-c72b-4201-8d9f-742348d16213/runs/9da0de07-4776-4c37-b961-73ca56c897ba/pids/forked.pid' I0804 18:45:27.322113 27267 containerizer.cpp:537] Fetching URIs for container '9da0de07-4776-4c37-b961-73ca56c897ba' using command '/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src/mesos-fetcher' I0804 18:45:27.357795 27231 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 54.49306ms I0804 18:45:27.357848 27231 replica.cpp:676] Persisted action at 4 I0804 18:45:27.358297 27231 replica.cpp:655] Replica received learned notice for position 4 I0804 18:45:27.372563 27231 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 14.196674ms I0804 18:45:27.372737 27231 leveldb.cpp:401] Deleting ~2 keys from leveldb took 40349ns I0804 18:45:27.372813 27231 replica.cpp:676] Persisted action at 4 I0804 18:45:27.372875 27231 replica.cpp:661] Replica learned TRUNCATE action at position 4 E0804 18:45:27.911058 27249 slave.cpp:2448] Container '9da0de07-4776-4c37-b961-73ca56c897ba' for executor 'e7b05c72-c72b-4201-8d9f-742348d16213' of framework '20140804-184527-453759884-41719-25520-0000' failed to start: TaskInfo/ExecutorInfo not supported WARNING: Logging before InitGoogleLogging() is written to STDERR I0804 18:45:28.000869 22699 process.cpp:1671] libprocess is initialized on 140.211.11.27:33727 for 24 cpus I0804 18:45:28.002581 22699 exec.cpp:131] Version: 0.20.0 I0804 18:45:28.003415 22726 exec.cpp:181] Executor started at: executor(1)@140.211.11.27:33727 with pid 22699 I0804 18:45:28.009750 27249 slave.cpp:1735] Got registration for executor 'e7b05c72-c72b-4201-8d9f-742348d16213' of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.009809 27249 slave.cpp:1820] Checkpointing executor pid 'executor(1)@140.211.11.27:33727' to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/meta/slaves/20140804-184527-453759884-41719-25520-0/frameworks/20140804-184527-453759884-41719-25520-0000/executors/e7b05c72-c72b-4201-8d9f-742348d16213/runs/9da0de07-4776-4c37-b961-73ca56c897ba/pids/libprocess.pid' I0804 18:45:28.010179 27249 slave.cpp:1854] Flushing queued task e7b05c72-c72b-4201-8d9f-742348d16213 for executor 'e7b05c72-c72b-4201-8d9f-742348d16213' of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.010658 27269 process.cpp:1098] Socket closed while receiving I0804 18:45:28.013875 22761 process.cpp:1037] Socket closed while receiving I0804 18:45:28.014106 25520 slave.cpp:485] Slave terminating I0804 18:45:28.014780 25520 containerizer.cpp:124] Using isolation: posix/cpu,posix/mem I0804 18:45:28.017727 22750 exec.cpp:205] Executor registered on slave 20140804-184527-453759884-41719-25520-0 I0804 18:45:28.017844 27261 slave.cpp:169] Slave started on 198)@140.211.11.27:41719 I0804 18:45:28.017871 27261 credentials.hpp:84] Loading credential for authentication from '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/credential' I0804 18:45:28.017861 27255 master.cpp:767] Slave 20140804-184527-453759884-41719-25520-0 at slave(197)@140.211.11.27:41719 (hemera.apache.org) disconnected I0804 18:45:28.017904 27255 master.cpp:1610] Disconnecting slave 20140804-184527-453759884-41719-25520-0 I0804 18:45:28.019037 22750 exec.cpp:217] Executor::registered took 103486ns I0804 18:45:28.019114 22750 exec.cpp:292] Executor asked to run task 'e7b05c72-c72b-4201-8d9f-742348d16213' I0804 18:45:28.019160 22750 exec.cpp:301] Executor::launchTask took 32311ns Registered executor on hemera.apache.org Starting task e7b05c72-c72b-4201-8d9f-742348d16213 sh -c 'sleep 1000' I0804 18:45:28.021733 27261 slave.cpp:267] Slave using credential for: test-principal I0804 18:45:28.021845 27261 slave.cpp:280] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I0804 18:45:28.021955 27261 slave.cpp:325] Slave hostname: hemera.apache.org I0804 18:45:28.021967 27261 slave.cpp:326] Slave checkpoint: true I0804 18:45:28.022542 27261 state.cpp:33] Recovering state from '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/meta' W0804 18:45:28.023190 27261 state.cpp:558] Failed to find status updates file '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/meta/slaves/20140804-184527-453759884-41719-25520-0/frameworks/20140804-184527-453759884-41719-25520-0000/executors/e7b05c72-c72b-4201-8d9f-742348d16213/runs/9da0de07-4776-4c37-b961-73ca56c897ba/tasks/e7b05c72-c72b-4201-8d9f-742348d16213/task.updates' I0804 18:45:28.023794 27261 slave.cpp:3221] Recovering framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.023814 27261 slave.cpp:3589] Recovering executor 'e7b05c72-c72b-4201-8d9f-742348d16213' of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.024324 27261 status_update_manager.cpp:193] Recovering status update manager I0804 18:45:28.024334 27261 status_update_manager.cpp:201] Recovering executor 'e7b05c72-c72b-4201-8d9f-742348d16213' of framework 20140804-184527-453759884-41719-25520-0000 W0804 18:45:28.024348 27261 status_update_manager.cpp:240] No updates found for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.024477 27261 slave.cpp:562] Successfully attached file '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_tblm1v/slaves/20140804-184527-453759884-41719-25520-0/frameworks/20140804-184527-453759884-41719-25520-0000/executors/e7b05c72-c72b-4201-8d9f-742348d16213/runs/9da0de07-4776-4c37-b961-73ca56c897ba' I0804 18:45:28.024637 27261 containerizer.cpp:287] Recovering containerizer I0804 18:45:28.024653 27261 containerizer.cpp:329] Recovering container '9da0de07-4776-4c37-b961-73ca56c897ba' for executor 'e7b05c72-c72b-4201-8d9f-742348d16213' of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.025266 27261 slave.cpp:3091] Sending reconnect request to executor e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 at executor(1)@140.211.11.27:33727 I0804 18:45:28.025404 27255 hierarchical_allocator_process.hpp:483] Slave 20140804-184527-453759884-41719-25520-0 deactivated Forked command at 22764 I0804 18:45:28.025706 27269 process.cpp:1098] Socket closed while receiving I0804 18:45:28.025939 22730 exec.cpp:251] Received reconnect request from slave 20140804-184527-453759884-41719-25520-0 I0804 18:45:28.025974 22761 process.cpp:1037] Socket closed while receiving I0804 18:45:28.031144 22750 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 0e527946-b427-47d9-83a5-d9269f9a588b) for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.037708 27261 hierarchical_allocator_process.hpp:686] Performed allocation for 1 slaves in 32273ns I0804 18:45:28.037775 27261 slave.cpp:1914] Re-registering executor e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.038620 27269 process.cpp:1098] Socket closed while receiving I0804 18:45:28.038673 27261 slave.cpp:2089] Handling status update TASK_RUNNING (UUID: 0e527946-b427-47d9-83a5-d9269f9a588b) for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 from executor(1)@140.211.11.27:33727 I0804 18:45:28.038727 22761 process.cpp:1037] Socket closed while receiving I0804 18:45:28.038748 22750 exec.cpp:228] Executor re-registered on slave 20140804-184527-453759884-41719-25520-0 I0804 18:45:28.038769 27261 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 0e527946-b427-47d9-83a5-d9269f9a588b) for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.038781 27261 status_update_manager.cpp:499] Creating StatusUpdate stream for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.038929 27261 status_update_manager.hpp:342] Checkpointing UPDATE for status update TASK_RUNNING (UUID: 0e527946-b427-47d9-83a5-d9269f9a588b) for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 Re-registered executor on hemera.apache.org I0804 18:45:28.040091 22750 exec.cpp:240] Executor::reregistered took 51962ns W0804 18:45:28.065003 27261 status_update_manager.cpp:381] Not forwarding status update TASK_RUNNING (UUID: 0e527946-b427-47d9-83a5-d9269f9a588b) for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 because no master is elected yet I0804 18:45:28.065130 27261 slave.cpp:2247] Status update manager successfully handled status update TASK_RUNNING (UUID: 0e527946-b427-47d9-83a5-d9269f9a588b) for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.065142 27261 slave.cpp:2253] Sending acknowledgement for status update TASK_RUNNING (UUID: 0e527946-b427-47d9-83a5-d9269f9a588b) for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 to executor(1)@140.211.11.27:33727 I0804 18:45:28.069711 27269 process.cpp:1098] Socket closed while receiving I0804 18:45:28.069857 22750 exec.cpp:338] Executor received status update acknowledgement 0e527946-b427-47d9-83a5-d9269f9a588b for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.069790 22761 process.cpp:1037] Socket closed while receiving I0804 18:45:28.365787 27246 containerizer.cpp:909] Destroying container '9da0de07-4776-4c37-b961-73ca56c897ba' I0804 18:45:28.511019 27269 process.cpp:1037] Socket closed while receiving I0804 18:45:28.917812 27246 containerizer.cpp:1025] Executor for container '9da0de07-4776-4c37-b961-73ca56c897ba' has exited I0804 18:45:28.918125 27246 slave.cpp:2550] Executor 'e7b05c72-c72b-4201-8d9f-742348d16213' of framework 20140804-184527-453759884-41719-25520-0000 terminated with signal Killed I0804 18:45:28.920038 27246 slave.cpp:2089] Handling status update TASK_FAILED (UUID: 31ac24ea-d3f6-4a1f-b79d-852ee5c35e00) for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 from @0.0.0.0:0 I0804 18:45:28.920066 27246 slave.cpp:3787] Terminating task e7b05c72-c72b-4201-8d9f-742348d16213 W0804 18:45:28.920225 27246 containerizer.cpp:815] Ignoring update for unknown container: 9da0de07-4776-4c37-b961-73ca56c897ba I0804 18:45:28.920354 27246 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: 31ac24ea-d3f6-4a1f-b79d-852ee5c35e00) for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.920372 27246 status_update_manager.hpp:342] Checkpointing UPDATE for status update TASK_FAILED (UUID: 31ac24ea-d3f6-4a1f-b79d-852ee5c35e00) for task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.921777 27237 sched.cpp:747] Stopping framework '20140804-184527-453759884-41719-25520-0000' I0804 18:45:28.921876 27231 master.cpp:626] Master terminating I0804 18:45:28.921939 27231 master.hpp:806] Removing task e7b05c72-c72b-4201-8d9f-742348d16213 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140804-184527-453759884-41719-25520-0 (hemera.apache.org) W0804 18:45:28.922025 27231 master.cpp:4262] Removing task e7b05c72-c72b-4201-8d9f-742348d16213 of framework 20140804-184527-453759884-41719-25520-0000 and slave 20140804-184527-453759884-41719-25520-0 in non-terminal state TASK_STAGING I0804 18:45:28.922214 27231 hierarchical_allocator_process.hpp:635] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 20140804-184527-453759884-41719-25520-0 from framework 20140804-184527-453759884-41719-25520-0000 I0804 18:45:28.933886 25520 slave.cpp:485] Slave terminating [ OK ] MesosContainerizerSlaveRecoveryTest.ResourceStatistics (2020 ms) [----------] 1 test from MesosContainerizerSlaveRecoveryTest (2020 ms total) [----------] Global test environment tear-down [==========] 392 tests from 64 test cases ran. (425574 ms total) [ PASSED ] 390 tests. [ FAILED ] 2 tests, listed below: [ FAILED ] SlaveRecoveryTest/0.RestartBeforeContainerizerLaunch, where TypeParam = mesos::internal::slave::MesosContainerizer [ FAILED ] SlaveTest.MesosExecutorWithOverride 2 FAILED TESTS YOU HAVE 4 DISABLED TESTS make[4]: *** [check-local] Error 1 make[4]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src' make[3]: *** [check-am] Error 2 make[3]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src' make[2]: *** [check] Error 2 make[2]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src' make[1]: *** [check-recursive] Error 1 make[1]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build' make: *** [distcheck] Error 1 Build step 'Execute shell' marked build as failure
