Looks like my zombie check caught an un-reaped executor! Will file a ticket.
On Fri, Jan 31, 2014 at 3:07 PM, Apache Jenkins Server < [email protected]> wrote: > See < > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/1863/changes > > > > Changes: > > [vinod] Sped up tag and vote scripts by not compiling the whole of mesos. > > ------------------------------------------ > [...truncated 21237 lines...] > I0131 23:07:31.484603 2329 status_update_manager.cpp:162] New master > detected at [email protected]:52903 > I0131 23:07:31.484642 2309 slave.cpp:526] Detecting new master > I0131 23:07:31.484662 2329 master.cpp:1812] Attempting to register slave > on hemera.apache.org at slave(139)@140.211.11.27:52903 > I0131 23:07:31.484673 2329 master.cpp:2782] Adding slave > 201401312307-453759884-52903-1958-0 at hemera.apache.org with cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] > I0131 23:07:31.484740 2315 sched.cpp:335] Successfully authenticated with > master [email protected]:52903 > I0131 23:07:31.484769 2309 slave.cpp:544] Registered with master > [email protected]:52903; given slave ID > 201401312307-453759884-52903-1958-0 > I0131 23:07:31.484786 2315 master.cpp:790] Received registration request > from scheduler(132)@140.211.11.27:52903 > I0131 23:07:31.484805 2315 master.cpp:808] Registering framework > 201401312307-453759884-52903-1958-0000 at scheduler(132)@ > 140.211.11.27:52903 > I0131 23:07:31.484923 2329 hierarchical_allocator_process.hpp:445] Added > slave 201401312307-453759884-52903-1958-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) > I0131 23:07:31.484956 2329 hierarchical_allocator_process.hpp:708] > Performed allocation for slave 201401312307-453759884-52903-1958-0 in 5371ns > I0131 23:07:31.484957 2309 slave.cpp:557] Checkpointing SlaveInfo to > '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_LXiiUD/meta/slaves/201401312307-453759884-52903-1958-0/ > slave.info' > I0131 23:07:31.485273 2316 sched.cpp:384] Framework registered with > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.485299 2316 sched.cpp:398] Scheduler::registered took > 9422ns > I0131 23:07:31.485452 2327 hierarchical_allocator_process.hpp:332] Added > framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.485504 2327 hierarchical_allocator_process.hpp:752] > Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on > slave 201401312307-453759884-52903-1958-0 to framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.485803 2327 hierarchical_allocator_process.hpp:688] > Performed allocation for 1 slaves in 327006ns > I0131 23:07:31.485921 2308 master.hpp:431] Adding offer > 201401312307-453759884-52903-1958-0 with resources cpus(*):2; mem(*):1024; > disk(*):1024; ports(*):[31000-32000] on slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) > I0131 23:07:31.485980 2308 master.cpp:2250] Sending 1 offers to framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.486187 2308 sched.cpp:518] Scheduler::resourceOffers took > 68842ns > I0131 23:07:31.486953 2316 master.hpp:441] Removing offer > 201401312307-453759884-52903-1958-0 with resources cpus(*):2; mem(*):1024; > disk(*):1024; ports(*):[31000-32000] on slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) > I0131 23:07:31.487057 2316 master.cpp:1546] Processing reply for offers: > [ 201401312307-453759884-52903-1958-0 ] on slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) for framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.487241 2316 master.hpp:403] Adding task 1 with resources > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) > I0131 23:07:31.487308 2316 master.cpp:2419] Launching task 1 of framework > 201401312307-453759884-52903-1958-0000 with resources cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) > I0131 23:07:31.487471 2315 slave.cpp:729] Got assigned task 1 for > framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.487534 2315 slave.cpp:2892] Checkpointing FrameworkInfo to > '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_LXiiUD/meta/slaves/201401312307-453759884-52903-1958-0/frameworks/201401312307-453759884-52903-1958-0000/ > framework.info' > I0131 23:07:31.492266 2315 slave.cpp:2899] Checkpointing framework pid > 'scheduler(132)@140.211.11.27:52903' to > '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_LXiiUD/meta/slaves/201401312307-453759884-52903-1958-0/frameworks/201401312307-453759884-52903-1958-0000/framework.pid' > I0131 23:07:31.492406 2315 slave.cpp:838] Launching task 1 for framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.493352 2315 slave.cpp:3162] Checkpointing ExecutorInfo to > '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_LXiiUD/meta/slaves/201401312307-453759884-52903-1958-0/frameworks/201401312307-453759884-52903-1958-0000/executors/default/ > executor.info' > I0131 23:07:31.493602 2315 slave.cpp:3250] Checkpointing TaskInfo to > '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_LXiiUD/meta/slaves/201401312307-453759884-52903-1958-0/frameworks/201401312307-453759884-52903-1958-0000/executors/default/runs/ef4afaaf-ef44-4e2a-80d1-1fc60964b187/tasks/1/ > task.info' > I0131 23:07:31.493706 2315 slave.cpp:948] Queuing task '1' for executor > default of framework '201401312307-453759884-52903-1958-0000 > I0131 23:07:31.493741 2315 slave.cpp:466] Successfully attached file > '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_LXiiUD/slaves/201401312307-453759884-52903-1958-0/frameworks/201401312307-453759884-52903-1958-0000/executors/default/runs/ef4afaaf-ef44-4e2a-80d1-1fc60964b187' > I0131 23:07:31.495774 2316 exec.cpp:178] Executor started at: > executor(43)@140.211.11.27:52903 with pid 1958 > I0131 23:07:31.495810 2327 slave.cpp:2091] Monitoring executor default of > framework 201401312307-453759884-52903-1958-0000 forked at pid 1958 > I0131 23:07:31.495878 2327 slave.cpp:1424] Got registration for executor > 'default' of framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.495913 2327 slave.cpp:1509] Checkpointing executor pid > 'executor(43)@140.211.11.27:52903' to > '/tmp/StatusUpdateManagerTest_DuplicateTerminalUpdateAfterAck_LXiiUD/meta/slaves/201401312307-453759884-52903-1958-0/frameworks/201401312307-453759884-52903-1958-0000/executors/default/runs/ef4afaaf-ef44-4e2a-80d1-1fc60964b187/pids/libprocess.pid' > I0131 23:07:31.496220 2327 slave.cpp:1545] Flushing queued task 1 for > executor 'default' of framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.496284 2313 exec.cpp:202] Executor registered on slave > 201401312307-453759884-52903-1958-0 > I0131 23:07:31.497958 2313 exec.cpp:214] Executor::registered took 19930ns > I0131 23:07:31.498061 2313 exec.cpp:289] Executor asked to run task '1' > I0131 23:07:31.498098 2313 exec.cpp:298] Executor::launchTask took 20765ns > I0131 23:07:31.499644 2313 exec.cpp:521] Executor sending status update > TASK_FINISHED (UUID: 0e914391-28bc-40a6-8f67-ce41f95bbb4b) for task 1 of > framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.499730 2313 slave.cpp:1758] Handling status update > TASK_FINISHED (UUID: 0e914391-28bc-40a6-8f67-ce41f95bbb4b) for task 1 of > framework 201401312307-453759884-52903-1958-0000 from executor(43)@ > 140.211.11.27:52903 > I0131 23:07:31.499755 2313 slave.cpp:3207] Terminating task 1 > I0131 23:07:31.500054 2321 status_update_manager.cpp:314] Received status > update TASK_FINISHED (UUID: 0e914391-28bc-40a6-8f67-ce41f95bbb4b) for task > 1 of framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.500078 2321 status_update_manager.cpp:493] Creating > StatusUpdate stream for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.500287 2321 status_update_manager.hpp:342] Checkpointing > UPDATE for status update TASK_FINISHED (UUID: > 0e914391-28bc-40a6-8f67-ce41f95bbb4b) for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.541497 2321 status_update_manager.cpp:367] Forwarding > status update TASK_FINISHED (UUID: 0e914391-28bc-40a6-8f67-ce41f95bbb4b) > for task 1 of framework 201401312307-453759884-52903-1958-0000 to > [email protected]:52903 > I0131 23:07:31.541651 2321 slave.cpp:1877] Status update manager > successfully handled status update TASK_FINISHED (UUID: > 0e914391-28bc-40a6-8f67-ce41f95bbb4b) for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.541676 2311 master.cpp:1998] Status update TASK_FINISHED > (UUID: 0e914391-28bc-40a6-8f67-ce41f95bbb4b) for task 1 of framework > 201401312307-453759884-52903-1958-0000 from slave(139)@140.211.11.27:52903 > I0131 23:07:31.541678 2321 slave.cpp:1883] Sending acknowledgement for > status update TASK_FINISHED (UUID: 0e914391-28bc-40a6-8f67-ce41f95bbb4b) > for task 1 of framework 201401312307-453759884-52903-1958-0000 to > executor(43)@140.211.11.27:52903 > I0131 23:07:31.541729 2311 master.hpp:421] Removing task 1 with resources > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) > I0131 23:07:31.541780 2327 sched.cpp:609] Scheduler::statusUpdate took > 32653ns > I0131 23:07:31.541825 2315 exec.cpp:335] Executor received status update > acknowledgement 0e914391-28bc-40a6-8f67-ce41f95bbb4b for task 1 of > framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.542050 2307 hierarchical_allocator_process.hpp:637] > Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] > (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000]) on slave 201401312307-453759884-52903-1958-0 from > framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.543520 2312 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: 0e914391-28bc-40a6-8f67-ce41f95bbb4b) for > task 1 of framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.543550 2312 status_update_manager.hpp:342] Checkpointing > ACK for status update TASK_FINISHED (UUID: > 0e914391-28bc-40a6-8f67-ce41f95bbb4b) for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.577967 2312 status_update_manager.cpp:524] Cleaning up > status update stream for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.578068 2312 slave.cpp:1364] Status update manager > successfully handled status update acknowledgement (UUID: > 0e914391-28bc-40a6-8f67-ce41f95bbb4b) for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.578095 2312 slave.cpp:3230] Completing task 1 > I0131 23:07:31.579377 2319 exec.cpp:521] Executor sending status update > TASK_KILLED (UUID: b9e4fb45-b400-41d0-bc76-dd65a10f38e2) for task 1 of > framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.579442 2319 slave.cpp:1758] Handling status update > TASK_KILLED (UUID: b9e4fb45-b400-41d0-bc76-dd65a10f38e2) for task 1 of > framework 201401312307-453759884-52903-1958-0000 from executor(43)@ > 140.211.11.27:52903 > W0131 23:07:31.579465 2319 slave.cpp:1789] Could not find the executor > for status update TASK_KILLED (UUID: b9e4fb45-b400-41d0-bc76-dd65a10f38e2) > for task 1 of framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.579573 2317 status_update_manager.cpp:314] Received status > update TASK_KILLED (UUID: b9e4fb45-b400-41d0-bc76-dd65a10f38e2) for task 1 > of framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.579589 2317 status_update_manager.cpp:493] Creating > StatusUpdate stream for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.579676 2317 status_update_manager.cpp:367] Forwarding > status update TASK_KILLED (UUID: b9e4fb45-b400-41d0-bc76-dd65a10f38e2) for > task 1 of framework 201401312307-453759884-52903-1958-0000 to > [email protected]:52903 > I0131 23:07:31.579851 2317 slave.cpp:1877] Status update manager > successfully handled status update TASK_KILLED (UUID: > b9e4fb45-b400-41d0-bc76-dd65a10f38e2) for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.579864 2317 slave.cpp:1883] Sending acknowledgement for > status update TASK_KILLED (UUID: b9e4fb45-b400-41d0-bc76-dd65a10f38e2) for > task 1 of framework 201401312307-453759884-52903-1958-0000 to executor(43)@ > 140.211.11.27:52903 > I0131 23:07:31.579891 2317 exec.cpp:335] Executor received status update > acknowledgement b9e4fb45-b400-41d0-bc76-dd65a10f38e2 for task 1 of > framework 201401312307-453759884-52903-1958-0000 > W0131 23:07:31.579937 2319 master.cpp:1991] Status update TASK_KILLED > (UUID: b9e4fb45-b400-41d0-bc76-dd65a10f38e2) for task 1 of framework > 201401312307-453759884-52903-1958-0000 from slave(139)@140.211.11.27:52903( > hemera.apache.org): error, couldn't lookup task > I0131 23:07:31.580252 2322 sched.cpp:609] Scheduler::statusUpdate took > 15680ns > I0131 23:07:31.580606 2322 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: b9e4fb45-b400-41d0-bc76-dd65a10f38e2) for > task 1 of framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.580705 2322 status_update_manager.cpp:524] Cleaning up > status update stream for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.581009 2322 slave.cpp:1364] Status update manager > successfully handled status update acknowledgement (UUID: > b9e4fb45-b400-41d0-bc76-dd65a10f38e2) for task 1 of framework > 201401312307-453759884-52903-1958-0000 > E0131 23:07:31.581218 2322 slave.cpp:1388] Status update acknowledgement > (UUID: b9e4fb45-b400-41d0-bc76-dd65a10f38e2) for task 1 of unknown executor > I0131 23:07:31.591876 1958 master.cpp:561] Master terminating > I0131 23:07:31.591907 1958 master.cpp:209] Shutting down master > I0131 23:07:31.591918 2315 sched.cpp:720] Stopping framework > '201401312307-453759884-52903-1958-0000' > I0131 23:07:31.591940 1958 master.cpp:252] Removing slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) > I0131 23:07:31.592185 2321 slave.cpp:1958] [email protected]:52903exited > W0131 23:07:31.592206 2321 slave.cpp:1961] Master disconnected! Waiting > for a new master to be elected > I0131 23:07:31.592924 2316 slave.cpp:391] Slave terminating > I0131 23:07:31.593530 2319 exec.cpp:446] Slave exited, but framework has > checkpointing enabled. Waiting 15mins to reconnect with slave > 201401312307-453759884-52903-1958-0 > [ OK ] StatusUpdateManagerTest.DuplicateTerminalUpdateAfterAck (116 > ms) > [ RUN ] StatusUpdateManagerTest.DuplicateUpdateBeforeAck > I0131 23:07:31.595402 2319 master.cpp:284] Master started on > 140.211.11.27:52903 > I0131 23:07:31.595432 2319 master.cpp:299] Master ID: > 201401312307-453759884-52903-1958 > I0131 23:07:31.595440 2319 master.cpp:302] Master only allowing > authenticated frameworks to register! > I0131 23:07:31.595830 2320 master.cpp:85] No whitelist given. Advertising > offers for all slaves > I0131 23:07:31.595877 2321 hierarchical_allocator_process.hpp:302] > Initializing hierarchical allocator process with master : > [email protected]:52903 > I0131 23:07:31.596487 2325 master.cpp:734] The newly elected leader is > [email protected]:52903 > I0131 23:07:31.596544 2325 master.cpp:742] Elected as the leading master! > I0131 23:07:31.597548 2306 slave.cpp:112] Slave started on 140)@ > 140.211.11.27:52903 > I0131 23:07:31.597712 2306 slave.cpp:212] Slave resources: cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] > I0131 23:07:31.598182 2326 sched.cpp:210] New master detected at > [email protected]:52903 > I0131 23:07:31.598199 2326 sched.cpp:261] Authenticating with master > [email protected]:52903 > I0131 23:07:31.598278 2326 sched.cpp:230] Detecting new master > I0131 23:07:31.598443 2320 authenticatee.hpp:124] Creating new client > SASL connection > I0131 23:07:31.598809 2312 master.cpp:2295] Authenticating framework at > scheduler(133)@140.211.11.27:52903 > I0131 23:07:31.599329 2320 state.cpp:33] Recovering state from > '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_NNrmm7/meta' > I0131 23:07:31.599376 2321 authenticator.hpp:140] Creating new server > SASL connection > I0131 23:07:31.600337 2313 status_update_manager.cpp:188] Recovering > status update manager > I0131 23:07:31.600702 2311 authenticatee.hpp:212] Received SASL > authentication mechanisms: CRAM-MD5 > I0131 23:07:31.600720 2311 authenticatee.hpp:238] Attempting to > authenticate with mechanism 'CRAM-MD5' > I0131 23:07:31.600857 2308 authenticator.hpp:243] Received SASL > authentication start > I0131 23:07:31.600908 2308 authenticator.hpp:325] Authentication requires > more steps > I0131 23:07:31.600973 2328 slave.cpp:2753] Finished recovery > I0131 23:07:31.601579 2319 authenticatee.hpp:258] Received SASL > authentication step > I0131 23:07:31.601631 2317 authenticator.hpp:271] Received SASL > authentication step > I0131 23:07:31.601651 2317 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 > I0131 23:07:31.601660 2317 auxprop.cpp:153] Looking up auxiliary property > '*userPassword' > I0131 23:07:31.601668 2317 auxprop.cpp:153] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I0131 23:07:31.601675 2317 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 > I0131 23:07:31.601680 2317 auxprop.cpp:103] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I0131 23:07:31.601682 2317 auxprop.cpp:103] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I0131 23:07:31.601691 2317 authenticator.hpp:317] Authentication success > I0131 23:07:31.601722 2310 slave.cpp:501] New master detected at > [email protected]:52903 > I0131 23:07:31.601883 2321 status_update_manager.cpp:162] New master > detected at [email protected]:52903 > I0131 23:07:31.601896 2310 slave.cpp:526] Detecting new master > I0131 23:07:31.601968 2316 master.cpp:1812] Attempting to register slave > on hemera.apache.org at slave(140)@140.211.11.27:52903 > I0131 23:07:31.601987 2316 master.cpp:2782] Adding slave > 201401312307-453759884-52903-1958-0 at hemera.apache.org with cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] > I0131 23:07:31.602210 2310 slave.cpp:544] Registered with master > [email protected]:52903; given slave ID > 201401312307-453759884-52903-1958-0 > I0131 23:07:31.602430 2310 slave.cpp:557] Checkpointing SlaveInfo to > '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_NNrmm7/meta/slaves/201401312307-453759884-52903-1958-0/ > slave.info' > I0131 23:07:31.602521 2316 master.cpp:2335] Successfully authenticated > framework at scheduler(133)@140.211.11.27:52903 > I0131 23:07:31.602535 2314 hierarchical_allocator_process.hpp:445] Added > slave 201401312307-453759884-52903-1958-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) > I0131 23:07:31.602551 2318 authenticatee.hpp:298] Authentication success > I0131 23:07:31.602566 2314 hierarchical_allocator_process.hpp:708] > Performed allocation for slave 201401312307-453759884-52903-1958-0 in 7217ns > I0131 23:07:31.602735 2315 sched.cpp:335] Successfully authenticated with > master [email protected]:52903 > I0131 23:07:31.602790 2311 master.cpp:790] Received registration request > from scheduler(133)@140.211.11.27:52903 > I0131 23:07:31.602821 2311 master.cpp:808] Registering framework > 201401312307-453759884-52903-1958-0000 at scheduler(133)@ > 140.211.11.27:52903 > I0131 23:07:31.602900 2314 sched.cpp:384] Framework registered with > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.602927 2314 sched.cpp:398] Scheduler::registered took > 6596ns > I0131 23:07:31.602943 2315 hierarchical_allocator_process.hpp:332] Added > framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.602972 2315 hierarchical_allocator_process.hpp:752] > Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on > slave 201401312307-453759884-52903-1958-0 to framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.603046 2315 hierarchical_allocator_process.hpp:688] > Performed allocation for 1 slaves in 91013ns > I0131 23:07:31.603106 2311 master.hpp:431] Adding offer > 201401312307-453759884-52903-1958-0 with resources cpus(*):2; mem(*):1024; > disk(*):1024; ports(*):[31000-32000] on slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) > I0131 23:07:31.603142 2311 master.cpp:2250] Sending 1 offers to framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.603236 2311 sched.cpp:518] Scheduler::resourceOffers took > 29436ns > I0131 23:07:31.604315 2314 master.hpp:441] Removing offer > 201401312307-453759884-52903-1958-0 with resources cpus(*):2; mem(*):1024; > disk(*):1024; ports(*):[31000-32000] on slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) > I0131 23:07:31.604353 2314 master.cpp:1546] Processing reply for offers: > [ 201401312307-453759884-52903-1958-0 ] on slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) for framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.604424 2314 master.hpp:403] Adding task 1 with resources > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) > I0131 23:07:31.604457 2314 master.cpp:2419] Launching task 1 of framework > 201401312307-453759884-52903-1958-0000 with resources cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) > I0131 23:07:31.604609 2307 slave.cpp:729] Got assigned task 1 for > framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.604720 2307 slave.cpp:2892] Checkpointing FrameworkInfo to > '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_NNrmm7/meta/slaves/201401312307-453759884-52903-1958-0/frameworks/201401312307-453759884-52903-1958-0000/ > framework.info' > I0131 23:07:31.610638 2307 slave.cpp:2899] Checkpointing framework pid > 'scheduler(133)@140.211.11.27:52903' to > '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_NNrmm7/meta/slaves/201401312307-453759884-52903-1958-0/frameworks/201401312307-453759884-52903-1958-0000/framework.pid' > I0131 23:07:31.610894 2307 slave.cpp:838] Launching task 1 for framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.612578 2307 slave.cpp:3162] Checkpointing ExecutorInfo to > '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_NNrmm7/meta/slaves/201401312307-453759884-52903-1958-0/frameworks/201401312307-453759884-52903-1958-0000/executors/default/ > executor.info' > I0131 23:07:31.613016 2307 slave.cpp:3250] Checkpointing TaskInfo to > '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_NNrmm7/meta/slaves/201401312307-453759884-52903-1958-0/frameworks/201401312307-453759884-52903-1958-0000/executors/default/runs/c4751a85-89bb-4a56-8643-0195f1d3a85a/tasks/1/ > task.info' > I0131 23:07:31.613219 2307 slave.cpp:948] Queuing task '1' for executor > default of framework '201401312307-453759884-52903-1958-0000 > I0131 23:07:31.613272 2307 slave.cpp:466] Successfully attached file > '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_NNrmm7/slaves/201401312307-453759884-52903-1958-0/frameworks/201401312307-453759884-52903-1958-0000/executors/default/runs/c4751a85-89bb-4a56-8643-0195f1d3a85a' > I0131 23:07:31.614061 2314 exec.cpp:178] Executor started at: > executor(44)@140.211.11.27:52903 with pid 1958 > I0131 23:07:31.614145 2325 slave.cpp:2091] Monitoring executor default of > framework 201401312307-453759884-52903-1958-0000 forked at pid 1958 > I0131 23:07:31.614308 2325 slave.cpp:1424] Got registration for executor > 'default' of framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.614344 2325 slave.cpp:1509] Checkpointing executor pid > 'executor(44)@140.211.11.27:52903' to > '/tmp/StatusUpdateManagerTest_DuplicateUpdateBeforeAck_NNrmm7/meta/slaves/201401312307-453759884-52903-1958-0/frameworks/201401312307-453759884-52903-1958-0000/executors/default/runs/c4751a85-89bb-4a56-8643-0195f1d3a85a/pids/libprocess.pid' > I0131 23:07:31.614667 2325 slave.cpp:1545] Flushing queued task 1 for > executor 'default' of framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.614686 2322 exec.cpp:202] Executor registered on slave > 201401312307-453759884-52903-1958-0 > I0131 23:07:31.615589 2322 exec.cpp:214] Executor::registered took 10093ns > I0131 23:07:31.615634 2322 exec.cpp:289] Executor asked to run task '1' > I0131 23:07:31.615655 2322 exec.cpp:298] Executor::launchTask took 14288ns > I0131 23:07:31.616436 2322 exec.cpp:521] Executor sending status update > TASK_RUNNING (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 of > framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.616515 2322 slave.cpp:1758] Handling status update > TASK_RUNNING (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 of > framework 201401312307-453759884-52903-1958-0000 from executor(44)@ > 140.211.11.27:52903 > I0131 23:07:31.616675 2327 status_update_manager.cpp:314] Received status > update TASK_RUNNING (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 > of framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.616705 2327 status_update_manager.cpp:493] Creating > StatusUpdate stream for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.616863 2327 status_update_manager.hpp:342] Checkpointing > UPDATE for status update TASK_RUNNING (UUID: > 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.647876 2327 status_update_manager.cpp:367] Forwarding > status update TASK_RUNNING (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for > task 1 of framework 201401312307-453759884-52903-1958-0000 to > [email protected]:52903 > I0131 23:07:31.648012 2312 slave.cpp:1877] Status update manager > successfully handled status update TASK_RUNNING (UUID: > 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.648036 2312 slave.cpp:1883] Sending acknowledgement for > status update TASK_RUNNING (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for > task 1 of framework 201401312307-453759884-52903-1958-0000 to executor(44)@ > 140.211.11.27:52903 > I0131 23:07:31.648150 2308 exec.cpp:335] Executor received status update > acknowledgement 38e466fe-592b-4725-8fd9-83fd876b9f98 for task 1 of > framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.648154 2327 master.cpp:1998] Status update TASK_RUNNING > (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 of framework > 201401312307-453759884-52903-1958-0000 from slave(140)@140.211.11.27:52903 > I0131 23:07:31.648211 2312 sched.cpp:609] Scheduler::statusUpdate took > 30990ns > I0131 23:07:31.648818 2314 slave.cpp:1758] Handling status update > TASK_RUNNING (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 of > framework 201401312307-453759884-52903-1958-0000 from executor(44)@ > 140.211.11.27:52903 > I0131 23:07:31.648980 2319 status_update_manager.cpp:314] Received status > update TASK_RUNNING (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 > of framework 201401312307-453759884-52903-1958-0000 > W0131 23:07:31.649097 2319 status_update_manager.hpp:231] Ignoring > duplicate status update TASK_RUNNING (UUID: > 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.649651 2329 slave.cpp:1877] Status update manager > successfully handled status update TASK_RUNNING (UUID: > 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.649677 2329 slave.cpp:1883] Sending acknowledgement for > status update TASK_RUNNING (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for > task 1 of framework 201401312307-453759884-52903-1958-0000 to executor(44)@ > 140.211.11.27:52903 > I0131 23:07:31.650537 2312 exec.cpp:335] Executor received status update > acknowledgement 38e466fe-592b-4725-8fd9-83fd876b9f98 for task 1 of > framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.650915 2306 master.cpp:85] No whitelist given. Advertising > offers for all slaves > I0131 23:07:31.650951 2316 hierarchical_allocator_process.hpp:688] > Performed allocation for 1 slaves in 29617ns > W0131 23:07:31.651060 2308 status_update_manager.cpp:471] Resending > status update TASK_RUNNING (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for > task 1 of framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.651088 2308 status_update_manager.cpp:367] Forwarding > status update TASK_RUNNING (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for > task 1 of framework 201401312307-453759884-52903-1958-0000 to > [email protected]:52903 > I0131 23:07:31.651252 2328 master.cpp:1998] Status update TASK_RUNNING > (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 of framework > 201401312307-453759884-52903-1958-0000 from slave(140)@140.211.11.27:52903 > I0131 23:07:31.651479 2320 sched.cpp:609] Scheduler::statusUpdate took > 36748ns > I0131 23:07:31.651659 2320 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: 38e466fe-592b-4725-8fd9-83fd876b9f98) for > task 1 of framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.651706 2320 status_update_manager.hpp:342] Checkpointing > ACK for status update TASK_RUNNING (UUID: > 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.680840 2320 slave.cpp:1364] Status update manager > successfully handled status update acknowledgement (UUID: > 38e466fe-592b-4725-8fd9-83fd876b9f98) for task 1 of framework > 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.690911 1958 master.cpp:561] Master terminating > I0131 23:07:31.690947 1958 master.cpp:209] Shutting down master > I0131 23:07:31.690963 2320 slave.cpp:1958] [email protected]:52903exited > I0131 23:07:31.690973 2324 sched.cpp:720] Stopping framework > '201401312307-453759884-52903-1958-0000' > W0131 23:07:31.690979 2320 slave.cpp:1961] Master disconnected! Waiting > for a new master to be elected > I0131 23:07:31.691041 1958 master.hpp:421] Removing task 1 with resources > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) > I0131 23:07:31.691196 1958 master.cpp:252] Removing slave > 201401312307-453759884-52903-1958-0 (hemera.apache.org) > I0131 23:07:31.691298 2327 hierarchical_allocator_process.hpp:637] > Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] > (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000]) on slave 201401312307-453759884-52903-1958-0 from > framework 201401312307-453759884-52903-1958-0000 > I0131 23:07:31.692598 2306 slave.cpp:391] Slave terminating > I0131 23:07:31.693362 2326 exec.cpp:446] Slave exited, but framework has > checkpointing enabled. Waiting 15mins to reconnect with slave > 201401312307-453759884-52903-1958-0 > [ OK ] StatusUpdateManagerTest.DuplicateUpdateBeforeAck (101 ms) > [----------] 7 tests from StatusUpdateManagerTest (785 ms total) > > [----------] 1 test from ZooKeeper > [ RUN ] ZooKeeper.URL > [ OK ] ZooKeeper.URL (0 ms) > [----------] 1 test from ZooKeeper (0 ms total) > > [----------] 5 tests from CgroupsCpusetTest > [ RUN ] CgroupsCpusetTest.OneCPUOneCpuset > [ OK ] CgroupsCpusetTest.OneCPUOneCpuset (0 ms) > [ RUN ] CgroupsCpusetTest.OneCPUManyCpusets > [ OK ] CgroupsCpusetTest.OneCPUManyCpusets (0 ms) > [ RUN ] CgroupsCpusetTest.ManyCPUOneCpuset > [ OK ] CgroupsCpusetTest.ManyCPUOneCpuset (0 ms) > [ RUN ] CgroupsCpusetTest.ManyCPUManyCpusets > [ OK ] CgroupsCpusetTest.ManyCPUManyCpusets (0 ms) > [ RUN ] CgroupsCpusetTest.IntegerAllocations > [ OK ] CgroupsCpusetTest.IntegerAllocations (0 ms) > [----------] 5 tests from CgroupsCpusetTest (0 ms total) > > [----------] 3 tests from FsTest > [ RUN ] FsTest.MountTableRead > [ OK ] FsTest.MountTableRead (0 ms) > [ RUN ] FsTest.MountTableHasOption > [ OK ] FsTest.MountTableHasOption (0 ms) > [ RUN ] FsTest.FileSystemTableRead > [ OK ] FsTest.FileSystemTableRead (0 ms) > [----------] 3 tests from FsTest (1 ms total) > > [----------] Global test environment tear-down > ../../src/tests/environment.cpp:247: Failure > Failed > Tests completed with child processes remaining: > -+- 1958 > /x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src/.libs/lt-mesos-tests > \-+- 5894 sh -c > /x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src/mesos-executor > \--- 5912 > /x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src/.libs/lt-mesos-executor > [==========] 220 tests from 39 test cases ran. (69898 ms total) > [ PASSED ] 220 tests. > [ FAILED ] 0 tests, listed below: > > 0 FAILED TESTS > > YOU HAVE 2 DISABLED TESTS > > I0131 23:07:31.799695 5950 process.cpp:1009] Socket closed while receiving > make[3]: *** [check-local] Error 1 > make[3]: Leaving directory > `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src' > I0131 23:07:31.799855 5929 exec.cpp:446] Slave exited, but framework has > checkpointing enabled. Waiting 15mins to reconnect with slave > 201401312307-453759884-52903-1958-0 > make[2]: *** [check-am] Error 2 > make[2]: Leaving directory > `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src' > make[1]: *** [check] Error 2 > make[1]: Leaving directory > `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src' > make: *** [check-recursive] Error 1 > Build step 'Execute shell' marked build as failure >
