See <https://builds.apache.org/job/Mesos-Ubuntu-distcheck/50/changes>
Changes: [bmahler] Added libprocess metrics to master/slave '/stats.json'. [vinod] Added Containerizer::containers() to get set of containers. [bmahler] Added metrics to the registrar. [vinod] Fixed containerizer::Termination use in SlaveRecoveryTest. [vinod] Added timeouts to registrar. [vinod] Fixed a warning in ReservationAllocatorTest.ResourcesReturned. [bmahler] Fixed a CHECK failure in Statistics. [vinod] Introduced exponential backoff for slave registration retries. [bmahler] Fixed a compiler warning in Statistics. ------------------------------------------ [...truncated 41300 lines...] I0424 04:24:29.751608 2358 authenticatee.hpp:265] Received SASL authentication step I0424 04:24:29.751649 2358 authenticator.hpp:282] Received SASL authentication step I0424 04:24:29.751668 2358 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0424 04:24:29.751677 2358 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0424 04:24:29.751688 2358 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0424 04:24:29.751699 2358 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0424 04:24:29.751706 2358 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0424 04:24:29.751713 2358 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true W0424 04:24:29.751732 2358 authenticator.hpp:348] Authentication failure: authentication failure [ OK ] SASL.failed1 (1 ms) [ RUN ] SASL.failed2 I0424 04:24:29.752231 2359 authenticatee.hpp:128] Creating new client SASL connection I0424 04:24:29.752578 2355 authenticator.hpp:148] Creating new server SASL connection I0424 04:24:29.752756 2356 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0424 04:24:29.752778 2356 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0424 04:24:29.752811 2356 authenticator.hpp:254] Received SASL authentication start I0424 04:24:29.752857 2356 authenticator.hpp:342] Authentication requires more steps I0424 04:24:29.752888 2356 authenticatee.hpp:265] Received SASL authentication step I0424 04:24:29.752934 2356 authenticator.hpp:282] Received SASL authentication step I0424 04:24:29.752955 2356 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0424 04:24:29.752964 2356 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0424 04:24:29.752974 2356 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0424 04:24:29.752984 2356 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0424 04:24:29.752990 2356 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0424 04:24:29.752995 2356 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true W0424 04:24:29.753005 2356 authenticator.hpp:348] Authentication failure: user not found [ OK ] SASL.failed2 (1 ms) [ RUN ] SASL.success I0424 04:24:29.753476 2355 authenticatee.hpp:128] Creating new client SASL connection I0424 04:24:29.753780 2355 authenticator.hpp:148] Creating new server SASL connection I0424 04:24:29.753886 2358 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0424 04:24:29.753907 2358 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0424 04:24:29.753942 2358 authenticator.hpp:254] Received SASL authentication start I0424 04:24:29.753985 2358 authenticator.hpp:342] Authentication requires more steps I0424 04:24:29.754017 2358 authenticatee.hpp:265] Received SASL authentication step I0424 04:24:29.754060 2358 authenticator.hpp:282] Received SASL authentication step I0424 04:24:29.754079 2358 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0424 04:24:29.754088 2358 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0424 04:24:29.754097 2358 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0424 04:24:29.754107 2358 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0424 04:24:29.754115 2358 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0424 04:24:29.754122 2358 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0424 04:24:29.754133 2358 authenticator.hpp:334] Authentication success I0424 04:24:29.754160 2358 authenticatee.hpp:305] Authentication success [ OK ] SASL.success (1 ms) [----------] 3 tests from SASL (4 ms total) [----------] 34 tests from ResourcesTest [ RUN ] ResourcesTest.BadResourcesNotAllocatable [ OK ] ResourcesTest.BadResourcesNotAllocatable (0 ms) [ RUN ] ResourcesTest.RangesEquals [ OK ] ResourcesTest.RangesEquals (0 ms) [ RUN ] ResourcesTest.SetSubtraction [ OK ] ResourcesTest.SetSubtraction (0 ms) [ RUN ] ResourcesTest.ScalarEquals [ OK ] ResourcesTest.ScalarEquals (0 ms) [ RUN ] ResourcesTest.ParsingWithRoles [ OK ] ResourcesTest.ParsingWithRoles (0 ms) [ RUN ] ResourcesTest.RangesSubtraction4 [ OK ] ResourcesTest.RangesSubtraction4 (0 ms) [ RUN ] ResourcesTest.RangesSubtraction [ OK ] ResourcesTest.RangesSubtraction (1 ms) [ RUN ] ResourcesTest.RangesSubtraction2 [ OK ] ResourcesTest.RangesSubtraction2 (0 ms) [ RUN ] ResourcesTest.RangesAddition2 [ OK ] ResourcesTest.RangesAddition2 (0 ms) [ RUN ] ResourcesTest.ParseError [ OK ] ResourcesTest.ParseError (0 ms) [ RUN ] ResourcesTest.ScalarSubset2 [ OK ] ResourcesTest.ScalarSubset2 (0 ms) [ RUN ] ResourcesTest.RangesAddition4 [ OK ] ResourcesTest.RangesAddition4 (0 ms) [ RUN ] ResourcesTest.Resources [ OK ] ResourcesTest.Resources (0 ms) [ RUN ] ResourcesTest.ScalarAddition [ OK ] ResourcesTest.ScalarAddition (0 ms) [ RUN ] ResourcesTest.RangesSubtraction3 [ OK ] ResourcesTest.RangesSubtraction3 (0 ms) [ RUN ] ResourcesTest.RangesSubtraction5 [ OK ] ResourcesTest.RangesSubtraction5 (0 ms) [ RUN ] ResourcesTest.RangesSubset [ OK ] ResourcesTest.RangesSubset (0 ms) [ RUN ] ResourcesTest.SetEquals [ OK ] ResourcesTest.SetEquals (0 ms) [ RUN ] ResourcesTest.SetSubset [ OK ] ResourcesTest.SetSubset (0 ms) [ RUN ] ResourcesTest.RangesSubtraction1 [ OK ] ResourcesTest.RangesSubtraction1 (0 ms) [ RUN ] ResourcesTest.InitializedIsEmpty [ OK ] ResourcesTest.InitializedIsEmpty (0 ms) [ RUN ] ResourcesTest.EmptyUnequal [ OK ] ResourcesTest.EmptyUnequal (0 ms) [ RUN ] ResourcesTest.ScalarAddition2 [ OK ] ResourcesTest.ScalarAddition2 (0 ms) [ RUN ] ResourcesTest.SetAddition [ OK ] ResourcesTest.SetAddition (0 ms) [ RUN ] ResourcesTest.RangesSubtraction6 [ OK ] ResourcesTest.RangesSubtraction6 (0 ms) [ RUN ] ResourcesTest.RangesAdditon3 [ OK ] ResourcesTest.RangesAdditon3 (0 ms) [ RUN ] ResourcesTest.FlattenRoles [ OK ] ResourcesTest.FlattenRoles (0 ms) [ RUN ] ResourcesTest.ScalarSubtraction [ OK ] ResourcesTest.ScalarSubtraction (0 ms) [ RUN ] ResourcesTest.Parsing [ OK ] ResourcesTest.Parsing (0 ms) [ RUN ] ResourcesTest.ScalarSubset [ OK ] ResourcesTest.ScalarSubset (0 ms) [ RUN ] ResourcesTest.ScalarSubtraction2 [ OK ] ResourcesTest.ScalarSubtraction2 (0 ms) [ RUN ] ResourcesTest.RangesAddition [ OK ] ResourcesTest.RangesAddition (0 ms) [ RUN ] ResourcesTest.Find [ OK ] ResourcesTest.Find (1 ms) [ RUN ] ResourcesTest.Printing [ OK ] ResourcesTest.Printing (0 ms) [----------] 34 tests from ResourcesTest (3 ms total) [----------] 1 test from HealthTest [ RUN ] HealthTest.ObserveEndpoint I0424 04:24:29.855509 2327 leveldb.cpp:174] Opened db in 97.566896ms I0424 04:24:29.864197 2327 leveldb.cpp:181] Compacted db in 8.666955ms I0424 04:24:29.864214 2327 leveldb.cpp:196] Created db iterator in 3525ns I0424 04:24:29.864222 2327 leveldb.cpp:202] Seeked to beginning of db in 441ns I0424 04:24:29.864226 2327 leveldb.cpp:271] Iterated through 0 keys in the db in 279ns I0424 04:24:29.864239 2327 replica.cpp:729] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0424 04:24:29.895467 2358 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.051391ms I0424 04:24:29.895485 2358 replica.cpp:320] Persisted replica status to VOTING I0424 04:24:29.979280 2327 leveldb.cpp:174] Opened db in 83.551101ms I0424 04:24:30.071321 2327 leveldb.cpp:181] Compacted db in 92.013037ms I0424 04:24:30.071343 2327 leveldb.cpp:196] Created db iterator in 4125ns I0424 04:24:30.071357 2327 leveldb.cpp:202] Seeked to beginning of db in 5894ns I0424 04:24:30.071377 2327 leveldb.cpp:271] Iterated through 1 keys in the db in 13197ns I0424 04:24:30.071390 2327 replica.cpp:729] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0424 04:24:30.071710 2352 recover.cpp:425] Starting replica recovery I0424 04:24:30.071877 2356 recover.cpp:451] Replica is in VOTING status I0424 04:24:30.072113 2356 recover.cpp:440] Recover process terminated I0424 04:24:30.072228 2354 master.cpp:264] Master 20140424-042430-1032504131-46198-2327 (juno.apache.org) started on 67.195.138.61:46198 I0424 04:24:30.072250 2354 master.cpp:298] Master only allowing authenticated frameworks to register! W0424 04:24:30.072341 2354 master.cpp:328] Permissions on credentials file '/tmp/HealthTest_ObserveEndpoint_zkfgTc/credentials' are too open. It is recommended that your credentials file is NOT accessible by others. I0424 04:24:30.072726 2357 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : [email protected]:46198 I0424 04:24:30.072783 2357 master.cpp:102] No whitelist given. Advertising offers for all slaves I0424 04:24:30.073072 2354 master.cpp:940] The newly elected leader is [email protected]:46198 with id 20140424-042430-1032504131-46198-2327 I0424 04:24:30.073086 2354 master.cpp:950] Elected as the leading master! I0424 04:24:30.073093 2354 master.cpp:773] Recovering from registrar I0424 04:24:30.073139 2357 registrar.cpp:284] Recovering registrar I0424 04:24:30.073346 2354 log.cpp:656] Attempting to start the writer I0424 04:24:30.073828 2359 replica.cpp:474] Replica received implicit promise request with proposal 1 I0424 04:24:30.106148 2359 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 32.297923ms I0424 04:24:30.106168 2359 replica.cpp:342] Persisted promised to 1 I0424 04:24:30.106461 2359 coordinator.cpp:229] Coordinator attemping to fill missing position I0424 04:24:30.106991 2355 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2 I0424 04:24:30.119005 2355 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 11.989562ms I0424 04:24:30.119027 2355 replica.cpp:664] Persisted action at 0 I0424 04:24:30.119539 2355 replica.cpp:508] Replica received write request for position 0 I0424 04:24:30.119560 2355 leveldb.cpp:436] Reading position from leveldb took 9741ns I0424 04:24:30.127322 2355 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 7.749733ms I0424 04:24:30.127341 2355 replica.cpp:664] Persisted action at 0 I0424 04:24:30.127589 2358 replica.cpp:643] Replica received learned notice for position 0 I0424 04:24:30.135661 2358 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 8.045545ms I0424 04:24:30.135684 2358 replica.cpp:664] Persisted action at 0 I0424 04:24:30.135694 2358 replica.cpp:649] Replica learned NOP action at position 0 I0424 04:24:30.135961 2355 log.cpp:672] Writer started with ending position 0 I0424 04:24:30.136409 2355 leveldb.cpp:436] Reading position from leveldb took 15107ns I0424 04:24:30.138046 2356 registrar.cpp:317] Successfully recovered registrar I0424 04:24:30.138075 2356 registrar.cpp:388] Attempting to update the 'registry' I0424 04:24:30.139614 2352 log.cpp:680] Attempting to append 136 bytes to the log I0424 04:24:30.139719 2358 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 1 I0424 04:24:30.140068 2358 replica.cpp:508] Replica received write request for position 1 I0424 04:24:30.143983 2358 leveldb.cpp:341] Persisting action (155 bytes) to leveldb took 3.899256ms I0424 04:24:30.144001 2358 replica.cpp:664] Persisted action at 1 I0424 04:24:30.144386 2355 replica.cpp:643] Replica received learned notice for position 1 I0424 04:24:30.152320 2355 leveldb.cpp:341] Persisting action (157 bytes) to leveldb took 7.911842ms I0424 04:24:30.152344 2355 replica.cpp:664] Persisted action at 1 I0424 04:24:30.152369 2355 replica.cpp:649] Replica learned APPEND action at position 1 I0424 04:24:30.152775 2359 registrar.cpp:436] Successfully updated 'registry' I0424 04:24:30.152895 2354 log.cpp:699] Attempting to truncate the log to 1 I0424 04:24:30.152959 2354 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 2 I0424 04:24:30.152990 2357 master.cpp:800] Recovered 0 slaves from the Registry (98B) ; allowing 75secs for slaves to re-register I0424 04:24:30.153290 2358 replica.cpp:508] Replica received write request for position 2 I0424 04:24:30.153352 2359 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.153441 2359 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.153750 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.154150 2354 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.154223 2354 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.154431 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.154768 2354 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.154844 2354 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.155043 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.155360 2357 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.155431 2357 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.155630 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.155954 2355 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.156033 2355 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.156255 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.156602 2359 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.156666 2359 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.156868 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.157171 2359 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.157227 2359 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.157457 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.157785 2356 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.157871 2356 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.158126 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.158488 2359 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.158547 2359 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.158789 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.159137 2354 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.159196 2354 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.159417 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.159759 2355 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.159823 2355 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.160054 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.160404 2354 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.160472 2354 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.160650 2358 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 7.337627ms I0424 04:24:30.160673 2358 replica.cpp:664] Persisted action at 2 I0424 04:24:30.160691 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.160930 2353 replica.cpp:643] Replica received learned notice for position 2 I0424 04:24:30.161094 2357 process.cpp:3201] Handling HTTP event for process 'master' with path: '/master/observe' I0424 04:24:30.161152 2357 http.cpp:258] HTTP request for '/master/observe' I0424 04:24:30.161383 2360 process.cpp:1013] Socket closed while receiving I0424 04:24:30.161610 2327 master.cpp:573] Master terminating I0424 04:24:30.168980 2353 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 8.02469ms I0424 04:24:30.169018 2353 leveldb.cpp:399] Deleting ~1 keys from leveldb took 17967ns I0424 04:24:30.169029 2353 replica.cpp:664] Persisted action at 2 I0424 04:24:30.169039 2353 replica.cpp:649] Replica learned TRUNCATE action at position 2 [ OK ] HealthTest.ObserveEndpoint (412 ms) [----------] 1 test from HealthTest (412 ms total) [----------] Global test environment tear-down [==========] 298 tests from 50 test cases ran. (327832 ms total) [ PASSED ] 297 tests. [ FAILED ] 1 test, listed below: [ FAILED ] MasterTest.MetricsInStatsEndpoint 1 FAILED TEST YOU HAVE 1 DISABLED TEST make[4]: *** [check-local] Error 1 make[4]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.19.0/_build/src'> make[3]: *** [check-am] Error 2 make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.19.0/_build/src'> make[2]: *** [check] Error 2 make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.19.0/_build/src'> make[1]: *** [check-recursive] Error 1 make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.19.0/_build'> make: *** [distcheck] Error 1 Build step 'Execute shell' marked build as failure
