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/29 06:45:42 UTC
Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1582
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1582/>
------------------------------------------
[...truncated 163268 lines...]
I0129 05:45:42.806942 995 status_update_manager.cpp:282] Closing status update streams for framework 31461138-aa82-47f6-873b-9cb0bfe2e399-0000
I0129 05:45:42.807004 995 status_update_manager.cpp:528] Cleaning up status update stream for task 93a0ce2d-0568-4a0b-b7b7-597c486b40a8 of framework 31461138-aa82-47f6-873b-9cb0bfe2e399-0000
I0129 05:45:42.807240 989 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_nIZFsi/slaves/31461138-aa82-47f6-873b-9cb0bfe2e399-S0/frameworks/31461138-aa82-47f6-873b-9cb0bfe2e399-0000' for gc 6.99999066126222days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (568 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0129 05:45:42.922763 961 leveldb.cpp:174] Opened db in 110.265041ms
I0129 05:45:42.963160 961 leveldb.cpp:181] Compacted db in 40.304285ms
I0129 05:45:42.963289 961 leveldb.cpp:196] Created db iterator in 33514ns
I0129 05:45:42.963311 961 leveldb.cpp:202] Seeked to beginning of db in 4183ns
I0129 05:45:42.963323 961 leveldb.cpp:271] Iterated through 0 keys in the db in 340ns
I0129 05:45:42.963383 961 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 05:45:42.964334 983 recover.cpp:447] Starting replica recovery
I0129 05:45:42.964656 983 recover.cpp:473] Replica is in EMPTY status
I0129 05:45:42.966096 987 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14169)@172.17.0.7:52269
I0129 05:45:42.971657 980 master.cpp:374] Master 75c5173e-8919-465c-8844-3fc65465616c (6687dbf628ac) started on 172.17.0.7:52269
I0129 05:45:42.971798 980 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/YvS2Ce/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.28.0/_inst/share/mesos/webui" --work_dir="/tmp/YvS2Ce/master" --zk_session_timeout="10secs"
I0129 05:45:42.972286 980 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 05:45:42.972359 980 master.cpp:426] Master only allowing authenticated slaves to register
I0129 05:45:42.972450 980 credentials.hpp:35] Loading credentials for authentication from '/tmp/YvS2Ce/credentials'
I0129 05:45:42.972936 980 master.cpp:466] Using default 'crammd5' authenticator
I0129 05:45:42.973170 980 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 05:45:42.973364 980 master.cpp:569] Authorization enabled
I0129 05:45:42.973779 984 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 05:45:42.973867 984 whitelist_watcher.cpp:77] No whitelist given
I0129 05:45:42.975667 980 master.cpp:1710] The newly elected leader is master@172.17.0.7:52269 with id 75c5173e-8919-465c-8844-3fc65465616c
I0129 05:45:42.975709 980 master.cpp:1723] Elected as the leading master!
I0129 05:45:42.975734 980 master.cpp:1468] Recovering from registrar
I0129 05:45:42.976025 980 registrar.cpp:307] Recovering registrar
I0129 05:45:42.980034 983 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 05:45:42.980790 991 recover.cpp:564] Updating replica status to STARTING
I0129 05:45:43.013260 991 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 32.199798ms
I0129 05:45:43.013342 991 replica.cpp:320] Persisted replica status to STARTING
I0129 05:45:43.013730 991 recover.cpp:473] Replica is in STARTING status
I0129 05:45:43.014976 991 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14171)@172.17.0.7:52269
I0129 05:45:43.015516 989 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 05:45:43.016015 982 recover.cpp:564] Updating replica status to VOTING
I0129 05:45:43.038396 992 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.245451ms
I0129 05:45:43.038446 992 replica.cpp:320] Persisted replica status to VOTING
I0129 05:45:43.038580 988 recover.cpp:578] Successfully joined the Paxos group
I0129 05:45:43.038843 988 recover.cpp:462] Recover process terminated
I0129 05:45:43.039320 991 log.cpp:659] Attempting to start the writer
I0129 05:45:43.040650 987 replica.cpp:493] Replica received implicit promise request from (14172)@172.17.0.7:52269 with proposal 1
I0129 05:45:43.063566 987 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.87936ms
I0129 05:45:43.063630 987 replica.cpp:342] Persisted promised to 1
I0129 05:45:43.064260 991 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 05:45:43.065773 981 replica.cpp:388] Replica received explicit promise request from (14173)@172.17.0.7:52269 for position 0 with proposal 2
I0129 05:45:43.122117 981 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 56.256872ms
I0129 05:45:43.122206 981 replica.cpp:712] Persisted action at 0
I0129 05:45:43.124089 980 replica.cpp:537] Replica received write request for position 0 from (14174)@172.17.0.7:52269
I0129 05:45:43.124351 980 leveldb.cpp:436] Reading position from leveldb took 56399ns
I0129 05:45:43.147374 980 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 22.809791ms
I0129 05:45:43.147459 980 replica.cpp:712] Persisted action at 0
I0129 05:45:43.148320 991 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 05:45:43.172504 991 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.127077ms
I0129 05:45:43.172613 991 replica.cpp:712] Persisted action at 0
I0129 05:45:43.172662 991 replica.cpp:697] Replica learned NOP action at position 0
I0129 05:45:43.173707 991 log.cpp:675] Writer started with ending position 0
I0129 05:45:43.174903 984 leveldb.cpp:436] Reading position from leveldb took 67710ns
I0129 05:45:43.175997 987 registrar.cpp:340] Successfully fetched the registry (0B) in 199.919872ms
I0129 05:45:43.176151 987 registrar.cpp:439] Applied 1 operations in 43749ns; attempting to update the 'registry'
I0129 05:45:43.176923 993 log.cpp:683] Attempting to append 170 bytes to the log
I0129 05:45:43.177048 984 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 05:45:43.177892 981 replica.cpp:537] Replica received write request for position 1 from (14175)@172.17.0.7:52269
I0129 05:45:43.197698 981 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 19.68231ms
I0129 05:45:43.197768 981 replica.cpp:712] Persisted action at 1
I0129 05:45:43.198575 983 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 05:45:43.229003 983 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 30.370082ms
I0129 05:45:43.229087 983 replica.cpp:712] Persisted action at 1
I0129 05:45:43.229122 983 replica.cpp:697] Replica learned APPEND action at position 1
I0129 05:45:43.230507 992 registrar.cpp:484] Successfully updated the 'registry' in 54.281984ms
I0129 05:45:43.230671 992 registrar.cpp:370] Successfully recovered registrar
I0129 05:45:43.230880 982 log.cpp:702] Attempting to truncate the log to 1
I0129 05:45:43.231096 982 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 05:45:43.231125 992 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 05:45:43.231493 984 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 05:45:43.232132 980 replica.cpp:537] Replica received write request for position 2 from (14176)@172.17.0.7:52269
I0129 05:45:43.270866 980 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.676692ms
I0129 05:45:43.270951 980 replica.cpp:712] Persisted action at 2
I0129 05:45:43.272378 980 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 05:45:43.312875 980 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.447021ms
I0129 05:45:43.313036 980 leveldb.cpp:399] Deleting ~1 keys from leveldb took 77297ns
I0129 05:45:43.313073 980 replica.cpp:712] Persisted action at 2
I0129 05:45:43.313117 980 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 05:45:43.323143 961 scheduler.cpp:154] Version: 0.28.0
I0129 05:45:43.324000 982 scheduler.cpp:236] New master detected at master@172.17.0.7:52269
I0129 05:45:43.325304 990 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.7:52269
I0129 05:45:43.327455 993 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 05:45:43.328071 989 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.7:53612
I0129 05:45:43.328290 989 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 05:45:43.328438 989 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 05:45:43.328953 989 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 05:45:43.329470 983 hierarchical.cpp:265] Added framework 75c5173e-8919-465c-8844-3fc65465616c-0000
I0129 05:45:43.329565 983 hierarchical.cpp:1403] No resources available to allocate!
I0129 05:45:43.329568 989 master.hpp:1658] Sending heartbeat to 75c5173e-8919-465c-8844-3fc65465616c-0000
I0129 05:45:43.329638 983 hierarchical.cpp:1498] No inverse offers to send out!
I0129 05:45:43.329675 983 hierarchical.cpp:1096] Performed allocation for 0 slaves in 181178ns
I0129 05:45:43.330481 984 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.7:52269
I0129 05:45:43.331171 984 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.7:52269
I0129 05:45:43.332134 984 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.7:52269
I0129 05:45:43.333217 984 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 05:45:43.334239 985 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 05:45:43.334692 988 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.7:53613
I0129 05:45:43.334825 988 master.cpp:2717] Processing REQUEST call for framework 75c5173e-8919-465c-8844-3fc65465616c-0000 (default)
I0129 05:45:43.335046 994 hierarchical.cpp:589] Received resource request from framework 75c5173e-8919-465c-8844-3fc65465616c-0000
I0129 05:45:43.335685 986 master.cpp:1025] Master terminating
I0129 05:45:43.335903 991 hierarchical.cpp:326] Removed framework 75c5173e-8919-465c-8844-3fc65465616c-0000
E0129 05:45:43.336932 982 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (530 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0129 05:45:43.464987 961 leveldb.cpp:174] Opened db in 122.34908ms
I0129 05:45:43.490692 961 leveldb.cpp:181] Compacted db in 25.63166ms
I0129 05:45:43.490768 961 leveldb.cpp:196] Created db iterator in 22933ns
I0129 05:45:43.490785 961 leveldb.cpp:202] Seeked to beginning of db in 2487ns
I0129 05:45:43.490793 961 leveldb.cpp:271] Iterated through 0 keys in the db in 230ns
I0129 05:45:43.490839 961 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 05:45:43.491374 984 recover.cpp:447] Starting replica recovery
I0129 05:45:43.491713 990 recover.cpp:473] Replica is in EMPTY status
I0129 05:45:43.492815 994 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14184)@172.17.0.7:52269
I0129 05:45:43.493294 990 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 05:45:43.493791 982 recover.cpp:564] Updating replica status to STARTING
I0129 05:45:43.494336 990 master.cpp:374] Master 5df622d0-3ccd-4085-b756-bcb624eeee07 (6687dbf628ac) started on 172.17.0.7:52269
I0129 05:45:43.494444 990 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/pjqpyz/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.28.0/_inst/share/mesos/webui" --work_dir="/tmp/pjqpyz/master" --zk_session_timeout="10secs"
I0129 05:45:43.494742 990 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 05:45:43.494752 990 master.cpp:426] Master only allowing authenticated slaves to register
I0129 05:45:43.494760 990 credentials.hpp:35] Loading credentials for authentication from '/tmp/pjqpyz/credentials'
I0129 05:45:43.495046 990 master.cpp:466] Using default 'crammd5' authenticator
I0129 05:45:43.495173 990 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 05:45:43.495316 990 master.cpp:569] Authorization enabled
I0129 05:45:43.495812 993 whitelist_watcher.cpp:77] No whitelist given
I0129 05:45:43.495915 980 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 05:45:43.497525 992 master.cpp:1710] The newly elected leader is master@172.17.0.7:52269 with id 5df622d0-3ccd-4085-b756-bcb624eeee07
I0129 05:45:43.497560 992 master.cpp:1723] Elected as the leading master!
I0129 05:45:43.497577 992 master.cpp:1468] Recovering from registrar
I0129 05:45:43.497750 989 registrar.cpp:307] Recovering registrar
I0129 05:45:43.515712 988 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 21.812172ms
I0129 05:45:43.515753 988 replica.cpp:320] Persisted replica status to STARTING
I0129 05:45:43.515961 986 recover.cpp:473] Replica is in STARTING status
I0129 05:45:43.516863 990 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14186)@172.17.0.7:52269
I0129 05:45:43.517058 989 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 05:45:43.517463 993 recover.cpp:564] Updating replica status to VOTING
I0129 05:45:43.540838 995 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.199185ms
I0129 05:45:43.540905 995 replica.cpp:320] Persisted replica status to VOTING
I0129 05:45:43.541106 995 recover.cpp:578] Successfully joined the Paxos group
I0129 05:45:43.541422 995 recover.cpp:462] Recover process terminated
I0129 05:45:43.542105 988 log.cpp:659] Attempting to start the writer
I0129 05:45:43.543431 983 replica.cpp:493] Replica received implicit promise request from (14187)@172.17.0.7:52269 with proposal 1
I0129 05:45:43.565968 983 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.483824ms
I0129 05:45:43.566051 983 replica.cpp:342] Persisted promised to 1
I0129 05:45:43.566881 988 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 05:45:43.568716 987 replica.cpp:388] Replica received explicit promise request from (14188)@172.17.0.7:52269 for position 0 with proposal 2
I0129 05:45:43.591159 987 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.373413ms
I0129 05:45:43.591248 987 replica.cpp:712] Persisted action at 0
I0129 05:45:43.592839 987 replica.cpp:537] Replica received write request for position 0 from (14189)@172.17.0.7:52269
I0129 05:45:43.592914 987 leveldb.cpp:436] Reading position from leveldb took 39712ns
I0129 05:45:43.616699 987 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.721846ms
I0129 05:45:43.616793 987 replica.cpp:712] Persisted action at 0
I0129 05:45:43.617841 983 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
2016-01-29 05:45:43,639:961(0x7f7edd3ab700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:45598] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I0129 05:45:43.647583 983 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 29.685195ms
I0129 05:45:43.647663 983 replica.cpp:712] Persisted action at 0
I0129 05:45:43.647708 983 replica.cpp:697] Replica learned NOP action at position 0
I0129 05:45:43.648592 994 log.cpp:675] Writer started with ending position 0
I0129 05:45:43.650140 995 leveldb.cpp:436] Reading position from leveldb took 71044ns
I0129 05:45:43.651373 988 registrar.cpp:340] Successfully fetched the registry (0B) in 153568us
I0129 05:45:43.651515 988 registrar.cpp:439] Applied 1 operations in 44778ns; attempting to update the 'registry'
I0129 05:45:43.652349 986 log.cpp:683] Attempting to append 170 bytes to the log
I0129 05:45:43.652480 991 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 05:45:43.653240 982 replica.cpp:537] Replica received write request for position 1 from (14190)@172.17.0.7:52269
I0129 05:45:43.689522 982 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.229962ms
I0129 05:45:43.689579 982 replica.cpp:712] Persisted action at 1
I0129 05:45:43.690337 982 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 05:45:43.724941 982 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 34.561062ms
I0129 05:45:43.725006 982 replica.cpp:712] Persisted action at 1
I0129 05:45:43.725034 982 replica.cpp:697] Replica learned APPEND action at position 1
I0129 05:45:43.726317 981 registrar.cpp:484] Successfully updated the 'registry' in 74.729216ms
I0129 05:45:43.726575 990 log.cpp:702] Attempting to truncate the log to 1
I0129 05:45:43.726689 981 registrar.cpp:370] Successfully recovered registrar
I0129 05:45:43.726869 986 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 05:45:43.727176 990 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 05:45:43.727244 986 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 05:45:43.727705 993 replica.cpp:537] Replica received write request for position 2 from (14191)@172.17.0.7:52269
I0129 05:45:43.764936 993 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 37.125522ms
I0129 05:45:43.765013 993 replica.cpp:712] Persisted action at 2
I0129 05:45:43.766144 993 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 05:45:43.800257 993 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 33.985715ms
I0129 05:45:43.800421 993 leveldb.cpp:399] Deleting ~1 keys from leveldb took 74130ns
I0129 05:45:43.800451 993 replica.cpp:712] Persisted action at 2
I0129 05:45:43.800487 993 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 05:45:43.810101 961 scheduler.cpp:154] Version: 0.28.0
I0129 05:45:43.811079 982 scheduler.cpp:236] New master detected at master@172.17.0.7:52269
I0129 05:45:43.813789 986 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.7:52269
I0129 05:45:43.816484 994 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 05:45:43.817104 980 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.7:53617
I0129 05:45:43.817524 980 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 05:45:43.817594 980 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 05:45:43.817886 980 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 05:45:43.818292 994 hierarchical.cpp:265] Added framework 5df622d0-3ccd-4085-b756-bcb624eeee07-0000
I0129 05:45:43.818378 994 hierarchical.cpp:1403] No resources available to allocate!
I0129 05:45:43.818418 994 hierarchical.cpp:1498] No inverse offers to send out!
I0129 05:45:43.818447 994 hierarchical.cpp:1096] Performed allocation for 0 slaves in 131415ns
I0129 05:45:43.818595 980 master.hpp:1658] Sending heartbeat to 5df622d0-3ccd-4085-b756-bcb624eeee07-0000
I0129 05:45:43.819630 994 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.7:52269
I0129 05:45:43.820318 980 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.7:52269
I0129 05:45:43.821133 980 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.7:52269
I0129 05:45:43.821197 992 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 05:45:43.823223 992 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 05:45:43.823695 992 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.7:53618
I0129 05:45:43.823938 992 master.cpp:2717] Processing REQUEST call for framework 5df622d0-3ccd-4085-b756-bcb624eeee07-0000 (default)
I0129 05:45:43.824177 992 hierarchical.cpp:589] Received resource request from framework 5df622d0-3ccd-4085-b756-bcb624eeee07-0000
I0129 05:45:43.824791 988 master.cpp:1025] Master terminating
I0129 05:45:43.825119 995 hierarchical.cpp:326] Removed framework 5df622d0-3ccd-4085-b756-bcb624eeee07-0000
E0129 05:45:43.826786 983 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (490 ms)
[----------] 22 tests from ContentType/SchedulerTest (15152 ms total)
[----------] Global test environment tear-down
[==========] 962 tests from 126 test cases ran. (717595 ms total)
[ PASSED ] 961 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ShasumTest.SHA512SimpleFile
1 FAILED TEST
YOU HAVE 8 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1454044007-29134
Untagged: mesos-1454044007-29134:latest
Deleted: c04b29d8069591ddaceffb89550affc295cead4e71f0e103280d0520fd69ff39
Deleted: ae6b2724a93f19309a19545a4d6ae74a44acc22e34e518d4d1d60e693c142588
Deleted: 9c66b305d0a76c7d5f9ab724f09a9fdbc8198099774d43d66e959f96457c5243
Deleted: fd0bf24bd20901e4e9541e1273114d32b4ae49c84f1b16acb3c37135f3ecf12d
Deleted: 29176e01e95938304a6e18e390be49ccfdaa3a8748f91ca5ec3d3db8c9ef9d36
Deleted: 1f8d56a5b483f7a5ba64e18381d00442456eb22bc51846473aeb62f6ff7b32c2
Deleted: 6f4ec2a3c5bd21c89d4ad03cc68d1c21f7359292d56b2e8f3f57c233a67deb0f
Deleted: c9b3cc4d90fd5e725b11f124cceb3370798bed282e8ebca37805fa679eea0dbf
Deleted: a22c132422e81cffa2e8d865110c482fb2ba0975a80ee435bfe149157ad48eff
Deleted: fc96dc9fb014a8c7839196f06c38fc57d650a622f1194cca6e05acfbbe8641db
Deleted: 0f4a61026d0e1f731ed181434e52db845b16295b0dc311cfa0f1884f0d5bb753
Deleted: 63a3efdadef99bbeb9248b5b3de01a35c6c40f20472f2c3ef25208ca3d6f9b30
Deleted: b965c14d58c316481ef8efc61fc68f2a941a63b94d573a6887d65b332f576414
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1588
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1588/>
Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1587
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1587/>
------------------------------------------
[...truncated 160089 lines...]
I0129 21:31:59.456373 975 slave.cpp:667] Slave terminating
I0129 21:31:59.456547 975 slave.cpp:2078] Asked to shut down framework 306afbb1-df94-468e-b04a-d9709df6f2c3-0000 by @0.0.0.0:0
I0129 21:31:59.456676 975 slave.cpp:2103] Shutting down framework 306afbb1-df94-468e-b04a-d9709df6f2c3-0000
I0129 21:31:59.456866 975 slave.cpp:4128] Shutting down executor 'default' of framework 306afbb1-df94-468e-b04a-d9709df6f2c3-0000 at executor(139)@172.17.0.6:41178
[ OK ] ContentType/SchedulerTest.Message/1 (126 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0129 21:31:59.469012 975 leveldb.cpp:174] Opened db in 2.580924ms
I0129 21:31:59.470223 975 leveldb.cpp:181] Compacted db in 1.091344ms
I0129 21:31:59.470337 975 leveldb.cpp:196] Created db iterator in 21181ns
I0129 21:31:59.470449 975 leveldb.cpp:202] Seeked to beginning of db in 2533ns
I0129 21:31:59.470546 975 leveldb.cpp:271] Iterated through 0 keys in the db in 432ns
I0129 21:31:59.470685 975 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 21:31:59.471577 1000 recover.cpp:447] Starting replica recovery
I0129 21:31:59.471895 1000 recover.cpp:473] Replica is in EMPTY status
I0129 21:31:59.473665 994 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14177)@172.17.0.6:41178
I0129 21:31:59.475364 1003 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 21:31:59.475805 1001 master.cpp:374] Master 1d79b63f-6f94-4746-8a40-c054975b8fd4 (d66130543b12) started on 172.17.0.6:41178
I0129 21:31:59.476156 1001 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/ucNPvy/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.28.0/_inst/share/mesos/webui" --work_dir="/tmp/ucNPvy/master" --zk_session_timeout="10secs"
I0129 21:31:59.476578 1001 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 21:31:59.476590 1001 master.cpp:426] Master only allowing authenticated slaves to register
I0129 21:31:59.476599 1001 credentials.hpp:35] Loading credentials for authentication from '/tmp/ucNPvy/credentials'
I0129 21:31:59.477010 1001 master.cpp:466] Using default 'crammd5' authenticator
I0129 21:31:59.477186 1001 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 21:31:59.477365 1001 master.cpp:569] Authorization enabled
I0129 21:31:59.477682 1000 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 21:31:59.477741 1006 whitelist_watcher.cpp:77] No whitelist given
I0129 21:31:59.477833 996 recover.cpp:564] Updating replica status to STARTING
I0129 21:31:59.478490 1006 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 495055ns
I0129 21:31:59.478513 1006 replica.cpp:320] Persisted replica status to STARTING
I0129 21:31:59.478745 999 recover.cpp:473] Replica is in STARTING status
I0129 21:31:59.479526 996 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14179)@172.17.0.6:41178
I0129 21:31:59.479610 1000 master.cpp:1710] The newly elected leader is master@172.17.0.6:41178 with id 1d79b63f-6f94-4746-8a40-c054975b8fd4
I0129 21:31:59.479745 1000 master.cpp:1723] Elected as the leading master!
I0129 21:31:59.479778 1000 master.cpp:1468] Recovering from registrar
I0129 21:31:59.479980 1005 registrar.cpp:307] Recovering registrar
I0129 21:31:59.479998 1007 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 21:31:59.480531 996 recover.cpp:564] Updating replica status to VOTING
I0129 21:31:59.481019 995 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 305963ns
I0129 21:31:59.481042 995 replica.cpp:320] Persisted replica status to VOTING
I0129 21:31:59.481139 1001 recover.cpp:578] Successfully joined the Paxos group
I0129 21:31:59.481340 1001 recover.cpp:462] Recover process terminated
I0129 21:31:59.481806 1004 log.cpp:659] Attempting to start the writer
I0129 21:31:59.482942 995 replica.cpp:493] Replica received implicit promise request from (14180)@172.17.0.6:41178 with proposal 1
I0129 21:31:59.483259 995 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 286350ns
I0129 21:31:59.483281 995 replica.cpp:342] Persisted promised to 1
I0129 21:31:59.483999 1008 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 21:31:59.485302 1004 replica.cpp:388] Replica received explicit promise request from (14181)@172.17.0.6:41178 for position 0 with proposal 2
I0129 21:31:59.485611 1004 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 268815ns
I0129 21:31:59.485635 1004 replica.cpp:712] Persisted action at 0
I0129 21:31:59.487153 1009 replica.cpp:537] Replica received write request for position 0 from (14182)@172.17.0.6:41178
I0129 21:31:59.487223 1009 leveldb.cpp:436] Reading position from leveldb took 31622ns
I0129 21:31:59.487675 1009 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 386749ns
I0129 21:31:59.487712 1009 replica.cpp:712] Persisted action at 0
I0129 21:31:59.488600 1008 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 21:31:59.489073 1008 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 372491ns
I0129 21:31:59.489109 1008 replica.cpp:712] Persisted action at 0
I0129 21:31:59.489130 1008 replica.cpp:697] Replica learned NOP action at position 0
I0129 21:31:59.489877 1005 log.cpp:675] Writer started with ending position 0
I0129 21:31:59.491212 995 leveldb.cpp:436] Reading position from leveldb took 28901ns
I0129 21:31:59.492470 1005 registrar.cpp:340] Successfully fetched the registry (0B) in 12.425984ms
I0129 21:31:59.492620 1005 registrar.cpp:439] Applied 1 operations in 36972ns; attempting to update the 'registry'
I0129 21:31:59.493448 999 log.cpp:683] Attempting to append 170 bytes to the log
I0129 21:31:59.493584 1006 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 21:31:59.494451 994 replica.cpp:537] Replica received write request for position 1 from (14183)@172.17.0.6:41178
I0129 21:31:59.494843 994 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 346366ns
I0129 21:31:59.494873 994 replica.cpp:712] Persisted action at 1
I0129 21:31:59.496042 1000 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 21:31:59.496501 1000 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 359999ns
I0129 21:31:59.496531 1000 replica.cpp:712] Persisted action at 1
I0129 21:31:59.496552 1000 replica.cpp:697] Replica learned APPEND action at position 1
I0129 21:31:59.497607 995 registrar.cpp:484] Successfully updated the 'registry' in 4.922112ms
I0129 21:31:59.497752 995 registrar.cpp:370] Successfully recovered registrar
I0129 21:31:59.497933 998 log.cpp:702] Attempting to truncate the log to 1
I0129 21:31:59.498286 1001 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 21:31:59.498291 1009 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 21:31:59.498328 1006 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 21:31:59.499166 1001 replica.cpp:537] Replica received write request for position 2 from (14184)@172.17.0.6:41178
I0129 21:31:59.499541 1001 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 333943ns
I0129 21:31:59.499574 1001 replica.cpp:712] Persisted action at 2
I0129 21:31:59.500339 1002 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 21:31:59.500712 1002 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 330536ns
I0129 21:31:59.500776 1002 leveldb.cpp:399] Deleting ~1 keys from leveldb took 32560ns
I0129 21:31:59.500805 1002 replica.cpp:712] Persisted action at 2
I0129 21:31:59.500860 1002 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 21:31:59.509646 975 scheduler.cpp:154] Version: 0.28.0
I0129 21:31:59.510967 1004 scheduler.cpp:236] New master detected at master@172.17.0.6:41178
I0129 21:31:59.512274 995 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.6:41178
I0129 21:31:59.514884 999 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 21:31:59.515410 1002 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.6:55358
I0129 21:31:59.515736 1002 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 21:31:59.515908 1002 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 21:31:59.516307 1002 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 21:31:59.517016 996 hierarchical.cpp:265] Added framework 1d79b63f-6f94-4746-8a40-c054975b8fd4-0000
I0129 21:31:59.517966 996 hierarchical.cpp:1403] No resources available to allocate!
I0129 21:31:59.518118 996 hierarchical.cpp:1498] No inverse offers to send out!
I0129 21:31:59.518232 996 hierarchical.cpp:1096] Performed allocation for 0 slaves in 333959ns
I0129 21:31:59.517335 1002 master.hpp:1658] Sending heartbeat to 1d79b63f-6f94-4746-8a40-c054975b8fd4-0000
I0129 21:31:59.520084 997 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.6:41178
I0129 21:31:59.520884 1009 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.6:41178
I0129 21:31:59.522068 1005 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 21:31:59.522969 1009 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.6:41178
I0129 21:31:59.525184 1005 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 21:31:59.526145 997 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.6:55359
I0129 21:31:59.526322 997 master.cpp:2717] Processing REQUEST call for framework 1d79b63f-6f94-4746-8a40-c054975b8fd4-0000 (default)
I0129 21:31:59.526609 997 hierarchical.cpp:589] Received resource request from framework 1d79b63f-6f94-4746-8a40-c054975b8fd4-0000
I0129 21:31:59.527719 975 master.cpp:1025] Master terminating
I0129 21:31:59.528703 997 hierarchical.cpp:326] Removed framework 1d79b63f-6f94-4746-8a40-c054975b8fd4-0000
E0129 21:31:59.530696 997 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (86 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0129 21:31:59.557366 975 leveldb.cpp:174] Opened db in 3.358128ms
I0129 21:31:59.558579 975 leveldb.cpp:181] Compacted db in 1.163825ms
I0129 21:31:59.558640 975 leveldb.cpp:196] Created db iterator in 20631ns
I0129 21:31:59.558660 975 leveldb.cpp:202] Seeked to beginning of db in 2224ns
I0129 21:31:59.558667 975 leveldb.cpp:271] Iterated through 0 keys in the db in 235ns
I0129 21:31:59.558707 975 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 21:31:59.559193 1004 recover.cpp:447] Starting replica recovery
I0129 21:31:59.559424 1004 recover.cpp:473] Replica is in EMPTY status
I0129 21:31:59.560430 1005 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14192)@172.17.0.6:41178
I0129 21:31:59.560729 1003 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 21:31:59.561184 1000 recover.cpp:564] Updating replica status to STARTING
I0129 21:31:59.561704 1007 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 388069ns
I0129 21:31:59.561728 1007 replica.cpp:320] Persisted replica status to STARTING
I0129 21:31:59.561902 997 recover.cpp:473] Replica is in STARTING status
I0129 21:31:59.562039 1005 master.cpp:374] Master 2b3039ee-3c8f-4282-bfc3-d85d699f3896 (d66130543b12) started on 172.17.0.6:41178
I0129 21:31:59.562063 1005 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/xiH32d/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.28.0/_inst/share/mesos/webui" --work_dir="/tmp/xiH32d/master" --zk_session_timeout="10secs"
I0129 21:31:59.562511 1005 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 21:31:59.562522 1005 master.cpp:426] Master only allowing authenticated slaves to register
I0129 21:31:59.562530 1005 credentials.hpp:35] Loading credentials for authentication from '/tmp/xiH32d/credentials'
I0129 21:31:59.562758 1001 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14193)@172.17.0.6:41178
I0129 21:31:59.562916 1005 master.cpp:466] Using default 'crammd5' authenticator
I0129 21:31:59.563010 999 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 21:31:59.563079 1005 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 21:31:59.563359 1005 master.cpp:569] Authorization enabled
I0129 21:31:59.563558 996 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 21:31:59.563561 1004 recover.cpp:564] Updating replica status to VOTING
I0129 21:31:59.563568 1008 whitelist_watcher.cpp:77] No whitelist given
I0129 21:31:59.564105 997 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 327357ns
I0129 21:31:59.564131 997 replica.cpp:320] Persisted replica status to VOTING
I0129 21:31:59.564268 1004 recover.cpp:578] Successfully joined the Paxos group
I0129 21:31:59.564478 1004 recover.cpp:462] Recover process terminated
I0129 21:31:59.565383 997 master.cpp:1710] The newly elected leader is master@172.17.0.6:41178 with id 2b3039ee-3c8f-4282-bfc3-d85d699f3896
I0129 21:31:59.565418 997 master.cpp:1723] Elected as the leading master!
I0129 21:31:59.565440 997 master.cpp:1468] Recovering from registrar
I0129 21:31:59.565575 1009 registrar.cpp:307] Recovering registrar
I0129 21:31:59.566113 1002 log.cpp:659] Attempting to start the writer
I0129 21:31:59.567210 1005 replica.cpp:493] Replica received implicit promise request from (14195)@172.17.0.6:41178 with proposal 1
I0129 21:31:59.567531 1005 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 287138ns
I0129 21:31:59.567554 1005 replica.cpp:342] Persisted promised to 1
I0129 21:31:59.568099 1008 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 21:31:59.569119 1005 replica.cpp:388] Replica received explicit promise request from (14196)@172.17.0.6:41178 for position 0 with proposal 2
I0129 21:31:59.569469 1005 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 309123ns
I0129 21:31:59.569494 1005 replica.cpp:712] Persisted action at 0
I0129 21:31:59.570600 1000 replica.cpp:537] Replica received write request for position 0 from (14197)@172.17.0.6:41178
I0129 21:31:59.570662 1000 leveldb.cpp:436] Reading position from leveldb took 27386ns
I0129 21:31:59.571008 1000 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 304878ns
I0129 21:31:59.571034 1000 replica.cpp:712] Persisted action at 0
I0129 21:31:59.571636 1002 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 21:31:59.572058 1002 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 384831ns
I0129 21:31:59.572090 1002 replica.cpp:712] Persisted action at 0
I0129 21:31:59.572113 1002 replica.cpp:697] Replica learned NOP action at position 0
I0129 21:31:59.572899 1009 log.cpp:675] Writer started with ending position 0
I0129 21:31:59.574156 997 leveldb.cpp:436] Reading position from leveldb took 37236ns
I0129 21:31:59.575402 994 registrar.cpp:340] Successfully fetched the registry (0B) in 9.772032ms
I0129 21:31:59.575525 994 registrar.cpp:439] Applied 1 operations in 28486ns; attempting to update the 'registry'
I0129 21:31:59.576361 1005 log.cpp:683] Attempting to append 170 bytes to the log
I0129 21:31:59.576508 1006 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 21:31:59.577405 1004 replica.cpp:537] Replica received write request for position 1 from (14198)@172.17.0.6:41178
I0129 21:31:59.577932 1004 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 475249ns
I0129 21:31:59.577966 1004 replica.cpp:712] Persisted action at 1
I0129 21:31:59.578752 1003 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 21:31:59.579201 1003 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 404051ns
I0129 21:31:59.579236 1003 replica.cpp:712] Persisted action at 1
I0129 21:31:59.579257 1003 replica.cpp:697] Replica learned APPEND action at position 1
I0129 21:31:59.580453 995 registrar.cpp:484] Successfully updated the 'registry' in 4.84608ms
I0129 21:31:59.580620 995 registrar.cpp:370] Successfully recovered registrar
I0129 21:31:59.580683 996 log.cpp:702] Attempting to truncate the log to 1
I0129 21:31:59.580858 1003 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 21:31:59.581423 994 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 21:31:59.581454 998 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 21:31:59.582008 1003 replica.cpp:537] Replica received write request for position 2 from (14199)@172.17.0.6:41178
I0129 21:31:59.582429 1003 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 370389ns
I0129 21:31:59.582461 1003 replica.cpp:712] Persisted action at 2
I0129 21:31:59.583206 996 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 21:31:59.583639 996 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 389413ns
I0129 21:31:59.583705 996 leveldb.cpp:399] Deleting ~1 keys from leveldb took 34574ns
I0129 21:31:59.583731 996 replica.cpp:712] Persisted action at 2
I0129 21:31:59.583755 996 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 21:31:59.592245 975 scheduler.cpp:154] Version: 0.28.0
I0129 21:31:59.593148 1002 scheduler.cpp:236] New master detected at master@172.17.0.6:41178
I0129 21:31:59.594462 999 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.6:41178
I0129 21:31:59.596606 997 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 21:31:59.597251 1005 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.6:55360
I0129 21:31:59.597637 1005 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 21:31:59.597707 1005 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 21:31:59.598016 1005 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 21:31:59.598485 996 hierarchical.cpp:265] Added framework 2b3039ee-3c8f-4282-bfc3-d85d699f3896-0000
I0129 21:31:59.598582 996 hierarchical.cpp:1403] No resources available to allocate!
I0129 21:31:59.598615 1000 master.hpp:1658] Sending heartbeat to 2b3039ee-3c8f-4282-bfc3-d85d699f3896-0000
I0129 21:31:59.598706 996 hierarchical.cpp:1498] No inverse offers to send out!
I0129 21:31:59.598736 996 hierarchical.cpp:1096] Performed allocation for 0 slaves in 215232ns
I0129 21:31:59.599658 995 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.6:41178
I0129 21:31:59.600270 995 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.6:41178
I0129 21:31:59.601065 995 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.6:41178
I0129 21:31:59.601115 1004 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 21:31:59.603474 997 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 21:31:59.603989 994 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.6:55361
I0129 21:31:59.604259 994 master.cpp:2717] Processing REQUEST call for framework 2b3039ee-3c8f-4282-bfc3-d85d699f3896-0000 (default)
I0129 21:31:59.604480 997 hierarchical.cpp:589] Received resource request from framework 2b3039ee-3c8f-4282-bfc3-d85d699f3896-0000
I0129 21:31:59.604961 1008 master.cpp:1025] Master terminating
I0129 21:31:59.605283 996 hierarchical.cpp:326] Removed framework 2b3039ee-3c8f-4282-bfc3-d85d699f3896-0000
E0129 21:31:59.607245 1007 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (60 ms)
[----------] 22 tests from ContentType/SchedulerTest (4490 ms total)
[----------] Global test environment tear-down
[==========] 963 tests from 126 test cases ran. (350129 ms total)
[ PASSED ] 962 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ShasumTest.SHA512SimpleFile
1 FAILED TEST
YOU HAVE 8 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1454101017-12995
Untagged: mesos-1454101017-12995:latest
Deleted: cd1dbd58025178e7666fc03a147fcbc4f916dec2284164c2a904ff458a48276e
Deleted: 9827d2fd3ed97132171e60c7375d322c9d785e496ca115901ef6cc376ad872e4
Deleted: 136557ae71fabf904aa6f3599c15d61db19b19ec3c417a70fc0a6962551c88db
Deleted: 2b44acb99c0986908b807bad1c0411b29c646e2fc2ae5a771037f741366775b2
Deleted: 07b42ef73c2723f6ec744f52360f23d462920dd8fc16dbdee88b5eae68cc5ea5
Deleted: 93c9d796d6cf4473dec036d7ddd08f658ca375b7e6a78fd3876c4850aedc4e08
Deleted: d9de8b70857dfc014afabd9bdada2e596c7d6117dda2ecc142c6cffe50c27e2d
Deleted: 7ecfd740e9b1cfeaacbae5bb7b177c2f9fe62d4d78a0e11b900979d15207a0b2
Deleted: a20406ca06b40b9315db1fc3a828ae423cb4156d09d5cea79c5972be71f3ba03
Deleted: 11a09f92e3815c10afba77bc846b080fd345f1cc78f556798ae8f8392edbe182
Deleted: 770da6b39ea19852a37b6f9964cc6c38d4a8a41fa5654c1f4a6b17df5764c65d
Deleted: 21a7f1bcd50775725b3f4449fe878bd28c3153b4a2dcfae5a1fdb73be26f23e0
Deleted: a37e22c5568a789b26f00d3f901ac6c7b5253e0d9cc7ba0db89411e2a6f53e27
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1586
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1586/>
------------------------------------------
[...truncated 159702 lines...]
I0129 19:54:20.987282 992 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_x92AAI/slaves/400b239b-74c9-4241-8edc-c6354fc27cbe-S0/frameworks/400b239b-74c9-4241-8edc-c6354fc27cbe-0000/executors/default' for gc 6.99998857464296days in the future
I0129 19:54:20.987401 999 status_update_manager.cpp:282] Closing status update streams for framework 400b239b-74c9-4241-8edc-c6354fc27cbe-0000
I0129 19:54:20.987417 992 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_x92AAI/slaves/400b239b-74c9-4241-8edc-c6354fc27cbe-S0/frameworks/400b239b-74c9-4241-8edc-c6354fc27cbe-0000' for gc 6.99998857246519days in the future
I0129 19:54:20.987483 999 status_update_manager.cpp:528] Cleaning up status update stream for task 8f483474-b4f0-4c3a-a0b4-fcbc5852ed44 of framework 400b239b-74c9-4241-8edc-c6354fc27cbe-0000
[ OK ] ContentType/SchedulerTest.Message/1 (124 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0129 19:54:20.996332 968 leveldb.cpp:174] Opened db in 3.286965ms
I0129 19:54:20.997465 968 leveldb.cpp:181] Compacted db in 1.090023ms
I0129 19:54:20.997531 968 leveldb.cpp:196] Created db iterator in 19825ns
I0129 19:54:20.997552 968 leveldb.cpp:202] Seeked to beginning of db in 1955ns
I0129 19:54:20.997565 968 leveldb.cpp:271] Iterated through 0 keys in the db in 310ns
I0129 19:54:20.997609 968 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 19:54:20.998302 996 recover.cpp:447] Starting replica recovery
I0129 19:54:20.998720 989 recover.cpp:473] Replica is in EMPTY status
I0129 19:54:20.999891 1002 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14153)@172.17.0.4:43331
I0129 19:54:21.000393 998 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 19:54:21.000833 996 recover.cpp:564] Updating replica status to STARTING
I0129 19:54:21.001600 989 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 487056ns
I0129 19:54:21.001629 989 replica.cpp:320] Persisted replica status to STARTING
I0129 19:54:21.001762 996 master.cpp:374] Master 75466650-49f2-4441-b87e-d3b6c651802c (31ea9d77aa96) started on 172.17.0.4:43331
I0129 19:54:21.001863 989 recover.cpp:473] Replica is in STARTING status
I0129 19:54:21.001786 996 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/PDUVyn/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.28.0/_inst/share/mesos/webui" --work_dir="/tmp/PDUVyn/master" --zk_session_timeout="10secs"
I0129 19:54:21.002127 996 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 19:54:21.002146 996 master.cpp:426] Master only allowing authenticated slaves to register
I0129 19:54:21.002158 996 credentials.hpp:35] Loading credentials for authentication from '/tmp/PDUVyn/credentials'
I0129 19:54:21.002454 996 master.cpp:466] Using default 'crammd5' authenticator
I0129 19:54:21.002593 996 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 19:54:21.002851 996 master.cpp:569] Authorization enabled
I0129 19:54:21.003382 993 whitelist_watcher.cpp:77] No whitelist given
I0129 19:54:21.003401 992 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 19:54:21.003499 995 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14155)@172.17.0.4:43331
I0129 19:54:21.003890 1000 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 19:54:21.004560 1002 recover.cpp:564] Updating replica status to VOTING
I0129 19:54:21.005240 991 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 459222ns
I0129 19:54:21.005295 991 replica.cpp:320] Persisted replica status to VOTING
I0129 19:54:21.005539 1002 recover.cpp:578] Successfully joined the Paxos group
I0129 19:54:21.005900 1002 recover.cpp:462] Recover process terminated
I0129 19:54:21.006870 999 master.cpp:1710] The newly elected leader is master@172.17.0.4:43331 with id 75466650-49f2-4441-b87e-d3b6c651802c
I0129 19:54:21.006916 999 master.cpp:1723] Elected as the leading master!
I0129 19:54:21.006942 999 master.cpp:1468] Recovering from registrar
I0129 19:54:21.007107 1002 registrar.cpp:307] Recovering registrar
I0129 19:54:21.008183 998 log.cpp:659] Attempting to start the writer
I0129 19:54:21.009821 988 replica.cpp:493] Replica received implicit promise request from (14156)@172.17.0.4:43331 with proposal 1
I0129 19:54:21.010311 988 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 449630ns
I0129 19:54:21.010344 988 replica.cpp:342] Persisted promised to 1
I0129 19:54:21.011107 1002 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 19:54:21.012635 988 replica.cpp:388] Replica received explicit promise request from (14157)@172.17.0.4:43331 for position 0 with proposal 2
I0129 19:54:21.013186 988 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 499324ns
I0129 19:54:21.013221 988 replica.cpp:712] Persisted action at 0
I0129 19:54:21.014659 1001 replica.cpp:537] Replica received write request for position 0 from (14158)@172.17.0.4:43331
I0129 19:54:21.014741 1001 leveldb.cpp:436] Reading position from leveldb took 34659ns
I0129 19:54:21.015154 1001 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 364334ns
I0129 19:54:21.015187 1001 replica.cpp:712] Persisted action at 0
I0129 19:54:21.015852 1002 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 19:54:21.016269 1002 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 372949ns
I0129 19:54:21.016301 1002 replica.cpp:712] Persisted action at 0
I0129 19:54:21.016324 1002 replica.cpp:697] Replica learned NOP action at position 0
I0129 19:54:21.016983 999 log.cpp:675] Writer started with ending position 0
I0129 19:54:21.018355 989 leveldb.cpp:436] Reading position from leveldb took 35257ns
I0129 19:54:21.019433 1001 registrar.cpp:340] Successfully fetched the registry (0B) in 12.272128ms
I0129 19:54:21.019559 1001 registrar.cpp:439] Applied 1 operations in 30151ns; attempting to update the 'registry'
I0129 19:54:21.020428 989 log.cpp:683] Attempting to append 170 bytes to the log
I0129 19:54:21.020581 996 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 19:54:21.021515 996 replica.cpp:537] Replica received write request for position 1 from (14159)@172.17.0.4:43331
I0129 19:54:21.022133 996 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 571282ns
I0129 19:54:21.022167 996 replica.cpp:712] Persisted action at 1
I0129 19:54:21.022930 988 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 19:54:21.023591 988 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 617976ns
I0129 19:54:21.023624 988 replica.cpp:712] Persisted action at 1
I0129 19:54:21.023646 988 replica.cpp:697] Replica learned APPEND action at position 1
I0129 19:54:21.024837 992 registrar.cpp:484] Successfully updated the 'registry' in 5.202944ms
I0129 19:54:21.025048 992 registrar.cpp:370] Successfully recovered registrar
I0129 19:54:21.025177 993 log.cpp:702] Attempting to truncate the log to 1
I0129 19:54:21.025591 1002 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 19:54:21.025629 1000 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 19:54:21.025740 1002 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 19:54:21.026867 988 replica.cpp:537] Replica received write request for position 2 from (14160)@172.17.0.4:43331
I0129 19:54:21.027497 988 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 584149ns
I0129 19:54:21.027529 988 replica.cpp:712] Persisted action at 2
I0129 19:54:21.028458 994 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 19:54:21.029014 994 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 521406ns
I0129 19:54:21.029114 994 leveldb.cpp:399] Deleting ~1 keys from leveldb took 61439ns
I0129 19:54:21.029144 994 replica.cpp:712] Persisted action at 2
I0129 19:54:21.029172 994 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 19:54:21.036303 968 scheduler.cpp:154] Version: 0.28.0
I0129 19:54:21.036963 990 scheduler.cpp:236] New master detected at master@172.17.0.4:43331
I0129 19:54:21.038348 992 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:43331
I0129 19:54:21.040298 1000 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 19:54:21.040690 995 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:43931
I0129 19:54:21.040854 995 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 19:54:21.040909 995 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 19:54:21.041182 994 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 19:54:21.041555 991 hierarchical.cpp:265] Added framework 75466650-49f2-4441-b87e-d3b6c651802c-0000
I0129 19:54:21.041628 991 hierarchical.cpp:1403] No resources available to allocate!
I0129 19:54:21.041630 994 master.hpp:1658] Sending heartbeat to 75466650-49f2-4441-b87e-d3b6c651802c-0000
I0129 19:54:21.041671 991 hierarchical.cpp:1498] No inverse offers to send out!
I0129 19:54:21.041698 991 hierarchical.cpp:1096] Performed allocation for 0 slaves in 116239ns
I0129 19:54:21.042273 996 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:43331
I0129 19:54:21.042665 996 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:43331
I0129 19:54:21.043419 992 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 19:54:21.043509 996 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:43331
I0129 19:54:21.045189 994 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 19:54:21.045650 1000 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:43932
I0129 19:54:21.045786 1000 master.cpp:2717] Processing REQUEST call for framework 75466650-49f2-4441-b87e-d3b6c651802c-0000 (default)
I0129 19:54:21.045966 994 hierarchical.cpp:589] Received resource request from framework 75466650-49f2-4441-b87e-d3b6c651802c-0000
I0129 19:54:21.046416 999 master.cpp:1025] Master terminating
I0129 19:54:21.046655 1001 hierarchical.cpp:326] Removed framework 75466650-49f2-4441-b87e-d3b6c651802c-0000
E0129 19:54:21.047761 990 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (61 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0129 19:54:21.057546 968 leveldb.cpp:174] Opened db in 3.075225ms
I0129 19:54:21.058589 968 leveldb.cpp:181] Compacted db in 1.002252ms
I0129 19:54:21.058650 968 leveldb.cpp:196] Created db iterator in 16867ns
I0129 19:54:21.058670 968 leveldb.cpp:202] Seeked to beginning of db in 1750ns
I0129 19:54:21.058682 968 leveldb.cpp:271] Iterated through 0 keys in the db in 290ns
I0129 19:54:21.058722 968 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 19:54:21.059322 1000 recover.cpp:447] Starting replica recovery
I0129 19:54:21.059598 1000 recover.cpp:473] Replica is in EMPTY status
I0129 19:54:21.060968 1000 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14168)@172.17.0.4:43331
I0129 19:54:21.061398 995 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 19:54:21.061960 987 recover.cpp:564] Updating replica status to STARTING
I0129 19:54:21.062839 988 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 658857ns
I0129 19:54:21.062875 988 replica.cpp:320] Persisted replica status to STARTING
I0129 19:54:21.063197 991 recover.cpp:473] Replica is in STARTING status
I0129 19:54:21.063253 999 master.cpp:374] Master b243e52e-9f55-41b9-b06e-50b3a923c0cc (31ea9d77aa96) started on 172.17.0.4:43331
I0129 19:54:21.063283 999 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/1zkOuB/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.28.0/_inst/share/mesos/webui" --work_dir="/tmp/1zkOuB/master" --zk_session_timeout="10secs"
I0129 19:54:21.063694 999 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 19:54:21.063712 999 master.cpp:426] Master only allowing authenticated slaves to register
I0129 19:54:21.063729 999 credentials.hpp:35] Loading credentials for authentication from '/tmp/1zkOuB/credentials'
I0129 19:54:21.064193 999 master.cpp:466] Using default 'crammd5' authenticator
I0129 19:54:21.064385 999 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 19:54:21.064579 999 master.cpp:569] Authorization enabled
I0129 19:54:21.064615 1001 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14169)@172.17.0.4:43331
I0129 19:54:21.064800 992 whitelist_watcher.cpp:77] No whitelist given
I0129 19:54:21.064807 993 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 19:54:21.064857 995 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 19:54:21.065428 993 recover.cpp:564] Updating replica status to VOTING
I0129 19:54:21.066047 988 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 345437ns
I0129 19:54:21.066095 988 replica.cpp:320] Persisted replica status to VOTING
I0129 19:54:21.066232 997 recover.cpp:578] Successfully joined the Paxos group
I0129 19:54:21.066498 997 recover.cpp:462] Recover process terminated
I0129 19:54:21.067276 1000 master.cpp:1710] The newly elected leader is master@172.17.0.4:43331 with id b243e52e-9f55-41b9-b06e-50b3a923c0cc
I0129 19:54:21.067314 1000 master.cpp:1723] Elected as the leading master!
I0129 19:54:21.067333 1000 master.cpp:1468] Recovering from registrar
I0129 19:54:21.067489 992 registrar.cpp:307] Recovering registrar
I0129 19:54:21.068238 997 log.cpp:659] Attempting to start the writer
I0129 19:54:21.069591 990 replica.cpp:493] Replica received implicit promise request from (14171)@172.17.0.4:43331 with proposal 1
I0129 19:54:21.070072 990 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 424525ns
I0129 19:54:21.070109 990 replica.cpp:342] Persisted promised to 1
I0129 19:54:21.070767 1002 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 19:54:21.072166 989 replica.cpp:388] Replica received explicit promise request from (14172)@172.17.0.4:43331 for position 0 with proposal 2
I0129 19:54:21.072628 989 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 415641ns
I0129 19:54:21.072665 989 replica.cpp:712] Persisted action at 0
I0129 19:54:21.073884 990 replica.cpp:537] Replica received write request for position 0 from (14173)@172.17.0.4:43331
I0129 19:54:21.073947 990 leveldb.cpp:436] Reading position from leveldb took 28745ns
I0129 19:54:21.074362 990 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 369063ns
I0129 19:54:21.074393 990 replica.cpp:712] Persisted action at 0
I0129 19:54:21.075104 989 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 19:54:21.075639 989 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 499819ns
I0129 19:54:21.075670 989 replica.cpp:712] Persisted action at 0
I0129 19:54:21.075690 989 replica.cpp:697] Replica learned NOP action at position 0
I0129 19:54:21.076397 996 log.cpp:675] Writer started with ending position 0
I0129 19:54:21.077538 989 leveldb.cpp:436] Reading position from leveldb took 34957ns
I0129 19:54:21.078568 987 registrar.cpp:340] Successfully fetched the registry (0B) in 11.02208ms
I0129 19:54:21.078683 987 registrar.cpp:439] Applied 1 operations in 25939ns; attempting to update the 'registry'
I0129 19:54:21.079491 995 log.cpp:683] Attempting to append 170 bytes to the log
I0129 19:54:21.079700 993 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 19:54:21.080508 1001 replica.cpp:537] Replica received write request for position 1 from (14174)@172.17.0.4:43331
I0129 19:54:21.080972 1001 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 419813ns
I0129 19:54:21.081003 1001 replica.cpp:712] Persisted action at 1
I0129 19:54:21.081830 987 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 19:54:21.082397 987 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 529118ns
I0129 19:54:21.082430 987 replica.cpp:712] Persisted action at 1
I0129 19:54:21.082453 987 replica.cpp:697] Replica learned APPEND action at position 1
I0129 19:54:21.083652 994 registrar.cpp:484] Successfully updated the 'registry' in 4.905984ms
I0129 19:54:21.083802 998 log.cpp:702] Attempting to truncate the log to 1
I0129 19:54:21.083818 994 registrar.cpp:370] Successfully recovered registrar
I0129 19:54:21.083952 996 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 19:54:21.084503 997 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 19:54:21.084533 989 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 19:54:21.085273 1000 replica.cpp:537] Replica received write request for position 2 from (14175)@172.17.0.4:43331
I0129 19:54:21.085682 1000 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 360695ns
I0129 19:54:21.085714 1000 replica.cpp:712] Persisted action at 2
I0129 19:54:21.086357 1001 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 19:54:21.086802 1001 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 401808ns
I0129 19:54:21.086868 1001 leveldb.cpp:399] Deleting ~1 keys from leveldb took 33749ns
I0129 19:54:21.086892 1001 replica.cpp:712] Persisted action at 2
I0129 19:54:21.086916 1001 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 19:54:21.095288 968 scheduler.cpp:154] Version: 0.28.0
I0129 19:54:21.096158 991 scheduler.cpp:236] New master detected at master@172.17.0.4:43331
I0129 19:54:21.097352 992 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:43331
I0129 19:54:21.099517 994 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 19:54:21.100302 989 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:43933
I0129 19:54:21.100719 989 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 19:54:21.100785 989 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 19:54:21.101125 989 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 19:54:21.101596 995 hierarchical.cpp:265] Added framework b243e52e-9f55-41b9-b06e-50b3a923c0cc-0000
I0129 19:54:21.101686 995 hierarchical.cpp:1403] No resources available to allocate!
I0129 19:54:21.101711 998 master.hpp:1658] Sending heartbeat to b243e52e-9f55-41b9-b06e-50b3a923c0cc-0000
I0129 19:54:21.101738 995 hierarchical.cpp:1498] No inverse offers to send out!
I0129 19:54:21.101778 995 hierarchical.cpp:1096] Performed allocation for 0 slaves in 145891ns
I0129 19:54:21.102943 1000 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:43331
I0129 19:54:21.103565 1000 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:43331
I0129 19:54:21.104210 992 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 19:54:21.104251 1000 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:43331
I0129 19:54:21.106369 989 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 19:54:21.106839 994 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:43934
I0129 19:54:21.107141 994 master.cpp:2717] Processing REQUEST call for framework b243e52e-9f55-41b9-b06e-50b3a923c0cc-0000 (default)
I0129 19:54:21.107372 991 hierarchical.cpp:589] Received resource request from framework b243e52e-9f55-41b9-b06e-50b3a923c0cc-0000
I0129 19:54:21.107848 968 master.cpp:1025] Master terminating
I0129 19:54:21.108204 997 hierarchical.cpp:326] Removed framework b243e52e-9f55-41b9-b06e-50b3a923c0cc-0000
E0129 19:54:21.109509 1002 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (62 ms)
[----------] 22 tests from ContentType/SchedulerTest (4333 ms total)
[----------] Global test environment tear-down
[==========] 962 tests from 126 test cases ran. (332256 ms total)
[ PASSED ] 961 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ShasumTest.SHA512SimpleFile
1 FAILED TEST
YOU HAVE 8 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1454095710-6030
Untagged: mesos-1454095710-6030:latest
Deleted: b6d8b4c2895ccb99b8d77c6df3c0ed7f6b0fa1aead3a964eab15e92c94433445
Deleted: d36c174e57bfc90842f1c558d8cfd526570015ff1a1649bcd126a8a73d6deec8
Deleted: 7e74ca567741fc858e64041f79dfcebc65fc591684257139348f8f6338a086c9
Deleted: 1b21cf106e48aa17da7d85ff46109cbbc1ca2bc986aadf646e1c72909383413f
Deleted: 3dcaf4af3ab92bc9bdf4299132605f40b1153134920b850147cccbdc37bdcbe4
Deleted: 2039ea0fbfb1f7fc8846fcc8e97d34c1e84cb70927854cfdd996119fafaebaf6
Deleted: ad07dd22ea2335e8437283db36dfdc558e0903224b6cd6ee48d4f3e90a4f255b
Deleted: c3a1ebf3db273d2f870b310370ad7f0b18ff07a70cad4c3c4081ccab9743a35b
Deleted: 9e084e093f4918f50ea880180910a3d7a0147ae16cd0c5d191acb7fa097af202
Deleted: 9a2ea74a778309e3473bfb3f4e655285ebaf89db8e66f7549a963e2440e8c34a
Deleted: b132a5a5e18f022316f29bd75e3677d758c6701b6b75f5287b4af74f9bb0a052
Deleted: 009b06b2ec08ce2e4f5d9596990769c8ff7a69295a6285dabb06bcd832d299be
Deleted: 30b3a9a4497ddf907a22bdfe59a567b3cc9a38b87622d55d9c99b16b4b5d5c91
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1585
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1585/>
------------------------------------------
Started by upstream project "Mesos" build number 1585
originally caused by:
Started by an SCM change
[EnvInject] - Loading node environment variables.
Building remotely on H2 (Mapreduce zookeeper Hadoop Pig falcon Hdfs) in workspace <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/ws/>
Cloning the remote Git repository
Using shallow clone
Cloning repository https://git-wip-us.apache.org/repos/asf/mesos.git
> git init <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/ws/> # timeout=10
Fetching upstream changes from https://git-wip-us.apache.org/repos/asf/mesos.git
> git --version # timeout=10
> git -c core.askpass=true fetch --tags --progress https://git-wip-us.apache.org/repos/asf/mesos.git +refs/heads/*:refs/remotes/origin/* --depth=1 # timeout=60
> git config remote.origin.url https://git-wip-us.apache.org/repos/asf/mesos.git # timeout=10
> git config --add remote.origin.fetch +refs/heads/*:refs/remotes/origin/* # timeout=10
> git config remote.origin.url https://git-wip-us.apache.org/repos/asf/mesos.git # timeout=10
Fetching upstream changes from https://git-wip-us.apache.org/repos/asf/mesos.git
> git -c core.askpass=true fetch --tags --progress https://git-wip-us.apache.org/repos/asf/mesos.git +refs/heads/*:refs/remotes/origin/* # timeout=60
Checking out Revision fac024fda0897a62377f17549e61b8ac8e531e2e (origin/master)
> git config core.sparsecheckout # timeout=10
> git checkout -f fac024fda0897a62377f17549e61b8ac8e531e2e
FATAL: Could not checkout fac024fda0897a62377f17549e61b8ac8e531e2e
hudson.plugins.git.GitException: Could not checkout fac024fda0897a62377f17549e61b8ac8e531e2e
at org.jenkinsci.plugins.gitclient.CliGitAPIImpl$9.execute(CliGitAPIImpl.java:1964)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:152)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:145)
at hudson.remoting.UserRequest.perform(UserRequest.java:121)
at hudson.remoting.UserRequest.perform(UserRequest.java:49)
at hudson.remoting.Request$2.run(Request.java:326)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:68)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
at ......remote call to H2(Native Method)
at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1413)
at hudson.remoting.UserResponse.retrieve(UserRequest.java:221)
at hudson.remoting.Channel.call(Channel.java:778)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler.execute(RemoteGitImpl.java:145)
at sun.reflect.GeneratedMethodAccessor533.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler.invoke(RemoteGitImpl.java:131)
at com.sun.proxy.$Proxy75.execute(Unknown Source)
at hudson.plugins.git.GitSCM.checkout(GitSCM.java:1081)
at hudson.scm.SCM.checkout(SCM.java:484)
at hudson.model.AbstractProject.checkout(AbstractProject.java:1274)
at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:609)
at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86)
at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:531)
at hudson.model.Run.execute(Run.java:1738)
at hudson.matrix.MatrixRun.run(MatrixRun.java:146)
at hudson.model.ResourceController.execute(ResourceController.java:98)
at hudson.model.Executor.run(Executor.java:381)
Caused by: hudson.plugins.git.GitException: Command "git checkout -f fac024fda0897a62377f17549e61b8ac8e531e2e" returned status code 128:
stdout:
stderr: fatal: reference is not a tree: fac024fda0897a62377f17549e61b8ac8e531e2e
at org.jenkinsci.plugins.gitclient.CliGitAPIImpl.launchCommandIn(CliGitAPIImpl.java:1693)
at org.jenkinsci.plugins.gitclient.CliGitAPIImpl.access$500(CliGitAPIImpl.java:62)
at org.jenkinsci.plugins.gitclient.CliGitAPIImpl$9.execute(CliGitAPIImpl.java:1956)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:152)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:145)
at hudson.remoting.UserRequest.perform(UserRequest.java:121)
at hudson.remoting.UserRequest.perform(UserRequest.java:49)
at hudson.remoting.Request$2.run(Request.java:326)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:68)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1584
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1584/>
------------------------------------------
[...truncated 159789 lines...]
I0129 08:27:06.025979 997 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_X03qBo/slaves/06fa67a4-8bad-4b07-b937-b61265c490cd-S0/frameworks/06fa67a4-8bad-4b07-b937-b61265c490cd-0000/executors/default' for gc 6.99999970048593days in the future
I0129 08:27:06.026029 993 status_update_manager.cpp:282] Closing status update streams for framework 06fa67a4-8bad-4b07-b937-b61265c490cd-0000
I0129 08:27:06.026126 993 status_update_manager.cpp:528] Cleaning up status update stream for task 9ab65ded-dcc1-4a26-ae5e-b83f8794f65a of framework 06fa67a4-8bad-4b07-b937-b61265c490cd-0000
I0129 08:27:06.026140 997 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_X03qBo/slaves/06fa67a4-8bad-4b07-b937-b61265c490cd-S0/frameworks/06fa67a4-8bad-4b07-b937-b61265c490cd-0000' for gc 6.99999969900444days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (111 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0129 08:27:06.034478 971 leveldb.cpp:174] Opened db in 3.482213ms
I0129 08:27:06.035583 971 leveldb.cpp:181] Compacted db in 1.063673ms
I0129 08:27:06.035642 971 leveldb.cpp:196] Created db iterator in 17544ns
I0129 08:27:06.035665 971 leveldb.cpp:202] Seeked to beginning of db in 1928ns
I0129 08:27:06.035676 971 leveldb.cpp:271] Iterated through 0 keys in the db in 275ns
I0129 08:27:06.035717 971 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 08:27:06.036255 1000 recover.cpp:447] Starting replica recovery
I0129 08:27:06.036681 998 recover.cpp:473] Replica is in EMPTY status
I0129 08:27:06.037839 1003 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14165)@172.17.0.3:41188
I0129 08:27:06.038384 1000 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 08:27:06.038919 993 recover.cpp:564] Updating replica status to STARTING
I0129 08:27:06.039700 1004 master.cpp:374] Master a82f8197-6d00-4956-b4c3-28b6a2d28a09 (03b959f17c49) started on 172.17.0.3:41188
I0129 08:27:06.040197 991 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.072063ms
I0129 08:27:06.040232 991 replica.cpp:320] Persisted replica status to STARTING
I0129 08:27:06.039847 1004 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/yNh7TU/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.28.0/_inst/share/mesos/webui" --work_dir="/tmp/yNh7TU/master" --zk_session_timeout="10secs"
I0129 08:27:06.040441 1004 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 08:27:06.040465 1004 master.cpp:426] Master only allowing authenticated slaves to register
I0129 08:27:06.040485 1004 credentials.hpp:35] Loading credentials for authentication from '/tmp/yNh7TU/credentials'
I0129 08:27:06.040506 1001 recover.cpp:473] Replica is in STARTING status
I0129 08:27:06.040828 1004 master.cpp:466] Using default 'crammd5' authenticator
I0129 08:27:06.040997 1004 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 08:27:06.041191 1004 master.cpp:569] Authorization enabled
I0129 08:27:06.041374 998 whitelist_watcher.cpp:77] No whitelist given
I0129 08:27:06.041399 990 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 08:27:06.041627 990 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14167)@172.17.0.3:41188
I0129 08:27:06.042078 992 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 08:27:06.042652 1005 recover.cpp:564] Updating replica status to VOTING
I0129 08:27:06.043332 1001 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 489672ns
I0129 08:27:06.043368 1001 replica.cpp:320] Persisted replica status to VOTING
I0129 08:27:06.043524 991 recover.cpp:578] Successfully joined the Paxos group
I0129 08:27:06.043642 1004 master.cpp:1710] The newly elected leader is master@172.17.0.3:41188 with id a82f8197-6d00-4956-b4c3-28b6a2d28a09
I0129 08:27:06.043675 1004 master.cpp:1723] Elected as the leading master!
I0129 08:27:06.043697 1004 master.cpp:1468] Recovering from registrar
I0129 08:27:06.043926 1001 registrar.cpp:307] Recovering registrar
I0129 08:27:06.044316 991 recover.cpp:462] Recover process terminated
I0129 08:27:06.045107 993 log.cpp:659] Attempting to start the writer
I0129 08:27:06.046458 995 replica.cpp:493] Replica received implicit promise request from (14168)@172.17.0.3:41188 with proposal 1
I0129 08:27:06.046886 995 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 384167ns
I0129 08:27:06.046916 995 replica.cpp:342] Persisted promised to 1
I0129 08:27:06.047569 1005 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 08:27:06.049031 998 replica.cpp:388] Replica received explicit promise request from (14169)@172.17.0.3:41188 for position 0 with proposal 2
I0129 08:27:06.049461 998 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 377057ns
I0129 08:27:06.049494 998 replica.cpp:712] Persisted action at 0
I0129 08:27:06.050839 997 replica.cpp:537] Replica received write request for position 0 from (14170)@172.17.0.3:41188
I0129 08:27:06.050925 997 leveldb.cpp:436] Reading position from leveldb took 39549ns
I0129 08:27:06.051401 997 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 412916ns
I0129 08:27:06.051434 997 replica.cpp:712] Persisted action at 0
I0129 08:27:06.052090 997 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 08:27:06.052640 997 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 508176ns
I0129 08:27:06.052673 997 replica.cpp:712] Persisted action at 0
I0129 08:27:06.052695 997 replica.cpp:697] Replica learned NOP action at position 0
I0129 08:27:06.053413 996 log.cpp:675] Writer started with ending position 0
I0129 08:27:06.054677 1004 leveldb.cpp:436] Reading position from leveldb took 34334ns
I0129 08:27:06.055778 992 registrar.cpp:340] Successfully fetched the registry (0B) in 11.792896ms
I0129 08:27:06.055894 992 registrar.cpp:439] Applied 1 operations in 25697ns; attempting to update the 'registry'
I0129 08:27:06.056710 995 log.cpp:683] Attempting to append 170 bytes to the log
I0129 08:27:06.056861 997 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 08:27:06.057726 994 replica.cpp:537] Replica received write request for position 1 from (14171)@172.17.0.3:41188
I0129 08:27:06.058207 994 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 433943ns
I0129 08:27:06.058238 994 replica.cpp:712] Persisted action at 1
I0129 08:27:06.058902 998 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 08:27:06.059476 998 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 531378ns
I0129 08:27:06.059509 998 replica.cpp:712] Persisted action at 1
I0129 08:27:06.059531 998 replica.cpp:697] Replica learned APPEND action at position 1
I0129 08:27:06.060856 990 registrar.cpp:484] Successfully updated the 'registry' in 4.893952ms
I0129 08:27:06.061139 1000 log.cpp:702] Attempting to truncate the log to 1
I0129 08:27:06.061097 990 registrar.cpp:370] Successfully recovered registrar
I0129 08:27:06.061326 998 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 08:27:06.062458 1000 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 08:27:06.062607 995 replica.cpp:537] Replica received write request for position 2 from (14172)@172.17.0.3:41188
I0129 08:27:06.062762 991 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 08:27:06.063169 995 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 504484ns
I0129 08:27:06.063201 995 replica.cpp:712] Persisted action at 2
I0129 08:27:06.064127 995 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 08:27:06.064777 995 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 529415ns
I0129 08:27:06.064846 995 leveldb.cpp:399] Deleting ~1 keys from leveldb took 34589ns
I0129 08:27:06.064878 995 replica.cpp:712] Persisted action at 2
I0129 08:27:06.064903 995 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 08:27:06.073142 971 scheduler.cpp:154] Version: 0.28.0
I0129 08:27:06.073796 996 scheduler.cpp:236] New master detected at master@172.17.0.3:41188
I0129 08:27:06.075006 997 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:41188
I0129 08:27:06.076910 992 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 08:27:06.077407 991 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:50875
I0129 08:27:06.077574 991 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 08:27:06.077626 991 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 08:27:06.077862 991 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 08:27:06.078263 1002 hierarchical.cpp:265] Added framework a82f8197-6d00-4956-b4c3-28b6a2d28a09-0000
I0129 08:27:06.078325 991 master.hpp:1658] Sending heartbeat to a82f8197-6d00-4956-b4c3-28b6a2d28a09-0000
I0129 08:27:06.078337 1002 hierarchical.cpp:1403] No resources available to allocate!
I0129 08:27:06.078367 1002 hierarchical.cpp:1498] No inverse offers to send out!
I0129 08:27:06.078393 1002 hierarchical.cpp:1096] Performed allocation for 0 slaves in 102347ns
I0129 08:27:06.079427 1000 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:41188
I0129 08:27:06.080235 1000 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:41188
I0129 08:27:06.080875 991 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 08:27:06.080906 1000 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:41188
I0129 08:27:06.082319 993 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 08:27:06.082697 998 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:50876
I0129 08:27:06.082805 998 master.cpp:2717] Processing REQUEST call for framework a82f8197-6d00-4956-b4c3-28b6a2d28a09-0000 (default)
I0129 08:27:06.082973 991 hierarchical.cpp:589] Received resource request from framework a82f8197-6d00-4956-b4c3-28b6a2d28a09-0000
I0129 08:27:06.083264 1000 master.cpp:1025] Master terminating
I0129 08:27:06.083427 997 hierarchical.cpp:326] Removed framework a82f8197-6d00-4956-b4c3-28b6a2d28a09-0000
E0129 08:27:06.084563 991 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (61 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0129 08:27:06.094828 971 leveldb.cpp:174] Opened db in 3.137629ms
I0129 08:27:06.095674 971 leveldb.cpp:181] Compacted db in 807209ns
I0129 08:27:06.095726 971 leveldb.cpp:196] Created db iterator in 17370ns
I0129 08:27:06.095757 971 leveldb.cpp:202] Seeked to beginning of db in 2488ns
I0129 08:27:06.095783 971 leveldb.cpp:271] Iterated through 0 keys in the db in 457ns
I0129 08:27:06.095846 971 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 08:27:06.096364 999 recover.cpp:447] Starting replica recovery
I0129 08:27:06.096716 999 recover.cpp:473] Replica is in EMPTY status
I0129 08:27:06.097586 1000 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14180)@172.17.0.3:41188
I0129 08:27:06.098021 1003 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 08:27:06.098537 997 recover.cpp:564] Updating replica status to STARTING
I0129 08:27:06.099241 995 master.cpp:374] Master 03771323-6bdc-4440-8d62-a8c070a8ceb7 (03b959f17c49) started on 172.17.0.3:41188
I0129 08:27:06.099258 991 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 561343ns
I0129 08:27:06.099282 991 replica.cpp:320] Persisted replica status to STARTING
I0129 08:27:06.099520 991 recover.cpp:473] Replica is in STARTING status
I0129 08:27:06.099266 995 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/siz6fL/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.28.0/_inst/share/mesos/webui" --work_dir="/tmp/siz6fL/master" --zk_session_timeout="10secs"
I0129 08:27:06.099719 995 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 08:27:06.099736 995 master.cpp:426] Master only allowing authenticated slaves to register
I0129 08:27:06.099748 995 credentials.hpp:35] Loading credentials for authentication from '/tmp/siz6fL/credentials'
I0129 08:27:06.100103 995 master.cpp:466] Using default 'crammd5' authenticator
I0129 08:27:06.100260 995 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 08:27:06.100411 995 master.cpp:569] Authorization enabled
I0129 08:27:06.100435 993 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14181)@172.17.0.3:41188
I0129 08:27:06.100600 1003 whitelist_watcher.cpp:77] No whitelist given
I0129 08:27:06.100616 1000 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 08:27:06.100672 1003 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 08:27:06.101143 1001 recover.cpp:564] Updating replica status to VOTING
I0129 08:27:06.101698 1005 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 382531ns
I0129 08:27:06.101727 1005 replica.cpp:320] Persisted replica status to VOTING
I0129 08:27:06.101865 994 recover.cpp:578] Successfully joined the Paxos group
I0129 08:27:06.102196 994 recover.cpp:462] Recover process terminated
I0129 08:27:06.102479 994 master.cpp:1710] The newly elected leader is master@172.17.0.3:41188 with id 03771323-6bdc-4440-8d62-a8c070a8ceb7
I0129 08:27:06.102511 994 master.cpp:1723] Elected as the leading master!
I0129 08:27:06.102530 994 master.cpp:1468] Recovering from registrar
I0129 08:27:06.102726 993 registrar.cpp:307] Recovering registrar
I0129 08:27:06.103349 997 log.cpp:659] Attempting to start the writer
I0129 08:27:06.104578 999 replica.cpp:493] Replica received implicit promise request from (14183)@172.17.0.3:41188 with proposal 1
I0129 08:27:06.104971 999 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 354723ns
I0129 08:27:06.105005 999 replica.cpp:342] Persisted promised to 1
I0129 08:27:06.105939 1002 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 08:27:06.107339 990 replica.cpp:388] Replica received explicit promise request from (14184)@172.17.0.3:41188 for position 0 with proposal 2
I0129 08:27:06.107702 990 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 320313ns
I0129 08:27:06.107729 990 replica.cpp:712] Persisted action at 0
I0129 08:27:06.109144 1002 replica.cpp:537] Replica received write request for position 0 from (14185)@172.17.0.3:41188
I0129 08:27:06.109242 1002 leveldb.cpp:436] Reading position from leveldb took 31109ns
I0129 08:27:06.109668 1002 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 366977ns
I0129 08:27:06.109727 1002 replica.cpp:712] Persisted action at 0
I0129 08:27:06.110627 993 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 08:27:06.111099 993 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 425626ns
I0129 08:27:06.111134 993 replica.cpp:712] Persisted action at 0
I0129 08:27:06.111181 993 replica.cpp:697] Replica learned NOP action at position 0
I0129 08:27:06.111980 1002 log.cpp:675] Writer started with ending position 0
I0129 08:27:06.113456 1001 leveldb.cpp:436] Reading position from leveldb took 36384ns
I0129 08:27:06.114610 1000 registrar.cpp:340] Successfully fetched the registry (0B) in 11.832064ms
I0129 08:27:06.114807 1000 registrar.cpp:439] Applied 1 operations in 34594ns; attempting to update the 'registry'
I0129 08:27:06.115870 999 log.cpp:683] Attempting to append 170 bytes to the log
I0129 08:27:06.116070 1004 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 08:27:06.117250 1003 replica.cpp:537] Replica received write request for position 1 from (14186)@172.17.0.3:41188
I0129 08:27:06.117704 1003 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 413927ns
I0129 08:27:06.117735 1003 replica.cpp:712] Persisted action at 1
I0129 08:27:06.118422 993 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 08:27:06.118829 993 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 359794ns
I0129 08:27:06.118865 993 replica.cpp:712] Persisted action at 1
I0129 08:27:06.118886 993 replica.cpp:697] Replica learned APPEND action at position 1
I0129 08:27:06.119993 997 registrar.cpp:484] Successfully updated the 'registry' in 5.101824ms
I0129 08:27:06.120179 992 log.cpp:702] Attempting to truncate the log to 1
I0129 08:27:06.120299 997 registrar.cpp:370] Successfully recovered registrar
I0129 08:27:06.120339 1004 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 08:27:06.120929 1002 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 08:27:06.120961 996 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 08:27:06.121312 993 replica.cpp:537] Replica received write request for position 2 from (14187)@172.17.0.3:41188
I0129 08:27:06.121709 993 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 349162ns
I0129 08:27:06.121745 993 replica.cpp:712] Persisted action at 2
I0129 08:27:06.122773 1000 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 08:27:06.123308 1000 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 477913ns
I0129 08:27:06.123370 1000 leveldb.cpp:399] Deleting ~1 keys from leveldb took 33634ns
I0129 08:27:06.123399 1000 replica.cpp:712] Persisted action at 2
I0129 08:27:06.123420 1000 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 08:27:06.131912 971 scheduler.cpp:154] Version: 0.28.0
I0129 08:27:06.132555 991 scheduler.cpp:236] New master detected at master@172.17.0.3:41188
I0129 08:27:06.133699 999 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:41188
I0129 08:27:06.136124 1004 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 08:27:06.136677 1002 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:50877
I0129 08:27:06.137084 1002 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 08:27:06.137182 1002 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 08:27:06.137536 1004 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 08:27:06.137976 997 hierarchical.cpp:265] Added framework 03771323-6bdc-4440-8d62-a8c070a8ceb7-0000
I0129 08:27:06.138072 997 hierarchical.cpp:1403] No resources available to allocate!
I0129 08:27:06.138089 998 master.hpp:1658] Sending heartbeat to 03771323-6bdc-4440-8d62-a8c070a8ceb7-0000
I0129 08:27:06.138116 997 hierarchical.cpp:1498] No inverse offers to send out!
I0129 08:27:06.138149 997 hierarchical.cpp:1096] Performed allocation for 0 slaves in 136532ns
I0129 08:27:06.139600 997 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:41188
I0129 08:27:06.140082 997 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:41188
I0129 08:27:06.140732 1005 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 08:27:06.140789 997 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:41188
I0129 08:27:06.142530 992 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 08:27:06.143067 1004 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:50878
I0129 08:27:06.143417 1004 master.cpp:2717] Processing REQUEST call for framework 03771323-6bdc-4440-8d62-a8c070a8ceb7-0000 (default)
I0129 08:27:06.143569 991 hierarchical.cpp:589] Received resource request from framework 03771323-6bdc-4440-8d62-a8c070a8ceb7-0000
I0129 08:27:06.143909 998 master.cpp:1025] Master terminating
I0129 08:27:06.144263 999 hierarchical.cpp:326] Removed framework 03771323-6bdc-4440-8d62-a8c070a8ceb7-0000
E0129 08:27:06.146709 1001 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (61 ms)
[----------] 22 tests from ContentType/SchedulerTest (4127 ms total)
[----------] Global test environment tear-down
[==========] 962 tests from 126 test cases ran. (329444 ms total)
[ PASSED ] 961 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ShasumTest.SHA512SimpleFile
1 FAILED TEST
YOU HAVE 8 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1454054343-27006
Untagged: mesos-1454054343-27006:latest
Deleted: c5f850cf3657e23a67c3fda9b99a572f70c73da8ad6f76c120bdadc98a7a6bde
Deleted: 0f7473a15c30b4182e64607693a4dc03eec72dacb4d87ac525cb639abbc730f9
Deleted: 92a3d4cfae7dc5a013663067098295bec8517cb6ff2cfdaf03290785e752aee8
Deleted: fcfe4668fe0d6a74d2a67122797cd8891584fa04c1c432aba55793de5483b97b
Deleted: fadf073d4e2763d26b520711174927bed0635dee026e781cebe949f3004c1712
Deleted: a3abe3eae8eeaef8efeb1464cfd8670ff2301887457c2dda7ca94e1a2f2c6c98
Deleted: b33400d891351ff8aeee41af5a4f0650a1d5be732dc12707cf9dc142c1c4758e
Deleted: 499ff868ecc3a814b3cc578f501f55dcb2c2ac028fa6cb4fca985eecf78684fa
Deleted: 9fa0ccce8479b23eb9c2e35f2e37fa61d9787e82f3ffe68a45c5134d0d63b140
Deleted: 966677c2a6b46da3eba64615c7ab1e2f12f1b8b2e8eb40110f1a4a3fdf7fdaa4
Deleted: 7a3929c13df1d485944165309af492f58f1dda9f84e29462d44c78f00ebe237d
Deleted: e56cf47e8f14cf12783ed1344aa93ed5caeba60165dd8b9cbfad32f7bf797441
Deleted: 43a5e75888372c1f7b22d4db1e49700f2f464b539c4e2bf24f31089d8bd4cb4e
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1583
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1583/changes>
Changes:
[mpark] Windows: Unified POSIX and Windows implementation of `shell.hpp`.
[joris.van.remoortere] Windows: Made 'os::chown' a POSIX-only function.
[joris.van.remoortere] Windows: Ported slave/paths.cpp.
------------------------------------------
[...truncated 163478 lines...]
I0129 07:05:20.317147 992 status_update_manager.cpp:282] Closing status update streams for framework df3deeaa-ec9c-40ae-bc76-35e0513352dc-0000
I0129 07:05:20.317205 992 status_update_manager.cpp:528] Cleaning up status update stream for task e08a7ffe-9078-46fa-806e-9a65d29fa378 of framework df3deeaa-ec9c-40ae-bc76-35e0513352dc-0000
I0129 07:05:20.317225 993 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_24t1K2/slaves/df3deeaa-ec9c-40ae-bc76-35e0513352dc-S0/frameworks/df3deeaa-ec9c-40ae-bc76-35e0513352dc-0000' for gc 6.99999632912days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (773 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0129 07:05:20.439398 960 leveldb.cpp:174] Opened db in 117.732273ms
I0129 07:05:20.473487 960 leveldb.cpp:181] Compacted db in 34.014424ms
I0129 07:05:20.473585 960 leveldb.cpp:196] Created db iterator in 27833ns
I0129 07:05:20.473614 960 leveldb.cpp:202] Seeked to beginning of db in 11724ns
I0129 07:05:20.473631 960 leveldb.cpp:271] Iterated through 0 keys in the db in 565ns
I0129 07:05:20.473688 960 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 07:05:20.476989 993 recover.cpp:447] Starting replica recovery
I0129 07:05:20.477260 993 recover.cpp:473] Replica is in EMPTY status
I0129 07:05:20.477674 987 master.cpp:374] Master 192ac07c-583b-4b88-adc8-2387564f57f4 (5139a3fdaea6) started on 172.17.0.7:49985
I0129 07:05:20.477699 987 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/2l9hWA/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.28.0/_inst/share/mesos/webui" --work_dir="/tmp/2l9hWA/master" --zk_session_timeout="10secs"
I0129 07:05:20.478184 987 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 07:05:20.478199 987 master.cpp:426] Master only allowing authenticated slaves to register
I0129 07:05:20.478209 987 credentials.hpp:35] Loading credentials for authentication from '/tmp/2l9hWA/credentials'
I0129 07:05:20.480631 987 master.cpp:466] Using default 'crammd5' authenticator
I0129 07:05:20.480949 987 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 07:05:20.481120 987 master.cpp:569] Authorization enabled
I0129 07:05:20.481513 989 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 07:05:20.481698 986 whitelist_watcher.cpp:77] No whitelist given
I0129 07:05:20.484484 991 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14172)@172.17.0.7:49985
I0129 07:05:20.484999 984 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 07:05:20.486822 987 master.cpp:1710] The newly elected leader is master@172.17.0.7:49985 with id 192ac07c-583b-4b88-adc8-2387564f57f4
I0129 07:05:20.486858 987 master.cpp:1723] Elected as the leading master!
I0129 07:05:20.486879 987 master.cpp:1468] Recovering from registrar
I0129 07:05:20.487217 982 recover.cpp:564] Updating replica status to STARTING
I0129 07:05:20.487761 992 registrar.cpp:307] Recovering registrar
I0129 07:05:20.523839 993 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 36.349434ms
I0129 07:05:20.523900 993 replica.cpp:320] Persisted replica status to STARTING
I0129 07:05:20.524171 987 recover.cpp:473] Replica is in STARTING status
I0129 07:05:20.525315 981 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14174)@172.17.0.7:49985
I0129 07:05:20.525733 990 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 07:05:20.526141 982 recover.cpp:564] Updating replica status to VOTING
I0129 07:05:20.540953 980 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 14.684257ms
I0129 07:05:20.540989 980 replica.cpp:320] Persisted replica status to VOTING
I0129 07:05:20.541088 984 recover.cpp:578] Successfully joined the Paxos group
I0129 07:05:20.541862 980 log.cpp:659] Attempting to start the writer
I0129 07:05:20.543211 984 recover.cpp:462] Recover process terminated
I0129 07:05:20.543301 991 replica.cpp:493] Replica received implicit promise request from (14175)@172.17.0.7:49985 with proposal 1
I0129 07:05:20.566053 991 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.69607ms
I0129 07:05:20.566141 991 replica.cpp:342] Persisted promised to 1
I0129 07:05:20.567476 984 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 07:05:20.569027 994 replica.cpp:388] Replica received explicit promise request from (14176)@172.17.0.7:49985 for position 0 with proposal 2
I0129 07:05:20.591318 994 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.238783ms
I0129 07:05:20.591358 994 replica.cpp:712] Persisted action at 0
I0129 07:05:20.592808 980 replica.cpp:537] Replica received write request for position 0 from (14177)@172.17.0.7:49985
I0129 07:05:20.592998 980 leveldb.cpp:436] Reading position from leveldb took 152661ns
I0129 07:05:20.630771 980 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 37.713371ms
I0129 07:05:20.630810 980 replica.cpp:712] Persisted action at 0
I0129 07:05:20.631649 986 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 07:05:20.672616 986 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.864794ms
I0129 07:05:20.672732 986 replica.cpp:712] Persisted action at 0
I0129 07:05:20.672773 986 replica.cpp:697] Replica learned NOP action at position 0
I0129 07:05:20.674058 986 log.cpp:675] Writer started with ending position 0
I0129 07:05:20.675756 987 leveldb.cpp:436] Reading position from leveldb took 67278ns
I0129 07:05:20.677372 993 registrar.cpp:340] Successfully fetched the registry (0B) in 189.55904ms
I0129 07:05:20.677532 993 registrar.cpp:439] Applied 1 operations in 41056ns; attempting to update the 'registry'
I0129 07:05:20.678412 979 log.cpp:683] Attempting to append 170 bytes to the log
I0129 07:05:20.678777 986 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 07:05:20.679744 986 replica.cpp:537] Replica received write request for position 1 from (14178)@172.17.0.7:49985
I0129 07:05:20.714419 986 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 34.607073ms
I0129 07:05:20.714526 986 replica.cpp:712] Persisted action at 1
I0129 07:05:20.716116 992 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 07:05:20.747921 992 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 31.721108ms
I0129 07:05:20.748014 992 replica.cpp:712] Persisted action at 1
I0129 07:05:20.748059 992 replica.cpp:697] Replica learned APPEND action at position 1
I0129 07:05:20.750291 982 registrar.cpp:484] Successfully updated the 'registry' in 72.683008ms
I0129 07:05:20.750422 986 log.cpp:702] Attempting to truncate the log to 1
I0129 07:05:20.750953 989 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 07:05:20.752295 989 replica.cpp:537] Replica received write request for position 2 from (14179)@172.17.0.7:49985
I0129 07:05:20.752912 982 registrar.cpp:370] Successfully recovered registrar
I0129 07:05:20.753536 982 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 07:05:20.753831 981 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 07:05:20.789763 989 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 37.299746ms
I0129 07:05:20.789825 989 replica.cpp:712] Persisted action at 2
I0129 07:05:20.790840 990 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 07:05:20.823194 990 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 32.312479ms
I0129 07:05:20.823271 990 leveldb.cpp:399] Deleting ~1 keys from leveldb took 37304ns
I0129 07:05:20.823290 990 replica.cpp:712] Persisted action at 2
I0129 07:05:20.823319 990 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 07:05:20.825233 960 scheduler.cpp:154] Version: 0.28.0
I0129 07:05:20.825882 988 scheduler.cpp:236] New master detected at master@172.17.0.7:49985
I0129 07:05:20.827019 982 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.7:49985
I0129 07:05:20.829015 980 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 07:05:20.829498 994 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.7:35223
I0129 07:05:20.829723 994 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 07:05:20.829800 994 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 07:05:20.830067 994 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 07:05:20.830505 988 hierarchical.cpp:265] Added framework 192ac07c-583b-4b88-adc8-2387564f57f4-0000
I0129 07:05:20.830546 994 master.hpp:1658] Sending heartbeat to 192ac07c-583b-4b88-adc8-2387564f57f4-0000
I0129 07:05:20.830621 988 hierarchical.cpp:1403] No resources available to allocate!
I0129 07:05:20.830672 988 hierarchical.cpp:1498] No inverse offers to send out!
I0129 07:05:20.830708 988 hierarchical.cpp:1096] Performed allocation for 0 slaves in 173257ns
I0129 07:05:20.831465 992 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.7:49985
I0129 07:05:20.831904 992 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.7:49985
I0129 07:05:20.832553 984 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 07:05:20.832638 992 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.7:49985
I0129 07:05:20.834110 981 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 07:05:20.834620 980 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.7:35224
I0129 07:05:20.834744 980 master.cpp:2717] Processing REQUEST call for framework 192ac07c-583b-4b88-adc8-2387564f57f4-0000 (default)
I0129 07:05:20.834913 984 hierarchical.cpp:589] Received resource request from framework 192ac07c-583b-4b88-adc8-2387564f57f4-0000
I0129 07:05:20.835202 993 master.cpp:1025] Master terminating
I0129 07:05:20.835410 987 hierarchical.cpp:326] Removed framework 192ac07c-583b-4b88-adc8-2387564f57f4-0000
E0129 07:05:20.836450 990 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (529 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0129 07:05:20.951098 960 leveldb.cpp:174] Opened db in 100.321382ms
I0129 07:05:20.992856 960 leveldb.cpp:181] Compacted db in 41.674503ms
I0129 07:05:20.992957 960 leveldb.cpp:196] Created db iterator in 28941ns
I0129 07:05:20.992977 960 leveldb.cpp:202] Seeked to beginning of db in 3130ns
I0129 07:05:20.992990 960 leveldb.cpp:271] Iterated through 0 keys in the db in 338ns
I0129 07:05:20.993047 960 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 07:05:20.993944 979 recover.cpp:447] Starting replica recovery
I0129 07:05:20.994371 979 recover.cpp:473] Replica is in EMPTY status
I0129 07:05:20.996337 979 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14187)@172.17.0.7:49985
I0129 07:05:20.998137 985 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 07:05:20.998819 982 recover.cpp:564] Updating replica status to STARTING
I0129 07:05:21.001286 986 master.cpp:374] Master e14a9ba9-352a-4641-967e-ccf663175785 (5139a3fdaea6) started on 172.17.0.7:49985
I0129 07:05:21.001315 986 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/GgtaSN/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.28.0/_inst/share/mesos/webui" --work_dir="/tmp/GgtaSN/master" --zk_session_timeout="10secs"
I0129 07:05:21.001899 986 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 07:05:21.001914 986 master.cpp:426] Master only allowing authenticated slaves to register
I0129 07:05:21.001924 986 credentials.hpp:35] Loading credentials for authentication from '/tmp/GgtaSN/credentials'
I0129 07:05:21.016373 986 master.cpp:466] Using default 'crammd5' authenticator
I0129 07:05:21.016739 986 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 07:05:21.017099 986 master.cpp:569] Authorization enabled
I0129 07:05:21.017699 992 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 07:05:21.017776 981 whitelist_watcher.cpp:77] No whitelist given
I0129 07:05:21.021939 982 master.cpp:1710] The newly elected leader is master@172.17.0.7:49985 with id e14a9ba9-352a-4641-967e-ccf663175785
I0129 07:05:21.022311 982 master.cpp:1723] Elected as the leading master!
I0129 07:05:21.022516 982 master.cpp:1468] Recovering from registrar
I0129 07:05:21.023000 987 registrar.cpp:307] Recovering registrar
I0129 07:05:21.024278 985 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 25.322768ms
I0129 07:05:21.024499 985 replica.cpp:320] Persisted replica status to STARTING
I0129 07:05:21.025223 982 recover.cpp:473] Replica is in STARTING status
I0129 07:05:21.026968 985 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14189)@172.17.0.7:49985
I0129 07:05:21.027844 982 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 07:05:21.028590 994 recover.cpp:564] Updating replica status to VOTING
I0129 07:05:21.066501 994 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.531596ms
I0129 07:05:21.066566 994 replica.cpp:320] Persisted replica status to VOTING
I0129 07:05:21.066778 993 recover.cpp:578] Successfully joined the Paxos group
I0129 07:05:21.067039 993 recover.cpp:462] Recover process terminated
I0129 07:05:21.067613 984 log.cpp:659] Attempting to start the writer
I0129 07:05:21.069250 982 replica.cpp:493] Replica received implicit promise request from (14190)@172.17.0.7:49985 with proposal 1
I0129 07:05:21.100198 982 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.871757ms
I0129 07:05:21.100286 982 replica.cpp:342] Persisted promised to 1
I0129 07:05:21.101173 993 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 07:05:21.102542 982 replica.cpp:388] Replica received explicit promise request from (14191)@172.17.0.7:49985 for position 0 with proposal 2
I0129 07:05:21.133673 982 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 31.085776ms
I0129 07:05:21.133714 982 replica.cpp:712] Persisted action at 0
I0129 07:05:21.134943 993 replica.cpp:537] Replica received write request for position 0 from (14192)@172.17.0.7:49985
I0129 07:05:21.135084 993 leveldb.cpp:436] Reading position from leveldb took 38531ns
I0129 07:05:21.167094 993 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 31.95971ms
I0129 07:05:21.167127 993 replica.cpp:712] Persisted action at 0
I0129 07:05:21.167778 993 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 07:05:21.200703 993 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.888675ms
I0129 07:05:21.200747 993 replica.cpp:712] Persisted action at 0
I0129 07:05:21.200775 993 replica.cpp:697] Replica learned NOP action at position 0
I0129 07:05:21.201823 981 log.cpp:675] Writer started with ending position 0
I0129 07:05:21.203181 981 leveldb.cpp:436] Reading position from leveldb took 34386ns
I0129 07:05:21.204210 992 registrar.cpp:340] Successfully fetched the registry (0B) in 181.165056ms
I0129 07:05:21.204337 992 registrar.cpp:439] Applied 1 operations in 37259ns; attempting to update the 'registry'
I0129 07:05:21.205059 987 log.cpp:683] Attempting to append 170 bytes to the log
I0129 07:05:21.205179 988 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 07:05:21.205894 984 replica.cpp:537] Replica received write request for position 1 from (14193)@172.17.0.7:49985
I0129 07:05:21.243266 984 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 37.326409ms
I0129 07:05:21.243347 984 replica.cpp:712] Persisted action at 1
I0129 07:05:21.244546 984 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 07:05:21.276726 984 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.09389ms
I0129 07:05:21.276828 984 replica.cpp:712] Persisted action at 1
I0129 07:05:21.276867 984 replica.cpp:697] Replica learned APPEND action at position 1
I0129 07:05:21.278302 980 registrar.cpp:484] Successfully updated the 'registry' in 73.889024ms
I0129 07:05:21.278484 980 registrar.cpp:370] Successfully recovered registrar
I0129 07:05:21.278578 988 log.cpp:702] Attempting to truncate the log to 1
I0129 07:05:21.278781 980 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 07:05:21.279988 988 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 07:05:21.280038 990 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 07:05:21.280586 988 replica.cpp:537] Replica received write request for position 2 from (14194)@172.17.0.7:49985
I0129 07:05:21.318522 988 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 37.860909ms
I0129 07:05:21.318625 988 replica.cpp:712] Persisted action at 2
I0129 07:05:21.319478 993 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 07:05:21.351924 993 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 32.385837ms
I0129 07:05:21.352087 993 leveldb.cpp:399] Deleting ~1 keys from leveldb took 77066ns
I0129 07:05:21.352110 993 replica.cpp:712] Persisted action at 2
I0129 07:05:21.352144 993 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 07:05:21.361379 960 scheduler.cpp:154] Version: 0.28.0
I0129 07:05:21.362160 994 scheduler.cpp:236] New master detected at master@172.17.0.7:49985
I0129 07:05:21.363417 994 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.7:49985
I0129 07:05:21.365397 984 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 07:05:21.365905 988 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.7:35226
I0129 07:05:21.366355 988 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 07:05:21.366435 988 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 07:05:21.366770 988 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 07:05:21.367274 994 hierarchical.cpp:265] Added framework e14a9ba9-352a-4641-967e-ccf663175785-0000
I0129 07:05:21.367303 988 master.hpp:1658] Sending heartbeat to e14a9ba9-352a-4641-967e-ccf663175785-0000
I0129 07:05:21.367373 994 hierarchical.cpp:1403] No resources available to allocate!
I0129 07:05:21.367422 994 hierarchical.cpp:1498] No inverse offers to send out!
I0129 07:05:21.367460 994 hierarchical.cpp:1096] Performed allocation for 0 slaves in 155919ns
I0129 07:05:21.368165 991 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.7:49985
I0129 07:05:21.368664 991 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.7:49985
I0129 07:05:21.369375 992 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.7:49985
I0129 07:05:21.369397 979 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 07:05:21.370698 989 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 07:05:21.371177 984 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.7:35227
I0129 07:05:21.371430 984 master.cpp:2717] Processing REQUEST call for framework e14a9ba9-352a-4641-967e-ccf663175785-0000 (default)
I0129 07:05:21.371563 992 hierarchical.cpp:589] Received resource request from framework e14a9ba9-352a-4641-967e-ccf663175785-0000
I0129 07:05:21.371939 989 master.cpp:1025] Master terminating
I0129 07:05:21.372141 992 hierarchical.cpp:326] Removed framework e14a9ba9-352a-4641-967e-ccf663175785-0000
E0129 07:05:21.373358 993 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (529 ms)
[----------] 22 tests from ContentType/SchedulerTest (16647 ms total)
[----------] Global test environment tear-down
2016-01-29 07:05:22,539:960(0x7f5744b9c700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:38232] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
[==========] 962 tests from 126 test cases ran. (759569 ms total)
[ PASSED ] 961 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ShasumTest.SHA512SimpleFile
1 FAILED TEST
YOU HAVE 8 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1454048453-17410
Untagged: mesos-1454048453-17410:latest
Deleted: 75653344cc4531e6efa30ac72c4c41fac7ecaedbb7341b86154c7929c3ba216b
Deleted: 13a2065c26f6ae25f464b1012bb6ddaa9f329f1951164c071c3e82c4b4a5e905
Deleted: 19a310cdabdf2a03a2933986c2bc81d5b114c9e4abc8207d73107ef0895547a5
Deleted: 3bf6a1ec11608c2da9c951a30da1eaf0cbb7ed87eb9b9cfc4c343e85469155d4
Deleted: 7643eb7094fd35c7517e137d7940abc749e220e6dbbad0c8c13c1a0789421774
Deleted: c34598d3f05bd94202c75e0ee7f95bf9ed7563230cc270ae0238c177b64e2494
Deleted: 6b07536ac930e9701d9ae69276e144031f7035b6e243691e7668ef20973639c6
Deleted: 30119b152514531328bb4ee2b85a281fbf6798ff79f4a10c21a1f54e893ec69e
Deleted: 262938f15a0341491d1da8ea9400a85224ea6c24288120d7fea0a155053172d9
Deleted: 2e118e2fc2dd6eea721337cbdbde8665f3684356a5dbaeae0c73e7d7756e5150
Deleted: 83e70a6d7eea1de49f9cb372ef6429035bf90821a6c0d4b1ca07fb209dd3abb2
Deleted: 8b3cedd5768c0fff4433596b19167d6de15afe4ae1644fd50b7292816147d3bc
Deleted: d2244bafc1a546437b3580b589757199f5b1b166a364bd18b333c2be97ff16a8
Build step 'Execute shell' marked build as failure