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/08 00:34:26 UTC
Build failed in Jenkins: mesos-reviewbot #10657
See <https://builds.apache.org/job/mesos-reviewbot/10657/>
------------------------------------------
[...truncated 168053 lines...]
I0107 23:34:16.252367 31123 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_UlpaJe/slaves/ca22dfc2-3928-4a80-8c10-f4f23327d906-S0/frameworks/ca22dfc2-3928-4a80-8c10-f4f23327d906-0000' for gc 6.99999708210667days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (1138 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0107 23:34:16.372720 31102 leveldb.cpp:174] Opened db in 114.861266ms
I0107 23:34:16.415540 31102 leveldb.cpp:181] Compacted db in 42.73061ms
I0107 23:34:16.415663 31102 leveldb.cpp:196] Created db iterator in 32791ns
I0107 23:34:16.415689 31102 leveldb.cpp:202] Seeked to beginning of db in 3722ns
I0107 23:34:16.415704 31102 leveldb.cpp:271] Iterated through 0 keys in the db in 265ns
I0107 23:34:16.415765 31102 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0107 23:34:16.416625 31128 recover.cpp:447] Starting replica recovery
I0107 23:34:16.417080 31128 recover.cpp:473] Replica is in EMPTY status
I0107 23:34:16.419064 31121 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12997)@172.17.0.3:43021
I0107 23:34:16.419364 31133 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0107 23:34:16.419577 31121 master.cpp:365] Master 1ca1e2f0-6565-4ebd-a0d6-552f8d881c43 (21c22e4c1514) started on 172.17.0.3:43021
I0107 23:34:16.419601 31121 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/oz1D7m/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/oz1D7m/master" --zk_session_timeout="10secs"
I0107 23:34:16.419991 31121 master.cpp:414] Master allowing unauthenticated frameworks to register
I0107 23:34:16.420006 31121 master.cpp:417] Master only allowing authenticated slaves to register
I0107 23:34:16.420017 31121 credentials.hpp:35] Loading credentials for authentication from '/tmp/oz1D7m/credentials'
I0107 23:34:16.420052 31133 recover.cpp:564] Updating replica status to STARTING
I0107 23:34:16.420421 31121 master.cpp:456] Using default 'crammd5' authenticator
I0107 23:34:16.420578 31121 master.cpp:493] Authorization enabled
I0107 23:34:16.420760 31135 whitelist_watcher.cpp:77] No whitelist given
I0107 23:34:16.420819 31126 hierarchical.cpp:147] Initialized hierarchical allocator process
I0107 23:34:16.422737 31129 master.cpp:1629] The newly elected leader is master@172.17.0.3:43021 with id 1ca1e2f0-6565-4ebd-a0d6-552f8d881c43
I0107 23:34:16.422770 31129 master.cpp:1642] Elected as the leading master!
I0107 23:34:16.422785 31129 master.cpp:1387] Recovering from registrar
I0107 23:34:16.422921 31121 registrar.cpp:307] Recovering registrar
I0107 23:34:16.458389 31133 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.068249ms
I0107 23:34:16.458477 31133 replica.cpp:320] Persisted replica status to STARTING
I0107 23:34:16.458868 31126 recover.cpp:473] Replica is in STARTING status
I0107 23:34:16.460400 31124 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12998)@172.17.0.3:43021
I0107 23:34:16.460888 31128 recover.cpp:193] Received a recover response from a replica in STARTING status
I0107 23:34:16.461387 31121 recover.cpp:564] Updating replica status to VOTING
I0107 23:34:16.493383 31128 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.755336ms
I0107 23:34:16.493455 31128 replica.cpp:320] Persisted replica status to VOTING
I0107 23:34:16.493662 31122 recover.cpp:578] Successfully joined the Paxos group
I0107 23:34:16.493939 31122 recover.cpp:462] Recover process terminated
I0107 23:34:16.494500 31133 log.cpp:659] Attempting to start the writer
I0107 23:34:16.496036 31125 replica.cpp:493] Replica received implicit promise request from (12999)@172.17.0.3:43021 with proposal 1
I0107 23:34:16.524617 31125 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 28.528772ms
I0107 23:34:16.524690 31125 replica.cpp:342] Persisted promised to 1
I0107 23:34:16.525696 31121 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0107 23:34:16.527648 31131 replica.cpp:388] Replica received explicit promise request from (13000)@172.17.0.3:43021 for position 0 with proposal 2
I0107 23:34:16.567289 31131 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.421158ms
I0107 23:34:16.567384 31131 replica.cpp:712] Persisted action at 0
I0107 23:34:16.569049 31129 replica.cpp:537] Replica received write request for position 0 from (13001)@172.17.0.3:43021
I0107 23:34:16.569207 31129 leveldb.cpp:436] Reading position from leveldb took 85027ns
I0107 23:34:16.611002 31129 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 41.58128ms
I0107 23:34:16.611088 31129 replica.cpp:712] Persisted action at 0
I0107 23:34:16.612165 31134 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0107 23:34:16.651104 31134 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.871279ms
I0107 23:34:16.651410 31134 replica.cpp:712] Persisted action at 0
I0107 23:34:16.651644 31134 replica.cpp:697] Replica learned NOP action at position 0
I0107 23:34:16.653230 31126 log.cpp:675] Writer started with ending position 0
I0107 23:34:16.654934 31131 leveldb.cpp:436] Reading position from leveldb took 68918ns
I0107 23:34:16.656569 31132 registrar.cpp:340] Successfully fetched the registry (0B) in 233.584896ms
I0107 23:34:16.656900 31132 registrar.cpp:439] Applied 1 operations in 106721ns; attempting to update the 'registry'
I0107 23:34:16.657894 31132 log.cpp:683] Attempting to append 170 bytes to the log
I0107 23:34:16.658157 31125 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0107 23:34:16.659378 31122 replica.cpp:537] Replica received write request for position 1 from (13002)@172.17.0.3:43021
I0107 23:34:16.697870 31122 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 38.409998ms
I0107 23:34:16.698191 31122 replica.cpp:712] Persisted action at 1
I0107 23:34:16.699434 31122 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0107 23:34:16.740277 31122 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.613059ms
I0107 23:34:16.740356 31122 replica.cpp:712] Persisted action at 1
I0107 23:34:16.740387 31122 replica.cpp:697] Replica learned APPEND action at position 1
I0107 23:34:16.741952 31132 registrar.cpp:484] Successfully updated the 'registry' in 84.900096ms
I0107 23:34:16.742110 31132 registrar.cpp:370] Successfully recovered registrar
I0107 23:34:16.742290 31133 log.cpp:702] Attempting to truncate the log to 1
I0107 23:34:16.742568 31123 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0107 23:34:16.742744 31126 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0107 23:34:16.742760 31132 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0107 23:34:16.743850 31131 replica.cpp:537] Replica received write request for position 2 from (13003)@172.17.0.3:43021
I0107 23:34:16.779322 31131 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 35.407785ms
I0107 23:34:16.779405 31131 replica.cpp:712] Persisted action at 2
I0107 23:34:16.780501 31134 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0107 23:34:16.804901 31134 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.343755ms
I0107 23:34:16.805030 31134 leveldb.cpp:399] Deleting ~1 keys from leveldb took 57678ns
I0107 23:34:16.805060 31134 replica.cpp:712] Persisted action at 2
I0107 23:34:16.805100 31134 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0107 23:34:16.814170 31102 scheduler.cpp:154] Version: 0.27.0
I0107 23:34:16.814853 31129 scheduler.cpp:236] New master detected at master@172.17.0.3:43021
I0107 23:34:16.816278 31122 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:43021
I0107 23:34:16.818550 31128 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 23:34:16.819265 31129 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:36763
I0107 23:34:16.819500 31129 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0107 23:34:16.819577 31129 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0107 23:34:16.819957 31129 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0107 23:34:16.820544 31132 hierarchical.cpp:260] Added framework 1ca1e2f0-6565-4ebd-a0d6-552f8d881c43-0000
I0107 23:34:16.820583 31123 master.hpp:1662] Sending heartbeat to 1ca1e2f0-6565-4ebd-a0d6-552f8d881c43-0000
I0107 23:34:16.820729 31132 hierarchical.cpp:1329] No resources available to allocate!
I0107 23:34:16.820821 31132 hierarchical.cpp:1423] No inverse offers to send out!
I0107 23:34:16.821221 31132 hierarchical.cpp:1079] Performed allocation for 0 slaves in 544163ns
I0107 23:34:16.821599 31135 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:43021
I0107 23:34:16.822186 31135 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:43021
I0107 23:34:16.822890 31122 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0107 23:34:16.823057 31128 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:43021
I0107 23:34:16.824923 31122 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 23:34:16.825347 31126 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:36764
I0107 23:34:16.825474 31126 master.cpp:2636] Processing REQUEST call for framework 1ca1e2f0-6565-4ebd-a0d6-552f8d881c43-0000 (default)
I0107 23:34:16.825667 31124 hierarchical.cpp:579] Received resource request from framework 1ca1e2f0-6565-4ebd-a0d6-552f8d881c43-0000
I0107 23:34:16.825969 31136 master.cpp:930] Master terminating
I0107 23:34:16.826251 31128 hierarchical.cpp:321] Removed framework 1ca1e2f0-6565-4ebd-a0d6-552f8d881c43-0000
E0107 23:34:16.827256 31136 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (576 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0107 23:34:16.938714 31102 leveldb.cpp:174] Opened db in 104.28282ms
I0107 23:34:17.006554 31102 leveldb.cpp:181] Compacted db in 67.759388ms
I0107 23:34:17.006657 31102 leveldb.cpp:196] Created db iterator in 30686ns
I0107 23:34:17.006682 31102 leveldb.cpp:202] Seeked to beginning of db in 3925ns
I0107 23:34:17.006698 31102 leveldb.cpp:271] Iterated through 0 keys in the db in 589ns
I0107 23:34:17.006765 31102 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0107 23:34:17.007534 31134 recover.cpp:447] Starting replica recovery
I0107 23:34:17.007835 31134 recover.cpp:473] Replica is in EMPTY status
I0107 23:34:17.008852 31127 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13011)@172.17.0.3:43021
I0107 23:34:17.009318 31134 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0107 23:34:17.009817 31133 recover.cpp:564] Updating replica status to STARTING
I0107 23:34:17.010741 31127 master.cpp:365] Master cf703e5a-e992-4962-95de-78a7194f8d76 (21c22e4c1514) started on 172.17.0.3:43021
I0107 23:34:17.010782 31127 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/xFoujM/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/xFoujM/master" --zk_session_timeout="10secs"
I0107 23:34:17.011207 31127 master.cpp:414] Master allowing unauthenticated frameworks to register
I0107 23:34:17.011229 31127 master.cpp:417] Master only allowing authenticated slaves to register
I0107 23:34:17.011241 31127 credentials.hpp:35] Loading credentials for authentication from '/tmp/xFoujM/credentials'
I0107 23:34:17.011590 31127 master.cpp:456] Using default 'crammd5' authenticator
I0107 23:34:17.011772 31127 master.cpp:493] Authorization enabled
I0107 23:34:17.011978 31132 hierarchical.cpp:147] Initialized hierarchical allocator process
I0107 23:34:17.012015 31123 whitelist_watcher.cpp:77] No whitelist given
I0107 23:34:17.013804 31133 master.cpp:1629] The newly elected leader is master@172.17.0.3:43021 with id cf703e5a-e992-4962-95de-78a7194f8d76
I0107 23:34:17.013849 31133 master.cpp:1642] Elected as the leading master!
I0107 23:34:17.013872 31133 master.cpp:1387] Recovering from registrar
I0107 23:34:17.014011 31124 registrar.cpp:307] Recovering registrar
I0107 23:34:17.048988 31136 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.030633ms
I0107 23:34:17.049347 31136 replica.cpp:320] Persisted replica status to STARTING
I0107 23:34:17.049825 31124 recover.cpp:473] Replica is in STARTING status
I0107 23:34:17.051060 31126 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13012)@172.17.0.3:43021
I0107 23:34:17.051563 31132 recover.cpp:193] Received a recover response from a replica in STARTING status
I0107 23:34:17.052021 31133 recover.cpp:564] Updating replica status to VOTING
I0107 23:34:17.089408 31125 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.191798ms
I0107 23:34:17.089483 31125 replica.cpp:320] Persisted replica status to VOTING
I0107 23:34:17.089697 31132 recover.cpp:578] Successfully joined the Paxos group
I0107 23:34:17.089962 31132 recover.cpp:462] Recover process terminated
I0107 23:34:17.090512 31136 log.cpp:659] Attempting to start the writer
I0107 23:34:17.091785 31121 replica.cpp:493] Replica received implicit promise request from (13013)@172.17.0.3:43021 with proposal 1
I0107 23:34:17.123517 31121 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.690525ms
I0107 23:34:17.123569 31121 replica.cpp:342] Persisted promised to 1
I0107 23:34:17.124300 31123 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0107 23:34:17.125658 31134 replica.cpp:388] Replica received explicit promise request from (13014)@172.17.0.3:43021 for position 0 with proposal 2
I0107 23:34:17.157238 31134 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 31.509874ms
I0107 23:34:17.157320 31134 replica.cpp:712] Persisted action at 0
I0107 23:34:17.158962 31128 replica.cpp:537] Replica received write request for position 0 from (13015)@172.17.0.3:43021
I0107 23:34:17.159057 31128 leveldb.cpp:436] Reading position from leveldb took 47964ns
I0107 23:34:17.208048 31128 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 48.917298ms
I0107 23:34:17.208173 31128 replica.cpp:712] Persisted action at 0
I0107 23:34:17.209220 31130 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0107 23:34:17.250154 31130 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.85727ms
I0107 23:34:17.250234 31130 replica.cpp:712] Persisted action at 0
I0107 23:34:17.250274 31130 replica.cpp:697] Replica learned NOP action at position 0
I0107 23:34:17.251116 31135 log.cpp:675] Writer started with ending position 0
I0107 23:34:17.252962 31129 leveldb.cpp:436] Reading position from leveldb took 57820ns
I0107 23:34:17.253999 31123 registrar.cpp:340] Successfully fetched the registry (0B) in 239.940096ms
I0107 23:34:17.254161 31123 registrar.cpp:439] Applied 1 operations in 62953ns; attempting to update the 'registry'
I0107 23:34:17.254863 31135 log.cpp:683] Attempting to append 170 bytes to the log
I0107 23:34:17.254986 31123 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0107 23:34:17.255700 31132 replica.cpp:537] Replica received write request for position 1 from (13016)@172.17.0.3:43021
I0107 23:34:17.292587 31132 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.786174ms
I0107 23:34:17.292659 31132 replica.cpp:712] Persisted action at 1
I0107 23:34:17.293486 31134 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0107 23:34:17.333292 31134 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 39.694747ms
I0107 23:34:17.333343 31134 replica.cpp:712] Persisted action at 1
I0107 23:34:17.333377 31134 replica.cpp:697] Replica learned APPEND action at position 1
I0107 23:34:17.334846 31129 registrar.cpp:484] Successfully updated the 'registry' in 80.602112ms
I0107 23:34:17.335029 31129 registrar.cpp:370] Successfully recovered registrar
I0107 23:34:17.335114 31126 log.cpp:702] Attempting to truncate the log to 1
I0107 23:34:17.335281 31135 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0107 23:34:17.335515 31122 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0107 23:34:17.335527 31130 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0107 23:34:17.336243 31133 replica.cpp:537] Replica received write request for position 2 from (13017)@172.17.0.3:43021
I0107 23:34:17.366750 31133 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 30.452373ms
I0107 23:34:17.367053 31133 replica.cpp:712] Persisted action at 2
I0107 23:34:17.368219 31135 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0107 23:34:17.392282 31135 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.010853ms
I0107 23:34:17.392417 31135 leveldb.cpp:399] Deleting ~1 keys from leveldb took 69661ns
I0107 23:34:17.392554 31135 replica.cpp:712] Persisted action at 2
I0107 23:34:17.392597 31135 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0107 23:34:17.396924 31102 scheduler.cpp:154] Version: 0.27.0
I0107 23:34:17.397583 31122 scheduler.cpp:236] New master detected at master@172.17.0.3:43021
I0107 23:34:17.398716 31134 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:43021
I0107 23:34:17.400676 31131 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 23:34:17.401150 31121 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:36767
I0107 23:34:17.401489 31121 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0107 23:34:17.401552 31121 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0107 23:34:17.401769 31121 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0107 23:34:17.402225 31136 hierarchical.cpp:260] Added framework cf703e5a-e992-4962-95de-78a7194f8d76-0000
I0107 23:34:17.402268 31121 master.hpp:1662] Sending heartbeat to cf703e5a-e992-4962-95de-78a7194f8d76-0000
I0107 23:34:17.402380 31136 hierarchical.cpp:1329] No resources available to allocate!
I0107 23:34:17.402425 31136 hierarchical.cpp:1423] No inverse offers to send out!
I0107 23:34:17.402457 31136 hierarchical.cpp:1079] Performed allocation for 0 slaves in 129280ns
I0107 23:34:17.403462 31134 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:43021
I0107 23:34:17.403910 31134 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:43021
I0107 23:34:17.404556 31128 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:43021
I0107 23:34:17.404711 31123 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0107 23:34:17.406230 31129 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 23:34:17.406627 31134 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:36768
I0107 23:34:17.406922 31134 master.cpp:2636] Processing REQUEST call for framework cf703e5a-e992-4962-95de-78a7194f8d76-0000 (default)
I0107 23:34:17.407090 31123 hierarchical.cpp:579] Received resource request from framework cf703e5a-e992-4962-95de-78a7194f8d76-0000
I0107 23:34:17.407503 31121 master.cpp:930] Master terminating
I0107 23:34:17.407881 31122 hierarchical.cpp:321] Removed framework cf703e5a-e992-4962-95de-78a7194f8d76-0000
E0107 23:34:17.408788 31124 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (582 ms)
[----------] 22 tests from ContentType/SchedulerTest (17255 ms total)
[----------] Global test environment tear-down
[==========] 922 tests from 120 test cases ran. (925395 ms total)
[ PASSED ] 921 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] PersistentVolumeTest.BadACLDropCreateAndDestroy
1 FAILED TEST
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make[1]: *** [check-recursive] Error 1
make: *** [distcheck] Error 1
+ docker rmi mesos-1452206500-25612
Untagged: mesos-1452206500-25612:latest
Deleted: 623f2d92fb0e26b7d67dd1c5ec4ad2a8d92c24a88e457c5ecfc4ea76a79e7afe
Deleted: a41c9802fd445c42d732a8e22d3d6892a2e0268368df3e7a1934ccb9a5d40bee
Deleted: 26417de407cdcffa86cc4b998eb571602579625477ce344903a90e568dfbc419
Deleted: 2fd11e3ac4b05911708242430ccc89049b878e90da1024c9f7e5d35aa5ef532f
Deleted: 6cc0b5198a6afe879c7bb42e1a3dccbeadab9660a2bc810fa5017af2a5b7efce
Deleted: 6b8f118fd234790b43a1da6bcba1a7b0d20426542c0b3235ac8bcb3ec95e4080
Deleted: d57e6a6db6481ed5672229a91751178592edef69672173dfbfa0958bca2f3596
Deleted: 244d1f5cd961db14ad288e8b21fd77c31a7d5fb1b52881aa909ed063dbcac705
Deleted: 59a2006b01ad415fd0f58a204cb9d6c56be1b67cd3ccb95e6657fa51e8b9d1bc
Deleted: 59d059399e855f1072b7ba1c839afb7b831bb41290a34f9d6145675b702d9a1f
Deleted: 2fb7183a6b5c393b36ab7c77c97b52302ce5f36998694bcb2fbab328a5202f26
Deleted: 72c4d7124e2b239cb4e979d1629324b2501b015630d1c9c803a0b2094e98e019
Deleted: f2aaa75f9a91b3249bf7c2639322c77e2e652b76b12d7919166331cc41e5910b
Error handling URL https://reviews.apache.org/api/review-requests/42035/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 9a9d0df9e482018dc32a631b4fc06d0b2501148b
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : mesos-reviewbot #10660
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10660/>
Build failed in Jenkins: mesos-reviewbot #10659
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10659/changes>
Changes:
[adam] Disabled flaky/failing TerminatingSlaveDoesNotReregister test.
[adam] Fixed typos in comments.
------------------------------------------
[...truncated 162669 lines...]
I0108 02:17:45.359297 31116 status_update_manager.cpp:528] Cleaning up status update stream for task cf0a7939-33bd-431e-850c-b9449c896854 of framework 8e75b8f8-0a2a-4a7f-8f27-ac5d504a6642-0000
[ OK ] ContentType/SchedulerTest.Message/1 (118 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0108 02:17:45.367096 31096 leveldb.cpp:174] Opened db in 2.7984ms
I0108 02:17:45.368113 31096 leveldb.cpp:181] Compacted db in 981385ns
I0108 02:17:45.368158 31096 leveldb.cpp:196] Created db iterator in 17744ns
I0108 02:17:45.368175 31096 leveldb.cpp:202] Seeked to beginning of db in 1534ns
I0108 02:17:45.368182 31096 leveldb.cpp:271] Iterated through 0 keys in the db in 275ns
I0108 02:17:45.368221 31096 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0108 02:17:45.368659 31125 recover.cpp:447] Starting replica recovery
I0108 02:17:45.368893 31125 recover.cpp:473] Replica is in EMPTY status
I0108 02:17:45.369815 31125 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12932)@172.17.0.1:46166
I0108 02:17:45.370218 31124 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0108 02:17:45.370636 31117 recover.cpp:564] Updating replica status to STARTING
I0108 02:17:45.371150 31118 master.cpp:365] Master 0bd15431-5241-49f1-bc44-0d3d7b8be330 (5b81990b2d72) started on 172.17.0.1:46166
I0108 02:17:45.371304 31124 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 561706ns
I0108 02:17:45.371330 31124 replica.cpp:320] Persisted replica status to STARTING
I0108 02:17:45.371176 31118 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/JHR5UZ/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/JHR5UZ/master" --zk_session_timeout="10secs"
I0108 02:17:45.371425 31118 master.cpp:414] Master allowing unauthenticated frameworks to register
I0108 02:17:45.371438 31118 master.cpp:417] Master only allowing authenticated slaves to register
I0108 02:17:45.371443 31118 credentials.hpp:35] Loading credentials for authentication from '/tmp/JHR5UZ/credentials'
I0108 02:17:45.371742 31120 recover.cpp:473] Replica is in STARTING status
I0108 02:17:45.371884 31118 master.cpp:456] Using default 'crammd5' authenticator
I0108 02:17:45.372020 31118 master.cpp:493] Authorization enabled
I0108 02:17:45.372208 31121 whitelist_watcher.cpp:77] No whitelist given
I0108 02:17:45.372279 31124 hierarchical.cpp:147] Initialized hierarchical allocator process
I0108 02:17:45.372756 31116 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12933)@172.17.0.1:46166
I0108 02:17:45.372972 31121 recover.cpp:193] Received a recover response from a replica in STARTING status
I0108 02:17:45.373548 31120 recover.cpp:564] Updating replica status to VOTING
I0108 02:17:45.374204 31121 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 416296ns
I0108 02:17:45.374233 31121 replica.cpp:320] Persisted replica status to VOTING
I0108 02:17:45.374400 31121 recover.cpp:578] Successfully joined the Paxos group
I0108 02:17:45.374578 31121 recover.cpp:462] Recover process terminated
I0108 02:17:45.374595 31130 master.cpp:1629] The newly elected leader is master@172.17.0.1:46166 with id 0bd15431-5241-49f1-bc44-0d3d7b8be330
I0108 02:17:45.374635 31130 master.cpp:1642] Elected as the leading master!
I0108 02:17:45.374660 31130 master.cpp:1387] Recovering from registrar
I0108 02:17:45.374851 31127 registrar.cpp:307] Recovering registrar
I0108 02:17:45.375352 31122 log.cpp:659] Attempting to start the writer
I0108 02:17:45.376421 31130 replica.cpp:493] Replica received implicit promise request from (12934)@172.17.0.1:46166 with proposal 1
I0108 02:17:45.376792 31130 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 334458ns
I0108 02:17:45.376814 31130 replica.cpp:342] Persisted promised to 1
I0108 02:17:45.377329 31124 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0108 02:17:45.378502 31126 replica.cpp:388] Replica received explicit promise request from (12935)@172.17.0.1:46166 for position 0 with proposal 2
I0108 02:17:45.378902 31126 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 356795ns
I0108 02:17:45.378926 31126 replica.cpp:712] Persisted action at 0
I0108 02:17:45.379789 31121 replica.cpp:537] Replica received write request for position 0 from (12936)@172.17.0.1:46166
I0108 02:17:45.379842 31121 leveldb.cpp:436] Reading position from leveldb took 24173ns
I0108 02:17:45.380228 31121 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 349812ns
I0108 02:17:45.380250 31121 replica.cpp:712] Persisted action at 0
I0108 02:17:45.381031 31119 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0108 02:17:45.381454 31119 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 390957ns
I0108 02:17:45.381477 31119 replica.cpp:712] Persisted action at 0
I0108 02:17:45.381494 31119 replica.cpp:697] Replica learned NOP action at position 0
I0108 02:17:45.382004 31124 log.cpp:675] Writer started with ending position 0
I0108 02:17:45.382988 31130 leveldb.cpp:436] Reading position from leveldb took 25144ns
I0108 02:17:45.383836 31120 registrar.cpp:340] Successfully fetched the registry (0B) in 8.937728ms
I0108 02:17:45.383942 31120 registrar.cpp:439] Applied 1 operations in 27786ns; attempting to update the 'registry'
I0108 02:17:45.384608 31127 log.cpp:683] Attempting to append 170 bytes to the log
I0108 02:17:45.384783 31115 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0108 02:17:45.385509 31125 replica.cpp:537] Replica received write request for position 1 from (12937)@172.17.0.1:46166
I0108 02:17:45.386142 31125 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 597250ns
I0108 02:17:45.386167 31125 replica.cpp:712] Persisted action at 1
I0108 02:17:45.386801 31126 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0108 02:17:45.387399 31126 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 534153ns
I0108 02:17:45.387423 31126 replica.cpp:712] Persisted action at 1
I0108 02:17:45.387440 31126 replica.cpp:697] Replica learned APPEND action at position 1
I0108 02:17:45.388358 31128 registrar.cpp:484] Successfully updated the 'registry' in 4.306944ms
I0108 02:17:45.388495 31128 registrar.cpp:370] Successfully recovered registrar
I0108 02:17:45.388520 31117 log.cpp:702] Attempting to truncate the log to 1
I0108 02:17:45.388718 31127 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0108 02:17:45.389112 31123 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0108 02:17:45.389152 31128 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0108 02:17:45.389703 31126 replica.cpp:537] Replica received write request for position 2 from (12938)@172.17.0.1:46166
I0108 02:17:45.390058 31126 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 322966ns
I0108 02:17:45.390080 31126 replica.cpp:712] Persisted action at 2
I0108 02:17:45.390753 31122 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0108 02:17:45.391099 31122 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 316573ns
I0108 02:17:45.391146 31122 leveldb.cpp:399] Deleting ~1 keys from leveldb took 24535ns
I0108 02:17:45.391165 31122 replica.cpp:712] Persisted action at 2
I0108 02:17:45.391181 31122 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0108 02:17:45.400360 31096 scheduler.cpp:154] Version: 0.27.0
I0108 02:17:45.401248 31125 scheduler.cpp:236] New master detected at master@172.17.0.1:46166
I0108 02:17:45.402354 31117 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.1:46166
I0108 02:17:45.404541 31123 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0108 02:17:45.405135 31130 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:52686
I0108 02:17:45.405333 31130 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0108 02:17:45.405392 31130 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0108 02:17:45.405694 31130 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0108 02:17:45.406219 31123 hierarchical.cpp:260] Added framework 0bd15431-5241-49f1-bc44-0d3d7b8be330-0000
I0108 02:17:45.406271 31118 master.hpp:1662] Sending heartbeat to 0bd15431-5241-49f1-bc44-0d3d7b8be330-0000
I0108 02:17:45.406399 31123 hierarchical.cpp:1329] No resources available to allocate!
I0108 02:17:45.406656 31123 hierarchical.cpp:1423] No inverse offers to send out!
I0108 02:17:45.406692 31123 hierarchical.cpp:1079] Performed allocation for 0 slaves in 354679ns
I0108 02:17:45.407306 31124 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.1:46166
I0108 02:17:45.407846 31124 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.1:46166
I0108 02:17:45.408334 31121 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0108 02:17:45.408740 31122 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.1:46166
I0108 02:17:45.410120 31123 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0108 02:17:45.410553 31115 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:52687
I0108 02:17:45.410662 31115 master.cpp:2636] Processing REQUEST call for framework 0bd15431-5241-49f1-bc44-0d3d7b8be330-0000 (default)
I0108 02:17:45.410851 31116 hierarchical.cpp:579] Received resource request from framework 0bd15431-5241-49f1-bc44-0d3d7b8be330-0000
I0108 02:17:45.411151 31127 master.cpp:930] Master terminating
I0108 02:17:45.411407 31120 hierarchical.cpp:321] Removed framework 0bd15431-5241-49f1-bc44-0d3d7b8be330-0000
E0108 02:17:45.412364 31117 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (55 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0108 02:17:45.421021 31096 leveldb.cpp:174] Opened db in 2.607318ms
I0108 02:17:45.421859 31096 leveldb.cpp:181] Compacted db in 804054ns
I0108 02:17:45.421907 31096 leveldb.cpp:196] Created db iterator in 18618ns
I0108 02:17:45.422061 31096 leveldb.cpp:202] Seeked to beginning of db in 2150ns
I0108 02:17:45.422083 31096 leveldb.cpp:271] Iterated through 0 keys in the db in 345ns
I0108 02:17:45.422137 31096 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0108 02:17:45.422569 31117 recover.cpp:447] Starting replica recovery
I0108 02:17:45.422845 31120 recover.cpp:473] Replica is in EMPTY status
I0108 02:17:45.423883 31129 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12946)@172.17.0.1:46166
I0108 02:17:45.424319 31128 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0108 02:17:45.424770 31124 recover.cpp:564] Updating replica status to STARTING
I0108 02:17:45.425345 31129 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 442403ns
I0108 02:17:45.425369 31129 replica.cpp:320] Persisted replica status to STARTING
I0108 02:17:45.425585 31125 recover.cpp:473] Replica is in STARTING status
I0108 02:17:45.425712 31121 master.cpp:365] Master de57f10e-3f91-46d1-b630-9b0169c8c8b2 (5b81990b2d72) started on 172.17.0.1:46166
I0108 02:17:45.425739 31121 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/F0SPIf/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/F0SPIf/master" --zk_session_timeout="10secs"
I0108 02:17:45.426002 31121 master.cpp:414] Master allowing unauthenticated frameworks to register
I0108 02:17:45.426012 31121 master.cpp:417] Master only allowing authenticated slaves to register
I0108 02:17:45.426018 31121 credentials.hpp:35] Loading credentials for authentication from '/tmp/F0SPIf/credentials'
I0108 02:17:45.426288 31121 master.cpp:456] Using default 'crammd5' authenticator
I0108 02:17:45.426436 31121 master.cpp:493] Authorization enabled
I0108 02:17:45.426568 31125 whitelist_watcher.cpp:77] No whitelist given
I0108 02:17:45.426576 31116 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12947)@172.17.0.1:46166
I0108 02:17:45.426617 31130 hierarchical.cpp:147] Initialized hierarchical allocator process
I0108 02:17:45.427042 31124 recover.cpp:193] Received a recover response from a replica in STARTING status
I0108 02:17:45.427584 31128 recover.cpp:564] Updating replica status to VOTING
I0108 02:17:45.428092 31124 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 344500ns
I0108 02:17:45.428119 31124 replica.cpp:320] Persisted replica status to VOTING
I0108 02:17:45.428248 31124 recover.cpp:578] Successfully joined the Paxos group
I0108 02:17:45.428427 31129 master.cpp:1629] The newly elected leader is master@172.17.0.1:46166 with id de57f10e-3f91-46d1-b630-9b0169c8c8b2
I0108 02:17:45.428459 31129 master.cpp:1642] Elected as the leading master!
I0108 02:17:45.428481 31129 master.cpp:1387] Recovering from registrar
I0108 02:17:45.428495 31124 recover.cpp:462] Recover process terminated
I0108 02:17:45.428841 31128 registrar.cpp:307] Recovering registrar
I0108 02:17:45.429358 31124 log.cpp:659] Attempting to start the writer
I0108 02:17:45.430543 31126 replica.cpp:493] Replica received implicit promise request from (12948)@172.17.0.1:46166 with proposal 1
I0108 02:17:45.430842 31126 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 269160ns
I0108 02:17:45.430865 31126 replica.cpp:342] Persisted promised to 1
I0108 02:17:45.431432 31122 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0108 02:17:45.432550 31128 replica.cpp:388] Replica received explicit promise request from (12949)@172.17.0.1:46166 for position 0 with proposal 2
I0108 02:17:45.433161 31128 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 574642ns
I0108 02:17:45.433187 31128 replica.cpp:712] Persisted action at 0
I0108 02:17:45.434280 31127 replica.cpp:537] Replica received write request for position 0 from (12950)@172.17.0.1:46166
I0108 02:17:45.434337 31127 leveldb.cpp:436] Reading position from leveldb took 27184ns
I0108 02:17:45.434739 31127 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 362336ns
I0108 02:17:45.434830 31127 replica.cpp:712] Persisted action at 0
I0108 02:17:45.435544 31123 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0108 02:17:45.436063 31123 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 460700ns
I0108 02:17:45.436097 31123 replica.cpp:712] Persisted action at 0
I0108 02:17:45.436133 31123 replica.cpp:697] Replica learned NOP action at position 0
I0108 02:17:45.436738 31116 log.cpp:675] Writer started with ending position 0
I0108 02:17:45.438469 31126 leveldb.cpp:436] Reading position from leveldb took 34931ns
I0108 02:17:45.439518 31130 registrar.cpp:340] Successfully fetched the registry (0B) in 10.628864ms
I0108 02:17:45.439677 31130 registrar.cpp:439] Applied 1 operations in 51422ns; attempting to update the 'registry'
I0108 02:17:45.440528 31117 log.cpp:683] Attempting to append 170 bytes to the log
I0108 02:17:45.440677 31116 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0108 02:17:45.441473 31129 replica.cpp:537] Replica received write request for position 1 from (12951)@172.17.0.1:46166
I0108 02:17:45.441896 31129 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 380949ns
I0108 02:17:45.441920 31129 replica.cpp:712] Persisted action at 1
I0108 02:17:45.442471 31129 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0108 02:17:45.442873 31129 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 374161ns
I0108 02:17:45.442899 31129 replica.cpp:712] Persisted action at 1
I0108 02:17:45.442926 31129 replica.cpp:697] Replica learned APPEND action at position 1
I0108 02:17:45.444293 31119 registrar.cpp:484] Successfully updated the 'registry' in 4.381952ms
I0108 02:17:45.444339 31117 log.cpp:702] Attempting to truncate the log to 1
I0108 02:17:45.444475 31119 registrar.cpp:370] Successfully recovered registrar
I0108 02:17:45.444483 31118 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0108 02:17:45.444978 31116 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0108 02:17:45.445010 31123 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0108 02:17:45.445413 31120 replica.cpp:537] Replica received write request for position 2 from (12952)@172.17.0.1:46166
I0108 02:17:45.445894 31120 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 375125ns
I0108 02:17:45.445921 31120 replica.cpp:712] Persisted action at 2
I0108 02:17:45.446854 31120 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0108 02:17:45.447487 31120 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 523118ns
I0108 02:17:45.447545 31120 leveldb.cpp:399] Deleting ~1 keys from leveldb took 28024ns
I0108 02:17:45.447563 31120 replica.cpp:712] Persisted action at 2
I0108 02:17:45.447582 31120 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0108 02:17:45.456295 31096 scheduler.cpp:154] Version: 0.27.0
I0108 02:17:45.456930 31123 scheduler.cpp:236] New master detected at master@172.17.0.1:46166
I0108 02:17:45.457864 31116 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.1:46166
I0108 02:17:45.459712 31127 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0108 02:17:45.460166 31129 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:52693
I0108 02:17:45.460517 31129 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0108 02:17:45.460575 31129 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0108 02:17:45.460827 31129 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0108 02:17:45.461235 31120 hierarchical.cpp:260] Added framework de57f10e-3f91-46d1-b630-9b0169c8c8b2-0000
I0108 02:17:45.461288 31128 master.hpp:1662] Sending heartbeat to de57f10e-3f91-46d1-b630-9b0169c8c8b2-0000
I0108 02:17:45.461308 31120 hierarchical.cpp:1329] No resources available to allocate!
I0108 02:17:45.461347 31120 hierarchical.cpp:1423] No inverse offers to send out!
I0108 02:17:45.461381 31120 hierarchical.cpp:1079] Performed allocation for 0 slaves in 115608ns
I0108 02:17:45.462126 31118 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.1:46166
I0108 02:17:45.462609 31127 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.1:46166
I0108 02:17:45.463129 31127 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.1:46166
I0108 02:17:45.463167 31119 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0108 02:17:45.464699 31130 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0108 02:17:45.465066 31120 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:52694
I0108 02:17:45.465353 31120 master.cpp:2636] Processing REQUEST call for framework de57f10e-3f91-46d1-b630-9b0169c8c8b2-0000 (default)
I0108 02:17:45.465514 31126 hierarchical.cpp:579] Received resource request from framework de57f10e-3f91-46d1-b630-9b0169c8c8b2-0000
I0108 02:17:45.465879 31119 master.cpp:930] Master terminating
I0108 02:17:45.466027 31115 hierarchical.cpp:321] Removed framework de57f10e-3f91-46d1-b630-9b0169c8c8b2-0000
E0108 02:17:45.466840 31115 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (55 ms)
[----------] 22 tests from ContentType/SchedulerTest (4278 ms total)
[----------] Global test environment tear-down
[==========] 922 tests from 120 test cases ran. (335386 ms total)
[ PASSED ] 921 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] DiskUsageCollectorTest.File
1 FAILED TEST
YOU HAVE 7 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1452217438-5460
Untagged: mesos-1452217438-5460:latest
Deleted: 1fd151d0d9d048ec007e8822051a61d451cc51e304cc88af1159af5b40a9cbf0
Deleted: e7048a36b0f29d78d992cacaa90e508a3f4291cbcb46063ef578e3d7659319a0
Deleted: d2a2c6a21b78c32c32a8838535a352f084bbd65b727f4ce1e90069bf44d4b440
Deleted: b65415c43c6fa9eb84411ea3ae01074e203ef4fca8bef2547ac4269662e464a2
Deleted: fee98c7fc216c5b636f8604f8c936a1cb8b83b595949a5b2154139b6e5e128cd
Deleted: ce5dfd2855e017cbbfd26c551b14b1a40816db7ebdf903ec3f1f908cdb8c4848
Deleted: 31c415cd90dead5cd82d2d7eae6b48af94605a5806dac188012cd8531cfb5630
Deleted: f6fab63cccb0b20db97476db4598d2f9d618f7445fa950e27ea74d684ddc3cd3
Deleted: b96794593dd98f4e149077788d84e721e8cefe4ad762e0341cd37cd6b372609c
Deleted: d6835b5662d46130c57f1e3c70cb4ca53920ee44fff5081cf659d4c50ae91465
Deleted: ca10db24ed8e3e5e8e330dcec7b4d6f687a177cabb0b4dfb7fcc88975ec240b2
Deleted: 35d0e9e03adfd09709c4bbb47168765df877e58a2cbd3f18b8dd6a20b60e85cb
Deleted: 3897278716f53f0c4390ea97baae3fc946fff6205b851a547b7b269756625024
Error handling URL https://reviews.apache.org/api/review-requests/41963/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 4615f82b6670fb3cdb47a5b17f161408da99a4c4
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10658
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10658/>
------------------------------------------
[...truncated 166598 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (651 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
2016-01-08 00:43:10,832:31097(0x2b06d6893700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:42622] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I0108 00:43:10.848232 31097 leveldb.cpp:174] Opened db in 108.061839ms
I0108 00:43:10.873417 31097 leveldb.cpp:181] Compacted db in 25.118819ms
I0108 00:43:10.873492 31097 leveldb.cpp:196] Created db iterator in 25434ns
I0108 00:43:10.873514 31097 leveldb.cpp:202] Seeked to beginning of db in 2120ns
I0108 00:43:10.873527 31097 leveldb.cpp:271] Iterated through 0 keys in the db in 305ns
I0108 00:43:10.873576 31097 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0108 00:43:10.874230 31123 recover.cpp:447] Starting replica recovery
I0108 00:43:10.874464 31123 recover.cpp:473] Replica is in EMPTY status
I0108 00:43:10.875511 31120 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12979)@172.17.0.3:42114
I0108 00:43:10.875937 31119 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0108 00:43:10.876416 31130 recover.cpp:564] Updating replica status to STARTING
I0108 00:43:10.877238 31123 master.cpp:365] Master c8e647d4-8790-441b-a170-64bb5e0c2ca5 (b40fa1b0a68b) started on 172.17.0.3:42114
I0108 00:43:10.877260 31123 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/H91AUy/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/H91AUy/master" --zk_session_timeout="10secs"
I0108 00:43:10.877552 31123 master.cpp:414] Master allowing unauthenticated frameworks to register
I0108 00:43:10.877573 31123 master.cpp:417] Master only allowing authenticated slaves to register
I0108 00:43:10.877588 31123 credentials.hpp:35] Loading credentials for authentication from '/tmp/H91AUy/credentials'
I0108 00:43:10.877902 31123 master.cpp:456] Using default 'crammd5' authenticator
I0108 00:43:10.878057 31123 master.cpp:493] Authorization enabled
I0108 00:43:10.878240 31117 hierarchical.cpp:147] Initialized hierarchical allocator process
I0108 00:43:10.878252 31128 whitelist_watcher.cpp:77] No whitelist given
I0108 00:43:10.879853 31120 master.cpp:1629] The newly elected leader is master@172.17.0.3:42114 with id c8e647d4-8790-441b-a170-64bb5e0c2ca5
I0108 00:43:10.879892 31120 master.cpp:1642] Elected as the leading master!
I0108 00:43:10.879909 31120 master.cpp:1387] Recovering from registrar
I0108 00:43:10.880079 31126 registrar.cpp:307] Recovering registrar
I0108 00:43:10.940037 31125 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 63.453048ms
I0108 00:43:10.940111 31125 replica.cpp:320] Persisted replica status to STARTING
I0108 00:43:10.940423 31125 recover.cpp:473] Replica is in STARTING status
I0108 00:43:10.941628 31127 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12980)@172.17.0.3:42114
I0108 00:43:10.941954 31127 recover.cpp:193] Received a recover response from a replica in STARTING status
I0108 00:43:10.942443 31128 recover.cpp:564] Updating replica status to VOTING
I0108 00:43:10.973415 31127 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.720615ms
I0108 00:43:10.973448 31127 replica.cpp:320] Persisted replica status to VOTING
I0108 00:43:10.973537 31128 recover.cpp:578] Successfully joined the Paxos group
I0108 00:43:10.973795 31128 recover.cpp:462] Recover process terminated
I0108 00:43:10.974479 31118 log.cpp:659] Attempting to start the writer
I0108 00:43:10.975895 31128 replica.cpp:493] Replica received implicit promise request from (12981)@172.17.0.3:42114 with proposal 1
I0108 00:43:11.006988 31128 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.015539ms
I0108 00:43:11.007084 31128 replica.cpp:342] Persisted promised to 1
I0108 00:43:11.008419 31118 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0108 00:43:11.010046 31118 replica.cpp:388] Replica received explicit promise request from (12982)@172.17.0.3:42114 for position 0 with proposal 2
I0108 00:43:11.040487 31118 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 30.393412ms
I0108 00:43:11.040529 31118 replica.cpp:712] Persisted action at 0
I0108 00:43:11.041839 31120 replica.cpp:537] Replica received write request for position 0 from (12983)@172.17.0.3:42114
I0108 00:43:11.041894 31120 leveldb.cpp:436] Reading position from leveldb took 27292ns
I0108 00:43:11.073956 31120 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 32.022421ms
I0108 00:43:11.073999 31120 replica.cpp:712] Persisted action at 0
I0108 00:43:11.074519 31116 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0108 00:43:11.107316 31116 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.751927ms
I0108 00:43:11.107391 31116 replica.cpp:712] Persisted action at 0
I0108 00:43:11.107422 31116 replica.cpp:697] Replica learned NOP action at position 0
I0108 00:43:11.108614 31125 log.cpp:675] Writer started with ending position 0
I0108 00:43:11.110095 31122 leveldb.cpp:436] Reading position from leveldb took 66869ns
I0108 00:43:11.111464 31117 registrar.cpp:340] Successfully fetched the registry (0B) in 231.340288ms
I0108 00:43:11.111593 31117 registrar.cpp:439] Applied 1 operations in 35311ns; attempting to update the 'registry'
I0108 00:43:11.112735 31129 log.cpp:683] Attempting to append 170 bytes to the log
I0108 00:43:11.112936 31129 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0108 00:43:11.113983 31121 replica.cpp:537] Replica received write request for position 1 from (12984)@172.17.0.3:42114
I0108 00:43:11.149142 31121 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 35.090062ms
I0108 00:43:11.149219 31121 replica.cpp:712] Persisted action at 1
I0108 00:43:11.150477 31121 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0108 00:43:11.182695 31121 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.165591ms
I0108 00:43:11.182785 31121 replica.cpp:712] Persisted action at 1
I0108 00:43:11.182832 31121 replica.cpp:697] Replica learned APPEND action at position 1
I0108 00:43:11.184162 31121 registrar.cpp:484] Successfully updated the 'registry' in 72.504064ms
I0108 00:43:11.184325 31121 registrar.cpp:370] Successfully recovered registrar
I0108 00:43:11.184393 31119 log.cpp:702] Attempting to truncate the log to 1
I0108 00:43:11.184530 31120 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0108 00:43:11.185309 31118 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0108 00:43:11.185307 31124 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0108 00:43:11.185443 31124 replica.cpp:537] Replica received write request for position 2 from (12985)@172.17.0.3:42114
I0108 00:43:11.218075 31124 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.588521ms
I0108 00:43:11.218108 31124 replica.cpp:712] Persisted action at 2
I0108 00:43:11.218703 31121 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0108 00:43:11.248718 31121 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 29.98336ms
I0108 00:43:11.248786 31121 leveldb.cpp:399] Deleting ~1 keys from leveldb took 33534ns
I0108 00:43:11.248807 31121 replica.cpp:712] Persisted action at 2
I0108 00:43:11.248823 31121 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0108 00:43:11.256896 31097 scheduler.cpp:154] Version: 0.27.0
I0108 00:43:11.257616 31117 scheduler.cpp:236] New master detected at master@172.17.0.3:42114
I0108 00:43:11.259670 31128 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:42114
I0108 00:43:11.261675 31125 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0108 00:43:11.262241 31125 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:41232
I0108 00:43:11.262439 31125 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0108 00:43:11.262502 31125 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0108 00:43:11.263013 31116 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0108 00:43:11.263387 31116 master.hpp:1662] Sending heartbeat to c8e647d4-8790-441b-a170-64bb5e0c2ca5-0000
I0108 00:43:11.263417 31126 hierarchical.cpp:260] Added framework c8e647d4-8790-441b-a170-64bb5e0c2ca5-0000
I0108 00:43:11.263492 31126 hierarchical.cpp:1329] No resources available to allocate!
I0108 00:43:11.263527 31126 hierarchical.cpp:1423] No inverse offers to send out!
I0108 00:43:11.263571 31126 hierarchical.cpp:1079] Performed allocation for 0 slaves in 120628ns
I0108 00:43:11.265014 31116 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:42114
I0108 00:43:11.266211 31116 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:42114
I0108 00:43:11.266882 31125 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:42114
I0108 00:43:11.267758 31125 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0108 00:43:11.267760 31129 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0108 00:43:11.268265 31119 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:41233
I0108 00:43:11.268368 31119 master.cpp:2636] Processing REQUEST call for framework c8e647d4-8790-441b-a170-64bb5e0c2ca5-0000 (default)
I0108 00:43:11.268501 31125 hierarchical.cpp:579] Received resource request from framework c8e647d4-8790-441b-a170-64bb5e0c2ca5-0000
I0108 00:43:11.268877 31119 master.cpp:930] Master terminating
I0108 00:43:11.269076 31123 hierarchical.cpp:321] Removed framework c8e647d4-8790-441b-a170-64bb5e0c2ca5-0000
E0108 00:43:11.271841 31124 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (536 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0108 00:43:11.350376 31097 leveldb.cpp:174] Opened db in 74.677079ms
I0108 00:43:11.375794 31097 leveldb.cpp:181] Compacted db in 25.349482ms
I0108 00:43:11.375867 31097 leveldb.cpp:196] Created db iterator in 24292ns
I0108 00:43:11.375888 31097 leveldb.cpp:202] Seeked to beginning of db in 1985ns
I0108 00:43:11.375900 31097 leveldb.cpp:271] Iterated through 0 keys in the db in 255ns
I0108 00:43:11.375952 31097 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0108 00:43:11.376488 31124 recover.cpp:447] Starting replica recovery
I0108 00:43:11.376731 31124 recover.cpp:473] Replica is in EMPTY status
I0108 00:43:11.377640 31126 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12993)@172.17.0.3:42114
I0108 00:43:11.378085 31117 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0108 00:43:11.378638 31122 recover.cpp:564] Updating replica status to STARTING
I0108 00:43:11.379647 31116 master.cpp:365] Master 5b39bdba-e6a3-4cc5-afba-b135488ac2cf (b40fa1b0a68b) started on 172.17.0.3:42114
I0108 00:43:11.379668 31116 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/yTv2R3/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/yTv2R3/master" --zk_session_timeout="10secs"
I0108 00:43:11.380004 31116 master.cpp:414] Master allowing unauthenticated frameworks to register
I0108 00:43:11.380019 31116 master.cpp:417] Master only allowing authenticated slaves to register
I0108 00:43:11.380028 31116 credentials.hpp:35] Loading credentials for authentication from '/tmp/yTv2R3/credentials'
I0108 00:43:11.380396 31116 master.cpp:456] Using default 'crammd5' authenticator
I0108 00:43:11.380556 31116 master.cpp:493] Authorization enabled
I0108 00:43:11.380758 31122 hierarchical.cpp:147] Initialized hierarchical allocator process
I0108 00:43:11.380803 31123 whitelist_watcher.cpp:77] No whitelist given
I0108 00:43:11.382599 31126 master.cpp:1629] The newly elected leader is master@172.17.0.3:42114 with id 5b39bdba-e6a3-4cc5-afba-b135488ac2cf
I0108 00:43:11.382642 31126 master.cpp:1642] Elected as the leading master!
I0108 00:43:11.382670 31126 master.cpp:1387] Recovering from registrar
I0108 00:43:11.382869 31118 registrar.cpp:307] Recovering registrar
I0108 00:43:11.407846 31117 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 29.095787ms
I0108 00:43:11.407878 31117 replica.cpp:320] Persisted replica status to STARTING
I0108 00:43:11.408176 31125 recover.cpp:473] Replica is in STARTING status
I0108 00:43:11.409325 31118 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12994)@172.17.0.3:42114
I0108 00:43:11.409718 31123 recover.cpp:193] Received a recover response from a replica in STARTING status
I0108 00:43:11.410202 31130 recover.cpp:564] Updating replica status to VOTING
I0108 00:43:11.441246 31116 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.841364ms
I0108 00:43:11.441283 31116 replica.cpp:320] Persisted replica status to VOTING
I0108 00:43:11.441411 31131 recover.cpp:578] Successfully joined the Paxos group
I0108 00:43:11.441604 31131 recover.cpp:462] Recover process terminated
I0108 00:43:11.442016 31118 log.cpp:659] Attempting to start the writer
I0108 00:43:11.443135 31124 replica.cpp:493] Replica received implicit promise request from (12995)@172.17.0.3:42114 with proposal 1
I0108 00:43:11.466297 31124 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.127809ms
I0108 00:43:11.466415 31124 replica.cpp:342] Persisted promised to 1
I0108 00:43:11.467267 31127 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0108 00:43:11.468492 31128 replica.cpp:388] Replica received explicit promise request from (12996)@172.17.0.3:42114 for position 0 with proposal 2
I0108 00:43:11.491467 31128 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.908614ms
I0108 00:43:11.491549 31128 replica.cpp:712] Persisted action at 0
I0108 00:43:11.492785 31117 replica.cpp:537] Replica received write request for position 0 from (12997)@172.17.0.3:42114
I0108 00:43:11.492866 31117 leveldb.cpp:436] Reading position from leveldb took 39231ns
I0108 00:43:11.541743 31117 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 48.8141ms
I0108 00:43:11.541821 31117 replica.cpp:712] Persisted action at 0
I0108 00:43:11.543140 31122 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0108 00:43:11.566870 31122 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 23.670662ms
I0108 00:43:11.566922 31122 replica.cpp:712] Persisted action at 0
I0108 00:43:11.566958 31122 replica.cpp:697] Replica learned NOP action at position 0
I0108 00:43:11.567698 31122 log.cpp:675] Writer started with ending position 0
I0108 00:43:11.568997 31122 leveldb.cpp:436] Reading position from leveldb took 59253ns
I0108 00:43:11.570263 31129 registrar.cpp:340] Successfully fetched the registry (0B) in 187328us
I0108 00:43:11.570420 31129 registrar.cpp:439] Applied 1 operations in 43773ns; attempting to update the 'registry'
I0108 00:43:11.571324 31119 log.cpp:683] Attempting to append 170 bytes to the log
I0108 00:43:11.571485 31120 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0108 00:43:11.572389 31116 replica.cpp:537] Replica received write request for position 1 from (12998)@172.17.0.3:42114
I0108 00:43:11.600144 31116 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 27.689863ms
I0108 00:43:11.600224 31116 replica.cpp:712] Persisted action at 1
I0108 00:43:11.601346 31116 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0108 00:43:11.616870 31116 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 15.488796ms
I0108 00:43:11.616902 31116 replica.cpp:712] Persisted action at 1
I0108 00:43:11.616924 31116 replica.cpp:697] Replica learned APPEND action at position 1
I0108 00:43:11.618202 31128 registrar.cpp:484] Successfully updated the 'registry' in 47.705088ms
I0108 00:43:11.618361 31128 registrar.cpp:370] Successfully recovered registrar
I0108 00:43:11.618456 31131 log.cpp:702] Attempting to truncate the log to 1
I0108 00:43:11.618619 31128 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0108 00:43:11.618731 31117 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0108 00:43:11.618823 31117 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0108 00:43:11.619580 31126 replica.cpp:537] Replica received write request for position 2 from (12999)@172.17.0.3:42114
I0108 00:43:11.642081 31126 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.445646ms
I0108 00:43:11.642163 31126 replica.cpp:712] Persisted action at 2
I0108 00:43:11.643420 31124 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0108 00:43:11.667155 31124 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 23.639535ms
I0108 00:43:11.667321 31124 leveldb.cpp:399] Deleting ~1 keys from leveldb took 79980ns
I0108 00:43:11.667354 31124 replica.cpp:712] Persisted action at 2
I0108 00:43:11.667402 31124 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0108 00:43:11.670011 31097 scheduler.cpp:154] Version: 0.27.0
I0108 00:43:11.670578 31116 scheduler.cpp:236] New master detected at master@172.17.0.3:42114
I0108 00:43:11.671594 31124 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:42114
I0108 00:43:11.673449 31121 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0108 00:43:11.673950 31122 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:41234
I0108 00:43:11.674281 31122 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0108 00:43:11.674340 31122 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0108 00:43:11.674592 31122 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0108 00:43:11.675006 31118 hierarchical.cpp:260] Added framework 5b39bdba-e6a3-4cc5-afba-b135488ac2cf-0000
I0108 00:43:11.675077 31118 hierarchical.cpp:1329] No resources available to allocate!
I0108 00:43:11.675114 31118 hierarchical.cpp:1423] No inverse offers to send out!
I0108 00:43:11.675122 31116 master.hpp:1662] Sending heartbeat to 5b39bdba-e6a3-4cc5-afba-b135488ac2cf-0000
I0108 00:43:11.675143 31118 hierarchical.cpp:1079] Performed allocation for 0 slaves in 109247ns
I0108 00:43:11.675766 31126 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:42114
I0108 00:43:11.676164 31126 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:42114
I0108 00:43:11.676713 31127 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0108 00:43:11.676725 31126 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:42114
I0108 00:43:11.678184 31119 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0108 00:43:11.678532 31117 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:41235
I0108 00:43:11.678742 31117 master.cpp:2636] Processing REQUEST call for framework 5b39bdba-e6a3-4cc5-afba-b135488ac2cf-0000 (default)
I0108 00:43:11.678894 31118 hierarchical.cpp:579] Received resource request from framework 5b39bdba-e6a3-4cc5-afba-b135488ac2cf-0000
I0108 00:43:11.679159 31118 master.cpp:930] Master terminating
I0108 00:43:11.679329 31117 hierarchical.cpp:321] Removed framework 5b39bdba-e6a3-4cc5-afba-b135488ac2cf-0000
E0108 00:43:11.680326 31121 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (410 ms)
[----------] 22 tests from ContentType/SchedulerTest (14051 ms total)
[----------] Global test environment tear-down
[==========] 922 tests from 120 test cases ran. (684817 ms total)
[ PASSED ] 921 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] PersistentVolumeTest.BadACLDropCreateAndDestroy
1 FAILED TEST
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1452211373-20257
Untagged: mesos-1452211373-20257:latest
Deleted: e5d62db2df5da90d33c5e1efde57420a411b956f5743b347f535aa82ec749f07
Deleted: 13e1d73ccf815f0d8fbf7a69f8cba53401236c894fb74b9c42890494b878b860
Deleted: b8821d6edabf47343f7821f321ee101f7b9ec3b445557339dbe4740df9042197
Deleted: 34f1f1a926f9f5b954a5711a52f37bc4bf9858edceda0e7730f6027741bff9ad
Deleted: 5a3d3d858b7f2b579d5d938f661421f9058df3b097714c38167dc17830986088
Deleted: fae1eb248595b11936b12c2a0c97cd54773d1785ba5ae13852ec98d0fd757ad3
Deleted: 530119bd78dfece9bd572365f783fd8bb0201575829f138c2699f4b24afb1197
Deleted: d9b9743d65e3681a63bf3d89d5f5441a1f5ee149ba71c558b3ede7ee29044012
Deleted: 608b41e72da17a3f26c4f1f1ed0c29d1da66ef7f38bb58d37e5b1cd5b8499fd1
Deleted: 1cdbd3b3c28bca3b6a20a2e3fcc6d7f0f378506347bc5a71c306e8b81b5683b3
Deleted: a977853b771bbac94a477cf5f1d17f61587ad85ef835d372e64c76de4bd19143
Deleted: b458d402df69e5000dff88d411122872966c8c66dad8ea326ad47e9c47b20324
Deleted: 584f4b8ca565ab2f6100485599e80eadcb7bdd4e68d5c5b712760c2e9812959b
Error handling URL https://reviews.apache.org/api/review-requests/42035/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 9a9d0df9e482018dc32a631b4fc06d0b2501148b
Build step 'Execute shell' marked build as failure