You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2016/01/25 16:32:05 UTC
Build failed in Jenkins: Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #1544
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1544/changes>
Changes:
[toenshoff] Improved rakefile to allow for external .md file links.
[toenshoff] Made links to .md files consistent across documentation.
------------------------------------------
[...truncated 164628 lines...]
I0125 15:31:53.907892 31995 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_FH51HS/slaves/6e16d26e-80dd-4b46-b8b5-1f7aa9133d80-S0/frameworks/6e16d26e-80dd-4b46-b8b5-1f7aa9133d80-0000/executors/default' for gc 6.9999895029037days in the future
I0125 15:31:53.908051 31995 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_FH51HS/slaves/6e16d26e-80dd-4b46-b8b5-1f7aa9133d80-S0/frameworks/6e16d26e-80dd-4b46-b8b5-1f7aa9133d80-0000' for gc 6.99998950096296days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (795 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0125 15:31:54.011689 31962 leveldb.cpp:174] Opened db in 95.027917ms
I0125 15:31:54.048696 31962 leveldb.cpp:181] Compacted db in 36.838022ms
I0125 15:31:54.049106 31962 leveldb.cpp:196] Created db iterator in 30240ns
I0125 15:31:54.049321 31962 leveldb.cpp:202] Seeked to beginning of db in 8041ns
I0125 15:31:54.049427 31962 leveldb.cpp:271] Iterated through 0 keys in the db in 480ns
I0125 15:31:54.049568 31962 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0125 15:31:54.050299 31993 recover.cpp:447] Starting replica recovery
I0125 15:31:54.050555 31993 recover.cpp:473] Replica is in EMPTY status
I0125 15:31:54.052047 31983 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14154)@172.17.0.2:52355
I0125 15:31:54.052635 31982 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0125 15:31:54.053282 31985 master.cpp:374] Master a41bf879-36b6-4769-82c6-4220f6ecc603 (6a3fa6c4588a) started on 172.17.0.2:52355
I0125 15:31:54.053308 31985 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/60pgVG/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/60pgVG/master" --zk_session_timeout="10secs"
I0125 15:31:54.053663 31985 master.cpp:423] Master allowing unauthenticated frameworks to register
I0125 15:31:54.053680 31985 master.cpp:426] Master only allowing authenticated slaves to register
I0125 15:31:54.053691 31985 credentials.hpp:35] Loading credentials for authentication from '/tmp/60pgVG/credentials'
I0125 15:31:54.054059 31985 master.cpp:466] Using default 'crammd5' authenticator
I0125 15:31:54.054276 31985 master.cpp:535] Using default 'basic' HTTP authenticator
I0125 15:31:54.054428 31985 master.cpp:569] Authorization enabled
I0125 15:31:54.055181 31990 whitelist_watcher.cpp:77] No whitelist given
I0125 15:31:54.056215 31983 recover.cpp:564] Updating replica status to STARTING
I0125 15:31:54.056524 31984 hierarchical.cpp:144] Initialized hierarchical allocator process
I0125 15:31:54.059185 31983 master.cpp:1710] The newly elected leader is master@172.17.0.2:52355 with id a41bf879-36b6-4769-82c6-4220f6ecc603
I0125 15:31:54.059321 31983 master.cpp:1723] Elected as the leading master!
I0125 15:31:54.059443 31983 master.cpp:1468] Recovering from registrar
I0125 15:31:54.059737 31981 registrar.cpp:307] Recovering registrar
I0125 15:31:54.087240 31987 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.864305ms
I0125 15:31:54.087321 31987 replica.cpp:320] Persisted replica status to STARTING
I0125 15:31:54.087695 31983 recover.cpp:473] Replica is in STARTING status
I0125 15:31:54.089272 31982 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14156)@172.17.0.2:52355
I0125 15:31:54.090032 31984 recover.cpp:193] Received a recover response from a replica in STARTING status
I0125 15:31:54.090538 31992 recover.cpp:564] Updating replica status to VOTING
I0125 15:31:54.121637 31994 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.821991ms
I0125 15:31:54.122213 31994 replica.cpp:320] Persisted replica status to VOTING
I0125 15:31:54.122750 31984 recover.cpp:578] Successfully joined the Paxos group
I0125 15:31:54.123332 31984 recover.cpp:462] Recover process terminated
I0125 15:31:54.123787 31994 log.cpp:659] Attempting to start the writer
I0125 15:31:54.125511 31987 replica.cpp:493] Replica received implicit promise request from (14157)@172.17.0.2:52355 with proposal 1
I0125 15:31:54.155309 31987 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 29.74374ms
I0125 15:31:54.155385 31987 replica.cpp:342] Persisted promised to 1
I0125 15:31:54.156337 31987 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0125 15:31:54.157927 31982 replica.cpp:388] Replica received explicit promise request from (14158)@172.17.0.2:52355 for position 0 with proposal 2
I0125 15:31:54.188997 31982 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 30.950597ms
I0125 15:31:54.189041 31982 replica.cpp:712] Persisted action at 0
I0125 15:31:54.191100 31991 replica.cpp:537] Replica received write request for position 0 from (14159)@172.17.0.2:52355
I0125 15:31:54.191232 31991 leveldb.cpp:436] Reading position from leveldb took 41457ns
I0125 15:31:54.231135 31991 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 39.831552ms
I0125 15:31:54.231209 31991 replica.cpp:712] Persisted action at 0
I0125 15:31:54.232348 31981 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0125 15:31:54.267117 31981 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 34.689577ms
I0125 15:31:54.267243 31981 replica.cpp:712] Persisted action at 0
I0125 15:31:54.267282 31981 replica.cpp:697] Replica learned NOP action at position 0
I0125 15:31:54.268566 31981 log.cpp:675] Writer started with ending position 0
I0125 15:31:54.270238 31981 leveldb.cpp:436] Reading position from leveldb took 61455ns
I0125 15:31:54.271752 31981 registrar.cpp:340] Successfully fetched the registry (0B) in 211.906048ms
I0125 15:31:54.272171 31981 registrar.cpp:439] Applied 1 operations in 67302ns; attempting to update the 'registry'
I0125 15:31:54.273457 31991 log.cpp:683] Attempting to append 170 bytes to the log
I0125 15:31:54.273764 31991 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0125 15:31:54.274986 31991 replica.cpp:537] Replica received write request for position 1 from (14160)@172.17.0.2:52355
I0125 15:31:54.304546 31991 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 29.510255ms
I0125 15:31:54.304596 31991 replica.cpp:712] Persisted action at 1
I0125 15:31:54.305603 31995 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0125 15:31:54.338044 31995 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.403673ms
I0125 15:31:54.338189 31995 replica.cpp:712] Persisted action at 1
I0125 15:31:54.338310 31995 replica.cpp:697] Replica learned APPEND action at position 1
I0125 15:31:54.340224 31995 registrar.cpp:484] Successfully updated the 'registry' in 67.756032ms
I0125 15:31:54.340562 31995 registrar.cpp:370] Successfully recovered registrar
I0125 15:31:54.340343 31981 log.cpp:702] Attempting to truncate the log to 1
I0125 15:31:54.341358 31992 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0125 15:31:54.341637 31992 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0125 15:31:54.341876 31981 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0125 15:31:54.343086 31984 replica.cpp:537] Replica received write request for position 2 from (14161)@172.17.0.2:52355
I0125 15:31:54.371588 31984 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 28.407207ms
I0125 15:31:54.371683 31984 replica.cpp:712] Persisted action at 2
I0125 15:31:54.372761 31988 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0125 15:31:54.401039 31988 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 28.21774ms
I0125 15:31:54.401218 31988 leveldb.cpp:399] Deleting ~1 keys from leveldb took 93808ns
I0125 15:31:54.401253 31988 replica.cpp:712] Persisted action at 2
I0125 15:31:54.401294 31988 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0125 15:31:54.404263 31962 scheduler.cpp:154] Version: 0.27.0
I0125 15:31:54.405225 31988 scheduler.cpp:236] New master detected at master@172.17.0.2:52355
I0125 15:31:54.406671 31986 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:52355
I0125 15:31:54.409914 31992 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0125 15:31:54.410778 31992 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:37622
I0125 15:31:54.411154 31992 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0125 15:31:54.411316 31992 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0125 15:31:54.411686 31992 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0125 15:31:54.412307 31992 master.hpp:1658] Sending heartbeat to a41bf879-36b6-4769-82c6-4220f6ecc603-0000
I0125 15:31:54.412309 31982 hierarchical.cpp:265] Added framework a41bf879-36b6-4769-82c6-4220f6ecc603-0000
I0125 15:31:54.412482 31982 hierarchical.cpp:1355] No resources available to allocate!
I0125 15:31:54.412521 31982 hierarchical.cpp:1450] No inverse offers to send out!
I0125 15:31:54.412550 31982 hierarchical.cpp:1090] Performed allocation for 0 slaves in 135344ns
I0125 15:31:54.414367 31986 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:52355
I0125 15:31:54.415199 31990 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:52355
I0125 15:31:54.415941 31990 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0125 15:31:54.416553 31991 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:52355
I0125 15:31:54.418658 31983 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0125 15:31:54.419219 31983 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:37623
I0125 15:31:54.419396 31983 master.cpp:2717] Processing REQUEST call for framework a41bf879-36b6-4769-82c6-4220f6ecc603-0000 (default)
I0125 15:31:54.419642 31985 hierarchical.cpp:585] Received resource request from framework a41bf879-36b6-4769-82c6-4220f6ecc603-0000
I0125 15:31:54.420088 31962 master.cpp:1025] Master terminating
I0125 15:31:54.420536 31982 hierarchical.cpp:326] Removed framework a41bf879-36b6-4769-82c6-4220f6ecc603-0000
E0125 15:31:54.422092 31984 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (555 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0125 15:31:54.628826 31962 leveldb.cpp:174] Opened db in 156.228813ms
I0125 15:31:54.691102 31962 leveldb.cpp:181] Compacted db in 62.199429ms
I0125 15:31:54.691582 31962 leveldb.cpp:196] Created db iterator in 23115ns
I0125 15:31:54.691715 31962 leveldb.cpp:202] Seeked to beginning of db in 3351ns
I0125 15:31:54.691836 31962 leveldb.cpp:271] Iterated through 0 keys in the db in 447ns
I0125 15:31:54.691990 31962 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0125 15:31:54.698237 31993 master.cpp:374] Master 534ad6a0-41c8-451f-a864-af4cc723c1f1 (6a3fa6c4588a) started on 172.17.0.2:52355
I0125 15:31:54.698278 31993 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/a9VAYj/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/a9VAYj/master" --zk_session_timeout="10secs"
I0125 15:31:54.698724 31993 master.cpp:423] Master allowing unauthenticated frameworks to register
I0125 15:31:54.698737 31993 master.cpp:426] Master only allowing authenticated slaves to register
I0125 15:31:54.698747 31993 credentials.hpp:35] Loading credentials for authentication from '/tmp/a9VAYj/credentials'
I0125 15:31:54.699280 31993 master.cpp:466] Using default 'crammd5' authenticator
I0125 15:31:54.699517 31993 master.cpp:535] Using default 'basic' HTTP authenticator
I0125 15:31:54.699681 31993 master.cpp:569] Authorization enabled
I0125 15:31:54.700637 31996 recover.cpp:447] Starting replica recovery
I0125 15:31:54.703264 31996 hierarchical.cpp:144] Initialized hierarchical allocator process
I0125 15:31:54.703402 31996 whitelist_watcher.cpp:77] No whitelist given
I0125 15:31:54.705231 31985 recover.cpp:473] Replica is in EMPTY status
I0125 15:31:54.708211 31994 master.cpp:1710] The newly elected leader is master@172.17.0.2:52355 with id 534ad6a0-41c8-451f-a864-af4cc723c1f1
I0125 15:31:54.708259 31994 master.cpp:1723] Elected as the leading master!
I0125 15:31:54.708284 31994 master.cpp:1468] Recovering from registrar
I0125 15:31:54.708586 31994 registrar.cpp:307] Recovering registrar
I0125 15:31:54.711406 31987 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14170)@172.17.0.2:52355
I0125 15:31:54.711874 31987 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0125 15:31:54.712570 31987 recover.cpp:564] Updating replica status to STARTING
I0125 15:31:54.759073 31987 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 45.444384ms
I0125 15:31:54.759220 31987 replica.cpp:320] Persisted replica status to STARTING
I0125 15:31:54.759579 31987 recover.cpp:473] Replica is in STARTING status
I0125 15:31:54.761481 31996 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14171)@172.17.0.2:52355
I0125 15:31:54.761909 31987 recover.cpp:193] Received a recover response from a replica in STARTING status
I0125 15:31:54.762668 31987 recover.cpp:564] Updating replica status to VOTING
I0125 15:31:54.786252 31987 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.380089ms
I0125 15:31:54.786440 31987 replica.cpp:320] Persisted replica status to VOTING
I0125 15:31:54.786736 31996 recover.cpp:578] Successfully joined the Paxos group
I0125 15:31:54.787066 31996 recover.cpp:462] Recover process terminated
I0125 15:31:54.787926 31991 log.cpp:659] Attempting to start the writer
I0125 15:31:54.789770 31994 replica.cpp:493] Replica received implicit promise request from (14172)@172.17.0.2:52355 with proposal 1
I0125 15:31:54.812048 31994 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.10006ms
I0125 15:31:54.812278 31994 replica.cpp:342] Persisted promised to 1
I0125 15:31:54.813483 31985 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0125 15:31:54.815243 31994 replica.cpp:388] Replica received explicit promise request from (14173)@172.17.0.2:52355 for position 0 with proposal 2
I0125 15:31:54.867024 31994 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 51.71959ms
I0125 15:31:54.867079 31994 replica.cpp:712] Persisted action at 0
I0125 15:31:54.868464 31990 replica.cpp:537] Replica received write request for position 0 from (14174)@172.17.0.2:52355
I0125 15:31:54.868600 31990 leveldb.cpp:436] Reading position from leveldb took 35464ns
I0125 15:31:54.934166 31990 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 65.421468ms
I0125 15:31:54.934221 31990 replica.cpp:712] Persisted action at 0
I0125 15:31:54.935314 31988 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0125 15:31:54.984663 31988 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 49.145216ms
I0125 15:31:54.984750 31988 replica.cpp:712] Persisted action at 0
I0125 15:31:54.984786 31988 replica.cpp:697] Replica learned NOP action at position 0
I0125 15:31:54.985885 31988 log.cpp:675] Writer started with ending position 0
I0125 15:31:54.987475 31988 leveldb.cpp:436] Reading position from leveldb took 54867ns
I0125 15:31:54.988917 31990 registrar.cpp:340] Successfully fetched the registry (0B) in 280.286976ms
I0125 15:31:54.989181 31990 registrar.cpp:439] Applied 1 operations in 82148ns; attempting to update the 'registry'
I0125 15:31:54.990272 31986 log.cpp:683] Attempting to append 170 bytes to the log
I0125 15:31:54.990396 31981 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0125 15:31:54.991430 31981 replica.cpp:537] Replica received write request for position 1 from (14175)@172.17.0.2:52355
I0125 15:31:55.026638 31981 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 35.168064ms
I0125 15:31:55.026679 31981 replica.cpp:712] Persisted action at 1
I0125 15:31:55.029295 31982 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0125 15:31:55.071430 31982 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 42.00698ms
I0125 15:31:55.071491 31982 replica.cpp:712] Persisted action at 1
I0125 15:31:55.071521 31982 replica.cpp:697] Replica learned APPEND action at position 1
I0125 15:31:55.073302 31982 registrar.cpp:484] Successfully updated the 'registry' in 84.050176ms
I0125 15:31:55.073321 31995 log.cpp:702] Attempting to truncate the log to 1
I0125 15:31:55.073575 31995 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0125 15:31:55.074652 31995 replica.cpp:537] Replica received write request for position 2 from (14176)@172.17.0.2:52355
I0125 15:31:55.074863 31982 registrar.cpp:370] Successfully recovered registrar
I0125 15:31:55.075283 31982 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0125 15:31:55.075455 31982 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
2016-01-25 15:31:55,096:31962(0x2abe2af7c700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:38887] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I0125 15:31:55.112395 31995 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 37.685723ms
I0125 15:31:55.112481 31995 replica.cpp:712] Persisted action at 2
I0125 15:31:55.113759 31995 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0125 15:31:55.137593 31995 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 23.795258ms
I0125 15:31:55.137698 31995 leveldb.cpp:399] Deleting ~1 keys from leveldb took 45651ns
I0125 15:31:55.137722 31995 replica.cpp:712] Persisted action at 2
I0125 15:31:55.137750 31995 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0125 15:31:55.146957 31962 scheduler.cpp:154] Version: 0.27.0
I0125 15:31:55.148099 31996 scheduler.cpp:236] New master detected at master@172.17.0.2:52355
I0125 15:31:55.149392 31996 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:52355
I0125 15:31:55.151747 31988 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0125 15:31:55.152426 31987 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:37625
I0125 15:31:55.152787 31987 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0125 15:31:55.152868 31987 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0125 15:31:55.153592 31990 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0125 15:31:55.154331 31990 hierarchical.cpp:265] Added framework 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000
I0125 15:31:55.154359 31991 master.hpp:1658] Sending heartbeat to 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000
I0125 15:31:55.154404 31990 hierarchical.cpp:1355] No resources available to allocate!
I0125 15:31:55.154434 31990 hierarchical.cpp:1450] No inverse offers to send out!
I0125 15:31:55.154459 31990 hierarchical.cpp:1090] Performed allocation for 0 slaves in 102693ns
I0125 15:31:55.156456 31990 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:52355
I0125 15:31:55.157753 31990 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:52355
I0125 15:31:55.158218 31990 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:52355
I0125 15:31:55.159273 31992 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0125 15:31:55.160440 31992 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0125 15:31:55.160969 31988 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:37626
I0125 15:31:55.161312 31988 master.cpp:2717] Processing REQUEST call for framework 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000 (default)
I0125 15:31:55.161464 31992 hierarchical.cpp:585] Received resource request from framework 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000
I0125 15:31:55.161980 31993 master.cpp:1025] Master terminating
I0125 15:31:55.162343 31982 hierarchical.cpp:326] Removed framework 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000
E0125 15:31:55.163547 31982 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (707 ms)
[----------] 22 tests from ContentType/SchedulerTest (16861 ms total)
[----------] Global test environment tear-down
[==========] 952 tests from 123 test cases ran. (759013 ms total)
[ PASSED ] 951 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] HealthCheckTest.HealthStatusChange
1 FAILED TEST
YOU HAVE 8 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make[1]: *** [check-recursive] Error 1
make: *** [distcheck] Error 1
+ docker rmi mesos-1453731992-29640
Untagged: mesos-1453731992-29640:latest
Deleted: bf1cf6862f5e8ebc3b2620bd5f9892ab74ecd8b032427b34e99846401d379c37
Deleted: 2dba3db3c355ef9f2af3ec1db4323d7148a7c56add8a7b09742b9ff0ec233314
Deleted: 8fe1de1c942fa379e3222bf750fb57145c77106b8c9f8838e162cf1f9acf2d1b
Deleted: 07683cbade061bd63980f45ffbe60e6a20b9cb72ebb807f9e89899d4429c0d19
Deleted: aca05c3484a3d58399546b66eaea6ea9728516b5d1880ad241c7707bf465ce9e
Deleted: 09641d8cc65cfdcf956c05ac080b7b33abe8039396646c5c664cec2f982412f4
Deleted: ceb4ada85723ffea8145c95ccaf5db09fa97d2e659876b40f691ab87771c3e1a
Deleted: 2432f9a1e40b2c88064e194165d0e5263fc2afbf9acf2c20e5c27eb520cd1ac9
Deleted: df23a73f74961797a6d50770bf7119580a4c79a2235324a286b5b50d34caae0c
Deleted: 6f30df9ea464f55a9e3d631346ac26fc57f6ebf734047436124fd6a60b65fb32
Deleted: 96598b7548ebd760c3d15af8efb6c75ac170fa35c2e02ef6021b5bae685278d5
Deleted: 5892a6e2afccc6c3310614c331495d2d1ad23d7093f9a3fa24381ecc92f18fb4
Deleted: 10bbd4cd1bc1e487d30a85a5d8828ec88160d6a407d81255d24ecea0cb0ea24f
Deleted: 655ccc5722bf9a44bbf7063808d0a3c8ac9afbc7f4f5c0a091b84f4532b7f47b
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins: Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #1544
Posted by Benjamin Mahler <bm...@apache.org>.
Hey Tim, are you planning to work on this? Or should we re-assign it?
On Mon, Jan 25, 2016 at 8:54 AM, Greg Mann <gr...@mesosphere.io> wrote:
> We have a ticket tracking this failure here:
> https://issues.apache.org/jira/browse/MESOS-1802
>
> On Mon, Jan 25, 2016 at 7:32 AM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
> > See <
> >
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1544/changes
> > >
> >
> > Changes:
> >
> > [toenshoff] Improved rakefile to allow for external .md file links.
> >
> > [toenshoff] Made links to .md files consistent across documentation.
> >
> > ------------------------------------------
> > [...truncated 164628 lines...]
> > I0125 15:31:53.907892 31995 gc.cpp:54] Scheduling
> >
> '/tmp/ContentType_SchedulerTest_Message_1_FH51HS/slaves/6e16d26e-80dd-4b46-b8b5-1f7aa9133d80-S0/frameworks/6e16d26e-80dd-4b46-b8b5-1f7aa9133d80-0000/executors/default'
> > for gc 6.9999895029037days in the future
> > I0125 15:31:53.908051 31995 gc.cpp:54] Scheduling
> >
> '/tmp/ContentType_SchedulerTest_Message_1_FH51HS/slaves/6e16d26e-80dd-4b46-b8b5-1f7aa9133d80-S0/frameworks/6e16d26e-80dd-4b46-b8b5-1f7aa9133d80-0000'
> > for gc 6.99998950096296days in the future
> > [ OK ] ContentType/SchedulerTest.Message/1 (795 ms)
> > [ RUN ] ContentType/SchedulerTest.Request/0
> > I0125 15:31:54.011689 31962 leveldb.cpp:174] Opened db in 95.027917ms
> > I0125 15:31:54.048696 31962 leveldb.cpp:181] Compacted db in 36.838022ms
> > I0125 15:31:54.049106 31962 leveldb.cpp:196] Created db iterator in
> 30240ns
> > I0125 15:31:54.049321 31962 leveldb.cpp:202] Seeked to beginning of db in
> > 8041ns
> > I0125 15:31:54.049427 31962 leveldb.cpp:271] Iterated through 0 keys in
> > the db in 480ns
> > I0125 15:31:54.049568 31962 replica.cpp:779] Replica recovered with log
> > positions 0 -> 0 with 1 holes and 0 unlearned
> > I0125 15:31:54.050299 31993 recover.cpp:447] Starting replica recovery
> > I0125 15:31:54.050555 31993 recover.cpp:473] Replica is in EMPTY status
> > I0125 15:31:54.052047 31983 replica.cpp:673] Replica in EMPTY status
> > received a broadcasted recover request from (14154)@172.17.0.2:52355
> > I0125 15:31:54.052635 31982 recover.cpp:193] Received a recover response
> > from a replica in EMPTY status
> > I0125 15:31:54.053282 31985 master.cpp:374] Master
> > a41bf879-36b6-4769-82c6-4220f6ecc603 (6a3fa6c4588a) started on
> > 172.17.0.2:52355
> > I0125 15:31:54.053308 31985 master.cpp:376] Flags at startup: --acls=""
> > --allocation_interval="1secs" --allocator="HierarchicalDRF"
> > --authenticate="false" --authenticate_http="true"
> > --authenticate_slaves="true" --authenticators="crammd5"
> > --authorizers="local" --credentials="/tmp/60pgVG/credentials"
> > --framework_sorter="drf" --help="false" --hostname_lookup="true"
> > --http_authenticators="basic" --initialize_driver_logging="true"
> > --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> > --max_completed_frameworks="50"
> --max_completed_tasks_per_framework="1000"
> > --max_slave_ping_timeouts="5" --quiet="false"
> > --recovery_slave_removal_limit="100%" --registry="replicated_log"
> > --registry_fetch_timeout="1mins" --registry_store_timeout="25secs"
> > --registry_strict="true" --root_submissions="true"
> > --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> > --user_sorter="drf" --version="false"
> > --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui"
> > --work_dir="/tmp/60pgVG/master" --zk_session_timeout="10secs"
> > I0125 15:31:54.053663 31985 master.cpp:423] Master allowing
> > unauthenticated frameworks to register
> > I0125 15:31:54.053680 31985 master.cpp:426] Master only allowing
> > authenticated slaves to register
> > I0125 15:31:54.053691 31985 credentials.hpp:35] Loading credentials for
> > authentication from '/tmp/60pgVG/credentials'
> > I0125 15:31:54.054059 31985 master.cpp:466] Using default 'crammd5'
> > authenticator
> > I0125 15:31:54.054276 31985 master.cpp:535] Using default 'basic' HTTP
> > authenticator
> > I0125 15:31:54.054428 31985 master.cpp:569] Authorization enabled
> > I0125 15:31:54.055181 31990 whitelist_watcher.cpp:77] No whitelist given
> > I0125 15:31:54.056215 31983 recover.cpp:564] Updating replica status to
> > STARTING
> > I0125 15:31:54.056524 31984 hierarchical.cpp:144] Initialized
> hierarchical
> > allocator process
> > I0125 15:31:54.059185 31983 master.cpp:1710] The newly elected leader is
> > master@172.17.0.2:52355 with id a41bf879-36b6-4769-82c6-4220f6ecc603
> > I0125 15:31:54.059321 31983 master.cpp:1723] Elected as the leading
> master!
> > I0125 15:31:54.059443 31983 master.cpp:1468] Recovering from registrar
> > I0125 15:31:54.059737 31981 registrar.cpp:307] Recovering registrar
> > I0125 15:31:54.087240 31987 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 30.864305ms
> > I0125 15:31:54.087321 31987 replica.cpp:320] Persisted replica status to
> > STARTING
> > I0125 15:31:54.087695 31983 recover.cpp:473] Replica is in STARTING
> status
> > I0125 15:31:54.089272 31982 replica.cpp:673] Replica in STARTING status
> > received a broadcasted recover request from (14156)@172.17.0.2:52355
> > I0125 15:31:54.090032 31984 recover.cpp:193] Received a recover response
> > from a replica in STARTING status
> > I0125 15:31:54.090538 31992 recover.cpp:564] Updating replica status to
> > VOTING
> > I0125 15:31:54.121637 31994 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 30.821991ms
> > I0125 15:31:54.122213 31994 replica.cpp:320] Persisted replica status to
> > VOTING
> > I0125 15:31:54.122750 31984 recover.cpp:578] Successfully joined the
> Paxos
> > group
> > I0125 15:31:54.123332 31984 recover.cpp:462] Recover process terminated
> > I0125 15:31:54.123787 31994 log.cpp:659] Attempting to start the writer
> > I0125 15:31:54.125511 31987 replica.cpp:493] Replica received implicit
> > promise request from (14157)@172.17.0.2:52355 with proposal 1
> > I0125 15:31:54.155309 31987 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 29.74374ms
> > I0125 15:31:54.155385 31987 replica.cpp:342] Persisted promised to 1
> > I0125 15:31:54.156337 31987 coordinator.cpp:238] Coordinator attempting
> to
> > fill missing positions
> > I0125 15:31:54.157927 31982 replica.cpp:388] Replica received explicit
> > promise request from (14158)@172.17.0.2:52355 for position 0 with
> > proposal 2
> > I0125 15:31:54.188997 31982 leveldb.cpp:341] Persisting action (8 bytes)
> > to leveldb took 30.950597ms
> > I0125 15:31:54.189041 31982 replica.cpp:712] Persisted action at 0
> > I0125 15:31:54.191100 31991 replica.cpp:537] Replica received write
> > request for position 0 from (14159)@172.17.0.2:52355
> > I0125 15:31:54.191232 31991 leveldb.cpp:436] Reading position from
> > leveldb took 41457ns
> > I0125 15:31:54.231135 31991 leveldb.cpp:341] Persisting action (14 bytes)
> > to leveldb took 39.831552ms
> > I0125 15:31:54.231209 31991 replica.cpp:712] Persisted action at 0
> > I0125 15:31:54.232348 31981 replica.cpp:691] Replica received learned
> > notice for position 0 from @0.0.0.0:0
> > I0125 15:31:54.267117 31981 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 34.689577ms
> > I0125 15:31:54.267243 31981 replica.cpp:712] Persisted action at 0
> > I0125 15:31:54.267282 31981 replica.cpp:697] Replica learned NOP action
> at
> > position 0
> > I0125 15:31:54.268566 31981 log.cpp:675] Writer started with ending
> > position 0
> > I0125 15:31:54.270238 31981 leveldb.cpp:436] Reading position from
> leveldb
> > took 61455ns
> > I0125 15:31:54.271752 31981 registrar.cpp:340] Successfully fetched the
> > registry (0B) in 211.906048ms
> > I0125 15:31:54.272171 31981 registrar.cpp:439] Applied 1 operations in
> > 67302ns; attempting to update the 'registry'
> > I0125 15:31:54.273457 31991 log.cpp:683] Attempting to append 170 bytes
> to
> > the log
> > I0125 15:31:54.273764 31991 coordinator.cpp:348] Coordinator attempting
> to
> > write APPEND action at position 1
> > I0125 15:31:54.274986 31991 replica.cpp:537] Replica received write
> > request for position 1 from (14160)@172.17.0.2:52355
> > I0125 15:31:54.304546 31991 leveldb.cpp:341] Persisting action (189
> bytes)
> > to leveldb took 29.510255ms
> > I0125 15:31:54.304596 31991 replica.cpp:712] Persisted action at 1
> > I0125 15:31:54.305603 31995 replica.cpp:691] Replica received learned
> > notice for position 1 from @0.0.0.0:0
> > I0125 15:31:54.338044 31995 leveldb.cpp:341] Persisting action (191
> bytes)
> > to leveldb took 32.403673ms
> > I0125 15:31:54.338189 31995 replica.cpp:712] Persisted action at 1
> > I0125 15:31:54.338310 31995 replica.cpp:697] Replica learned APPEND
> action
> > at position 1
> > I0125 15:31:54.340224 31995 registrar.cpp:484] Successfully updated the
> > 'registry' in 67.756032ms
> > I0125 15:31:54.340562 31995 registrar.cpp:370] Successfully recovered
> > registrar
> > I0125 15:31:54.340343 31981 log.cpp:702] Attempting to truncate the log
> to
> > 1
> > I0125 15:31:54.341358 31992 master.cpp:1520] Recovered 0 slaves from the
> > Registry (131B) ; allowing 10mins for slaves to re-register
> > I0125 15:31:54.341637 31992 hierarchical.cpp:171] Skipping recovery of
> > hierarchical allocator: nothing to recover
> > I0125 15:31:54.341876 31981 coordinator.cpp:348] Coordinator attempting
> to
> > write TRUNCATE action at position 2
> > I0125 15:31:54.343086 31984 replica.cpp:537] Replica received write
> > request for position 2 from (14161)@172.17.0.2:52355
> > I0125 15:31:54.371588 31984 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 28.407207ms
> > I0125 15:31:54.371683 31984 replica.cpp:712] Persisted action at 2
> > I0125 15:31:54.372761 31988 replica.cpp:691] Replica received learned
> > notice for position 2 from @0.0.0.0:0
> > I0125 15:31:54.401039 31988 leveldb.cpp:341] Persisting action (18 bytes)
> > to leveldb took 28.21774ms
> > I0125 15:31:54.401218 31988 leveldb.cpp:399] Deleting ~1 keys from
> leveldb
> > took 93808ns
> > I0125 15:31:54.401253 31988 replica.cpp:712] Persisted action at 2
> > I0125 15:31:54.401294 31988 replica.cpp:697] Replica learned TRUNCATE
> > action at position 2
> > I0125 15:31:54.404263 31962 scheduler.cpp:154] Version: 0.27.0
> > I0125 15:31:54.405225 31988 scheduler.cpp:236] New master detected at
> > master@172.17.0.2:52355
> > I0125 15:31:54.406671 31986 scheduler.cpp:298] Sending SUBSCRIBE call to
> > master@172.17.0.2:52355
> > I0125 15:31:54.409914 31992 process.cpp:3141] Handling HTTP event for
> > process 'master' with path: '/master/api/v1/scheduler'
> > I0125 15:31:54.410778 31992 http.cpp:503] HTTP POST for
> > /master/api/v1/scheduler from 172.17.0.2:37622
> > I0125 15:31:54.411154 31992 master.cpp:1972] Received subscription
> request
> > for HTTP framework 'default'
> > I0125 15:31:54.411316 31992 master.cpp:1749] Authorizing framework
> > principal 'test-principal' to receive offers for role '*'
> > I0125 15:31:54.411686 31992 master.cpp:2063] Subscribing framework
> > 'default' with checkpointing disabled and capabilities [ ]
> > I0125 15:31:54.412307 31992 master.hpp:1658] Sending heartbeat to
> > a41bf879-36b6-4769-82c6-4220f6ecc603-0000
> > I0125 15:31:54.412309 31982 hierarchical.cpp:265] Added framework
> > a41bf879-36b6-4769-82c6-4220f6ecc603-0000
> > I0125 15:31:54.412482 31982 hierarchical.cpp:1355] No resources available
> > to allocate!
> > I0125 15:31:54.412521 31982 hierarchical.cpp:1450] No inverse offers to
> > send out!
> > I0125 15:31:54.412550 31982 hierarchical.cpp:1090] Performed allocation
> > for 0 slaves in 135344ns
> > I0125 15:31:54.414367 31986 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> > received from master@172.17.0.2:52355
> > I0125 15:31:54.415199 31990 scheduler.cpp:457] Enqueuing event HEARTBEAT
> > received from master@172.17.0.2:52355
> > I0125 15:31:54.415941 31990 master_maintenance_tests.cpp:177] Ignoring
> > HEARTBEAT event
> > I0125 15:31:54.416553 31991 scheduler.cpp:298] Sending REQUEST call to
> > master@172.17.0.2:52355
> > I0125 15:31:54.418658 31983 process.cpp:3141] Handling HTTP event for
> > process 'master' with path: '/master/api/v1/scheduler'
> > I0125 15:31:54.419219 31983 http.cpp:503] HTTP POST for
> > /master/api/v1/scheduler from 172.17.0.2:37623
> > I0125 15:31:54.419396 31983 master.cpp:2717] Processing REQUEST call for
> > framework a41bf879-36b6-4769-82c6-4220f6ecc603-0000 (default)
> > I0125 15:31:54.419642 31985 hierarchical.cpp:585] Received resource
> > request from framework a41bf879-36b6-4769-82c6-4220f6ecc603-0000
> > I0125 15:31:54.420088 31962 master.cpp:1025] Master terminating
> > I0125 15:31:54.420536 31982 hierarchical.cpp:326] Removed framework
> > a41bf879-36b6-4769-82c6-4220f6ecc603-0000
> > E0125 15:31:54.422092 31984 scheduler.cpp:431] End-Of-File received from
> > master. The master closed the event stream
> > [ OK ] ContentType/SchedulerTest.Request/0 (555 ms)
> > [ RUN ] ContentType/SchedulerTest.Request/1
> > I0125 15:31:54.628826 31962 leveldb.cpp:174] Opened db in 156.228813ms
> > I0125 15:31:54.691102 31962 leveldb.cpp:181] Compacted db in 62.199429ms
> > I0125 15:31:54.691582 31962 leveldb.cpp:196] Created db iterator in
> 23115ns
> > I0125 15:31:54.691715 31962 leveldb.cpp:202] Seeked to beginning of db in
> > 3351ns
> > I0125 15:31:54.691836 31962 leveldb.cpp:271] Iterated through 0 keys in
> > the db in 447ns
> > I0125 15:31:54.691990 31962 replica.cpp:779] Replica recovered with log
> > positions 0 -> 0 with 1 holes and 0 unlearned
> > I0125 15:31:54.698237 31993 master.cpp:374] Master
> > 534ad6a0-41c8-451f-a864-af4cc723c1f1 (6a3fa6c4588a) started on
> > 172.17.0.2:52355
> > I0125 15:31:54.698278 31993 master.cpp:376] Flags at startup: --acls=""
> > --allocation_interval="1secs" --allocator="HierarchicalDRF"
> > --authenticate="false" --authenticate_http="true"
> > --authenticate_slaves="true" --authenticators="crammd5"
> > --authorizers="local" --credentials="/tmp/a9VAYj/credentials"
> > --framework_sorter="drf" --help="false" --hostname_lookup="true"
> > --http_authenticators="basic" --initialize_driver_logging="true"
> > --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> > --max_completed_frameworks="50"
> --max_completed_tasks_per_framework="1000"
> > --max_slave_ping_timeouts="5" --quiet="false"
> > --recovery_slave_removal_limit="100%" --registry="replicated_log"
> > --registry_fetch_timeout="1mins" --registry_store_timeout="25secs"
> > --registry_strict="true" --root_submissions="true"
> > --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> > --user_sorter="drf" --version="false"
> > --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui"
> > --work_dir="/tmp/a9VAYj/master" --zk_session_timeout="10secs"
> > I0125 15:31:54.698724 31993 master.cpp:423] Master allowing
> > unauthenticated frameworks to register
> > I0125 15:31:54.698737 31993 master.cpp:426] Master only allowing
> > authenticated slaves to register
> > I0125 15:31:54.698747 31993 credentials.hpp:35] Loading credentials for
> > authentication from '/tmp/a9VAYj/credentials'
> > I0125 15:31:54.699280 31993 master.cpp:466] Using default 'crammd5'
> > authenticator
> > I0125 15:31:54.699517 31993 master.cpp:535] Using default 'basic' HTTP
> > authenticator
> > I0125 15:31:54.699681 31993 master.cpp:569] Authorization enabled
> > I0125 15:31:54.700637 31996 recover.cpp:447] Starting replica recovery
> > I0125 15:31:54.703264 31996 hierarchical.cpp:144] Initialized
> hierarchical
> > allocator process
> > I0125 15:31:54.703402 31996 whitelist_watcher.cpp:77] No whitelist given
> > I0125 15:31:54.705231 31985 recover.cpp:473] Replica is in EMPTY status
> > I0125 15:31:54.708211 31994 master.cpp:1710] The newly elected leader is
> > master@172.17.0.2:52355 with id 534ad6a0-41c8-451f-a864-af4cc723c1f1
> > I0125 15:31:54.708259 31994 master.cpp:1723] Elected as the leading
> master!
> > I0125 15:31:54.708284 31994 master.cpp:1468] Recovering from registrar
> > I0125 15:31:54.708586 31994 registrar.cpp:307] Recovering registrar
> > I0125 15:31:54.711406 31987 replica.cpp:673] Replica in EMPTY status
> > received a broadcasted recover request from (14170)@172.17.0.2:52355
> > I0125 15:31:54.711874 31987 recover.cpp:193] Received a recover response
> > from a replica in EMPTY status
> > I0125 15:31:54.712570 31987 recover.cpp:564] Updating replica status to
> > STARTING
> > I0125 15:31:54.759073 31987 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 45.444384ms
> > I0125 15:31:54.759220 31987 replica.cpp:320] Persisted replica status to
> > STARTING
> > I0125 15:31:54.759579 31987 recover.cpp:473] Replica is in STARTING
> status
> > I0125 15:31:54.761481 31996 replica.cpp:673] Replica in STARTING status
> > received a broadcasted recover request from (14171)@172.17.0.2:52355
> > I0125 15:31:54.761909 31987 recover.cpp:193] Received a recover response
> > from a replica in STARTING status
> > I0125 15:31:54.762668 31987 recover.cpp:564] Updating replica status to
> > VOTING
> > I0125 15:31:54.786252 31987 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 23.380089ms
> > I0125 15:31:54.786440 31987 replica.cpp:320] Persisted replica status to
> > VOTING
> > I0125 15:31:54.786736 31996 recover.cpp:578] Successfully joined the
> Paxos
> > group
> > I0125 15:31:54.787066 31996 recover.cpp:462] Recover process terminated
> > I0125 15:31:54.787926 31991 log.cpp:659] Attempting to start the writer
> > I0125 15:31:54.789770 31994 replica.cpp:493] Replica received implicit
> > promise request from (14172)@172.17.0.2:52355 with proposal 1
> > I0125 15:31:54.812048 31994 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 22.10006ms
> > I0125 15:31:54.812278 31994 replica.cpp:342] Persisted promised to 1
> > I0125 15:31:54.813483 31985 coordinator.cpp:238] Coordinator attempting
> to
> > fill missing positions
> > I0125 15:31:54.815243 31994 replica.cpp:388] Replica received explicit
> > promise request from (14173)@172.17.0.2:52355 for position 0 with
> > proposal 2
> > I0125 15:31:54.867024 31994 leveldb.cpp:341] Persisting action (8 bytes)
> > to leveldb took 51.71959ms
> > I0125 15:31:54.867079 31994 replica.cpp:712] Persisted action at 0
> > I0125 15:31:54.868464 31990 replica.cpp:537] Replica received write
> > request for position 0 from (14174)@172.17.0.2:52355
> > I0125 15:31:54.868600 31990 leveldb.cpp:436] Reading position from
> leveldb
> > took 35464ns
> > I0125 15:31:54.934166 31990 leveldb.cpp:341] Persisting action (14 bytes)
> > to leveldb took 65.421468ms
> > I0125 15:31:54.934221 31990 replica.cpp:712] Persisted action at 0
> > I0125 15:31:54.935314 31988 replica.cpp:691] Replica received learned
> > notice for position 0 from @0.0.0.0:0
> > I0125 15:31:54.984663 31988 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 49.145216ms
> > I0125 15:31:54.984750 31988 replica.cpp:712] Persisted action at 0
> > I0125 15:31:54.984786 31988 replica.cpp:697] Replica learned NOP action
> at
> > position 0
> > I0125 15:31:54.985885 31988 log.cpp:675] Writer started with ending
> > position 0
> > I0125 15:31:54.987475 31988 leveldb.cpp:436] Reading position from
> leveldb
> > took 54867ns
> > I0125 15:31:54.988917 31990 registrar.cpp:340] Successfully fetched the
> > registry (0B) in 280.286976ms
> > I0125 15:31:54.989181 31990 registrar.cpp:439] Applied 1 operations in
> > 82148ns; attempting to update the 'registry'
> > I0125 15:31:54.990272 31986 log.cpp:683] Attempting to append 170 bytes
> to
> > the log
> > I0125 15:31:54.990396 31981 coordinator.cpp:348] Coordinator attempting
> to
> > write APPEND action at position 1
> > I0125 15:31:54.991430 31981 replica.cpp:537] Replica received write
> > request for position 1 from (14175)@172.17.0.2:52355
> > I0125 15:31:55.026638 31981 leveldb.cpp:341] Persisting action (189
> bytes)
> > to leveldb took 35.168064ms
> > I0125 15:31:55.026679 31981 replica.cpp:712] Persisted action at 1
> > I0125 15:31:55.029295 31982 replica.cpp:691] Replica received learned
> > notice for position 1 from @0.0.0.0:0
> > I0125 15:31:55.071430 31982 leveldb.cpp:341] Persisting action (191
> bytes)
> > to leveldb took 42.00698ms
> > I0125 15:31:55.071491 31982 replica.cpp:712] Persisted action at 1
> > I0125 15:31:55.071521 31982 replica.cpp:697] Replica learned APPEND
> action
> > at position 1
> > I0125 15:31:55.073302 31982 registrar.cpp:484] Successfully updated the
> > 'registry' in 84.050176ms
> > I0125 15:31:55.073321 31995 log.cpp:702] Attempting to truncate the log
> to
> > 1
> > I0125 15:31:55.073575 31995 coordinator.cpp:348] Coordinator attempting
> to
> > write TRUNCATE action at position 2
> > I0125 15:31:55.074652 31995 replica.cpp:537] Replica received write
> > request for position 2 from (14176)@172.17.0.2:52355
> > I0125 15:31:55.074863 31982 registrar.cpp:370] Successfully recovered
> > registrar
> > I0125 15:31:55.075283 31982 master.cpp:1520] Recovered 0 slaves from the
> > Registry (131B) ; allowing 10mins for slaves to re-register
> > I0125 15:31:55.075455 31982 hierarchical.cpp:171] Skipping recovery of
> > hierarchical allocator: nothing to recover
> > 2016-01-25
> > 15:31:55,096:31962(0x2abe2af7c700):ZOO_ERROR@handle_socket_error_msg
> @1697:
> > Socket [127.0.0.1:38887] zk retcode=-4, errno=111(Connection refused):
> > server refused to accept the client
> > I0125 15:31:55.112395 31995 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 37.685723ms
> > I0125 15:31:55.112481 31995 replica.cpp:712] Persisted action at 2
> > I0125 15:31:55.113759 31995 replica.cpp:691] Replica received learned
> > notice for position 2 from @0.0.0.0:0
> > I0125 15:31:55.137593 31995 leveldb.cpp:341] Persisting action (18 bytes)
> > to leveldb took 23.795258ms
> > I0125 15:31:55.137698 31995 leveldb.cpp:399] Deleting ~1 keys from
> leveldb
> > took 45651ns
> > I0125 15:31:55.137722 31995 replica.cpp:712] Persisted action at 2
> > I0125 15:31:55.137750 31995 replica.cpp:697] Replica learned TRUNCATE
> > action at position 2
> > I0125 15:31:55.146957 31962 scheduler.cpp:154] Version: 0.27.0
> > I0125 15:31:55.148099 31996 scheduler.cpp:236] New master detected at
> > master@172.17.0.2:52355
> > I0125 15:31:55.149392 31996 scheduler.cpp:298] Sending SUBSCRIBE call to
> > master@172.17.0.2:52355
> > I0125 15:31:55.151747 31988 process.cpp:3141] Handling HTTP event for
> > process 'master' with path: '/master/api/v1/scheduler'
> > I0125 15:31:55.152426 31987 http.cpp:503] HTTP POST for
> > /master/api/v1/scheduler from 172.17.0.2:37625
> > I0125 15:31:55.152787 31987 master.cpp:1972] Received subscription
> request
> > for HTTP framework 'default'
> > I0125 15:31:55.152868 31987 master.cpp:1749] Authorizing framework
> > principal 'test-principal' to receive offers for role '*'
> > I0125 15:31:55.153592 31990 master.cpp:2063] Subscribing framework
> > 'default' with checkpointing disabled and capabilities [ ]
> > I0125 15:31:55.154331 31990 hierarchical.cpp:265] Added framework
> > 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000
> > I0125 15:31:55.154359 31991 master.hpp:1658] Sending heartbeat to
> > 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000
> > I0125 15:31:55.154404 31990 hierarchical.cpp:1355] No resources available
> > to allocate!
> > I0125 15:31:55.154434 31990 hierarchical.cpp:1450] No inverse offers to
> > send out!
> > I0125 15:31:55.154459 31990 hierarchical.cpp:1090] Performed allocation
> > for 0 slaves in 102693ns
> > I0125 15:31:55.156456 31990 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> > received from master@172.17.0.2:52355
> > I0125 15:31:55.157753 31990 scheduler.cpp:457] Enqueuing event HEARTBEAT
> > received from master@172.17.0.2:52355
> > I0125 15:31:55.158218 31990 scheduler.cpp:298] Sending REQUEST call to
> > master@172.17.0.2:52355
> > I0125 15:31:55.159273 31992 master_maintenance_tests.cpp:177] Ignoring
> > HEARTBEAT event
> > I0125 15:31:55.160440 31992 process.cpp:3141] Handling HTTP event for
> > process 'master' with path: '/master/api/v1/scheduler'
> > I0125 15:31:55.160969 31988 http.cpp:503] HTTP POST for
> > /master/api/v1/scheduler from 172.17.0.2:37626
> > I0125 15:31:55.161312 31988 master.cpp:2717] Processing REQUEST call for
> > framework 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000 (default)
> > I0125 15:31:55.161464 31992 hierarchical.cpp:585] Received resource
> > request from framework 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000
> > I0125 15:31:55.161980 31993 master.cpp:1025] Master terminating
> > I0125 15:31:55.162343 31982 hierarchical.cpp:326] Removed framework
> > 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000
> > E0125 15:31:55.163547 31982 scheduler.cpp:431] End-Of-File received from
> > master. The master closed the event stream
> > [ OK ] ContentType/SchedulerTest.Request/1 (707 ms)
> > [----------] 22 tests from ContentType/SchedulerTest (16861 ms total)
> >
> > [----------] Global test environment tear-down
> > [==========] 952 tests from 123 test cases ran. (759013 ms total)
> > [ PASSED ] 951 tests.
> > [ FAILED ] 1 test, listed below:
> > [ FAILED ] HealthCheckTest.HealthStatusChange
> >
> > 1 FAILED TEST
> > YOU HAVE 8 DISABLED TESTS
> >
> > make[4]: *** [check-local] Error 1
> > make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> > make[3]: *** [check-am] Error 2
> > make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> > make[2]: *** [check] Error 2
> > make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> > make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
> > make[1]: *** [check-recursive] Error 1
> > make: *** [distcheck] Error 1
> > + docker rmi mesos-1453731992-29640
> > Untagged: mesos-1453731992-29640:latest
> > Deleted: bf1cf6862f5e8ebc3b2620bd5f9892ab74ecd8b032427b34e99846401d379c37
> > Deleted: 2dba3db3c355ef9f2af3ec1db4323d7148a7c56add8a7b09742b9ff0ec233314
> > Deleted: 8fe1de1c942fa379e3222bf750fb57145c77106b8c9f8838e162cf1f9acf2d1b
> > Deleted: 07683cbade061bd63980f45ffbe60e6a20b9cb72ebb807f9e89899d4429c0d19
> > Deleted: aca05c3484a3d58399546b66eaea6ea9728516b5d1880ad241c7707bf465ce9e
> > Deleted: 09641d8cc65cfdcf956c05ac080b7b33abe8039396646c5c664cec2f982412f4
> > Deleted: ceb4ada85723ffea8145c95ccaf5db09fa97d2e659876b40f691ab87771c3e1a
> > Deleted: 2432f9a1e40b2c88064e194165d0e5263fc2afbf9acf2c20e5c27eb520cd1ac9
> > Deleted: df23a73f74961797a6d50770bf7119580a4c79a2235324a286b5b50d34caae0c
> > Deleted: 6f30df9ea464f55a9e3d631346ac26fc57f6ebf734047436124fd6a60b65fb32
> > Deleted: 96598b7548ebd760c3d15af8efb6c75ac170fa35c2e02ef6021b5bae685278d5
> > Deleted: 5892a6e2afccc6c3310614c331495d2d1ad23d7093f9a3fa24381ecc92f18fb4
> > Deleted: 10bbd4cd1bc1e487d30a85a5d8828ec88160d6a407d81255d24ecea0cb0ea24f
> > Deleted: 655ccc5722bf9a44bbf7063808d0a3c8ac9afbc7f4f5c0a091b84f4532b7f47b
> > Build step 'Execute shell' marked build as failure
> >
>
Re: Build failed in Jenkins: Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #1544
Posted by Greg Mann <gr...@mesosphere.io>.
We have a ticket tracking this failure here:
https://issues.apache.org/jira/browse/MESOS-1802
On Mon, Jan 25, 2016 at 7:32 AM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1544/changes
> >
>
> Changes:
>
> [toenshoff] Improved rakefile to allow for external .md file links.
>
> [toenshoff] Made links to .md files consistent across documentation.
>
> ------------------------------------------
> [...truncated 164628 lines...]
> I0125 15:31:53.907892 31995 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_FH51HS/slaves/6e16d26e-80dd-4b46-b8b5-1f7aa9133d80-S0/frameworks/6e16d26e-80dd-4b46-b8b5-1f7aa9133d80-0000/executors/default'
> for gc 6.9999895029037days in the future
> I0125 15:31:53.908051 31995 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_FH51HS/slaves/6e16d26e-80dd-4b46-b8b5-1f7aa9133d80-S0/frameworks/6e16d26e-80dd-4b46-b8b5-1f7aa9133d80-0000'
> for gc 6.99998950096296days in the future
> [ OK ] ContentType/SchedulerTest.Message/1 (795 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> I0125 15:31:54.011689 31962 leveldb.cpp:174] Opened db in 95.027917ms
> I0125 15:31:54.048696 31962 leveldb.cpp:181] Compacted db in 36.838022ms
> I0125 15:31:54.049106 31962 leveldb.cpp:196] Created db iterator in 30240ns
> I0125 15:31:54.049321 31962 leveldb.cpp:202] Seeked to beginning of db in
> 8041ns
> I0125 15:31:54.049427 31962 leveldb.cpp:271] Iterated through 0 keys in
> the db in 480ns
> I0125 15:31:54.049568 31962 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0125 15:31:54.050299 31993 recover.cpp:447] Starting replica recovery
> I0125 15:31:54.050555 31993 recover.cpp:473] Replica is in EMPTY status
> I0125 15:31:54.052047 31983 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (14154)@172.17.0.2:52355
> I0125 15:31:54.052635 31982 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0125 15:31:54.053282 31985 master.cpp:374] Master
> a41bf879-36b6-4769-82c6-4220f6ecc603 (6a3fa6c4588a) started on
> 172.17.0.2:52355
> I0125 15:31:54.053308 31985 master.cpp:376] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/60pgVG/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="25secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui"
> --work_dir="/tmp/60pgVG/master" --zk_session_timeout="10secs"
> I0125 15:31:54.053663 31985 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0125 15:31:54.053680 31985 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0125 15:31:54.053691 31985 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/60pgVG/credentials'
> I0125 15:31:54.054059 31985 master.cpp:466] Using default 'crammd5'
> authenticator
> I0125 15:31:54.054276 31985 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0125 15:31:54.054428 31985 master.cpp:569] Authorization enabled
> I0125 15:31:54.055181 31990 whitelist_watcher.cpp:77] No whitelist given
> I0125 15:31:54.056215 31983 recover.cpp:564] Updating replica status to
> STARTING
> I0125 15:31:54.056524 31984 hierarchical.cpp:144] Initialized hierarchical
> allocator process
> I0125 15:31:54.059185 31983 master.cpp:1710] The newly elected leader is
> master@172.17.0.2:52355 with id a41bf879-36b6-4769-82c6-4220f6ecc603
> I0125 15:31:54.059321 31983 master.cpp:1723] Elected as the leading master!
> I0125 15:31:54.059443 31983 master.cpp:1468] Recovering from registrar
> I0125 15:31:54.059737 31981 registrar.cpp:307] Recovering registrar
> I0125 15:31:54.087240 31987 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 30.864305ms
> I0125 15:31:54.087321 31987 replica.cpp:320] Persisted replica status to
> STARTING
> I0125 15:31:54.087695 31983 recover.cpp:473] Replica is in STARTING status
> I0125 15:31:54.089272 31982 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (14156)@172.17.0.2:52355
> I0125 15:31:54.090032 31984 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0125 15:31:54.090538 31992 recover.cpp:564] Updating replica status to
> VOTING
> I0125 15:31:54.121637 31994 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 30.821991ms
> I0125 15:31:54.122213 31994 replica.cpp:320] Persisted replica status to
> VOTING
> I0125 15:31:54.122750 31984 recover.cpp:578] Successfully joined the Paxos
> group
> I0125 15:31:54.123332 31984 recover.cpp:462] Recover process terminated
> I0125 15:31:54.123787 31994 log.cpp:659] Attempting to start the writer
> I0125 15:31:54.125511 31987 replica.cpp:493] Replica received implicit
> promise request from (14157)@172.17.0.2:52355 with proposal 1
> I0125 15:31:54.155309 31987 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 29.74374ms
> I0125 15:31:54.155385 31987 replica.cpp:342] Persisted promised to 1
> I0125 15:31:54.156337 31987 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0125 15:31:54.157927 31982 replica.cpp:388] Replica received explicit
> promise request from (14158)@172.17.0.2:52355 for position 0 with
> proposal 2
> I0125 15:31:54.188997 31982 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 30.950597ms
> I0125 15:31:54.189041 31982 replica.cpp:712] Persisted action at 0
> I0125 15:31:54.191100 31991 replica.cpp:537] Replica received write
> request for position 0 from (14159)@172.17.0.2:52355
> I0125 15:31:54.191232 31991 leveldb.cpp:436] Reading position from
> leveldb took 41457ns
> I0125 15:31:54.231135 31991 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 39.831552ms
> I0125 15:31:54.231209 31991 replica.cpp:712] Persisted action at 0
> I0125 15:31:54.232348 31981 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0125 15:31:54.267117 31981 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 34.689577ms
> I0125 15:31:54.267243 31981 replica.cpp:712] Persisted action at 0
> I0125 15:31:54.267282 31981 replica.cpp:697] Replica learned NOP action at
> position 0
> I0125 15:31:54.268566 31981 log.cpp:675] Writer started with ending
> position 0
> I0125 15:31:54.270238 31981 leveldb.cpp:436] Reading position from leveldb
> took 61455ns
> I0125 15:31:54.271752 31981 registrar.cpp:340] Successfully fetched the
> registry (0B) in 211.906048ms
> I0125 15:31:54.272171 31981 registrar.cpp:439] Applied 1 operations in
> 67302ns; attempting to update the 'registry'
> I0125 15:31:54.273457 31991 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0125 15:31:54.273764 31991 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0125 15:31:54.274986 31991 replica.cpp:537] Replica received write
> request for position 1 from (14160)@172.17.0.2:52355
> I0125 15:31:54.304546 31991 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 29.510255ms
> I0125 15:31:54.304596 31991 replica.cpp:712] Persisted action at 1
> I0125 15:31:54.305603 31995 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0125 15:31:54.338044 31995 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 32.403673ms
> I0125 15:31:54.338189 31995 replica.cpp:712] Persisted action at 1
> I0125 15:31:54.338310 31995 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0125 15:31:54.340224 31995 registrar.cpp:484] Successfully updated the
> 'registry' in 67.756032ms
> I0125 15:31:54.340562 31995 registrar.cpp:370] Successfully recovered
> registrar
> I0125 15:31:54.340343 31981 log.cpp:702] Attempting to truncate the log to
> 1
> I0125 15:31:54.341358 31992 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0125 15:31:54.341637 31992 hierarchical.cpp:171] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0125 15:31:54.341876 31981 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0125 15:31:54.343086 31984 replica.cpp:537] Replica received write
> request for position 2 from (14161)@172.17.0.2:52355
> I0125 15:31:54.371588 31984 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 28.407207ms
> I0125 15:31:54.371683 31984 replica.cpp:712] Persisted action at 2
> I0125 15:31:54.372761 31988 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0125 15:31:54.401039 31988 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 28.21774ms
> I0125 15:31:54.401218 31988 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 93808ns
> I0125 15:31:54.401253 31988 replica.cpp:712] Persisted action at 2
> I0125 15:31:54.401294 31988 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0125 15:31:54.404263 31962 scheduler.cpp:154] Version: 0.27.0
> I0125 15:31:54.405225 31988 scheduler.cpp:236] New master detected at
> master@172.17.0.2:52355
> I0125 15:31:54.406671 31986 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.2:52355
> I0125 15:31:54.409914 31992 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0125 15:31:54.410778 31992 http.cpp:503] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:37622
> I0125 15:31:54.411154 31992 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0125 15:31:54.411316 31992 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0125 15:31:54.411686 31992 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0125 15:31:54.412307 31992 master.hpp:1658] Sending heartbeat to
> a41bf879-36b6-4769-82c6-4220f6ecc603-0000
> I0125 15:31:54.412309 31982 hierarchical.cpp:265] Added framework
> a41bf879-36b6-4769-82c6-4220f6ecc603-0000
> I0125 15:31:54.412482 31982 hierarchical.cpp:1355] No resources available
> to allocate!
> I0125 15:31:54.412521 31982 hierarchical.cpp:1450] No inverse offers to
> send out!
> I0125 15:31:54.412550 31982 hierarchical.cpp:1090] Performed allocation
> for 0 slaves in 135344ns
> I0125 15:31:54.414367 31986 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.2:52355
> I0125 15:31:54.415199 31990 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.2:52355
> I0125 15:31:54.415941 31990 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0125 15:31:54.416553 31991 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.2:52355
> I0125 15:31:54.418658 31983 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0125 15:31:54.419219 31983 http.cpp:503] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:37623
> I0125 15:31:54.419396 31983 master.cpp:2717] Processing REQUEST call for
> framework a41bf879-36b6-4769-82c6-4220f6ecc603-0000 (default)
> I0125 15:31:54.419642 31985 hierarchical.cpp:585] Received resource
> request from framework a41bf879-36b6-4769-82c6-4220f6ecc603-0000
> I0125 15:31:54.420088 31962 master.cpp:1025] Master terminating
> I0125 15:31:54.420536 31982 hierarchical.cpp:326] Removed framework
> a41bf879-36b6-4769-82c6-4220f6ecc603-0000
> E0125 15:31:54.422092 31984 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/0 (555 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> I0125 15:31:54.628826 31962 leveldb.cpp:174] Opened db in 156.228813ms
> I0125 15:31:54.691102 31962 leveldb.cpp:181] Compacted db in 62.199429ms
> I0125 15:31:54.691582 31962 leveldb.cpp:196] Created db iterator in 23115ns
> I0125 15:31:54.691715 31962 leveldb.cpp:202] Seeked to beginning of db in
> 3351ns
> I0125 15:31:54.691836 31962 leveldb.cpp:271] Iterated through 0 keys in
> the db in 447ns
> I0125 15:31:54.691990 31962 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0125 15:31:54.698237 31993 master.cpp:374] Master
> 534ad6a0-41c8-451f-a864-af4cc723c1f1 (6a3fa6c4588a) started on
> 172.17.0.2:52355
> I0125 15:31:54.698278 31993 master.cpp:376] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/a9VAYj/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="25secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui"
> --work_dir="/tmp/a9VAYj/master" --zk_session_timeout="10secs"
> I0125 15:31:54.698724 31993 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0125 15:31:54.698737 31993 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0125 15:31:54.698747 31993 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/a9VAYj/credentials'
> I0125 15:31:54.699280 31993 master.cpp:466] Using default 'crammd5'
> authenticator
> I0125 15:31:54.699517 31993 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0125 15:31:54.699681 31993 master.cpp:569] Authorization enabled
> I0125 15:31:54.700637 31996 recover.cpp:447] Starting replica recovery
> I0125 15:31:54.703264 31996 hierarchical.cpp:144] Initialized hierarchical
> allocator process
> I0125 15:31:54.703402 31996 whitelist_watcher.cpp:77] No whitelist given
> I0125 15:31:54.705231 31985 recover.cpp:473] Replica is in EMPTY status
> I0125 15:31:54.708211 31994 master.cpp:1710] The newly elected leader is
> master@172.17.0.2:52355 with id 534ad6a0-41c8-451f-a864-af4cc723c1f1
> I0125 15:31:54.708259 31994 master.cpp:1723] Elected as the leading master!
> I0125 15:31:54.708284 31994 master.cpp:1468] Recovering from registrar
> I0125 15:31:54.708586 31994 registrar.cpp:307] Recovering registrar
> I0125 15:31:54.711406 31987 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (14170)@172.17.0.2:52355
> I0125 15:31:54.711874 31987 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0125 15:31:54.712570 31987 recover.cpp:564] Updating replica status to
> STARTING
> I0125 15:31:54.759073 31987 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 45.444384ms
> I0125 15:31:54.759220 31987 replica.cpp:320] Persisted replica status to
> STARTING
> I0125 15:31:54.759579 31987 recover.cpp:473] Replica is in STARTING status
> I0125 15:31:54.761481 31996 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (14171)@172.17.0.2:52355
> I0125 15:31:54.761909 31987 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0125 15:31:54.762668 31987 recover.cpp:564] Updating replica status to
> VOTING
> I0125 15:31:54.786252 31987 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 23.380089ms
> I0125 15:31:54.786440 31987 replica.cpp:320] Persisted replica status to
> VOTING
> I0125 15:31:54.786736 31996 recover.cpp:578] Successfully joined the Paxos
> group
> I0125 15:31:54.787066 31996 recover.cpp:462] Recover process terminated
> I0125 15:31:54.787926 31991 log.cpp:659] Attempting to start the writer
> I0125 15:31:54.789770 31994 replica.cpp:493] Replica received implicit
> promise request from (14172)@172.17.0.2:52355 with proposal 1
> I0125 15:31:54.812048 31994 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 22.10006ms
> I0125 15:31:54.812278 31994 replica.cpp:342] Persisted promised to 1
> I0125 15:31:54.813483 31985 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0125 15:31:54.815243 31994 replica.cpp:388] Replica received explicit
> promise request from (14173)@172.17.0.2:52355 for position 0 with
> proposal 2
> I0125 15:31:54.867024 31994 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 51.71959ms
> I0125 15:31:54.867079 31994 replica.cpp:712] Persisted action at 0
> I0125 15:31:54.868464 31990 replica.cpp:537] Replica received write
> request for position 0 from (14174)@172.17.0.2:52355
> I0125 15:31:54.868600 31990 leveldb.cpp:436] Reading position from leveldb
> took 35464ns
> I0125 15:31:54.934166 31990 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 65.421468ms
> I0125 15:31:54.934221 31990 replica.cpp:712] Persisted action at 0
> I0125 15:31:54.935314 31988 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0125 15:31:54.984663 31988 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 49.145216ms
> I0125 15:31:54.984750 31988 replica.cpp:712] Persisted action at 0
> I0125 15:31:54.984786 31988 replica.cpp:697] Replica learned NOP action at
> position 0
> I0125 15:31:54.985885 31988 log.cpp:675] Writer started with ending
> position 0
> I0125 15:31:54.987475 31988 leveldb.cpp:436] Reading position from leveldb
> took 54867ns
> I0125 15:31:54.988917 31990 registrar.cpp:340] Successfully fetched the
> registry (0B) in 280.286976ms
> I0125 15:31:54.989181 31990 registrar.cpp:439] Applied 1 operations in
> 82148ns; attempting to update the 'registry'
> I0125 15:31:54.990272 31986 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0125 15:31:54.990396 31981 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0125 15:31:54.991430 31981 replica.cpp:537] Replica received write
> request for position 1 from (14175)@172.17.0.2:52355
> I0125 15:31:55.026638 31981 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 35.168064ms
> I0125 15:31:55.026679 31981 replica.cpp:712] Persisted action at 1
> I0125 15:31:55.029295 31982 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0125 15:31:55.071430 31982 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 42.00698ms
> I0125 15:31:55.071491 31982 replica.cpp:712] Persisted action at 1
> I0125 15:31:55.071521 31982 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0125 15:31:55.073302 31982 registrar.cpp:484] Successfully updated the
> 'registry' in 84.050176ms
> I0125 15:31:55.073321 31995 log.cpp:702] Attempting to truncate the log to
> 1
> I0125 15:31:55.073575 31995 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0125 15:31:55.074652 31995 replica.cpp:537] Replica received write
> request for position 2 from (14176)@172.17.0.2:52355
> I0125 15:31:55.074863 31982 registrar.cpp:370] Successfully recovered
> registrar
> I0125 15:31:55.075283 31982 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0125 15:31:55.075455 31982 hierarchical.cpp:171] Skipping recovery of
> hierarchical allocator: nothing to recover
> 2016-01-25
> 15:31:55,096:31962(0x2abe2af7c700):ZOO_ERROR@handle_socket_error_msg@1697:
> Socket [127.0.0.1:38887] zk retcode=-4, errno=111(Connection refused):
> server refused to accept the client
> I0125 15:31:55.112395 31995 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 37.685723ms
> I0125 15:31:55.112481 31995 replica.cpp:712] Persisted action at 2
> I0125 15:31:55.113759 31995 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0125 15:31:55.137593 31995 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 23.795258ms
> I0125 15:31:55.137698 31995 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 45651ns
> I0125 15:31:55.137722 31995 replica.cpp:712] Persisted action at 2
> I0125 15:31:55.137750 31995 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0125 15:31:55.146957 31962 scheduler.cpp:154] Version: 0.27.0
> I0125 15:31:55.148099 31996 scheduler.cpp:236] New master detected at
> master@172.17.0.2:52355
> I0125 15:31:55.149392 31996 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.2:52355
> I0125 15:31:55.151747 31988 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0125 15:31:55.152426 31987 http.cpp:503] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:37625
> I0125 15:31:55.152787 31987 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0125 15:31:55.152868 31987 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0125 15:31:55.153592 31990 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0125 15:31:55.154331 31990 hierarchical.cpp:265] Added framework
> 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000
> I0125 15:31:55.154359 31991 master.hpp:1658] Sending heartbeat to
> 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000
> I0125 15:31:55.154404 31990 hierarchical.cpp:1355] No resources available
> to allocate!
> I0125 15:31:55.154434 31990 hierarchical.cpp:1450] No inverse offers to
> send out!
> I0125 15:31:55.154459 31990 hierarchical.cpp:1090] Performed allocation
> for 0 slaves in 102693ns
> I0125 15:31:55.156456 31990 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.2:52355
> I0125 15:31:55.157753 31990 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.2:52355
> I0125 15:31:55.158218 31990 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.2:52355
> I0125 15:31:55.159273 31992 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0125 15:31:55.160440 31992 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0125 15:31:55.160969 31988 http.cpp:503] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:37626
> I0125 15:31:55.161312 31988 master.cpp:2717] Processing REQUEST call for
> framework 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000 (default)
> I0125 15:31:55.161464 31992 hierarchical.cpp:585] Received resource
> request from framework 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000
> I0125 15:31:55.161980 31993 master.cpp:1025] Master terminating
> I0125 15:31:55.162343 31982 hierarchical.cpp:326] Removed framework
> 534ad6a0-41c8-451f-a864-af4cc723c1f1-0000
> E0125 15:31:55.163547 31982 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (707 ms)
> [----------] 22 tests from ContentType/SchedulerTest (16861 ms total)
>
> [----------] Global test environment tear-down
> [==========] 952 tests from 123 test cases ran. (759013 ms total)
> [ PASSED ] 951 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] HealthCheckTest.HealthStatusChange
>
> 1 FAILED TEST
> YOU HAVE 8 DISABLED TESTS
>
> make[4]: *** [check-local] Error 1
> make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
> make[1]: *** [check-recursive] Error 1
> make: *** [distcheck] Error 1
> + docker rmi mesos-1453731992-29640
> Untagged: mesos-1453731992-29640:latest
> Deleted: bf1cf6862f5e8ebc3b2620bd5f9892ab74ecd8b032427b34e99846401d379c37
> Deleted: 2dba3db3c355ef9f2af3ec1db4323d7148a7c56add8a7b09742b9ff0ec233314
> Deleted: 8fe1de1c942fa379e3222bf750fb57145c77106b8c9f8838e162cf1f9acf2d1b
> Deleted: 07683cbade061bd63980f45ffbe60e6a20b9cb72ebb807f9e89899d4429c0d19
> Deleted: aca05c3484a3d58399546b66eaea6ea9728516b5d1880ad241c7707bf465ce9e
> Deleted: 09641d8cc65cfdcf956c05ac080b7b33abe8039396646c5c664cec2f982412f4
> Deleted: ceb4ada85723ffea8145c95ccaf5db09fa97d2e659876b40f691ab87771c3e1a
> Deleted: 2432f9a1e40b2c88064e194165d0e5263fc2afbf9acf2c20e5c27eb520cd1ac9
> Deleted: df23a73f74961797a6d50770bf7119580a4c79a2235324a286b5b50d34caae0c
> Deleted: 6f30df9ea464f55a9e3d631346ac26fc57f6ebf734047436124fd6a60b65fb32
> Deleted: 96598b7548ebd760c3d15af8efb6c75ac170fa35c2e02ef6021b5bae685278d5
> Deleted: 5892a6e2afccc6c3310614c331495d2d1ad23d7093f9a3fa24381ecc92f18fb4
> Deleted: 10bbd4cd1bc1e487d30a85a5d8828ec88160d6a407d81255d24ecea0cb0ea24f
> Deleted: 655ccc5722bf9a44bbf7063808d0a3c8ac9afbc7f4f5c0a091b84f4532b7f47b
> Build step 'Execute shell' marked build as failure
>
Jenkins build is back to normal : Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #1545
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1545/changes>