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/01 02:50:42 UTC
Build failed in Jenkins: mesos-reviewbot #10515
See <https://builds.apache.org/job/mesos-reviewbot/10515/>
------------------------------------------
[...truncated 165318 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (661 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0101 01:50:34.714423 31019 leveldb.cpp:174] Opened db in 119.445065ms
I0101 01:50:34.739823 31019 leveldb.cpp:181] Compacted db in 25.366169ms
I0101 01:50:34.739888 31019 leveldb.cpp:196] Created db iterator in 20152ns
I0101 01:50:34.739909 31019 leveldb.cpp:202] Seeked to beginning of db in 2145ns
I0101 01:50:34.739922 31019 leveldb.cpp:271] Iterated through 0 keys in the db in 432ns
I0101 01:50:34.739961 31019 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 01:50:34.740485 31049 recover.cpp:447] Starting replica recovery
I0101 01:50:34.740931 31049 recover.cpp:473] Replica is in EMPTY status
I0101 01:50:34.742090 31047 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12851)@172.17.0.5:56330
I0101 01:50:34.742545 31046 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 01:50:34.743006 31039 recover.cpp:564] Updating replica status to STARTING
I0101 01:50:34.743860 31050 master.cpp:365] Master e303a848-982d-492f-9afc-ad9a565cd127 (19ca6dd634d5) started on 172.17.0.5:56330
I0101 01:50:34.743878 31050 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/pJHPBD/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/pJHPBD/master" --zk_session_timeout="10secs"
I0101 01:50:34.744108 31050 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 01:50:34.744122 31050 master.cpp:417] Master only allowing authenticated slaves to register
I0101 01:50:34.744133 31050 credentials.hpp:35] Loading credentials for authentication from '/tmp/pJHPBD/credentials'
I0101 01:50:34.744354 31050 master.cpp:456] Using default 'crammd5' authenticator
I0101 01:50:34.744479 31050 master.cpp:493] Authorization enabled
I0101 01:50:34.744680 31052 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 01:50:34.744704 31040 whitelist_watcher.cpp:77] No whitelist given
I0101 01:50:34.746202 31043 master.cpp:1629] The newly elected leader is master@172.17.0.5:56330 with id e303a848-982d-492f-9afc-ad9a565cd127
I0101 01:50:34.746240 31043 master.cpp:1642] Elected as the leading master!
I0101 01:50:34.746268 31043 master.cpp:1387] Recovering from registrar
I0101 01:50:34.746450 31042 registrar.cpp:307] Recovering registrar
I0101 01:50:34.781347 31046 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.229648ms
I0101 01:50:34.781381 31046 replica.cpp:320] Persisted replica status to STARTING
I0101 01:50:34.781571 31044 recover.cpp:473] Replica is in STARTING status
I0101 01:50:34.782402 31048 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12852)@172.17.0.5:56330
I0101 01:50:34.782750 31042 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 01:50:34.783220 31045 recover.cpp:564] Updating replica status to VOTING
I0101 01:50:34.823223 31053 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.806455ms
I0101 01:50:34.823254 31053 replica.cpp:320] Persisted replica status to VOTING
I0101 01:50:34.823359 31046 recover.cpp:578] Successfully joined the Paxos group
I0101 01:50:34.823699 31046 recover.cpp:462] Recover process terminated
I0101 01:50:34.824188 31044 log.cpp:659] Attempting to start the writer
I0101 01:50:34.825569 31052 replica.cpp:493] Replica received implicit promise request from (12853)@172.17.0.5:56330 with proposal 1
I0101 01:50:34.865092 31052 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.463908ms
I0101 01:50:34.865136 31052 replica.cpp:342] Persisted promised to 1
I0101 01:50:34.865880 31044 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 01:50:34.867375 31046 replica.cpp:388] Replica received explicit promise request from (12854)@172.17.0.5:56330 for position 0 with proposal 2
I0101 01:50:34.906661 31046 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.232107ms
I0101 01:50:34.906709 31046 replica.cpp:712] Persisted action at 0
I0101 01:50:34.907943 31052 replica.cpp:537] Replica received write request for position 0 from (12855)@172.17.0.5:56330
I0101 01:50:34.908023 31052 leveldb.cpp:436] Reading position from leveldb took 35707ns
I0101 01:50:34.948550 31052 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.473465ms
I0101 01:50:34.948596 31052 replica.cpp:712] Persisted action at 0
I0101 01:50:34.949342 31039 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 01:50:34.990303 31039 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.824175ms
I0101 01:50:34.990348 31039 replica.cpp:712] Persisted action at 0
I0101 01:50:34.990373 31039 replica.cpp:697] Replica learned NOP action at position 0
I0101 01:50:34.991149 31044 log.cpp:675] Writer started with ending position 0
I0101 01:50:34.992460 31039 leveldb.cpp:436] Reading position from leveldb took 34532ns
I0101 01:50:34.993484 31045 registrar.cpp:340] Successfully fetched the registry (0B) in 246.976768ms
I0101 01:50:34.993633 31045 registrar.cpp:439] Applied 1 operations in 44088ns; attempting to update the 'registry'
I0101 01:50:34.994225 31047 log.cpp:683] Attempting to append 170 bytes to the log
I0101 01:50:34.994341 31053 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 01:50:34.995076 31052 replica.cpp:537] Replica received write request for position 1 from (12856)@172.17.0.5:56330
I0101 01:50:35.032207 31052 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 37.084815ms
I0101 01:50:35.032251 31052 replica.cpp:712] Persisted action at 1
I0101 01:50:35.033051 31046 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 01:50:35.073923 31046 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.828377ms
I0101 01:50:35.073966 31046 replica.cpp:712] Persisted action at 1
I0101 01:50:35.073997 31046 replica.cpp:697] Replica learned APPEND action at position 1
I0101 01:50:35.075155 31039 registrar.cpp:484] Successfully updated the 'registry' in 81.462016ms
I0101 01:50:35.075336 31039 registrar.cpp:370] Successfully recovered registrar
I0101 01:50:35.075403 31053 log.cpp:702] Attempting to truncate the log to 1
I0101 01:50:35.075549 31045 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 01:50:35.075990 31049 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 01:50:35.076084 31038 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 01:50:35.076666 31043 replica.cpp:537] Replica received write request for position 2 from (12857)@172.17.0.5:56330
I0101 01:50:35.112994 31043 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 36.280059ms
I0101 01:50:35.113037 31043 replica.cpp:712] Persisted action at 2
I0101 01:50:35.113809 31041 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 01:50:35.138252 31041 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.398162ms
I0101 01:50:35.138332 31041 leveldb.cpp:399] Deleting ~1 keys from leveldb took 41034ns
I0101 01:50:35.138356 31041 replica.cpp:712] Persisted action at 2
I0101 01:50:35.138378 31041 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 01:50:35.147125 31019 scheduler.cpp:154] Version: 0.27.0
I0101 01:50:35.147910 31038 scheduler.cpp:236] New master detected at master@172.17.0.5:56330
I0101 01:50:35.149142 31049 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:56330
I0101 01:50:35.151348 31038 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 01:50:35.151901 31050 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:55813
I0101 01:50:35.152144 31050 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 01:50:35.152231 31050 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 01:50:35.152586 31050 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 01:50:35.153074 31046 hierarchical.cpp:260] Added framework e303a848-982d-492f-9afc-ad9a565cd127-0000
I0101 01:50:35.153192 31046 hierarchical.cpp:1329] No resources available to allocate!
I0101 01:50:35.153122 31052 master.hpp:1659] Sending heartbeat to e303a848-982d-492f-9afc-ad9a565cd127-0000
I0101 01:50:35.153272 31046 hierarchical.cpp:1423] No inverse offers to send out!
I0101 01:50:35.153334 31046 hierarchical.cpp:1079] Performed allocation for 0 slaves in 221012ns
I0101 01:50:35.154041 31050 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:56330
I0101 01:50:35.154567 31050 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:56330
I0101 01:50:35.155364 31047 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 01:50:35.155423 31050 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:56330
I0101 01:50:35.157145 31047 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 01:50:35.157666 31046 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:55814
I0101 01:50:35.157781 31046 master.cpp:2636] Processing REQUEST call for framework e303a848-982d-492f-9afc-ad9a565cd127-0000 (default)
I0101 01:50:35.157968 31044 hierarchical.cpp:579] Received resource request from framework e303a848-982d-492f-9afc-ad9a565cd127-0000
I0101 01:50:35.158314 31042 master.cpp:930] Master terminating
I0101 01:50:35.158787 31043 hierarchical.cpp:321] Removed framework e303a848-982d-492f-9afc-ad9a565cd127-0000
E0101 01:50:35.159684 31043 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (572 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0101 01:50:35.231384 31019 leveldb.cpp:174] Opened db in 64.786741ms
I0101 01:50:35.248484 31019 leveldb.cpp:181] Compacted db in 17.057796ms
I0101 01:50:35.248548 31019 leveldb.cpp:196] Created db iterator in 18602ns
I0101 01:50:35.248570 31019 leveldb.cpp:202] Seeked to beginning of db in 2073ns
I0101 01:50:35.248581 31019 leveldb.cpp:271] Iterated through 0 keys in the db in 430ns
I0101 01:50:35.248652 31019 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 01:50:35.249169 31041 recover.cpp:447] Starting replica recovery
I0101 01:50:35.249510 31048 recover.cpp:473] Replica is in EMPTY status
I0101 01:50:35.250690 31053 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12865)@172.17.0.5:56330
I0101 01:50:35.250948 31049 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 01:50:35.251457 31048 recover.cpp:564] Updating replica status to STARTING
I0101 01:50:35.252481 31052 master.cpp:365] Master f80fa85a-ca80-49c0-ba33-885fcee1bdaf (19ca6dd634d5) started on 172.17.0.5:56330
I0101 01:50:35.252516 31052 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/AzqNAM/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/AzqNAM/master" --zk_session_timeout="10secs"
I0101 01:50:35.252841 31052 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 01:50:35.252853 31052 master.cpp:417] Master only allowing authenticated slaves to register
I0101 01:50:35.252861 31052 credentials.hpp:35] Loading credentials for authentication from '/tmp/AzqNAM/credentials'
I0101 01:50:35.253088 31052 master.cpp:456] Using default 'crammd5' authenticator
I0101 01:50:35.253203 31052 master.cpp:493] Authorization enabled
I0101 01:50:35.253357 31046 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 01:50:35.253367 31051 whitelist_watcher.cpp:77] No whitelist given
I0101 01:50:35.254952 31039 master.cpp:1629] The newly elected leader is master@172.17.0.5:56330 with id f80fa85a-ca80-49c0-ba33-885fcee1bdaf
I0101 01:50:35.254988 31039 master.cpp:1642] Elected as the leading master!
I0101 01:50:35.255008 31039 master.cpp:1387] Recovering from registrar
I0101 01:50:35.255211 31051 registrar.cpp:307] Recovering registrar
I0101 01:50:35.315554 31044 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 63.913019ms
I0101 01:50:35.315584 31044 replica.cpp:320] Persisted replica status to STARTING
I0101 01:50:35.315868 31039 recover.cpp:473] Replica is in STARTING status
I0101 01:50:35.316949 31050 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12866)@172.17.0.5:56330
I0101 01:50:35.317245 31040 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 01:50:35.317670 31050 recover.cpp:564] Updating replica status to VOTING
I0101 01:50:35.349133 31043 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.303361ms
I0101 01:50:35.349169 31043 replica.cpp:320] Persisted replica status to VOTING
I0101 01:50:35.349295 31043 recover.cpp:578] Successfully joined the Paxos group
I0101 01:50:35.349493 31043 recover.cpp:462] Recover process terminated
I0101 01:50:35.350066 31042 log.cpp:659] Attempting to start the writer
I0101 01:50:35.351258 31048 replica.cpp:493] Replica received implicit promise request from (12867)@172.17.0.5:56330 with proposal 1
I0101 01:50:35.374135 31048 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.8344ms
I0101 01:50:35.374177 31048 replica.cpp:342] Persisted promised to 1
I0101 01:50:35.374927 31049 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 01:50:35.376294 31042 replica.cpp:388] Replica received explicit promise request from (12868)@172.17.0.5:56330 for position 0 with proposal 2
I0101 01:50:35.424314 31042 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 47.964931ms
I0101 01:50:35.424360 31042 replica.cpp:712] Persisted action at 0
I0101 01:50:35.425681 31041 replica.cpp:537] Replica received write request for position 0 from (12869)@172.17.0.5:56330
I0101 01:50:35.425763 31041 leveldb.cpp:436] Reading position from leveldb took 37607ns
I0101 01:50:35.449462 31041 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.642465ms
I0101 01:50:35.449501 31041 replica.cpp:712] Persisted action at 0
I0101 01:50:35.450265 31050 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 01:50:35.474586 31050 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.230424ms
I0101 01:50:35.474644 31050 replica.cpp:712] Persisted action at 0
I0101 01:50:35.474668 31050 replica.cpp:697] Replica learned NOP action at position 0
I0101 01:50:35.475400 31050 log.cpp:675] Writer started with ending position 0
I0101 01:50:35.476511 31042 leveldb.cpp:436] Reading position from leveldb took 28616ns
I0101 01:50:35.477318 31044 registrar.cpp:340] Successfully fetched the registry (0B) in 222.048256ms
I0101 01:50:35.477433 31044 registrar.cpp:439] Applied 1 operations in 24385ns; attempting to update the 'registry'
I0101 01:50:35.478143 31050 log.cpp:683] Attempting to append 170 bytes to the log
I0101 01:50:35.478261 31051 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 01:50:35.479014 31046 replica.cpp:537] Replica received write request for position 1 from (12870)@172.17.0.5:56330
I0101 01:50:35.500236 31046 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 21.180913ms
I0101 01:50:35.500283 31046 replica.cpp:712] Persisted action at 1
I0101 01:50:35.501127 31043 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 01:50:35.525447 31043 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.282302ms
I0101 01:50:35.525490 31043 replica.cpp:712] Persisted action at 1
I0101 01:50:35.525527 31043 replica.cpp:697] Replica learned APPEND action at position 1
I0101 01:50:35.526679 31052 registrar.cpp:484] Successfully updated the 'registry' in 49.171968ms
I0101 01:50:35.526872 31052 registrar.cpp:370] Successfully recovered registrar
I0101 01:50:35.526950 31048 log.cpp:702] Attempting to truncate the log to 1
I0101 01:50:35.527222 31051 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 01:50:35.527346 31047 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 01:50:35.527371 31041 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 01:50:35.528280 31053 replica.cpp:537] Replica received write request for position 2 from (12871)@172.17.0.5:56330
I0101 01:50:35.550504 31053 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.17741ms
I0101 01:50:35.550544 31053 replica.cpp:712] Persisted action at 2
I0101 01:50:35.551321 31047 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 01:50:35.575587 31047 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.223364ms
I0101 01:50:35.575688 31047 leveldb.cpp:399] Deleting ~1 keys from leveldb took 41926ns
I0101 01:50:35.575716 31047 replica.cpp:712] Persisted action at 2
I0101 01:50:35.575737 31047 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 01:50:35.578289 31019 scheduler.cpp:154] Version: 0.27.0
I0101 01:50:35.579093 31041 scheduler.cpp:236] New master detected at master@172.17.0.5:56330
I0101 01:50:35.580519 31051 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:56330
I0101 01:50:35.582532 31042 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 01:50:35.583080 31049 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:55815
I0101 01:50:35.583380 31049 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 01:50:35.583434 31049 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 01:50:35.583688 31049 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 01:50:35.584090 31044 hierarchical.cpp:260] Added framework f80fa85a-ca80-49c0-ba33-885fcee1bdaf-0000
I0101 01:50:35.584151 31044 hierarchical.cpp:1329] No resources available to allocate!
I0101 01:50:35.584182 31044 hierarchical.cpp:1423] No inverse offers to send out!
I0101 01:50:35.584204 31044 hierarchical.cpp:1079] Performed allocation for 0 slaves in 90616ns
I0101 01:50:35.584213 31041 master.hpp:1659] Sending heartbeat to f80fa85a-ca80-49c0-ba33-885fcee1bdaf-0000
I0101 01:50:35.585105 31050 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:56330
I0101 01:50:35.585588 31050 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:56330
I0101 01:50:35.586066 31042 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 01:50:35.586107 31050 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:56330
I0101 01:50:35.587510 31052 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 01:50:35.587924 31048 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:55816
I0101 01:50:35.588130 31048 master.cpp:2636] Processing REQUEST call for framework f80fa85a-ca80-49c0-ba33-885fcee1bdaf-0000 (default)
I0101 01:50:35.588284 31040 hierarchical.cpp:579] Received resource request from framework f80fa85a-ca80-49c0-ba33-885fcee1bdaf-0000
I0101 01:50:35.588537 31043 master.cpp:930] Master terminating
I0101 01:50:35.588702 31048 hierarchical.cpp:321] Removed framework f80fa85a-ca80-49c0-ba33-885fcee1bdaf-0000
E0101 01:50:35.589692 31045 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (429 ms)
[----------] 22 tests from ContentType/SchedulerTest (15651 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (710505 ms total)
[ PASSED ] 913 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[ FAILED ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization
2 FAILED TESTS
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-1451610581-24737
Untagged: mesos-1451610581-24737:latest
Deleted: 5aa576111262c533f8898acf82f709810dcb4a8138f2c155419e0eea70b602e4
Deleted: 2d4af597dd4bf29a7d0f279b64dba68dc7fbcb43b24af76dded61661d4cc9191
Deleted: bc08c0bccf29eff0e63bf975e1807c58144c2b0141adea4d86dea8aecb3562bd
Deleted: cf56146591d4ff8756fc2b325f9ccf3eee76403eace3782289d5545a31fe4444
Deleted: 5357123609b14bf3bf886df45c78b0ad6d9a8f23317b44093bcf244824a75b13
Deleted: c66c79a844d3172e960767d7bca51361deaa49e3b6497a9c68750d0f262c20fb
Deleted: 60232e94f80b175b4812142de10556fd464f68e6d4620dcfc3974cc0d433b7c9
Deleted: 737faa06cd6f14000da98191b0cb276afe9832866f8531bea719f33853b23596
Deleted: 283db6b4e174e17bd37fa74658279074f016c5f99e88dafba6d268865e8ede5a
Deleted: d6ca1691404091973a3f006105fc972380aa9126e1726e65f221a2c753a02d4e
Deleted: 90c7ed1d64add0a41f2aa04f386d5bb97c829d405b893ec58c5e23e11e624eb3
Deleted: 877ce32eb524f3ddaad3a25862ad0e63d7241b4c6465cdb98e5a41847c074dcb
Deleted: a9df99460e8240f43c9305f05079d167cc4711e26fbbc19428c4e90ed6e6135f
Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : mesos-reviewbot #10519
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10519/>
Build failed in Jenkins: mesos-reviewbot #10518
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10518/>
------------------------------------------
[...truncated 166151 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (881 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0101 22:35:55.883417 31019 leveldb.cpp:174] Opened db in 115.416274ms
I0101 22:35:55.935228 31019 leveldb.cpp:181] Compacted db in 51.724141ms
I0101 22:35:55.935336 31019 leveldb.cpp:196] Created db iterator in 32884ns
I0101 22:35:55.935360 31019 leveldb.cpp:202] Seeked to beginning of db in 4983ns
I0101 22:35:55.935374 31019 leveldb.cpp:271] Iterated through 0 keys in the db in 388ns
I0101 22:35:55.935438 31019 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 22:35:55.936384 31038 recover.cpp:447] Starting replica recovery
I0101 22:35:55.937042 31038 recover.cpp:473] Replica is in EMPTY status
I0101 22:35:55.938730 31051 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12823)@172.17.0.2:58932
I0101 22:35:55.939395 31047 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 22:35:55.939839 31043 recover.cpp:564] Updating replica status to STARTING
I0101 22:35:55.941004 31050 master.cpp:365] Master bed7a913-a882-4381-9abf-c56a6b056858 (6a95f11e1db6) started on 172.17.0.2:58932
I0101 22:35:55.941030 31050 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/nrvJA6/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/nrvJA6/master" --zk_session_timeout="10secs"
I0101 22:35:55.941411 31050 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 22:35:55.941431 31050 master.cpp:417] Master only allowing authenticated slaves to register
I0101 22:35:55.941442 31050 credentials.hpp:35] Loading credentials for authentication from '/tmp/nrvJA6/credentials'
I0101 22:35:55.941792 31050 master.cpp:456] Using default 'crammd5' authenticator
I0101 22:35:55.941954 31050 master.cpp:493] Authorization enabled
I0101 22:35:55.942225 31042 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 22:35:55.942226 31039 whitelist_watcher.cpp:77] No whitelist given
I0101 22:35:55.944427 31051 master.cpp:1629] The newly elected leader is master@172.17.0.2:58932 with id bed7a913-a882-4381-9abf-c56a6b056858
I0101 22:35:55.944469 31051 master.cpp:1642] Elected as the leading master!
I0101 22:35:55.944497 31051 master.cpp:1387] Recovering from registrar
I0101 22:35:55.944689 31041 registrar.cpp:307] Recovering registrar
I0101 22:35:55.968621 31045 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 28.557074ms
I0101 22:35:55.968684 31045 replica.cpp:320] Persisted replica status to STARTING
I0101 22:35:55.969008 31046 recover.cpp:473] Replica is in STARTING status
I0101 22:35:55.970238 31045 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12824)@172.17.0.2:58932
I0101 22:35:55.970711 31053 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 22:35:55.971258 31038 recover.cpp:564] Updating replica status to VOTING
I0101 22:35:56.002233 31039 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.775481ms
I0101 22:35:56.002329 31039 replica.cpp:320] Persisted replica status to VOTING
I0101 22:35:56.002607 31046 recover.cpp:578] Successfully joined the Paxos group
I0101 22:35:56.002846 31046 recover.cpp:462] Recover process terminated
I0101 22:35:56.003543 31050 log.cpp:659] Attempting to start the writer
I0101 22:35:56.004704 31043 replica.cpp:493] Replica received implicit promise request from (12825)@172.17.0.2:58932 with proposal 1
I0101 22:35:56.063122 31043 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 58.359209ms
I0101 22:35:56.063216 31043 replica.cpp:342] Persisted promised to 1
I0101 22:35:56.063961 31048 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 22:35:56.065145 31044 replica.cpp:388] Replica received explicit promise request from (12826)@172.17.0.2:58932 for position 0 with proposal 2
I0101 22:35:56.113477 31044 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 48.263627ms
I0101 22:35:56.113579 31044 replica.cpp:712] Persisted action at 0
I0101 22:35:56.115460 31043 replica.cpp:537] Replica received write request for position 0 from (12827)@172.17.0.2:58932
I0101 22:35:56.115583 31043 leveldb.cpp:436] Reading position from leveldb took 63744ns
I0101 22:35:56.180411 31043 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 64.728864ms
I0101 22:35:56.180510 31043 replica.cpp:712] Persisted action at 0
I0101 22:35:56.181655 31039 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 22:35:56.230556 31039 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 48.826139ms
I0101 22:35:56.230646 31039 replica.cpp:712] Persisted action at 0
I0101 22:35:56.230687 31039 replica.cpp:697] Replica learned NOP action at position 0
I0101 22:35:56.231925 31039 log.cpp:675] Writer started with ending position 0
I0101 22:35:56.233243 31049 leveldb.cpp:436] Reading position from leveldb took 56470ns
I0101 22:35:56.234326 31042 registrar.cpp:340] Successfully fetched the registry (0B) in 289.587968ms
I0101 22:35:56.234462 31042 registrar.cpp:439] Applied 1 operations in 32421ns; attempting to update the 'registry'
I0101 22:35:56.235426 31044 log.cpp:683] Attempting to append 170 bytes to the log
I0101 22:35:56.235599 31042 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 22:35:56.236485 31044 replica.cpp:537] Replica received write request for position 1 from (12828)@172.17.0.2:58932
I0101 22:35:56.289353 31044 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 52.805971ms
I0101 22:35:56.289428 31044 replica.cpp:712] Persisted action at 1
I0101 22:35:56.290143 31041 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 22:35:56.339320 31041 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 49.118611ms
I0101 22:35:56.339421 31041 replica.cpp:712] Persisted action at 1
I0101 22:35:56.339468 31041 replica.cpp:697] Replica learned APPEND action at position 1
I0101 22:35:56.341094 31045 registrar.cpp:484] Successfully updated the 'registry' in 106.55488ms
I0101 22:35:56.341300 31045 registrar.cpp:370] Successfully recovered registrar
I0101 22:35:56.341593 31053 log.cpp:702] Attempting to truncate the log to 1
I0101 22:35:56.341868 31051 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 22:35:56.342020 31038 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 22:35:56.342070 31053 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 22:35:56.342998 31046 replica.cpp:537] Replica received write request for position 2 from (12829)@172.17.0.2:58932
I0101 22:35:56.385823 31046 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 42.76184ms
I0101 22:35:56.385895 31046 replica.cpp:712] Persisted action at 2
I0101 22:35:56.386739 31051 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 22:35:56.436097 31051 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 49.308395ms
I0101 22:35:56.436230 31051 leveldb.cpp:399] Deleting ~1 keys from leveldb took 56587ns
I0101 22:35:56.436256 31051 replica.cpp:712] Persisted action at 2
I0101 22:35:56.436286 31051 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 22:35:56.444037 31019 scheduler.cpp:154] Version: 0.27.0
I0101 22:35:56.444907 31039 scheduler.cpp:236] New master detected at master@172.17.0.2:58932
I0101 22:35:56.446053 31047 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:58932
I0101 22:35:56.448092 31040 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 22:35:56.448554 31039 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53139
I0101 22:35:56.448742 31039 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 22:35:56.448814 31039 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 22:35:56.449162 31042 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 22:35:56.449657 31050 hierarchical.cpp:260] Added framework bed7a913-a882-4381-9abf-c56a6b056858-0000
I0101 22:35:56.449714 31045 master.hpp:1659] Sending heartbeat to bed7a913-a882-4381-9abf-c56a6b056858-0000
I0101 22:35:56.449723 31050 hierarchical.cpp:1329] No resources available to allocate!
I0101 22:35:56.449769 31050 hierarchical.cpp:1423] No inverse offers to send out!
I0101 22:35:56.449791 31050 hierarchical.cpp:1079] Performed allocation for 0 slaves in 110007ns
I0101 22:35:56.450518 31040 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:58932
I0101 22:35:56.451025 31040 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:58932
I0101 22:35:56.452409 31040 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:58932
I0101 22:35:56.453336 31050 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 22:35:56.453934 31050 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 22:35:56.454401 31050 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53140
I0101 22:35:56.454524 31050 master.cpp:2636] Processing REQUEST call for framework bed7a913-a882-4381-9abf-c56a6b056858-0000 (default)
I0101 22:35:56.454661 31038 hierarchical.cpp:579] Received resource request from framework bed7a913-a882-4381-9abf-c56a6b056858-0000
I0101 22:35:56.455031 31045 master.cpp:930] Master terminating
I0101 22:35:56.455297 31052 hierarchical.cpp:321] Removed framework bed7a913-a882-4381-9abf-c56a6b056858-0000
E0101 22:35:56.456648 31038 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (695 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0101 22:35:56.604296 31019 leveldb.cpp:174] Opened db in 141.864789ms
I0101 22:35:56.656949 31019 leveldb.cpp:181] Compacted db in 52.563089ms
I0101 22:35:56.657066 31019 leveldb.cpp:196] Created db iterator in 33578ns
I0101 22:35:56.657089 31019 leveldb.cpp:202] Seeked to beginning of db in 3836ns
I0101 22:35:56.657102 31019 leveldb.cpp:271] Iterated through 0 keys in the db in 435ns
I0101 22:35:56.657181 31019 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 22:35:56.658115 31049 recover.cpp:447] Starting replica recovery
I0101 22:35:56.658421 31041 recover.cpp:473] Replica is in EMPTY status
I0101 22:35:56.659484 31039 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12837)@172.17.0.2:58932
I0101 22:35:56.659915 31043 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 22:35:56.660398 31039 recover.cpp:564] Updating replica status to STARTING
I0101 22:35:56.662847 31040 master.cpp:365] Master fd370785-e345-482c-a2b6-7b8f98cea3a3 (6a95f11e1db6) started on 172.17.0.2:58932
I0101 22:35:56.662881 31040 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/miEq8R/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/miEq8R/master" --zk_session_timeout="10secs"
I0101 22:35:56.663292 31040 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 22:35:56.663312 31040 master.cpp:417] Master only allowing authenticated slaves to register
I0101 22:35:56.663326 31040 credentials.hpp:35] Loading credentials for authentication from '/tmp/miEq8R/credentials'
I0101 22:35:56.663647 31040 master.cpp:456] Using default 'crammd5' authenticator
I0101 22:35:56.663801 31040 master.cpp:493] Authorization enabled
I0101 22:35:56.663983 31051 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 22:35:56.663995 31046 whitelist_watcher.cpp:77] No whitelist given
I0101 22:35:56.666262 31051 master.cpp:1629] The newly elected leader is master@172.17.0.2:58932 with id fd370785-e345-482c-a2b6-7b8f98cea3a3
I0101 22:35:56.666304 31051 master.cpp:1642] Elected as the leading master!
I0101 22:35:56.666327 31051 master.cpp:1387] Recovering from registrar
I0101 22:35:56.666450 31052 registrar.cpp:307] Recovering registrar
I0101 22:35:56.694926 31043 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 34.357019ms
I0101 22:35:56.695053 31043 replica.cpp:320] Persisted replica status to STARTING
I0101 22:35:56.695426 31041 recover.cpp:473] Replica is in STARTING status
I0101 22:35:56.696910 31043 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12838)@172.17.0.2:58932
I0101 22:35:56.697173 31041 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 22:35:56.697700 31047 recover.cpp:564] Updating replica status to VOTING
I0101 22:35:56.740629 31040 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 42.744497ms
I0101 22:35:56.740700 31040 replica.cpp:320] Persisted replica status to VOTING
I0101 22:35:56.740890 31047 recover.cpp:578] Successfully joined the Paxos group
I0101 22:35:56.741317 31047 recover.cpp:462] Recover process terminated
I0101 22:35:56.741662 31048 log.cpp:659] Attempting to start the writer
I0101 22:35:56.743017 31053 replica.cpp:493] Replica received implicit promise request from (12839)@172.17.0.2:58932 with proposal 1
I0101 22:35:56.765807 31053 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.735541ms
I0101 22:35:56.765882 31053 replica.cpp:342] Persisted promised to 1
I0101 22:35:56.766628 31053 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 22:35:56.768061 31049 replica.cpp:388] Replica received explicit promise request from (12840)@172.17.0.2:58932 for position 0 with proposal 2
I0101 22:35:56.791013 31049 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.883146ms
I0101 22:35:56.791087 31049 replica.cpp:712] Persisted action at 0
I0101 22:35:56.792517 31041 replica.cpp:537] Replica received write request for position 0 from (12841)@172.17.0.2:58932
I0101 22:35:56.792598 31041 leveldb.cpp:436] Reading position from leveldb took 41660ns
I0101 22:35:56.816159 31041 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.49032ms
I0101 22:35:56.816236 31041 replica.cpp:712] Persisted action at 0
I0101 22:35:56.816983 31041 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 22:35:56.841629 31041 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.59475ms
I0101 22:35:56.841702 31041 replica.cpp:712] Persisted action at 0
I0101 22:35:56.841728 31041 replica.cpp:697] Replica learned NOP action at position 0
I0101 22:35:56.842705 31041 log.cpp:675] Writer started with ending position 0
I0101 22:35:56.843848 31049 leveldb.cpp:436] Reading position from leveldb took 48294ns
I0101 22:35:56.844786 31043 registrar.cpp:340] Successfully fetched the registry (0B) in 178.292992ms
I0101 22:35:56.844900 31043 registrar.cpp:439] Applied 1 operations in 31400ns; attempting to update the 'registry'
I0101 22:35:56.845612 31046 log.cpp:683] Attempting to append 170 bytes to the log
I0101 22:35:56.845751 31051 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 22:35:56.846536 31050 replica.cpp:537] Replica received write request for position 1 from (12842)@172.17.0.2:58932
I0101 22:35:56.887979 31050 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 41.383266ms
I0101 22:35:56.888051 31050 replica.cpp:712] Persisted action at 1
I0101 22:35:56.888842 31038 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 22:35:56.947387 31038 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 58.492679ms
I0101 22:35:56.947473 31038 replica.cpp:712] Persisted action at 1
I0101 22:35:56.947509 31038 replica.cpp:697] Replica learned APPEND action at position 1
I0101 22:35:56.949388 31046 registrar.cpp:484] Successfully updated the 'registry' in 104.423168ms
I0101 22:35:56.949555 31046 registrar.cpp:370] Successfully recovered registrar
I0101 22:35:56.949704 31038 log.cpp:702] Attempting to truncate the log to 1
I0101 22:35:56.949859 31049 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 22:35:56.950029 31038 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 22:35:56.950009 31051 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 22:35:56.951239 31046 replica.cpp:537] Replica received write request for position 2 from (12843)@172.17.0.2:58932
I0101 22:35:56.989645 31046 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.333403ms
I0101 22:35:56.989716 31046 replica.cpp:712] Persisted action at 2
I0101 22:35:56.990767 31039 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 22:35:57.031610 31039 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.791688ms
I0101 22:35:57.031740 31039 leveldb.cpp:399] Deleting ~1 keys from leveldb took 59032ns
I0101 22:35:57.031762 31039 replica.cpp:712] Persisted action at 2
I0101 22:35:57.031790 31039 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 22:35:57.042912 31019 scheduler.cpp:154] Version: 0.27.0
I0101 22:35:57.044065 31050 scheduler.cpp:236] New master detected at master@172.17.0.2:58932
I0101 22:35:57.045231 31038 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:58932
I0101 22:35:57.048015 31047 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 22:35:57.048822 31047 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53148
I0101 22:35:57.049440 31047 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 22:35:57.049535 31047 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 22:35:57.050011 31053 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 22:35:57.050602 31047 hierarchical.cpp:260] Added framework fd370785-e345-482c-a2b6-7b8f98cea3a3-0000
I0101 22:35:57.050706 31047 hierarchical.cpp:1329] No resources available to allocate!
I0101 22:35:57.050758 31047 hierarchical.cpp:1423] No inverse offers to send out!
I0101 22:35:57.050791 31047 hierarchical.cpp:1079] Performed allocation for 0 slaves in 155136ns
I0101 22:35:57.050916 31049 master.hpp:1659] Sending heartbeat to fd370785-e345-482c-a2b6-7b8f98cea3a3-0000
I0101 22:35:57.051873 31052 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:58932
I0101 22:35:57.052371 31052 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:58932
I0101 22:35:57.053078 31038 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 22:35:57.053133 31048 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:58932
I0101 22:35:57.054946 31053 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 22:35:57.055467 31053 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53149
I0101 22:35:57.055806 31053 master.cpp:2636] Processing REQUEST call for framework fd370785-e345-482c-a2b6-7b8f98cea3a3-0000 (default)
I0101 22:35:57.055995 31044 hierarchical.cpp:579] Received resource request from framework fd370785-e345-482c-a2b6-7b8f98cea3a3-0000
I0101 22:35:57.056303 31019 master.cpp:930] Master terminating
I0101 22:35:57.056509 31044 hierarchical.cpp:321] Removed framework fd370785-e345-482c-a2b6-7b8f98cea3a3-0000
E0101 22:35:57.057874 31045 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (601 ms)
[----------] 22 tests from ContentType/SchedulerTest (19435 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (853709 ms total)
[ PASSED ] 913 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[ FAILED ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization
2 FAILED TESTS
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-1451685015-28723
Untagged: mesos-1451685015-28723:latest
Deleted: fdf745ae05af46c81f72c3b5859b749e89e1222c9ec244b18dad8c84c7ccea48
Deleted: aee4784408e13d48925a8c427a4abc28ef5fb60878060c6e15bbb8c226d7d37d
Deleted: 323cb42e5630af48bbdbb8a11fd5572a23716e6354a9e189807df0e187e8963c
Deleted: 46d3e4746d1d0dbaa8abb9af7eeb0c2adffa9fc048d026998e732d5d5548a0ea
Deleted: 294bdb56360c11846469d5bad39be556a0db95a97400a51b859a3ee882e51095
Deleted: c96565a5c0fa41a45263500dfa31ba1607168d752a9a6f3f2c6ae42ac4a1b3f2
Deleted: 6021d680a96ff8049d093318f67588c8af1a9b879ad54945f9435145d90ada56
Deleted: 3b6494a2cf65209b6082ca010a7d7b3d2fd2b084930eaff12453cc43901a9470
Deleted: 49771110dfd00da52154feb99fd325428f33082255d7ac236e1e96fcb3abd475
Deleted: 50b3dc05ca38032d85db72fdd7194b967357e3481717c82a67e42387c4ff8f44
Deleted: a5f09ff9d138e60d6855277c7098c4407f600917d9f42552b1d22d0e801b86a9
Deleted: 13512da729ad7a856860b675618364e68d4b2659f6f80393e2f6bc3ae883807d
Deleted: 0f5078695b860d984a2fa79fbf05c6f3dbfe771cdc7bb0f2614d7de45dd831bb
Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10517
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10517/>
------------------------------------------
[...truncated 165742 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (944 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0101 05:27:56.807873 31018 leveldb.cpp:174] Opened db in 132.962268ms
I0101 05:27:56.852802 31018 leveldb.cpp:181] Compacted db in 44.88852ms
I0101 05:27:56.852865 31018 leveldb.cpp:196] Created db iterator in 18910ns
I0101 05:27:56.852886 31018 leveldb.cpp:202] Seeked to beginning of db in 1920ns
I0101 05:27:56.852897 31018 leveldb.cpp:271] Iterated through 0 keys in the db in 305ns
I0101 05:27:56.852936 31018 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 05:27:56.853621 31051 recover.cpp:447] Starting replica recovery
I0101 05:27:56.854074 31051 recover.cpp:473] Replica is in EMPTY status
I0101 05:27:56.855047 31037 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12834)@172.17.0.2:56458
I0101 05:27:56.855479 31051 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 05:27:56.856559 31045 master.cpp:365] Master 7100f71a-86cb-42bc-ad2c-6d9db44a3686 (da49798f2d01) started on 172.17.0.2:56458
I0101 05:27:56.856582 31045 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/oEVqkG/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/oEVqkG/master" --zk_session_timeout="10secs"
I0101 05:27:56.856899 31041 recover.cpp:564] Updating replica status to STARTING
I0101 05:27:56.856962 31045 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 05:27:56.856986 31045 master.cpp:417] Master only allowing authenticated slaves to register
I0101 05:27:56.857000 31045 credentials.hpp:35] Loading credentials for authentication from '/tmp/oEVqkG/credentials'
I0101 05:27:56.857321 31045 master.cpp:456] Using default 'crammd5' authenticator
I0101 05:27:56.857476 31045 master.cpp:493] Authorization enabled
I0101 05:27:56.857658 31041 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 05:27:56.857779 31039 whitelist_watcher.cpp:77] No whitelist given
I0101 05:27:56.859465 31050 master.cpp:1629] The newly elected leader is master@172.17.0.2:56458 with id 7100f71a-86cb-42bc-ad2c-6d9db44a3686
I0101 05:27:56.859495 31050 master.cpp:1642] Elected as the leading master!
I0101 05:27:56.859519 31050 master.cpp:1387] Recovering from registrar
I0101 05:27:56.859681 31041 registrar.cpp:307] Recovering registrar
I0101 05:27:56.894410 31042 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.3455ms
I0101 05:27:56.894446 31042 replica.cpp:320] Persisted replica status to STARTING
I0101 05:27:56.894666 31037 recover.cpp:473] Replica is in STARTING status
I0101 05:27:56.895745 31049 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12835)@172.17.0.2:56458
I0101 05:27:56.896044 31039 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 05:27:56.896466 31044 recover.cpp:564] Updating replica status to VOTING
I0101 05:27:56.936203 31052 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.601453ms
I0101 05:27:56.936239 31052 replica.cpp:320] Persisted replica status to VOTING
I0101 05:27:56.936345 31050 recover.cpp:578] Successfully joined the Paxos group
I0101 05:27:56.936595 31050 recover.cpp:462] Recover process terminated
I0101 05:27:56.937041 31046 log.cpp:659] Attempting to start the writer
I0101 05:27:56.938339 31046 replica.cpp:493] Replica received implicit promise request from (12836)@172.17.0.2:56458 with proposal 1
I0101 05:27:56.977987 31046 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.604774ms
I0101 05:27:56.978023 31046 replica.cpp:342] Persisted promised to 1
I0101 05:27:56.978904 31042 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 05:27:56.980264 31043 replica.cpp:388] Replica received explicit promise request from (12837)@172.17.0.2:56458 for position 0 with proposal 2
I0101 05:27:57.019816 31043 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.50552ms
I0101 05:27:57.019860 31043 replica.cpp:712] Persisted action at 0
I0101 05:27:57.021057 31044 replica.cpp:537] Replica received write request for position 0 from (12838)@172.17.0.2:56458
I0101 05:27:57.021162 31044 leveldb.cpp:436] Reading position from leveldb took 57293ns
I0101 05:27:57.061615 31044 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.399861ms
I0101 05:27:57.061653 31044 replica.cpp:712] Persisted action at 0
I0101 05:27:57.062374 31043 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 05:27:57.103353 31043 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.941585ms
I0101 05:27:57.103390 31043 replica.cpp:712] Persisted action at 0
I0101 05:27:57.103412 31043 replica.cpp:697] Replica learned NOP action at position 0
I0101 05:27:57.104233 31048 log.cpp:675] Writer started with ending position 0
I0101 05:27:57.105357 31048 leveldb.cpp:436] Reading position from leveldb took 35714ns
I0101 05:27:57.106400 31048 registrar.cpp:340] Successfully fetched the registry (0B) in 246.617088ms
I0101 05:27:57.106534 31048 registrar.cpp:439] Applied 1 operations in 27347ns; attempting to update the 'registry'
I0101 05:27:57.107353 31038 log.cpp:683] Attempting to append 170 bytes to the log
I0101 05:27:57.107488 31050 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 05:27:57.108343 31041 replica.cpp:537] Replica received write request for position 1 from (12839)@172.17.0.2:56458
I0101 05:27:57.145222 31041 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.832287ms
I0101 05:27:57.145262 31041 replica.cpp:712] Persisted action at 1
I0101 05:27:57.146040 31045 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 05:27:57.190196 31045 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 44.114066ms
I0101 05:27:57.190233 31045 replica.cpp:712] Persisted action at 1
I0101 05:27:57.190256 31045 replica.cpp:697] Replica learned APPEND action at position 1
I0101 05:27:57.191296 31051 registrar.cpp:484] Successfully updated the 'registry' in 84.696064ms
I0101 05:27:57.191488 31051 registrar.cpp:370] Successfully recovered registrar
I0101 05:27:57.191576 31052 log.cpp:702] Attempting to truncate the log to 1
I0101 05:27:57.191700 31046 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 05:27:57.191990 31042 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 05:27:57.192034 31038 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 05:27:57.192539 31043 replica.cpp:537] Replica received write request for position 2 from (12840)@172.17.0.2:56458
I0101 05:27:57.225360 31043 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.787118ms
I0101 05:27:57.225399 31043 replica.cpp:712] Persisted action at 2
I0101 05:27:57.226279 31051 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 05:27:57.242871 31051 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 16.54797ms
I0101 05:27:57.242954 31051 leveldb.cpp:399] Deleting ~1 keys from leveldb took 42031ns
I0101 05:27:57.242976 31051 replica.cpp:712] Persisted action at 2
I0101 05:27:57.243000 31051 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 05:27:57.253185 31018 scheduler.cpp:154] Version: 0.27.0
I0101 05:27:57.253820 31037 scheduler.cpp:236] New master detected at master@172.17.0.2:56458
I0101 05:27:57.255059 31040 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:56458
I0101 05:27:57.257164 31052 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 05:27:57.257841 31038 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:55746
I0101 05:27:57.258090 31038 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 05:27:57.258179 31038 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 05:27:57.258512 31038 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 05:27:57.258890 31042 hierarchical.cpp:260] Added framework 7100f71a-86cb-42bc-ad2c-6d9db44a3686-0000
I0101 05:27:57.258963 31042 hierarchical.cpp:1329] No resources available to allocate!
I0101 05:27:57.258990 31045 master.hpp:1659] Sending heartbeat to 7100f71a-86cb-42bc-ad2c-6d9db44a3686-0000
I0101 05:27:57.258996 31042 hierarchical.cpp:1423] No inverse offers to send out!
I0101 05:27:57.259054 31042 hierarchical.cpp:1079] Performed allocation for 0 slaves in 128872ns
I0101 05:27:57.260006 31047 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:56458
I0101 05:27:57.260738 31047 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:56458
I0101 05:27:57.261554 31052 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 05:27:57.261638 31047 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:56458
I0101 05:27:57.263478 31039 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 05:27:57.263938 31050 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:55747
I0101 05:27:57.264070 31050 master.cpp:2636] Processing REQUEST call for framework 7100f71a-86cb-42bc-ad2c-6d9db44a3686-0000 (default)
I0101 05:27:57.264317 31040 hierarchical.cpp:579] Received resource request from framework 7100f71a-86cb-42bc-ad2c-6d9db44a3686-0000
I0101 05:27:57.264714 31050 master.cpp:930] Master terminating
I0101 05:27:57.265013 31045 hierarchical.cpp:321] Removed framework 7100f71a-86cb-42bc-ad2c-6d9db44a3686-0000
E0101 05:27:57.266216 31044 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (598 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0101 05:27:57.394415 31018 leveldb.cpp:174] Opened db in 121.58621ms
I0101 05:27:57.436422 31018 leveldb.cpp:181] Compacted db in 41.965037ms
I0101 05:27:57.436483 31018 leveldb.cpp:196] Created db iterator in 16627ns
I0101 05:27:57.436503 31018 leveldb.cpp:202] Seeked to beginning of db in 1902ns
I0101 05:27:57.436514 31018 leveldb.cpp:271] Iterated through 0 keys in the db in 310ns
I0101 05:27:57.436549 31018 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 05:27:57.437034 31037 recover.cpp:447] Starting replica recovery
I0101 05:27:57.437356 31037 recover.cpp:473] Replica is in EMPTY status
I0101 05:27:57.438020 31050 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12848)@172.17.0.2:56458
I0101 05:27:57.438415 31048 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 05:27:57.438784 31038 recover.cpp:564] Updating replica status to STARTING
I0101 05:27:57.439339 31051 master.cpp:365] Master 7bada703-dfbb-47aa-a489-696750706fc7 (da49798f2d01) started on 172.17.0.2:56458
I0101 05:27:57.439357 31051 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/2rfnTd/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/2rfnTd/master" --zk_session_timeout="10secs"
I0101 05:27:57.439585 31051 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 05:27:57.439595 31051 master.cpp:417] Master only allowing authenticated slaves to register
I0101 05:27:57.439601 31051 credentials.hpp:35] Loading credentials for authentication from '/tmp/2rfnTd/credentials'
I0101 05:27:57.439803 31051 master.cpp:456] Using default 'crammd5' authenticator
I0101 05:27:57.439904 31051 master.cpp:493] Authorization enabled
I0101 05:27:57.440047 31042 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 05:27:57.440055 31044 whitelist_watcher.cpp:77] No whitelist given
I0101 05:27:57.441545 31052 master.cpp:1629] The newly elected leader is master@172.17.0.2:56458 with id 7bada703-dfbb-47aa-a489-696750706fc7
I0101 05:27:57.441578 31052 master.cpp:1642] Elected as the leading master!
I0101 05:27:57.441596 31052 master.cpp:1387] Recovering from registrar
I0101 05:27:57.441741 31041 registrar.cpp:307] Recovering registrar
I0101 05:27:57.470532 31050 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.605742ms
I0101 05:27:57.470567 31050 replica.cpp:320] Persisted replica status to STARTING
I0101 05:27:57.470752 31051 recover.cpp:473] Replica is in STARTING status
I0101 05:27:57.471701 31045 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12849)@172.17.0.2:56458
I0101 05:27:57.472049 31040 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 05:27:57.472427 31042 recover.cpp:564] Updating replica status to VOTING
I0101 05:27:57.512233 31048 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.682105ms
I0101 05:27:57.512270 31048 replica.cpp:320] Persisted replica status to VOTING
I0101 05:27:57.512382 31045 recover.cpp:578] Successfully joined the Paxos group
I0101 05:27:57.512696 31045 recover.cpp:462] Recover process terminated
I0101 05:27:57.513247 31052 log.cpp:659] Attempting to start the writer
I0101 05:27:57.514508 31040 replica.cpp:493] Replica received implicit promise request from (12850)@172.17.0.2:56458 with proposal 1
I0101 05:27:57.553968 31040 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.429373ms
I0101 05:27:57.553995 31040 replica.cpp:342] Persisted promised to 1
I0101 05:27:57.554723 31046 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 05:27:57.556166 31038 replica.cpp:388] Replica received explicit promise request from (12851)@172.17.0.2:56458 for position 0 with proposal 2
I0101 05:27:57.595976 31038 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.762928ms
I0101 05:27:57.596021 31038 replica.cpp:712] Persisted action at 0
I0101 05:27:57.597301 31042 replica.cpp:537] Replica received write request for position 0 from (12852)@172.17.0.2:56458
I0101 05:27:57.597357 31042 leveldb.cpp:436] Reading position from leveldb took 26834ns
I0101 05:27:57.637670 31042 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.267372ms
I0101 05:27:57.637709 31042 replica.cpp:712] Persisted action at 0
I0101 05:27:57.638517 31046 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 05:27:57.679425 31046 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.806271ms
I0101 05:27:57.679453 31046 replica.cpp:712] Persisted action at 0
I0101 05:27:57.679469 31046 replica.cpp:697] Replica learned NOP action at position 0
I0101 05:27:57.680217 31044 log.cpp:675] Writer started with ending position 0
I0101 05:27:57.681390 31045 leveldb.cpp:436] Reading position from leveldb took 31704ns
I0101 05:27:57.682343 31051 registrar.cpp:340] Successfully fetched the registry (0B) in 240.553984ms
I0101 05:27:57.682461 31051 registrar.cpp:439] Applied 1 operations in 24544ns; attempting to update the 'registry'
I0101 05:27:57.683287 31042 log.cpp:683] Attempting to append 170 bytes to the log
I0101 05:27:57.683444 31037 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 05:27:57.684324 31047 replica.cpp:537] Replica received write request for position 1 from (12853)@172.17.0.2:56458
I0101 05:27:57.729506 31047 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 45.133648ms
I0101 05:27:57.729545 31047 replica.cpp:712] Persisted action at 1
I0101 05:27:57.730378 31047 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 05:27:57.771358 31047 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.941653ms
I0101 05:27:57.771396 31047 replica.cpp:712] Persisted action at 1
I0101 05:27:57.771420 31047 replica.cpp:697] Replica learned APPEND action at position 1
I0101 05:27:57.772564 31052 registrar.cpp:484] Successfully updated the 'registry' in 90.034944ms
I0101 05:27:57.772723 31052 registrar.cpp:370] Successfully recovered registrar
I0101 05:27:57.772888 31043 log.cpp:702] Attempting to truncate the log to 1
I0101 05:27:57.773046 31039 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 05:27:57.773207 31038 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 05:27:57.773298 31044 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 05:27:57.774106 31043 replica.cpp:537] Replica received write request for position 2 from (12854)@172.17.0.2:56458
I0101 05:27:57.813122 31043 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.956165ms
I0101 05:27:57.813184 31043 replica.cpp:712] Persisted action at 2
I0101 05:27:57.813886 31051 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 05:27:57.854943 31051 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 41.015656ms
I0101 05:27:57.855028 31051 leveldb.cpp:399] Deleting ~1 keys from leveldb took 44149ns
I0101 05:27:57.855062 31051 replica.cpp:712] Persisted action at 2
I0101 05:27:57.855085 31051 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 05:27:57.864615 31018 scheduler.cpp:154] Version: 0.27.0
I0101 05:27:57.865263 31040 scheduler.cpp:236] New master detected at master@172.17.0.2:56458
I0101 05:27:57.866523 31050 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:56458
I0101 05:27:57.868557 31038 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 05:27:57.869058 31049 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:55748
I0101 05:27:57.869472 31049 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 05:27:57.869537 31049 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 05:27:57.869843 31049 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 05:27:57.870317 31039 hierarchical.cpp:260] Added framework 7bada703-dfbb-47aa-a489-696750706fc7-0000
I0101 05:27:57.870383 31039 hierarchical.cpp:1329] No resources available to allocate!
I0101 05:27:57.870450 31048 master.hpp:1659] Sending heartbeat to 7bada703-dfbb-47aa-a489-696750706fc7-0000
I0101 05:27:57.870517 31039 hierarchical.cpp:1423] No inverse offers to send out!
I0101 05:27:57.870554 31039 hierarchical.cpp:1079] Performed allocation for 0 slaves in 205274ns
I0101 05:27:57.871409 31038 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:56458
I0101 05:27:57.871919 31038 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:56458
I0101 05:27:57.872951 31040 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 05:27:57.872990 31038 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:56458
I0101 05:27:57.874894 31045 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 05:27:57.875394 31038 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:55749
I0101 05:27:57.875644 31038 master.cpp:2636] Processing REQUEST call for framework 7bada703-dfbb-47aa-a489-696750706fc7-0000 (default)
I0101 05:27:57.875818 31043 hierarchical.cpp:579] Received resource request from framework 7bada703-dfbb-47aa-a489-696750706fc7-0000
I0101 05:27:57.876258 31038 master.cpp:930] Master terminating
I0101 05:27:57.876472 31051 hierarchical.cpp:321] Removed framework 7bada703-dfbb-47aa-a489-696750706fc7-0000
E0101 05:27:57.877720 31047 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (611 ms)
[----------] 22 tests from ContentType/SchedulerTest (16101 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (728428 ms total)
[ PASSED ] 913 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[ FAILED ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization
2 FAILED TESTS
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-1451623776-8726
Untagged: mesos-1451623776-8726:latest
Deleted: 4a3ebe931dba15aea58ac47c3b9f92a1b23374f5a49b8cc05cc9d8737c83fa9c
Deleted: 0fed94f059e337e27665355051c364b9bb3e383906a568ff1362d18aef17ed56
Deleted: c998ff325c11fa5fb522a07faf9729e63cf1984b937a1d8c1420cbb3fd10e411
Deleted: 5b9f08a322266e4738d0b83eeda7fc39734c88e8a2d7890f9261c485869263d9
Deleted: 33e0d7ff42a1c94eb21b7fe4087c0fc2b6604ab052efa65abb1580280b6dd5f1
Deleted: 0416527c76ce10f09e76dc41951eaaa75c946777107e50ba205de4a36ad5437e
Deleted: 619cf825dd41b4712b9baa657809d4af90f3fc852dffec838c6e4c445e246bf9
Deleted: b3be9e40a649d35a7ec4d2e802a47fae14c9119056c181e9bef33fe929bf8fc3
Deleted: d810e54d37a2f2ab57a3548e7837ccffdd0025be89652e5d925c00c3ac321a68
Deleted: 5ccbbf6d0bb84f9d762c66e43901cad4f4941e50e59f3426d41697606de58d9f
Deleted: 4815704f30606776a5626280c84d9be20277ab32c95dd33a37a5eea262359952
Deleted: 46f90c83637d73d9a0ee77ae63df98638cd68001540dc3028ab0fe78b120e751
Deleted: c26c1c89c5790fa6044dc67cfa58b6f2e2654aea31dc1d80a3fa8c54c180d8c6
Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10516
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10516/>
------------------------------------------
[...truncated 165366 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (762 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0101 02:51:30.003588 31016 leveldb.cpp:174] Opened db in 83.468544ms
I0101 02:51:30.045824 31016 leveldb.cpp:181] Compacted db in 42.165663ms
I0101 02:51:30.045889 31016 leveldb.cpp:196] Created db iterator in 20037ns
I0101 02:51:30.045910 31016 leveldb.cpp:202] Seeked to beginning of db in 2122ns
I0101 02:51:30.045922 31016 leveldb.cpp:271] Iterated through 0 keys in the db in 458ns
I0101 02:51:30.045960 31016 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 02:51:30.046497 31046 recover.cpp:447] Starting replica recovery
I0101 02:51:30.046952 31046 recover.cpp:473] Replica is in EMPTY status
I0101 02:51:30.048137 31049 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12821)@172.17.0.5:35106
I0101 02:51:30.048648 31050 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 02:51:30.049172 31046 recover.cpp:564] Updating replica status to STARTING
I0101 02:51:30.050076 31044 master.cpp:365] Master d1be98d8-4a96-43ab-8f74-51a5bd6ce205 (9e617c76a5a5) started on 172.17.0.5:35106
I0101 02:51:30.050106 31044 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/McIY5t/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/McIY5t/master" --zk_session_timeout="10secs"
I0101 02:51:30.050438 31044 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 02:51:30.050452 31044 master.cpp:417] Master only allowing authenticated slaves to register
I0101 02:51:30.050462 31044 credentials.hpp:35] Loading credentials for authentication from '/tmp/McIY5t/credentials'
I0101 02:51:30.050760 31044 master.cpp:456] Using default 'crammd5' authenticator
I0101 02:51:30.050907 31044 master.cpp:493] Authorization enabled
I0101 02:51:30.051091 31046 whitelist_watcher.cpp:77] No whitelist given
I0101 02:51:30.051096 31042 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 02:51:30.053025 31040 master.cpp:1629] The newly elected leader is master@172.17.0.5:35106 with id d1be98d8-4a96-43ab-8f74-51a5bd6ce205
I0101 02:51:30.053066 31040 master.cpp:1642] Elected as the leading master!
I0101 02:51:30.053086 31040 master.cpp:1387] Recovering from registrar
I0101 02:51:30.053259 31041 registrar.cpp:307] Recovering registrar
I0101 02:51:30.070567 31043 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 21.220676ms
I0101 02:51:30.070631 31043 replica.cpp:320] Persisted replica status to STARTING
I0101 02:51:30.070902 31045 recover.cpp:473] Replica is in STARTING status
I0101 02:51:30.071868 31036 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12822)@172.17.0.5:35106
I0101 02:51:30.072084 31047 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 02:51:30.072541 31039 recover.cpp:564] Updating replica status to VOTING
I0101 02:51:30.095731 31038 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.995708ms
I0101 02:51:30.095767 31038 replica.cpp:320] Persisted replica status to VOTING
I0101 02:51:30.095903 31048 recover.cpp:578] Successfully joined the Paxos group
I0101 02:51:30.096154 31048 recover.cpp:462] Recover process terminated
I0101 02:51:30.096648 31044 log.cpp:659] Attempting to start the writer
I0101 02:51:30.097745 31041 replica.cpp:493] Replica received implicit promise request from (12823)@172.17.0.5:35106 with proposal 1
I0101 02:51:30.120789 31041 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.011088ms
I0101 02:51:30.120826 31041 replica.cpp:342] Persisted promised to 1
I0101 02:51:30.121532 31049 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 02:51:30.122666 31041 replica.cpp:388] Replica received explicit promise request from (12824)@172.17.0.5:35106 for position 0 with proposal 2
I0101 02:51:30.145894 31041 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 23.173371ms
I0101 02:51:30.145932 31041 replica.cpp:712] Persisted action at 0
I0101 02:51:30.147279 31041 replica.cpp:537] Replica received write request for position 0 from (12825)@172.17.0.5:35106
I0101 02:51:30.147362 31041 leveldb.cpp:436] Reading position from leveldb took 41049ns
I0101 02:51:30.171136 31041 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.707712ms
I0101 02:51:30.171183 31041 replica.cpp:712] Persisted action at 0
I0101 02:51:30.172147 31044 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 02:51:30.196249 31044 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.057861ms
I0101 02:51:30.196295 31044 replica.cpp:712] Persisted action at 0
I0101 02:51:30.196321 31044 replica.cpp:697] Replica learned NOP action at position 0
I0101 02:51:30.197032 31049 log.cpp:675] Writer started with ending position 0
I0101 02:51:30.198230 31050 leveldb.cpp:436] Reading position from leveldb took 37462ns
I0101 02:51:30.199360 31038 registrar.cpp:340] Successfully fetched the registry (0B) in 145.944832ms
I0101 02:51:30.199481 31038 registrar.cpp:439] Applied 1 operations in 27514ns; attempting to update the 'registry'
I0101 02:51:30.200316 31041 log.cpp:683] Attempting to append 170 bytes to the log
I0101 02:51:30.200459 31047 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 02:51:30.201249 31046 replica.cpp:537] Replica received write request for position 1 from (12826)@172.17.0.5:35106
I0101 02:51:30.221236 31046 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 19.936651ms
I0101 02:51:30.221276 31046 replica.cpp:712] Persisted action at 1
I0101 02:51:30.222009 31041 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 02:51:30.246405 31041 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.296363ms
I0101 02:51:30.246445 31041 replica.cpp:712] Persisted action at 1
I0101 02:51:30.246467 31041 replica.cpp:697] Replica learned APPEND action at position 1
I0101 02:51:30.247598 31049 registrar.cpp:484] Successfully updated the 'registry' in 48.048128ms
I0101 02:51:30.247871 31049 registrar.cpp:370] Successfully recovered registrar
I0101 02:51:30.248080 31037 log.cpp:702] Attempting to truncate the log to 1
I0101 02:51:30.248242 31050 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 02:51:30.248335 31040 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 02:51:30.248392 31043 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 02:51:30.249028 31037 replica.cpp:537] Replica received write request for position 2 from (12827)@172.17.0.5:35106
I0101 02:51:30.271453 31037 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.390678ms
I0101 02:51:30.271482 31037 replica.cpp:712] Persisted action at 2
I0101 02:51:30.272166 31049 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 02:51:30.296561 31049 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.357269ms
I0101 02:51:30.296663 31049 leveldb.cpp:399] Deleting ~1 keys from leveldb took 60424ns
I0101 02:51:30.296691 31049 replica.cpp:712] Persisted action at 2
I0101 02:51:30.296716 31049 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 02:51:30.299289 31016 scheduler.cpp:154] Version: 0.27.0
I0101 02:51:30.299993 31044 scheduler.cpp:236] New master detected at master@172.17.0.5:35106
I0101 02:51:30.301180 31039 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:35106
I0101 02:51:30.303236 31038 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 02:51:30.303778 31035 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35295
I0101 02:51:30.303978 31035 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 02:51:30.304044 31035 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 02:51:30.304348 31035 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 02:51:30.304746 31045 hierarchical.cpp:260] Added framework d1be98d8-4a96-43ab-8f74-51a5bd6ce205-0000
I0101 02:51:30.304808 31046 master.hpp:1659] Sending heartbeat to d1be98d8-4a96-43ab-8f74-51a5bd6ce205-0000
I0101 02:51:30.304816 31045 hierarchical.cpp:1329] No resources available to allocate!
I0101 02:51:30.304908 31045 hierarchical.cpp:1423] No inverse offers to send out!
I0101 02:51:30.304945 31045 hierarchical.cpp:1079] Performed allocation for 0 slaves in 169656ns
I0101 02:51:30.305770 31037 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:35106
I0101 02:51:30.306277 31037 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:35106
I0101 02:51:30.306975 31045 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 02:51:30.307207 31046 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:35106
I0101 02:51:30.308794 31037 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 02:51:30.309344 31040 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35296
I0101 02:51:30.309454 31040 master.cpp:2636] Processing REQUEST call for framework d1be98d8-4a96-43ab-8f74-51a5bd6ce205-0000 (default)
I0101 02:51:30.309634 31036 hierarchical.cpp:579] Received resource request from framework d1be98d8-4a96-43ab-8f74-51a5bd6ce205-0000
I0101 02:51:30.309927 31035 master.cpp:930] Master terminating
I0101 02:51:30.310127 31045 hierarchical.cpp:321] Removed framework d1be98d8-4a96-43ab-8f74-51a5bd6ce205-0000
E0101 02:51:30.311393 31043 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (397 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0101 02:51:30.425891 31016 leveldb.cpp:174] Opened db in 108.612561ms
I0101 02:51:30.465581 31016 leveldb.cpp:181] Compacted db in 39.645243ms
I0101 02:51:30.465675 31016 leveldb.cpp:196] Created db iterator in 19630ns
I0101 02:51:30.465695 31016 leveldb.cpp:202] Seeked to beginning of db in 1760ns
I0101 02:51:30.465708 31016 leveldb.cpp:271] Iterated through 0 keys in the db in 455ns
I0101 02:51:30.465745 31016 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 02:51:30.466296 31040 recover.cpp:447] Starting replica recovery
I0101 02:51:30.466660 31040 recover.cpp:473] Replica is in EMPTY status
I0101 02:51:30.467795 31040 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12835)@172.17.0.5:35106
I0101 02:51:30.468376 31035 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 02:51:30.468904 31039 recover.cpp:564] Updating replica status to STARTING
I0101 02:51:30.469902 31042 master.cpp:365] Master 4703c9fb-0889-4c5c-868d-f9a2e0b2694d (9e617c76a5a5) started on 172.17.0.5:35106
I0101 02:51:30.469926 31042 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ErTvL4/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/ErTvL4/master" --zk_session_timeout="10secs"
I0101 02:51:30.470233 31042 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 02:51:30.470247 31042 master.cpp:417] Master only allowing authenticated slaves to register
I0101 02:51:30.470255 31042 credentials.hpp:35] Loading credentials for authentication from '/tmp/ErTvL4/credentials'
I0101 02:51:30.470527 31042 master.cpp:456] Using default 'crammd5' authenticator
I0101 02:51:30.470701 31042 master.cpp:493] Authorization enabled
I0101 02:51:30.470886 31045 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 02:51:30.470882 31047 whitelist_watcher.cpp:77] No whitelist given
I0101 02:51:30.472751 31050 master.cpp:1629] The newly elected leader is master@172.17.0.5:35106 with id 4703c9fb-0889-4c5c-868d-f9a2e0b2694d
I0101 02:51:30.472791 31050 master.cpp:1642] Elected as the leading master!
I0101 02:51:30.472810 31050 master.cpp:1387] Recovering from registrar
I0101 02:51:30.472959 31041 registrar.cpp:307] Recovering registrar
I0101 02:51:30.504971 31046 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 35.897014ms
I0101 02:51:30.505010 31046 replica.cpp:320] Persisted replica status to STARTING
I0101 02:51:30.505281 31047 recover.cpp:473] Replica is in STARTING status
I0101 02:51:30.506242 31035 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12836)@172.17.0.5:35106
I0101 02:51:30.506528 31048 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 02:51:30.507068 31047 recover.cpp:564] Updating replica status to VOTING
I0101 02:51:30.546898 31036 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.637344ms
I0101 02:51:30.546943 31036 replica.cpp:320] Persisted replica status to VOTING
I0101 02:51:30.547083 31039 recover.cpp:578] Successfully joined the Paxos group
I0101 02:51:30.547333 31039 recover.cpp:462] Recover process terminated
I0101 02:51:30.547840 31040 log.cpp:659] Attempting to start the writer
I0101 02:51:30.549192 31035 replica.cpp:493] Replica received implicit promise request from (12837)@172.17.0.5:35106 with proposal 1
I0101 02:51:30.588580 31035 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.347428ms
I0101 02:51:30.588637 31035 replica.cpp:342] Persisted promised to 1
I0101 02:51:30.589326 31050 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 02:51:30.590852 31050 replica.cpp:388] Replica received explicit promise request from (12838)@172.17.0.5:35106 for position 0 with proposal 2
I0101 02:51:30.630280 31050 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.372087ms
I0101 02:51:30.630319 31050 replica.cpp:712] Persisted action at 0
I0101 02:51:30.631727 31049 replica.cpp:537] Replica received write request for position 0 from (12839)@172.17.0.5:35106
I0101 02:51:30.631801 31049 leveldb.cpp:436] Reading position from leveldb took 30574ns
I0101 02:51:30.672179 31049 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.331142ms
I0101 02:51:30.672219 31049 replica.cpp:712] Persisted action at 0
I0101 02:51:30.672950 31050 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 02:51:30.713867 31050 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.822099ms
I0101 02:51:30.713907 31050 replica.cpp:712] Persisted action at 0
I0101 02:51:30.713932 31050 replica.cpp:697] Replica learned NOP action at position 0
I0101 02:51:30.714561 31047 log.cpp:675] Writer started with ending position 0
I0101 02:51:30.715791 31038 leveldb.cpp:436] Reading position from leveldb took 30867ns
I0101 02:51:30.716845 31044 registrar.cpp:340] Successfully fetched the registry (0B) in 243.806208ms
I0101 02:51:30.716965 31044 registrar.cpp:439] Applied 1 operations in 25979ns; attempting to update the 'registry'
I0101 02:51:30.717825 31045 log.cpp:683] Attempting to append 170 bytes to the log
I0101 02:51:30.717984 31037 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 02:51:30.718855 31049 replica.cpp:537] Replica received write request for position 1 from (12840)@172.17.0.5:35106
I0101 02:51:30.755714 31049 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.807508ms
I0101 02:51:30.755756 31049 replica.cpp:712] Persisted action at 1
I0101 02:51:30.756485 31041 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 02:51:30.797520 31041 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.998799ms
I0101 02:51:30.797560 31041 replica.cpp:712] Persisted action at 1
I0101 02:51:30.797582 31041 replica.cpp:697] Replica learned APPEND action at position 1
I0101 02:51:30.798801 31048 registrar.cpp:484] Successfully updated the 'registry' in 81.772032ms
I0101 02:51:30.798975 31048 registrar.cpp:370] Successfully recovered registrar
I0101 02:51:30.799059 31036 log.cpp:702] Attempting to truncate the log to 1
I0101 02:51:30.799260 31043 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 02:51:30.799866 31036 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 02:51:30.799952 31035 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 02:51:30.800333 31049 replica.cpp:537] Replica received write request for position 2 from (12841)@172.17.0.5:35106
I0101 02:51:30.839213 31049 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.835934ms
I0101 02:51:30.839252 31049 replica.cpp:712] Persisted action at 2
I0101 02:51:30.839951 31048 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 02:51:30.881055 31048 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.966791ms
I0101 02:51:30.881134 31048 leveldb.cpp:399] Deleting ~1 keys from leveldb took 39712ns
I0101 02:51:30.881162 31048 replica.cpp:712] Persisted action at 2
I0101 02:51:30.881186 31048 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 02:51:30.891137 31016 scheduler.cpp:154] Version: 0.27.0
I0101 02:51:30.891906 31042 scheduler.cpp:236] New master detected at master@172.17.0.5:35106
I0101 02:51:30.893247 31050 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:35106
I0101 02:51:30.895257 31042 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 02:51:30.895747 31037 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35298
I0101 02:51:30.896103 31037 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 02:51:30.896162 31037 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 02:51:30.896435 31037 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 02:51:30.896806 31049 hierarchical.cpp:260] Added framework 4703c9fb-0889-4c5c-868d-f9a2e0b2694d-0000
I0101 02:51:30.896885 31049 hierarchical.cpp:1329] No resources available to allocate!
I0101 02:51:30.896930 31049 hierarchical.cpp:1423] No inverse offers to send out!
I0101 02:51:30.896932 31038 master.hpp:1659] Sending heartbeat to 4703c9fb-0889-4c5c-868d-f9a2e0b2694d-0000
I0101 02:51:30.896968 31049 hierarchical.cpp:1079] Performed allocation for 0 slaves in 131410ns
I0101 02:51:30.897650 31036 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:35106
I0101 02:51:30.898130 31036 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:35106
I0101 02:51:30.898718 31050 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 02:51:30.898753 31036 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:35106
I0101 02:51:30.900336 31038 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 02:51:30.900738 31043 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35299
I0101 02:51:30.901001 31043 master.cpp:2636] Processing REQUEST call for framework 4703c9fb-0889-4c5c-868d-f9a2e0b2694d-0000 (default)
I0101 02:51:30.901197 31049 hierarchical.cpp:579] Received resource request from framework 4703c9fb-0889-4c5c-868d-f9a2e0b2694d-0000
I0101 02:51:30.901525 31041 master.cpp:930] Master terminating
I0101 02:51:30.901736 31036 hierarchical.cpp:321] Removed framework 4703c9fb-0889-4c5c-868d-f9a2e0b2694d-0000
E0101 02:51:30.902776 31042 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (591 ms)
[----------] 22 tests from ContentType/SchedulerTest (17023 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (722115 ms total)
[ PASSED ] 913 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[ FAILED ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization
2 FAILED TESTS
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-1451614251-20225
Untagged: mesos-1451614251-20225:latest
Deleted: be8f7b6dac35271edb7d7705644798331645673beaa70aa3e2bc636879d591d9
Deleted: 5503ce5f55da891079f83266490933e4139ca3d73b36366fc589b366b27aa51f
Deleted: f948f51b27de0af2ee9d2c8c697756d32f7868ca36e81d87c9deddd1e723acc3
Deleted: e35b8abcd6eeefb56c585bb277bcd5033d0b3c0fa3e32c3a838a3d5b2f2d225f
Deleted: 10ad0cf56eef33e47b36ca4beeb2248c95f0eb71dd677099049ce5dcd535b3ee
Deleted: a58c01ee19cb2dabd25dc88d09f47519291cb2e18aa4b8a07aed44f477d202ac
Deleted: c4ea7d3074979801855b6972a82c5f30bb480d8d5d1a5ff3c72fea78f88db209
Deleted: f471e4a8789a63ca22b055740a131125df7b26df30d70ee8bab26ec9d1f935a0
Deleted: 61d42e1c15581b6b488665aaa7abefc82807be70c542c33bf72f6fd4f2c92e4d
Deleted: 6bf4d1c2d0ded06fb1e12e8f0a7c0b27eb0676287aaa3a3c0ff906ce107aaf95
Deleted: 183a6e5c5f168a260d54669b3f0fc45636dfc067a7dcdcb2a35f11c64f364344
Deleted: 1f6334722ebf83422cf69cd463ab2a51b7f02b730c8efb993b6d2f0148210ded
Deleted: 2810da7276841e2e51b0d1f010aede3137e0102b412848b78b5514d1f2061149
Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26
Build step 'Execute shell' marked build as failure