See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2566/changes>
Changes: [benjamin.hindman] Replaced Timer::create/cancel with Clock::timer/cancel. [benjamin.hindman] Updates to Mesos for Timer::create/cancel -> Clock::timer/cancel. [benjamin.hindman] Abstract clock internals from ProcessManager::settle. [benjamin.hindman] Introduced a callback for timer expiration. [benjamin.hindman] Removed redundant synchronization and conditional check. [benjamin.hindman] Simplified redundant Clock::order/update usage. [benjamin.hindman] Introduced a libev async watcher specifically for updating timers. [benjamin.hindman] Moved Clock implementation into clock.cpp. [benjamin.hindman] Started moving libev specific functionality out of process.cpp. [benjamin.hindman] Moved event loop specific polling into poll.cpp. [benjamin.hindman] Moved process::io::* into io.cpp. [benjamin.hindman] Used io::poll instead of libev for recv_data. [benjamin.hindman] Used io::poll instead of libev for ignore_data. [benjamin.hindman] Used io::poll instead of libev for receiving_connect. [benjamin.hindman] Used io::poll instead of libev for send*. [benjamin.hindman] Replaced circular include dependency w/ TODO. [benjamin.hindman] Fix race condition in process.cpp. [benjamin.hindman] Introduce std::make_shared configure check in libprocess. [benjamin.hindman] Introduce std::make_shared configure check. [benjamin.hindman] Use std::shared_ptr to do reference counting in Socket. [benjamin.hindman] Introduce std::enable_shared_from_this configure check in libprocess. [benjamin.hindman] Add connect() to the Socket interface. [benjamin.hindman] Remove dead code in process.cpp. [benjamin.hindman] Add read() to Socket interface. [benjamin.hindman] Use Socket::read for ignore_data. [benjamin.hindman] Introduce Kind enumeration in Encoder. [benjamin.hindman] Virtualize backup(length) and remaining() in Encoder interface. [benjamin.hindman] Introduce Socket::send() and Socket::sendfile(). [benjamin.hindman] Use Socket::send() for temporary connections. [benjamin.hindman] Add bind(), listen(), and accept() to Socket interface. ------------------------------------------ [...truncated 48092 lines...] I1116 02:46:23.056648 20930 slave.cpp:741] Successfully authenticated with master [email protected]:50119 I1116 02:46:23.056742 20930 slave.cpp:1069] Will retry registration in 16.053064ms if necessary I1116 02:46:23.056874 20917 master.cpp:3063] Registering slave at slave(154)@67.195.81.187:50119 (pomona.apache.org) with id 20141116-024623-3142697795-50119-20903-S0 I1116 02:46:23.057222 20932 registrar.cpp:445] Applied 1 operations in 48210ns; attempting to update the 'registry' I1116 02:46:23.059203 20903 sched.cpp:148] Version: 0.22.0 I1116 02:46:23.059662 20928 sched.cpp:245] New master detected at [email protected]:50119 I1116 02:46:23.059702 20928 sched.cpp:301] Authenticating with master [email protected]:50119 I1116 02:46:23.059716 20928 sched.cpp:308] Using default CRAM-MD5 authenticatee I1116 02:46:23.059950 20925 authenticatee.hpp:138] Creating new client SASL connection I1116 02:46:23.060101 20926 master.cpp:3896] Authenticating [email protected]:50119 I1116 02:46:23.060142 20926 master.cpp:3907] Using default CRAM-MD5 authenticator I1116 02:46:23.060394 20920 log.cpp:680] Attempting to append 316 bytes to the log I1116 02:46:23.060406 20928 authenticator.hpp:170] Creating new server SASL connection I1116 02:46:23.060540 20918 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3 I1116 02:46:23.060592 20929 authenticatee.hpp:229] Received SASL authentication mechanisms: CRAM-MD5 I1116 02:46:23.060624 20929 authenticatee.hpp:255] Attempting to authenticate with mechanism 'CRAM-MD5' I1116 02:46:23.060742 20922 authenticator.hpp:276] Received SASL authentication start I1116 02:46:23.060799 20922 authenticator.hpp:398] Authentication requires more steps I1116 02:46:23.060907 20921 authenticatee.hpp:275] Received SASL authentication step I1116 02:46:23.061029 20920 authenticator.hpp:304] Received SASL authentication step I1116 02:46:23.061064 20920 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'pomona.apache.org' server FQDN: 'pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1116 02:46:23.061085 20920 auxprop.cpp:171] Looking up auxiliary property '*userPassword' I1116 02:46:23.061121 20920 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1116 02:46:23.061147 20920 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'pomona.apache.org' server FQDN: 'pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1116 02:46:23.061159 20920 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1116 02:46:23.061168 20920 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1116 02:46:23.061184 20920 authenticator.hpp:390] Authentication success I1116 02:46:23.061295 20922 authenticatee.hpp:315] Authentication success I1116 02:46:23.061384 20925 master.cpp:3954] Successfully authenticated principal 'test-principal' at [email protected]:50119 I1116 02:46:23.061564 20932 sched.cpp:389] Successfully authenticated with master [email protected]:50119 I1116 02:46:23.061597 20932 sched.cpp:512] Sending registration request to [email protected]:50119 I1116 02:46:23.061611 20923 replica.cpp:508] Replica received write request for position 3 I1116 02:46:23.061641 20932 sched.cpp:545] Will retry registration in 413.992477ms if necessary I1116 02:46:23.061733 20925 master.cpp:1383] Received registration request for framework 'default' at [email protected]:50119 I1116 02:46:23.061796 20925 master.cpp:1342] Authorizing framework principal 'test-principal' to receive offers for role '*' I1116 02:46:23.062072 20923 leveldb.cpp:343] Persisting action (335 bytes) to leveldb took 429073ns I1116 02:46:23.062098 20923 replica.cpp:676] Persisted action at 3 I1116 02:46:23.062098 20930 master.cpp:1447] Registering framework 20141116-024623-3142697795-50119-20903-0000 (default) at [email protected]:50119 I1116 02:46:23.062445 20926 hierarchical_allocator_process.hpp:329] Added framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.062470 20926 hierarchical_allocator_process.hpp:697] No resources available to allocate! I1116 02:46:23.062481 20926 hierarchical_allocator_process.hpp:659] Performed allocation for 0 slaves in 14205ns I1116 02:46:23.062739 20918 replica.cpp:655] Replica received learned notice for position 3 I1116 02:46:23.062930 20920 sched.cpp:439] Framework registered with 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.062973 20920 sched.cpp:453] Scheduler::registered took 19440ns I1116 02:46:23.063154 20918 leveldb.cpp:343] Persisting action (337 bytes) to leveldb took 391049ns I1116 02:46:23.063176 20918 replica.cpp:676] Persisted action at 3 I1116 02:46:23.063194 20918 replica.cpp:661] Replica learned APPEND action at position 3 I1116 02:46:23.064033 20918 registrar.cpp:490] Successfully updated the 'registry' in 6.756864ms I1116 02:46:23.064354 20925 log.cpp:699] Attempting to truncate the log to 3 I1116 02:46:23.064478 20921 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4 I1116 02:46:23.064539 20919 slave.cpp:2555] Received ping from slave-observer(152)@67.195.81.187:50119 I1116 02:46:23.064601 20926 master.cpp:3117] Registered slave 20141116-024623-3142697795-50119-20903-S0 at slave(154)@67.195.81.187:50119 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1116 02:46:23.064692 20919 slave.cpp:775] Registered with master [email protected]:50119; given slave ID 20141116-024623-3142697795-50119-20903-S0 I1116 02:46:23.064771 20928 status_update_manager.cpp:178] Resuming sending status updates I1116 02:46:23.064739 20931 hierarchical_allocator_process.hpp:442] Added slave 20141116-024623-3142697795-50119-20903-S0 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I1116 02:46:23.065124 20920 replica.cpp:508] Replica received write request for position 4 I1116 02:46:23.155635 20931 hierarchical_allocator_process.hpp:734] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141116-024623-3142697795-50119-20903-S0 to framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.155972 20931 hierarchical_allocator_process.hpp:679] Performed allocation for slave 20141116-024623-3142697795-50119-20903-S0 in 456499ns I1116 02:46:23.156324 20919 master.cpp:3838] Sending 1 offers to framework 20141116-024623-3142697795-50119-20903-0000 (default) at [email protected]:50119 I1116 02:46:23.156348 20920 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 747009ns I1116 02:46:23.156373 20920 replica.cpp:676] Persisted action at 4 I1116 02:46:23.156747 20931 sched.cpp:602] Scheduler::resourceOffers took 87351ns I1116 02:46:23.157088 20928 replica.cpp:655] Replica received learned notice for position 4 I1116 02:46:23.157573 20928 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 458308ns I1116 02:46:23.157670 20928 leveldb.cpp:401] Deleting ~2 keys from leveldb took 63266ns I1116 02:46:23.157695 20928 replica.cpp:676] Persisted action at 4 I1116 02:46:23.157716 20928 replica.cpp:661] Replica learned TRUNCATE action at position 4 I1116 02:46:23.158383 20925 master.cpp:2356] Processing reply for offers: [ 20141116-024623-3142697795-50119-20903-O0 ] on slave 20141116-024623-3142697795-50119-20903-S0 at slave(154)@67.195.81.187:50119 (pomona.apache.org) for framework 20141116-024623-3142697795-50119-20903-0000 (default) at [email protected]:50119 I1116 02:46:23.158417 20925 master.cpp:2454] Authorizing framework principal 'test-principal' to launch task 1 as user 'jenkins' I1116 02:46:23.159272 20931 master.hpp:753] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141116-024623-3142697795-50119-20903-S0 (pomona.apache.org) I1116 02:46:23.159411 20931 master.cpp:2522] Launching task 1 of framework 20141116-024623-3142697795-50119-20903-0000 (default) at [email protected]:50119 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141116-024623-3142697795-50119-20903-S0 at slave(154)@67.195.81.187:50119 (pomona.apache.org) I1116 02:46:23.159653 20920 slave.cpp:1100] Got assigned task 1 for framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.160323 20920 slave.cpp:1210] Launching task 1 for framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.162986 20920 slave.cpp:4014] Launching executor 1 of framework 20141116-024623-3142697795-50119-20903-0000 in work directory '/tmp/SlaveTest_MesosExecutorWithOverride_ExlPqM/slaves/20141116-024623-3142697795-50119-20903-S0/frameworks/20141116-024623-3142697795-50119-20903-0000/executors/1/runs/2f96da88-a9a5-461d-b66f-8bab8afbf6cb' I1116 02:46:23.163497 20920 slave.cpp:1333] Queuing task '1' for executor 1 of framework '20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.163617 20920 slave.cpp:560] Successfully attached file '/tmp/SlaveTest_MesosExecutorWithOverride_ExlPqM/slaves/20141116-024623-3142697795-50119-20903-S0/frameworks/20141116-024623-3142697795-50119-20903-0000/executors/1/runs/2f96da88-a9a5-461d-b66f-8bab8afbf6cb' I1116 02:46:23.163741 20920 slave.cpp:2857] Monitoring executor '1' of framework '20141116-024623-3142697795-50119-20903-0000' in container '2f96da88-a9a5-461d-b66f-8bab8afbf6cb' I1116 02:46:23.222535 20930 slave.cpp:1877] Got registration for executor '1' of framework 20141116-024623-3142697795-50119-20903-0000 from executor(1)@67.195.81.187:35146 I1116 02:46:23.223431 20930 slave.cpp:1996] Flushing queued task 1 for executor '1' of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.230938 20925 slave.cpp:2232] Handling status update TASK_RUNNING (UUID: f59733ff-0a74-4611-81b0-920bd7ca3ded) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 from executor(1)@67.195.81.187:35146 I1116 02:46:23.231266 20921 status_update_manager.cpp:317] Received status update TASK_RUNNING (UUID: f59733ff-0a74-4611-81b0-920bd7ca3ded) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.231343 20921 status_update_manager.cpp:494] Creating StatusUpdate stream for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.231631 20921 status_update_manager.cpp:371] Forwarding update TASK_RUNNING (UUID: f59733ff-0a74-4611-81b0-920bd7ca3ded) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 to the slave I1116 02:46:23.231961 20919 slave.cpp:2475] Forwarding the update TASK_RUNNING (UUID: f59733ff-0a74-4611-81b0-920bd7ca3ded) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 to [email protected]:50119 I1116 02:46:23.232131 20919 slave.cpp:2402] Status update manager successfully handled status update TASK_RUNNING (UUID: f59733ff-0a74-4611-81b0-920bd7ca3ded) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.232167 20919 slave.cpp:2408] Sending acknowledgement for status update TASK_RUNNING (UUID: f59733ff-0a74-4611-81b0-920bd7ca3ded) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 to executor(1)@67.195.81.187:35146 I1116 02:46:23.232522 20925 master.cpp:3441] Forwarding status update TASK_RUNNING (UUID: f59733ff-0a74-4611-81b0-920bd7ca3ded) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.232652 20925 master.cpp:3413] Status update TASK_RUNNING (UUID: f59733ff-0a74-4611-81b0-920bd7ca3ded) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 from slave 20141116-024623-3142697795-50119-20903-S0 at slave(154)@67.195.81.187:50119 (pomona.apache.org) I1116 02:46:23.232707 20925 master.cpp:4688] Updating the latest state of task 1 of framework 20141116-024623-3142697795-50119-20903-0000 to TASK_RUNNING I1116 02:46:23.232856 20930 sched.cpp:693] Scheduler::statusUpdate took 63586ns I1116 02:46:23.233374 20921 master.cpp:2913] Forwarding status update acknowledgement f59733ff-0a74-4611-81b0-920bd7ca3ded for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 (default) at [email protected]:50119 to slave 20141116-024623-3142697795-50119-20903-S0 at slave(154)@67.195.81.187:50119 (pomona.apache.org) I1116 02:46:23.233748 20930 status_update_manager.cpp:389] Received status update acknowledgement (UUID: f59733ff-0a74-4611-81b0-920bd7ca3ded) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.233983 20922 slave.cpp:1817] Status update manager successfully handled status update acknowledgement (UUID: f59733ff-0a74-4611-81b0-920bd7ca3ded) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.331262 20930 slave.cpp:2232] Handling status update TASK_FINISHED (UUID: 3ebd543f-8b2a-44d1-aefa-6dbb82fd0531) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 from executor(1)@67.195.81.187:35146 I1116 02:46:23.331429 20930 slave.cpp:4322] Terminating task 1 I1116 02:46:23.331967 20930 status_update_manager.cpp:317] Received status update TASK_FINISHED (UUID: 3ebd543f-8b2a-44d1-aefa-6dbb82fd0531) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:23.332048 20930 status_update_manager.cpp:371] Forwarding update TASK_FINISHED (UUID: 3ebd543f-8b2a-44d1-aefa-6dbb82fd0531) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 to the slave I1116 02:46:23.332293 20923 slave.cpp:2475] Forwarding the update TASK_FINISHED (UUID: 3ebd543f-8b2a-44d1-aefa-6dbb82fd0531) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 to [email protected]:50119 I1116 02:46:24.015517 20920 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 146469ns I1116 02:46:24.996919 20923 slave.cpp:2402] Status update manager successfully handled status update TASK_FINISHED (UUID: 3ebd543f-8b2a-44d1-aefa-6dbb82fd0531) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:24.996959 20923 slave.cpp:2408] Sending acknowledgement for status update TASK_FINISHED (UUID: 3ebd543f-8b2a-44d1-aefa-6dbb82fd0531) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 to executor(1)@67.195.81.187:35146 I1116 02:46:24.997028 20920 master.cpp:3441] Forwarding status update TASK_FINISHED (UUID: 3ebd543f-8b2a-44d1-aefa-6dbb82fd0531) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:24.997160 20920 master.cpp:3413] Status update TASK_FINISHED (UUID: 3ebd543f-8b2a-44d1-aefa-6dbb82fd0531) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 from slave 20141116-024623-3142697795-50119-20903-S0 at slave(154)@67.195.81.187:50119 (pomona.apache.org) I1116 02:46:24.997226 20920 master.cpp:4688] Updating the latest state of task 1 of framework 20141116-024623-3142697795-50119-20903-0000 to TASK_FINISHED I1116 02:46:24.997346 20919 sched.cpp:693] Scheduler::statusUpdate took 74018ns I1116 02:46:24.997411 20933 process.cpp:1259] Socket error while connecting I1116 02:46:24.997567 20933 process.cpp:1732] Failed to send, connect: Socket error while connecting F1116 02:46:24.997681 20933 future.hpp:1178] Check failed: !isFailed() Future::get() but state == FAILED: Socket error while connecting *** Check failure stack trace: *** I1116 02:46:24.997740 20920 master.cpp:4747] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework 20141116-024623-3142697795-50119-20903-0000 on slave 20141116-024623-3142697795-50119-20903-S0 at slave(154)@67.195.81.187:50119 (pomona.apache.org) I1116 02:46:24.997817 20932 hierarchical_allocator_process.hpp:563] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 20141116-024623-3142697795-50119-20903-S0 from framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:24.997934 20903 sched.cpp:1364] Asked to stop the driver I1116 02:46:24.998055 20920 master.cpp:2913] Forwarding status update acknowledgement 3ebd543f-8b2a-44d1-aefa-6dbb82fd0531 for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 (default) at [email protected]:50119 to slave 20141116-024623-3142697795-50119-20903-S0 at slave(154)@67.195.81.187:50119 (pomona.apache.org) I1116 02:46:24.998154 20917 sched.cpp:805] Stopping framework '20141116-024623-3142697795-50119-20903-0000' I1116 02:46:24.998221 20926 slave.cpp:2915] Executor '1' of framework 20141116-024623-3142697795-50119-20903-0000 exited with status 0 I1116 02:46:24.998317 20925 master.cpp:698] Master terminating I1116 02:46:24.998725 20930 status_update_manager.cpp:389] Received status update acknowledgement (UUID: 3ebd543f-8b2a-44d1-aefa-6dbb82fd0531) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:24.998844 20930 status_update_manager.cpp:525] Cleaning up status update stream for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:24.998961 20917 slave.cpp:2640] [email protected]:50119 exited W1116 02:46:24.998991 20917 slave.cpp:2643] Master disconnected! Waiting for a new master to be elected I1116 02:46:24.999147 20921 slave.cpp:1817] Status update manager successfully handled status update acknowledgement (UUID: 3ebd543f-8b2a-44d1-aefa-6dbb82fd0531) for task 1 of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:24.999229 20921 slave.cpp:4361] Completing task 1 I1116 02:46:24.999320 20921 slave.cpp:3024] Cleaning up executor '1' of framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:24.999655 20922 gc.cpp:56] Scheduling '/tmp/SlaveTest_MesosExecutorWithOverride_ExlPqM/slaves/20141116-024623-3142697795-50119-20903-S0/frameworks/20141116-024623-3142697795-50119-20903-0000/executors/1/runs/2f96da88-a9a5-461d-b66f-8bab8afbf6cb' for gc 6.99998843217482days in the future I1116 02:46:24.999881 20921 slave.cpp:3101] Cleaning up framework 20141116-024623-3142697795-50119-20903-0000 I1116 02:46:24.999902 20922 gc.cpp:56] Scheduling '/tmp/SlaveTest_MesosExecutorWithOverride_ExlPqM/slaves/20141116-024623-3142697795-50119-20903-S0/frameworks/20141116-024623-3142697795-50119-20903-0000/executors/1' for gc 6.99998842882074days in the future I1116 02:46:25.000005 20928 status_update_manager.cpp:279] Closing status update streams for framework 20141116-024623-3142697795-50119-20903-0000 @ 0x2aea85d4e478 google::LogMessage::Fail() I1116 02:46:25.000265 20931 gc.cpp:56] Scheduling '/tmp/SlaveTest_MesosExecutorWithOverride_ExlPqM/slaves/20141116-024623-3142697795-50119-20903-S0/frameworks/20141116-024623-3142697795-50119-20903-0000' for gc 6.99998842606519days in the future @ 0x2aea85d4e3c4 google::LogMessage::SendToLog() I1116 02:46:25.012702 20926 slave.cpp:489] Slave terminating @ 0x2aea85d4ddc6 google::LogMessage::Flush() @ 0x2aea85d50cda google::LogMessageFatal::~LogMessageFatal() [ OK ] SlaveTest.MesosExecutorWithOverride (2026 ms) [ RUN ] SlaveTest.StateEndpoint Using temporary directory '/tmp/SlaveTest_StateEndpoint_8OrPFQ' @ 0x2aea85cf4588 process::Future<>::get() @ 0x2aea85cda1ad process::internal::send_connect() I1116 02:46:25.022238 20903 leveldb.cpp:176] Opened db in 2.668527ms I1116 02:46:25.023061 20903 leveldb.cpp:183] Compacted db in 796672ns I1116 02:46:25.023094 20903 leveldb.cpp:198] Created db iterator in 14618ns I1116 02:46:25.023104 20903 leveldb.cpp:204] Seeked to beginning of db in 1158ns I1116 02:46:25.023111 20903 leveldb.cpp:273] Iterated through 0 keys in the db in 307ns I1116 02:46:25.023144 20903 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned @ 0x2aea85d1edb5 _ZNSt5_BindIFPFvRKN7process6FutureINS0_6SocketEEEPNS0_7MessageEESt12_PlaceholderILi1EES7_EE6__callIvIS5_EILm0ELm1EEEET_OSt5tupleIIDpT0_EESt12_Index_tupleIIXspT1_EEE I1116 02:46:25.023538 20919 recover.cpp:437] Starting replica recovery I1116 02:46:25.023825 20919 recover.cpp:463] Replica is in EMPTY status I1116 02:46:25.024862 20917 replica.cpp:638] Replica in EMPTY status received a broadcasted recover request I1116 02:46:25.025313 20926 recover.cpp:188] Received a recover response from a replica in EMPTY status I1116 02:46:25.025702 20918 recover.cpp:554] Updating replica status to STARTING I1116 02:46:25.026252 20917 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 468054ns I1116 02:46:25.026274 20917 replica.cpp:320] Persisted replica status to STARTING I1116 02:46:25.026507 20926 recover.cpp:463] Replica is in STARTING status I1116 02:46:25.027580 20920 replica.cpp:638] Replica in STARTING status received a broadcasted recover request I1116 02:46:25.027833 20923 recover.cpp:188] Received a recover response from a replica in STARTING status I1116 02:46:25.028177 20918 recover.cpp:554] Updating replica status to VOTING I1116 02:46:25.028717 20924 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 397710ns I1116 02:46:25.028739 20924 replica.cpp:320] Persisted replica status to VOTING I1116 02:46:25.028821 20930 recover.cpp:568] Successfully joined the Paxos group I1116 02:46:25.029000 20930 recover.cpp:452] Recover process terminated @ 0x2aea85d11ead _ZNSt5_BindIFPFvRKN7process6FutureINS0_6SocketEEEPNS0_7MessageEESt12_PlaceholderILi1EES7_EEclIJS5_EvEET0_DpOT_ I @ 0x2aea85d05861 _ZZNK7process6FutureINS_6SocketEE5onAnyISt5_BindIFPFvRKS2_PNS_7MessageEESt12_PlaceholderILi1EES8_EEvEES6_OT_NS2_6PreferEENUlS6_E_clES6_ 1116 02:46:25.034868 20928 master.cpp:318] Master 20141116-024625-3142697795-50119-20903 (pomona.apache.org) started on 67.195.81.187:50119 I1116 02:46:25.149854 20928 master.cpp:364] Master only allowing authenticated frameworks to register I1116 02:46:25.149871 20928 master.cpp:369] Master only allowing authenticated slaves to register I1116 02:46:25.149894 20928 credentials.hpp:36] Loading credentials for authentication from '/tmp/SlaveTest_StateEndpoint_8OrPFQ/credentials' I1116 02:46:25.150151 20928 master.cpp:413] Authorization enabled I1116 02:46:25.150655 20932 master.cpp:126] No whitelist given. Advertising offers for all slaves I1116 02:46:25.150802 20924 hierarchical_allocator_process.hpp:299] Initializing hierarchical allocator process with master : [email protected]:50119 I1116 02:46:25.151839 20930 master.cpp:1263] The newly elected leader is [email protected]:50119 with id 20141116-024625-3142697795-50119-20903 I1116 02:46:25.151867 20930 master.cpp:1276] Elected as the leading master! I1116 02:46:25.151883 20930 master.cpp:1094] Recovering from registrar I1116 02:46:25.152047 20931 registrar.cpp:313] Recovering registrar I1116 02:46:25.152812 20928 log.cpp:656] Attempting to start the writer @ 0x2aea85d1ee3d _ZNSt17_Function_handlerIFvRKN7process6FutureINS0_6SocketEEEEZNKS3_5onAnyISt5_BindIFPFvS5_PNS0_7MessageEESt12_PlaceholderILi1EESA_EEvEES5_OT_NS3_6PreferEEUlS5_E_E9_M_invokeERKSt9_Any_dataS5_ I1116 02:46:25.154265 20927 replica.cpp:474] Replica received implicit promise request with proposal 1 I1116 02:46:25.154826 20927 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 508870ns I1116 02:46:25.154852 20927 replica.cpp:342] Persisted promised to 1 @ 0x2aea85d0e055 std::function<>::operator()() I1116 02:46:25.155567 20920 coordinator.cpp:230] Coordinator attemping to fill missing position I1116 02:46:25.156894 20927 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2 @ 0x2aea85d01829 process::Future<>::fail() I1116 02:46:25.157332 20927 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 409992ns I1116 02:46:25.157351 20927 replica.cpp:676] Persisted action at 0 I1116 02:46:25.158149 20917 replica.cpp:508] Replica received write request for position 0 I1116 02:46:25.158196 20917 leveldb.cpp:438] Reading position from leveldb took 23439ns I1116 02:46:25.158577 20917 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 354246ns I1116 02:46:25.158597 20917 replica.cpp:676] Persisted action at 0 I1116 02:46:25.159034 20929 replica.cpp:655] Replica received learned notice for position 0 I1116 02:46:25.159438 20929 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 378849ns I1116 02:46:25.159457 20929 replica.cpp:676] Persisted action at 0 I1116 02:46:25.159472 20929 replica.cpp:661] Replica learned NOP action at position 0 I1116 02:46:25.159930 20925 log.cpp:672] Writer started with ending position 0 @ 0x2aea85d36bd3 _ZNKSt7_Mem_fnIMN7process6FutureINS0_6SocketEEEFbRKSsEEclIJS5_EvEEbRS3_DpOT_ @ 0x2aea85d35a23 _ZNSt5_BindIFSt7_Mem_fnIMN7process6FutureINS1_6SocketEEEFbRKSsEES4_St12_PlaceholderILi1EEEE6__callIbJS6_EJLm0ELm1EEEET_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE I1116 02:46:25.160917 20921 leveldb.cpp:438] Reading position from leveldb took 23181ns I1116 02:46:25.163107 20923 registrar.cpp:346] Successfully fetched the registry (0B) in 11.023104ms I1116 02:46:25.163188 20923 registrar.cpp:445] Applied 1 operations in 14943ns; attempting to update the 'registry' @ 0x2aea85d34055 _ZNSt5_BindIFSt7_Mem_fnIMN7process6FutureINS1_6SocketEEEFbRKSsEES4_St12_PlaceholderILi1EEEEclIJS6_EbEET0_DpOT_ I1116 02:46:25.165209 20925 log.cpp:680] Attempting to append 139 bytes to the log I1116 02:46:25.165364 20932 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1 I1116 02:46:25.165940 20922 replica.cpp:508] Replica received write request for position 1 I1116 02:46:25.166328 20922 leveldb.cpp:343] Persisting action (158 bytes) to leveldb took 362223ns @ 0x2aea85d312b9 _ZZNK7process6FutureINS_6SocketEE8onFailedISt5_BindIFSt7_Mem_fnIMS2_FbRKSsEES2_St12_PlaceholderILi1EEEEbEERKS2_OT_NS2_6PreferEENUlS7_E_clES7_ I1116 02:46:25.166347 20922 replica.cpp:676] Persisted action at 1 I1116 02:46:25.210595 20930 replica.cpp:655] Replica received learned notice for position 1 @ 0x2aea85d35aa9 _ZNSt17_Function_handlerIFvRKSsEZNK7process6FutureINS3_6SocketEE8onFailedISt5_BindIFSt7_Mem_fnIMS6_FbS1_EES6_St12_PlaceholderILi1EEEEbEERKS6_OT_NS6_6PreferEEUlS1_E_E9_M_invokeERKSt9_Any_dataS1_ I1116 02:46:25.211196 20930 leveldb.cpp:343] Persisting action (160 bytes) to leveldb took 567831ns I1116 02:46:25.211223 20930 replica.cpp:676] Persisted action at 1 I1116 02:46:25.211246 20930 replica.cpp:661] Replica learned APPEND action at position 1 I1116 02:46:25.212384 20920 registrar.cpp:490] Successfully updated the 'registry' in 49.142784ms I1116 02:46:25.212535 20920 registrar.cpp:376] Successfully recovered registrar I1116 02:46:25.212632 20932 log.cpp:699] Attempting to truncate the log to 1 @ 0x98e7a3 std::function<>::operator()() I1116 02:46:25.212844 20927 master.cpp:1121] Recovered 0 slaves from the Registry (101B) ; allowing 10mins for slaves to re-register I1116 02:46:25.212956 20924 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2 I1116 02:46:25.213984 20924 replica.cpp:508] Replica received write request for position 2 I1116 02:46:25.214588 20924 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 555648ns I1116 02:46:25.214614 20924 replica.cpp:676] Persisted action at 2 I1116 02:46:25.215423 20926 replica.cpp:655] Replica received learned notice for position 2 I1116 02:46:25.215885 20926 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 439969ns I1116 02:46:25.215937 20926 leveldb.cpp:401] Deleting ~1 keys from leveldb took 30214ns I1116 02:46:25.215955 20926 replica.cpp:676] Persisted action at 2 I1116 02:46:25.215971 20926 replica.cpp:661] Replica learned TRUNCATE action at position 2 @ 0x2aea85d341c7 process::Future<>::onFailed() @ 0x2aea85d31399 process::Future<>::onFailed<>() @ 0x2aea85d2cb86 process::Future<>::onFailed<>() @ 0x2aea85d268a2 process::Promise<>::associate() @ 0x2aea85d1b96c process::internal::thenf<>() @ 0x2aea85d3194f _ZNSt5_BindIFPFvRKSt10shared_ptrIN7process7PromiseINS1_6SocketEEEERKSt8functionIFNS1_6FutureIS3_EERKsEERKNS9_IsEEES5_SE_St12_PlaceholderILi1EEEE6__callIvJSJ_EJLm0ELm1ELm2EEEET_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE @ 0x2aea85d2d033 _ZNSt5_BindIFPFvRKSt10shared_ptrIN7process7PromiseINS1_6SocketEEEERKSt8functionIFNS1_6FutureIS3_EERKsEERKNS9_IsEEES5_SE_St12_PlaceholderILi1EEEEclIJSJ_EvEET0_DpOT_ @ 0x2aea85d26d29 std::_Function_handler<>::_M_invoke() @ 0x2aea85ca2063 std::function<>::operator()() @ 0x2aea85d26df3 _ZZNK7process6FutureIsE5onAnyIRSt8functionIFvRKS1_EEvEES5_OT_NS1_6PreferEENUlS5_E_clES5_ @ 0x2aea85d319f6 _ZNSt17_Function_handlerIFvRKN7process6FutureIsEEEZNKS2_5onAnyIRSt8functionIS5_EvEES4_OT_NS2_6PreferEEUlS4_E_E9_M_invokeERKSt9_Any_dataS4_ @ 0x2aea85ca2063 std::function<>::operator()() @ 0x2aea85ca131c process::Future<>::set() @ 0x2aea85cd01bd std::_Mem_fn<>::operator()<>() make[3]: *** [check-local] Aborted make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'> make[2]: *** [check-am] Error 2 make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'> make[1]: *** [check] Error 2 make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'> make: *** [check-recursive] Error 1 Test finished Exit status: 2 Build step 'Execute shell' marked build as failure Recording test results
