See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/2180/changes>
Changes: [niklas] Allowed unloading of a single module. ------------------------------------------ [...truncated 8889 lines...] I1016 22:50:13.211139 28455 master.cpp:1362] Received registration request for framework 'default' at scheduler-0552db12-4b6e-4d3f-8231-b8555d10a558@67.195.81.187:53609 I1016 22:50:13.211166 28455 master.cpp:1321] Authorizing framework principal 'test-principal' to receive offers for role '*' I1016 22:50:13.211333 28464 master.cpp:1426] Registering framework 20141016-225013-3142697795-53609-28427-0000 (default) at scheduler-0552db12-4b6e-4d3f-8231-b8555d10a558@67.195.81.187:53609 I1016 22:50:13.211447 28454 hierarchical_allocator_process.hpp:329] Added framework 20141016-225013-3142697795-53609-28427-0000 I1016 22:50:13.211463 28454 hierarchical_allocator_process.hpp:697] No resources available to allocate! I1016 22:50:13.211469 28454 hierarchical_allocator_process.hpp:659] Performed allocation for 0 slaves in 7132ns I1016 22:50:13.211480 28453 sched.cpp:407] Framework registered with 20141016-225013-3142697795-53609-28427-0000 I1016 22:50:13.211501 28453 sched.cpp:421] Scheduler::registered took 9873ns I1016 22:50:13.219907 28456 sched.cpp:745] Stopping framework '20141016-225013-3142697795-53609-28427-0000' I1016 22:50:13.219913 28427 master.cpp:677] Master terminating [ OK ] AuthenticationTest.DropIntermediateSASLMessage (42 ms) [ RUN ] AuthenticationTest.RetrySlaveAuthentication Using temporary directory '/tmp/AuthenticationTest_RetrySlaveAuthentication_II3Kqx' I1016 22:50:13.225847 28427 leveldb.cpp:176] Opened db in 2.453903ms I1016 22:50:13.226562 28427 leveldb.cpp:183] Compacted db in 684723ns I1016 22:50:13.226586 28427 leveldb.cpp:198] Created db iterator in 2698ns I1016 22:50:13.226599 28427 leveldb.cpp:204] Seeked to beginning of db in 537ns I1016 22:50:13.226609 28427 leveldb.cpp:273] Iterated through 0 keys in the db in 220ns I1016 22:50:13.226622 28427 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I1016 22:50:13.226811 28456 recover.cpp:425] Starting replica recovery I1016 22:50:13.227210 28456 recover.cpp:451] Replica is in EMPTY status I1016 22:50:13.227610 28468 replica.cpp:638] Replica in EMPTY status received a broadcasted recover request I1016 22:50:13.227725 28467 recover.cpp:188] Received a recover response from a replica in EMPTY status I1016 22:50:13.227949 28460 recover.cpp:542] Updating replica status to STARTING I1016 22:50:13.228489 28454 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 481873ns I1016 22:50:13.228505 28454 replica.cpp:320] Persisted replica status to STARTING I1016 22:50:13.228554 28454 recover.cpp:451] Replica is in STARTING status I1016 22:50:13.228798 28458 master.cpp:312] Master 20141016-225013-3142697795-53609-28427 (pomona.apache.org) started on 67.195.81.187:53609 I1016 22:50:13.228832 28458 master.cpp:358] Master only allowing authenticated frameworks to register I1016 22:50:13.228842 28458 master.cpp:363] Master only allowing authenticated slaves to register I1016 22:50:13.228852 28458 credentials.hpp:36] Loading credentials for authentication from '/tmp/AuthenticationTest_RetrySlaveAuthentication_II3Kqx/credentials' I1016 22:50:13.228927 28455 replica.cpp:638] Replica in STARTING status received a broadcasted recover request I1016 22:50:13.228988 28458 master.cpp:392] Authorization enabled I1016 22:50:13.229079 28456 recover.cpp:188] Received a recover response from a replica in STARTING status I1016 22:50:13.229179 28455 master.cpp:120] No whitelist given. Advertising offers for all slaves I1016 22:50:13.229208 28467 hierarchical_allocator_process.hpp:299] Initializing hierarchical allocator process with master : master@67.195.81.187:53609 I1016 22:50:13.229360 28455 recover.cpp:542] Updating replica status to VOTING I1016 22:50:13.229661 28458 master.cpp:1242] The newly elected leader is master@67.195.81.187:53609 with id 20141016-225013-3142697795-53609-28427 I1016 22:50:13.229676 28458 master.cpp:1255] Elected as the leading master! I1016 22:50:13.229682 28458 master.cpp:1073] Recovering from registrar I1016 22:50:13.229732 28457 registrar.cpp:313] Recovering registrar I1016 22:50:13.229830 28460 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 313794ns I1016 22:50:13.229850 28460 replica.cpp:320] Persisted replica status to VOTING I1016 22:50:13.229900 28453 recover.cpp:556] Successfully joined the Paxos group I1016 22:50:13.229986 28453 recover.cpp:440] Recover process terminated I1016 22:50:13.230145 28459 log.cpp:656] Attempting to start the writer I1016 22:50:13.230729 28459 replica.cpp:474] Replica received implicit promise request with proposal 1 I1016 22:50:13.231133 28459 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 388161ns I1016 22:50:13.231147 28459 replica.cpp:342] Persisted promised to 1 I1016 22:50:13.231340 28457 coordinator.cpp:230] Coordinator attemping to fill missing position I1016 22:50:13.231936 28458 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2 I1016 22:50:13.232239 28458 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 284479ns I1016 22:50:13.232252 28458 replica.cpp:676] Persisted action at 0 I1016 22:50:13.232987 28465 replica.cpp:508] Replica received write request for position 0 I1016 22:50:13.233016 28465 leveldb.cpp:438] Reading position from leveldb took 11582ns I1016 22:50:13.233328 28465 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 299043ns I1016 22:50:13.233342 28465 replica.cpp:676] Persisted action at 0 I1016 22:50:13.233643 28463 replica.cpp:655] Replica received learned notice for position 0 I1016 22:50:13.233989 28463 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 320767ns I1016 22:50:13.234007 28463 replica.cpp:676] Persisted action at 0 I1016 22:50:13.234016 28463 replica.cpp:661] Replica learned NOP action at position 0 I1016 22:50:13.234248 28462 log.cpp:672] Writer started with ending position 0 I1016 22:50:13.234591 28467 leveldb.cpp:438] Reading position from leveldb took 10380ns I1016 22:50:13.235877 28457 registrar.cpp:346] Successfully fetched the registry (0B) in 6.104064ms I1016 22:50:13.235924 28457 registrar.cpp:445] Applied 1 operations in 3399ns; attempting to update the 'registry' I1016 22:50:13.236855 28465 log.cpp:680] Attempting to append 139 bytes to the log I1016 22:50:13.236932 28464 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1 I1016 22:50:13.237391 28456 replica.cpp:508] Replica received write request for position 1 I1016 22:50:13.237702 28456 leveldb.cpp:343] Persisting action (158 bytes) to leveldb took 293725ns I1016 22:50:13.237716 28456 replica.cpp:676] Persisted action at 1 I1016 22:50:13.237953 28458 replica.cpp:655] Replica received learned notice for position 1 I1016 22:50:13.238072 28458 leveldb.cpp:343] Persisting action (160 bytes) to leveldb took 101917ns I1016 22:50:13.238086 28458 replica.cpp:676] Persisted action at 1 I1016 22:50:13.238092 28458 replica.cpp:661] Replica learned APPEND action at position 1 I1016 22:50:13.238359 28465 registrar.cpp:490] Successfully updated the 'registry' in 2.415872ms I1016 22:50:13.238425 28465 registrar.cpp:376] Successfully recovered registrar I1016 22:50:13.238447 28455 log.cpp:699] Attempting to truncate the log to 1 I1016 22:50:13.238553 28457 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2 I1016 22:50:13.238549 28453 master.cpp:1100] Recovered 0 slaves from the Registry (101B) ; allowing 10mins for slaves to re-register I1016 22:50:13.238989 28459 replica.cpp:508] Replica received write request for position 2 I1016 22:50:13.239310 28459 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 296320ns I1016 22:50:13.239331 28459 replica.cpp:676] Persisted action at 2 I1016 22:50:13.239713 28458 replica.cpp:655] Replica received learned notice for position 2 I1016 22:50:13.240030 28458 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 291690ns I1016 22:50:13.240066 28458 leveldb.cpp:401] Deleting ~1 keys from leveldb took 16037ns I1016 22:50:13.240077 28458 replica.cpp:676] Persisted action at 2 I1016 22:50:13.240084 28458 replica.cpp:661] Replica learned TRUNCATE action at position 2 I1016 22:50:13.249413 28427 containerizer.cpp:89] Using isolation: posix/cpu,posix/mem I1016 22:50:13.251238 28456 slave.cpp:169] Slave started on 14)@67.195.81.187:53609 I1016 22:50:13.251276 28456 credentials.hpp:84] Loading credential for authentication from '/tmp/AuthenticationTest_RetrySlaveAuthentication_ds2izT/credential' I1016 22:50:13.251402 28456 slave.cpp:276] Slave using credential for: test-principal I1016 22:50:13.251500 28456 slave.cpp:289] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1016 22:50:13.251567 28456 slave.cpp:318] Slave hostname: pomona.apache.org I1016 22:50:13.251580 28456 slave.cpp:319] Slave checkpoint: false I1016 22:50:13.251950 28462 state.cpp:33] Recovering state from '/tmp/AuthenticationTest_RetrySlaveAuthentication_ds2izT/meta' I1016 22:50:13.252163 28466 status_update_manager.cpp:193] Recovering status update manager I1016 22:50:13.252269 28464 containerizer.cpp:252] Recovering containerizer I1016 22:50:13.252657 28465 slave.cpp:3329] Finished recovery I1016 22:50:13.252943 28460 slave.cpp:600] New master detected at master@67.195.81.187:53609 I1016 22:50:13.252985 28460 slave.cpp:674] Authenticating with master master@67.195.81.187:53609 I1016 22:50:13.253017 28464 status_update_manager.cpp:167] New master detected at master@67.195.81.187:53609 I1016 22:50:13.253032 28460 slave.cpp:647] Detecting new master I1016 22:50:13.253058 28465 authenticatee.hpp:133] Creating new client SASL connection I1016 22:50:13.253530 28458 master.cpp:120] No whitelist given. Advertising offers for all slaves I1016 22:50:13.253614 28466 hierarchical_allocator_process.hpp:697] No resources available to allocate! I1016 22:50:13.253630 28466 hierarchical_allocator_process.hpp:659] Performed allocation for 0 slaves in 19692ns W1016 22:50:13.253649 28460 slave.cpp:748] Authentication timed out W1016 22:50:13.253696 28460 slave.cpp:712] Failed to authenticate with master master@67.195.81.187:53609: Authentication discarded I1016 22:50:13.253743 28460 slave.cpp:674] Authenticating with master master@67.195.81.187:53609 I1016 22:50:13.253857 28465 authenticatee.hpp:133] Creating new client SASL connection I1016 22:50:13.253973 28463 master.cpp:3787] Authenticating slave(14)@67.195.81.187:53609 I1016 22:50:13.254062 28466 authenticator.hpp:161] Creating new server SASL connection I1016 22:50:13.254151 28465 authenticatee.hpp:224] Received SASL authentication mechanisms: CRAM-MD5 I1016 22:50:13.254178 28465 authenticatee.hpp:250] Attempting to authenticate with mechanism 'CRAM-MD5' I1016 22:50:13.254235 28466 authenticator.hpp:267] Received SASL authentication start I1016 22:50:13.254308 28466 authenticator.hpp:389] Authentication requires more steps I1016 22:50:13.254354 28466 authenticatee.hpp:270] Received SASL authentication step I1016 22:50:13.254428 28464 authenticator.hpp:295] Received SASL authentication step I1016 22:50:13.254457 28464 auxprop.cpp:81] 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 I1016 22:50:13.254475 28464 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1016 22:50:13.254487 28464 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1016 22:50:13.254504 28464 auxprop.cpp:81] 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 I1016 22:50:13.254513 28464 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1016 22:50:13.254518 28464 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1016 22:50:13.254531 28464 authenticator.hpp:381] Authentication success I1016 22:50:13.254585 28466 authenticatee.hpp:310] Authentication success I1016 22:50:13.254631 28464 master.cpp:3827] Successfully authenticated principal 'test-principal' at slave(14)@67.195.81.187:53609 I1016 22:50:13.254714 28455 slave.cpp:731] Successfully authenticated with master master@67.195.81.187:53609 I1016 22:50:13.254780 28455 slave.cpp:1048] Will retry registration in 14.158819ms if necessary I1016 22:50:13.254848 28453 master.cpp:2968] Registering slave at slave(14)@67.195.81.187:53609 (pomona.apache.org) with id 20141016-225013-3142697795-53609-28427-0 I1016 22:50:13.255002 28461 registrar.cpp:445] Applied 1 operations in 13842ns; attempting to update the 'registry' I1016 22:50:13.256332 28461 log.cpp:680] Attempting to append 315 bytes to the log I1016 22:50:13.256402 28461 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3 I1016 22:50:13.256845 28463 replica.cpp:508] Replica received write request for position 3 I1016 22:50:13.257081 28463 leveldb.cpp:343] Persisting action (334 bytes) to leveldb took 213243ns I1016 22:50:13.257105 28463 replica.cpp:676] Persisted action at 3 I1016 22:50:13.257398 28462 replica.cpp:655] Replica received learned notice for position 3 I1016 22:50:13.257915 28462 leveldb.cpp:343] Persisting action (336 bytes) to leveldb took 443022ns I1016 22:50:13.257936 28462 replica.cpp:676] Persisted action at 3 I1016 22:50:13.257943 28462 replica.cpp:661] Replica learned APPEND action at position 3 I1016 22:50:13.258294 28461 registrar.cpp:490] Successfully updated the 'registry' in 0ns I1016 22:50:13.258373 28453 log.cpp:699] Attempting to truncate the log to 3 I1016 22:50:13.258498 28468 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4 I1016 22:50:13.258548 28462 master.cpp:3022] Registered slave 20141016-225013-3142697795-53609-28427-0 at slave(14)@67.195.81.187:53609 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1016 22:50:13.258656 28468 slave.cpp:765] Registered with master master@67.195.81.187:53609; given slave ID 20141016-225013-3142697795-53609-28427-0 I1016 22:50:13.258672 28456 hierarchical_allocator_process.hpp:442] Added slave 20141016-225013-3142697795-53609-28427-0 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I1016 22:50:13.258714 28468 slave.cpp:2403] Received ping from slave-observer(13)@67.195.81.187:53609 I1016 22:50:13.258739 28456 hierarchical_allocator_process.hpp:679] Performed allocation for slave 20141016-225013-3142697795-53609-28427-0 in 9472ns I1016 22:50:13.258963 28459 replica.cpp:508] Replica received write request for position 4 I1016 22:50:13.259385 28459 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 397785ns I1016 22:50:13.259405 28459 replica.cpp:676] Persisted action at 4 I1016 22:50:13.259716 28458 replica.cpp:655] Replica received learned notice for position 4 I1016 22:50:13.260133 28458 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 395530ns I1016 22:50:13.260170 28458 leveldb.cpp:401] Deleting ~2 keys from leveldb took 18680ns I1016 22:50:13.260181 28458 replica.cpp:676] Persisted action at 4 I1016 22:50:13.260190 28458 replica.cpp:661] Replica learned TRUNCATE action at position 4 I1016 22:50:13.263506 28427 master.cpp:677] Master terminating I1016 22:50:13.263753 28462 slave.cpp:2488] master@67.195.81.187:53609 exited W1016 22:50:13.263793 28462 slave.cpp:2491] Master disconnected! Waiting for a new master to be elected I1016 22:50:13.265553 28461 slave.cpp:479] Slave terminating [ OK ] AuthenticationTest.RetrySlaveAuthentication (44 ms) [----------] 20 tests from AuthenticationTest (813 ms total) [----------] 2 tests from SorterTest [ RUN ] SorterTest.DRFSorter [ OK ] SorterTest.DRFSorter (1 ms) [ RUN ] SorterTest.WDRFSorter [ OK ] SorterTest.WDRFSorter (0 ms) [----------] 2 tests from SorterTest (1 ms total) [----------] 14 tests from ModuleTest [ RUN ] ModuleTest.EmptyLibraryFilename Using temporary directory '/tmp/ModuleTest_EmptyLibraryFilename_c4DRKf' [ OK ] ModuleTest.EmptyLibraryFilename (0 ms) [ RUN ] ModuleTest.NonModuleLibrary Using temporary directory '/tmp/ModuleTest_NonModuleLibrary_HOMtWB' [ OK ] ModuleTest.NonModuleLibrary (1 ms) [ RUN ] ModuleTest.AuthorInfoTest Using temporary directory '/tmp/ModuleTest_AuthorInfoTest_GFo97X' [ OK ] ModuleTest.AuthorInfoTest (0 ms) [ RUN ] ModuleTest.DuplicateModule Using temporary directory '/tmp/ModuleTest_DuplicateModule_FIhTjk' [ OK ] ModuleTest.DuplicateModule (0 ms) [ RUN ] ModuleTest.LibraryNameWithExtension Using temporary directory '/tmp/ModuleTest_LibraryNameWithExtension_EV1GvG' [ OK ] ModuleTest.LibraryNameWithExtension (1 ms) [ RUN ] ModuleTest.UnknownModuleInstantiationTest Using temporary directory '/tmp/ModuleTest_UnknownModuleInstantiationTest_fYHxH2' [ OK ] ModuleTest.UnknownModuleInstantiationTest (0 ms) [ RUN ] ModuleTest.UnknownLibraryTest Using temporary directory '/tmp/ModuleTest_UnknownLibraryTest_QRbrTo' [ OK ] ModuleTest.UnknownLibraryTest (0 ms) [ RUN ] ModuleTest.DifferentApiVersion Using temporary directory '/tmp/ModuleTest_DifferentApiVersion_7zxn5K' [ OK ] ModuleTest.DifferentApiVersion (1 ms) [ RUN ] ModuleTest.NewerModuleLibrary Using temporary directory '/tmp/ModuleTest_NewerModuleLibrary_IsDnh7' [ OK ] ModuleTest.NewerModuleLibrary (0 ms) [ RUN ] ModuleTest.OlderModuleLibrary Using temporary directory '/tmp/ModuleTest_OlderModuleLibrary_ZM9qtt' [ OK ] ModuleTest.OlderModuleLibrary (0 ms) [ RUN ] ModuleTest.EmptyModuleName Using temporary directory '/tmp/ModuleTest_EmptyModuleName_mvBxFP' [ OK ] ModuleTest.EmptyModuleName (1 ms) [ RUN ] ModuleTest.LibraryNameWithoutExtension Using temporary directory '/tmp/ModuleTest_LibraryNameWithoutExtension_fJvGRb' tests/module_tests.cpp:130: Failure ModuleManager::load(modules): Error verifying module 'org_apache_mesos_TestModule': Module API version mismatch. Mesos has: 1, library requires: ThisIsNotAnAPIVersion! tests/module_tests.cpp:135: Failure ModuleManager::unload(moduleName): Error unloading module 'org_apache_mesos_TestModule': module not loaded [ FAILED ] ModuleTest.LibraryNameWithoutExtension (0 ms) [ RUN ] ModuleTest.UnknownModuleTest Using temporary directory '/tmp/ModuleTest_UnknownModuleTest_G2ST3x' [ OK ] ModuleTest.UnknownModuleTest (0 ms) [ RUN ] ModuleTest.ExampleModuleParseStringTest Using temporary directory '/tmp/ModuleTest_ExampleModuleParseStringTest_3w09fU' tests/module_tests.cpp:75: Failure ModuleManager::load(modules): Error verifying module 'org_apache_mesos_TestModule': Module API version mismatch. Mesos has: 1, library requires: ThisIsNotAnAPIVersion! tests/module_tests.cpp:78: Failure module: Module 'org_apache_mesos_TestModule' unknown ABORT: (../3rdparty/libprocess/3rdparty/stout/include/stout/try.hpp:92): Try::get() but state == ERROR: Module 'org_apache_mesos_TestModule' unknown*** Aborted at 1413499813 (unix time) try "date -d @1413499813" if you are using GNU date *** PC: @ 0x2b82a6083bb9 (unknown) *** SIGABRT (@0x95b00006f0b) received by PID 28427 (TID 0x2b82a3374f80) from PID 28427; stack trace: *** @ 0x2b82a5e3f340 (unknown) @ 0x2b82a6083bb9 (unknown) @ 0x2b82a6086fc8 (unknown) @ 0x4c4c12 _Abort() @ 0x4c4c4c _Abort() @ 0x7caf37 ModuleTest_ExampleModuleParseStringTest_Test::TestBody() @ 0x9c3773 testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x9ba947 testing::Test::Run() @ 0x9ba9ee testing::TestInfo::Run() @ 0x9baaf5 testing::TestCase::Run() @ 0x9bad98 testing::internal::UnitTestImpl::RunAllTests() @ 0x9bb037 testing::UnitTest::Run() @ 0x494883 main @ 0x2b82a606eec5 (unknown) @ 0x4a1f98 (unknown) make[3]: *** [check-local] Aborted make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'> make[2]: *** [check-am] Error 2 make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'> make[1]: *** [check] Error 2 make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'> make: *** [check-recursive] Error 1 Test finished Exit status: 2 Build step 'Execute shell' marked build as failure Recording test results