Mailing-List: contact dev-help@mesos.apache.org; run by ezmlm
Precedence: bulk
Reply-To: dev@mesos.apache.org
Date: Fri, 20 Jun 2014 02:25:52 +0000 (UTC)
From: Apache Jenkins Server  <jenkins@builds.apache.org>
To: dev@mesos.apache.org
Message-ID: <1780228238.4241.1403231152676.JavaMail.jenkins@crius>
In-Reply-To: <1500811035.4202.1403222866446.JavaMail.jenkins@crius>
References: <1500811035.4202.1403222866446.JavaMail.jenkins@crius>
Subject: Build failed in Jenkins: Mesos-Ubuntu-distcheck #162
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 7bit

See <https://builds.apache.org/job/Mesos-Ubuntu-distcheck/162/changes>

Changes:

[bmahler] Exposed method in Process to get event counts of specific types.

[bmahler] Exposed MessageEvent queue size from Master/Scheduler.

------------------------------------------
[...truncated 57970 lines...]
I0620 02:25:49.649246 25765 replica.cpp:508] Replica received write request for position 2
I0620 02:25:49.649292 25767 replica.cpp:508] Replica received write request for position 2
I0620 02:25:49.670907 25765 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 21.647992ms
I0620 02:25:49.670930 25765 replica.cpp:676] Persisted action at 2
I0620 02:25:49.671282 25767 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 21.976825ms
I0620 02:25:49.671303 25767 replica.cpp:676] Persisted action at 2
I0620 02:25:49.671464 25767 replica.cpp:655] Replica received learned notice for position 2
I0620 02:25:49.671470 25764 replica.cpp:655] Replica received learned notice for position 2
I0620 02:25:49.689733 25767 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 18.250736ms
I0620 02:25:49.689775 25767 leveldb.cpp:401] Deleting ~1 keys from leveldb took 16979ns
I0620 02:25:49.689788 25767 replica.cpp:676] Persisted action at 2
I0620 02:25:49.689798 25767 replica.cpp:661] Replica learned TRUNCATE action at position 2
I0620 02:25:49.690085 25764 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 18.598298ms
I0620 02:25:49.690129 25764 leveldb.cpp:401] Deleting ~1 keys from leveldb took 22096ns
I0620 02:25:49.690139 25768 log.cpp:680] Attempting to append 167 bytes to the log
I0620 02:25:49.690141 25764 replica.cpp:676] Persisted action at 2
I0620 02:25:49.690171 25764 replica.cpp:661] Replica learned TRUNCATE action at position 2
I0620 02:25:49.690191 25764 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3
I0620 02:25:49.690498 25770 replica.cpp:508] Replica received write request for position 3
I0620 02:25:49.690577 25764 replica.cpp:508] Replica received write request for position 3
I0620 02:25:49.705569 25770 leveldb.cpp:343] Persisting action (186 bytes) to leveldb took 15.048121ms
I0620 02:25:49.705595 25770 replica.cpp:676] Persisted action at 3
I0620 02:25:49.705945 25764 leveldb.cpp:343] Persisting action (186 bytes) to leveldb took 15.351493ms
I0620 02:25:49.705963 25764 replica.cpp:676] Persisted action at 3
I0620 02:25:49.706161 25766 replica.cpp:655] Replica received learned notice for position 3
I0620 02:25:49.706162 25768 replica.cpp:655] Replica received learned notice for position 3
I0620 02:25:49.723018 25768 leveldb.cpp:343] Persisting action (188 bytes) to leveldb took 16.822402ms
I0620 02:25:49.723042 25768 replica.cpp:676] Persisted action at 3
I0620 02:25:49.723052 25768 replica.cpp:661] Replica learned APPEND action at position 3
I0620 02:25:49.723348 25770 registrar.cpp:479] Successfully updated 'registry'
I0620 02:25:49.723397 25770 registrar.cpp:422] Attempting to update the 'registry'
I0620 02:25:49.723423 25765 log.cpp:699] Attempting to truncate the log to 3
I0620 02:25:49.723470 25766 leveldb.cpp:343] Persisting action (188 bytes) to leveldb took 17.284295ms
I0620 02:25:49.723494 25766 replica.cpp:676] Persisted action at 3
I0620 02:25:49.723502 25766 replica.cpp:661] Replica learned APPEND action at position 3
I0620 02:25:49.723558 25768 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4
I0620 02:25:49.723776 25768 replica.cpp:508] Replica received write request for position 4
I0620 02:25:49.723811 25771 replica.cpp:508] Replica received write request for position 4
I0620 02:25:49.738881 25768 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 15.089865ms
I0620 02:25:49.738901 25768 replica.cpp:676] Persisted action at 4
I0620 02:25:49.739262 25771 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 15.434135ms
I0620 02:25:49.739285 25771 replica.cpp:676] Persisted action at 4
I0620 02:25:49.739441 25765 replica.cpp:655] Replica received learned notice for position 4
I0620 02:25:49.739442 25771 replica.cpp:655] Replica received learned notice for position 4
I0620 02:25:49.756337 25765 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 16.866874ms
I0620 02:25:49.756381 25765 leveldb.cpp:401] Deleting ~2 keys from leveldb took 19920ns
I0620 02:25:49.756393 25765 replica.cpp:676] Persisted action at 4
I0620 02:25:49.756402 25765 replica.cpp:661] Replica learned TRUNCATE action at position 4
I0620 02:25:49.756636 25765 log.cpp:680] Attempting to append 146 bytes to the log
I0620 02:25:49.756670 25765 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 5
I0620 02:25:49.756866 25765 replica.cpp:508] Replica received write request for position 5
I0620 02:25:49.763875 25771 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 24.401377ms
I0620 02:25:49.763913 25771 leveldb.cpp:401] Deleting ~2 keys from leveldb took 18743ns
I0620 02:25:49.763926 25771 replica.cpp:676] Persisted action at 4
I0620 02:25:49.763936 25771 replica.cpp:661] Replica learned TRUNCATE action at position 4
I0620 02:25:49.763948 25771 replica.cpp:508] Replica received write request for position 5
I0620 02:25:49.764338 25765 leveldb.cpp:343] Persisting action (165 bytes) to leveldb took 7.459108ms
I0620 02:25:49.764356 25765 replica.cpp:676] Persisted action at 5
I0620 02:25:49.772986 25771 leveldb.cpp:343] Persisting action (165 bytes) to leveldb took 9.026527ms
I0620 02:25:49.773005 25771 replica.cpp:676] Persisted action at 5
I0620 02:25:49.773154 25768 replica.cpp:655] Replica received learned notice for position 5
I0620 02:25:49.773164 25765 replica.cpp:655] Replica received learned notice for position 5
I0620 02:25:49.789671 25768 leveldb.cpp:343] Persisting action (167 bytes) to leveldb took 16.502303ms
I0620 02:25:49.789690 25768 replica.cpp:676] Persisted action at 5
I0620 02:25:49.789700 25768 replica.cpp:661] Replica learned APPEND action at position 5
I0620 02:25:49.790042 25765 leveldb.cpp:343] Persisting action (167 bytes) to leveldb took 16.866008ms
I0620 02:25:49.790061 25765 replica.cpp:676] Persisted action at 5
I0620 02:25:49.790069 25765 replica.cpp:661] Replica learned APPEND action at position 5
I0620 02:25:49.790307 25765 registrar.cpp:479] Successfully updated 'registry'
I0620 02:25:49.790362 25765 log.cpp:699] Attempting to truncate the log to 5
I0620 02:25:49.790403 25765 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 6
I0620 02:25:49.790611 25765 replica.cpp:508] Replica received write request for position 6
I0620 02:25:49.790674 25764 replica.cpp:508] Replica received write request for position 6
I0620 02:25:49.805522 25765 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 14.885207ms
I0620 02:25:49.805543 25765 replica.cpp:676] Persisted action at 6
I0620 02:25:49.805894 25764 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 15.204254ms
I0620 02:25:49.805925 25764 replica.cpp:676] Persisted action at 6
[       OK ] Strict/RegistrarTest.recover/0 (862 ms)
[----------] 16 tests from Strict/RegistrarTest (13711 ms total)

[----------] 7 tests from InMemoryStateTest
[ RUN      ] InMemoryStateTest.FetchAndStoreAndStoreAndFetch
[       OK ] InMemoryStateTest.FetchAndStoreAndStoreAndFetch (5 ms)
[ RUN      ] InMemoryStateTest.FetchAndStoreAndExpungeAndExpunge
[       OK ] InMemoryStateTest.FetchAndStoreAndExpungeAndExpunge (3 ms)
[ RUN      ] InMemoryStateTest.Names
[       OK ] InMemoryStateTest.Names (3 ms)
[ RUN      ] InMemoryStateTest.FetchAndStoreAndFetch
[       OK ] InMemoryStateTest.FetchAndStoreAndFetch (3 ms)
[ RUN      ] InMemoryStateTest.FetchAndStoreAndExpungeAndStoreAndFetch
[       OK ] InMemoryStateTest.FetchAndStoreAndExpungeAndStoreAndFetch (4 ms)
[ RUN      ] InMemoryStateTest.FetchAndStoreAndStoreFailAndFetch
[       OK ] InMemoryStateTest.FetchAndStoreAndStoreFailAndFetch (4 ms)
[ RUN      ] InMemoryStateTest.FetchAndStoreAndExpungeAndFetch
[       OK ] InMemoryStateTest.FetchAndStoreAndExpungeAndFetch (4 ms)
[----------] 7 tests from InMemoryStateTest (26 ms total)

[----------] 7 tests from MesosContainerizerProcessTest
[ RUN      ] MesosContainerizerProcessTest.NoExtractExecutable
[       OK ] MesosContainerizerProcessTest.NoExtractExecutable (1 ms)
[ RUN      ] MesosContainerizerProcessTest.MultipleURIs
[       OK ] MesosContainerizerProcessTest.MultipleURIs (0 ms)
[ RUN      ] MesosContainerizerProcessTest.Simple
[       OK ] MesosContainerizerProcessTest.Simple (0 ms)
[ RUN      ] MesosContainerizerProcessTest.EmptyHadoop
[       OK ] MesosContainerizerProcessTest.EmptyHadoop (0 ms)
[ RUN      ] MesosContainerizerProcessTest.NoHadoop
[       OK ] MesosContainerizerProcessTest.NoHadoop (1 ms)
[ RUN      ] MesosContainerizerProcessTest.NoExtract
[       OK ] MesosContainerizerProcessTest.NoExtract (0 ms)
[ RUN      ] MesosContainerizerProcessTest.NoUser
[       OK ] MesosContainerizerProcessTest.NoUser (0 ms)
[----------] 7 tests from MesosContainerizerProcessTest (2 ms total)

[----------] 1 test from HealthTest
[ RUN      ] HealthTest.ObserveEndpoint
Using temporary directory '/tmp/HealthTest_ObserveEndpoint_hR4hgs'
I0620 02:25:49.917611 25609 leveldb.cpp:176] Opened db in 82.319875ms
I0620 02:25:49.920944 25609 leveldb.cpp:183] Compacted db in 3.308373ms
I0620 02:25:49.920965 25609 leveldb.cpp:198] Created db iterator in 4521ns
I0620 02:25:49.920975 25609 leveldb.cpp:204] Seeked to beginning of db in 684ns
I0620 02:25:49.920984 25609 leveldb.cpp:273] Iterated through 0 keys in the db in 210ns
I0620 02:25:49.920999 25609 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0620 02:25:49.921480 25766 recover.cpp:425] Starting replica recovery
I0620 02:25:49.921636 25767 recover.cpp:451] Replica is in EMPTY status
I0620 02:25:49.922830 25767 replica.cpp:638] Replica in EMPTY status received a broadcasted recover request
I0620 02:25:49.922976 25765 recover.cpp:188] Received a recover response from a replica in EMPTY status
I0620 02:25:49.923215 25771 master.cpp:286] Master 20140620-022549-1015726915-43172-25609 (janus.apache.org) started on 67.195.138.60:43172
I0620 02:25:49.923238 25771 master.cpp:323] Master only allowing authenticated frameworks to register
I0620 02:25:49.923246 25771 master.cpp:328] Master only allowing authenticated slaves to register
I0620 02:25:49.923256 25771 credentials.hpp:35] Loading credentials for authentication from '/tmp/HealthTest_ObserveEndpoint_hR4hgs/credentials'
I0620 02:25:49.923339 25765 recover.cpp:542] Updating replica status to STARTING
I0620 02:25:49.923341 25771 master.cpp:354] Authorization enabled
I0620 02:25:49.923888 25769 hierarchical_allocator_process.hpp:301] Initializing hierarchical allocator process with master : master@67.195.138.60:43172
I0620 02:25:49.923964 25769 master.cpp:120] No whitelist given. Advertising offers for all slaves
I0620 02:25:49.924254 25771 master.cpp:1077] The newly elected leader is master@67.195.138.60:43172 with id 20140620-022549-1015726915-43172-25609
I0620 02:25:49.924269 25771 master.cpp:1090] Elected as the leading master!
I0620 02:25:49.924278 25771 master.cpp:908] Recovering from registrar
I0620 02:25:49.924335 25767 registrar.cpp:313] Recovering registrar
I0620 02:25:49.951181 25765 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 27.76096ms
I0620 02:25:49.951203 25765 replica.cpp:320] Persisted replica status to STARTING
I0620 02:25:49.951320 25766 recover.cpp:451] Replica is in STARTING status
I0620 02:25:49.951642 25769 replica.cpp:638] Replica in STARTING status received a broadcasted recover request
I0620 02:25:49.951741 25767 recover.cpp:188] Received a recover response from a replica in STARTING status
I0620 02:25:49.951912 25771 recover.cpp:542] Updating replica status to VOTING
I0620 02:25:49.959229 25767 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 7.253842ms
I0620 02:25:49.959251 25767 replica.cpp:320] Persisted replica status to VOTING
I0620 02:25:49.959311 25769 recover.cpp:556] Successfully joined the Paxos group
I0620 02:25:49.959417 25769 recover.cpp:440] Recover process terminated
I0620 02:25:49.959590 25764 log.cpp:656] Attempting to start the writer
I0620 02:25:49.960114 25769 replica.cpp:474] Replica received implicit promise request with proposal 1
I0620 02:25:49.967551 25769 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 7.420095ms
I0620 02:25:49.967571 25769 replica.cpp:342] Persisted promised to 1
I0620 02:25:49.967782 25769 coordinator.cpp:230] Coordinator attemping to fill missing position
I0620 02:25:49.968286 25768 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I0620 02:25:49.975890 25768 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 7.585935ms
I0620 02:25:49.975915 25768 replica.cpp:676] Persisted action at 0
I0620 02:25:49.976368 25770 replica.cpp:508] Replica received write request for position 0
I0620 02:25:49.976395 25770 leveldb.cpp:438] Reading position from leveldb took 11193ns
I0620 02:25:49.984212 25770 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 7.802325ms
I0620 02:25:49.984232 25770 replica.cpp:676] Persisted action at 0
I0620 02:25:49.984498 25765 replica.cpp:655] Replica received learned notice for position 0
2014-06-20 02:25:49,989:25609(0x2b8614200700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:59010] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I0620 02:25:49.992544 25765 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 8.029023ms
I0620 02:25:49.992563 25765 replica.cpp:676] Persisted action at 0
I0620 02:25:49.992573 25765 replica.cpp:661] Replica learned NOP action at position 0
I0620 02:25:49.992781 25764 log.cpp:672] Writer started with ending position 0
I0620 02:25:49.993186 25766 leveldb.cpp:438] Reading position from leveldb took 8235ns
I0620 02:25:49.994684 25764 registrar.cpp:346] Successfully fetched the registry (0B)
I0620 02:25:49.994709 25764 registrar.cpp:422] Attempting to update the 'registry'
I0620 02:25:49.996083 25764 log.cpp:680] Attempting to append 138 bytes to the log
I0620 02:25:49.996136 25764 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1
I0620 02:25:49.996374 25764 replica.cpp:508] Replica received write request for position 1
I0620 02:25:50.005136 25764 leveldb.cpp:343] Persisting action (157 bytes) to leveldb took 8.748084ms
I0620 02:25:50.005156 25764 replica.cpp:676] Persisted action at 1
I0620 02:25:50.005358 25764 replica.cpp:655] Replica received learned notice for position 1
I0620 02:25:50.013437 25764 leveldb.cpp:343] Persisting action (159 bytes) to leveldb took 8.065646ms
I0620 02:25:50.013455 25764 replica.cpp:676] Persisted action at 1
I0620 02:25:50.013464 25764 replica.cpp:661] Replica learned APPEND action at position 1
I0620 02:25:50.013749 25764 registrar.cpp:479] Successfully updated 'registry'
I0620 02:25:50.013787 25764 registrar.cpp:372] Successfully recovered registrar
I0620 02:25:50.013833 25764 log.cpp:699] Attempting to truncate the log to 1
I0620 02:25:50.013906 25764 master.cpp:935] Recovered 0 slaves from the Registry (100B) ; allowing 10mins for slaves to re-register
I0620 02:25:50.013960 25764 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2
I0620 02:25:50.014220 25764 replica.cpp:508] Replica received write request for position 2
I0620 02:25:50.014370 25770 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.014430 25770 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.014811 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.015219 25768 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.015300 25768 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.015509 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.015856 25768 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.015909 25768 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.016111 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.016470 25766 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.016525 25766 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.016736 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.017094 25769 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.017225 25769 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.017428 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.017789 25767 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.017843 25767 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.018107 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.018426 25771 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.018483 25771 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.018717 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.019074 25765 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.019145 25765 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.019425 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.019775 25768 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.019826 25768 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.020081 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.020478 25767 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.020601 25767 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.020862 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.021236 25767 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.021296 25767 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.021550 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.021950 25770 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.022016 25770 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.022253 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.022608 25766 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.022670 25766 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.022900 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.023136 25609 master.cpp:610] Master terminating
I0620 02:25:50.029005 25764 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 14.738799ms
I0620 02:25:50.029032 25764 replica.cpp:676] Persisted action at 2
[       OK ] HealthTest.ObserveEndpoint (195 ms)
[----------] 1 test from HealthTest (195 ms total)

[----------] Global test environment tear-down
[==========] 377 tests from 62 test cases ran. (334352 ms total)
[  PASSED  ] 376 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] ExamplesTest.PythonFramework

 1 FAILED TEST
  YOU HAVE 3 DISABLED TESTS

make[4]: *** [check-local] Error 1
make[4]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.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.20.0/_build/src'>
make[2]: *** [check] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.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.20.0/_build'>
make: *** [distcheck] Error 1
Build step 'Execute shell' marked build as failure