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 2015/12/15 08:07:03 UTC
Build failed in Jenkins: mesos-reviewbot #10176
See <https://builds.apache.org/job/mesos-reviewbot/10176/changes>
Changes:
[adam] Improved authorization documentation.
[adam] MESOS-2315 Removed deprecated CommandInfo::ContainerInfo.
------------------------------------------
[...truncated 158685 lines...]
[ RUN ] ContentType/SchedulerTest.Request/0
I1215 07:06:47.357197 30319 leveldb.cpp:174] Opened db in 3.160998ms
I1215 07:06:47.358157 30319 leveldb.cpp:181] Compacted db in 917618ns
I1215 07:06:47.358207 30319 leveldb.cpp:196] Created db iterator in 18837ns
I1215 07:06:47.358225 30319 leveldb.cpp:202] Seeked to beginning of db in 2078ns
I1215 07:06:47.358237 30319 leveldb.cpp:271] Iterated through 0 keys in the db in 333ns
I1215 07:06:47.358276 30319 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1215 07:06:47.358700 30345 recover.cpp:447] Starting replica recovery
I1215 07:06:47.359081 30345 recover.cpp:473] Replica is in EMPTY status
I1215 07:06:47.360183 30343 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12015)@172.17.0.3:41203
I1215 07:06:47.360959 30347 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1215 07:06:47.361477 30349 recover.cpp:564] Updating replica status to STARTING
I1215 07:06:47.362129 30341 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 447764ns
I1215 07:06:47.362159 30341 replica.cpp:320] Persisted replica status to STARTING
I1215 07:06:47.362437 30342 recover.cpp:473] Replica is in STARTING status
I1215 07:06:47.363030 30338 master.cpp:366] Master 7f4368c7-fef6-49b9-b9a3-f11491afd4d3 (18f774228f04) started on 172.17.0.3:41203
I1215 07:06:47.363059 30338 master.cpp:368] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/QiFjBC/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/QiFjBC/master" --zk_session_timeout="10secs"
I1215 07:06:47.363399 30338 master.cpp:415] Master allowing unauthenticated frameworks to register
I1215 07:06:47.363425 30338 master.cpp:418] Master only allowing authenticated slaves to register
I1215 07:06:47.363442 30338 credentials.hpp:35] Loading credentials for authentication from '/tmp/QiFjBC/credentials'
I1215 07:06:47.363612 30347 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12016)@172.17.0.3:41203
I1215 07:06:47.363729 30338 master.cpp:457] Using default 'crammd5' authenticator
I1215 07:06:47.363975 30338 master.cpp:494] Authorization enabled
I1215 07:06:47.364131 30349 recover.cpp:193] Received a recover response from a replica in STARTING status
I1215 07:06:47.364261 30339 whitelist_watcher.cpp:77] No whitelist given
I1215 07:06:47.364297 30350 hierarchical.cpp:163] Initialized hierarchical allocator process
I1215 07:06:47.364768 30342 recover.cpp:564] Updating replica status to VOTING
I1215 07:06:47.365393 30339 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 346935ns
I1215 07:06:47.365424 30339 replica.cpp:320] Persisted replica status to VOTING
I1215 07:06:47.365607 30346 recover.cpp:578] Successfully joined the Paxos group
I1215 07:06:47.365924 30346 recover.cpp:462] Recover process terminated
I1215 07:06:47.366904 30343 master.cpp:1636] The newly elected leader is master@172.17.0.3:41203 with id 7f4368c7-fef6-49b9-b9a3-f11491afd4d3
I1215 07:06:47.366945 30343 master.cpp:1649] Elected as the leading master!
I1215 07:06:47.366976 30343 master.cpp:1394] Recovering from registrar
I1215 07:06:47.367154 30340 registrar.cpp:307] Recovering registrar
I1215 07:06:47.367916 30346 log.cpp:659] Attempting to start the writer
I1215 07:06:47.369328 30349 replica.cpp:493] Replica received implicit promise request from (12017)@172.17.0.3:41203 with proposal 1
I1215 07:06:47.369774 30349 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 408310ns
I1215 07:06:47.369804 30349 replica.cpp:342] Persisted promised to 1
I1215 07:06:47.370456 30338 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1215 07:06:47.371948 30344 replica.cpp:388] Replica received explicit promise request from (12018)@172.17.0.3:41203 for position 0 with proposal 2
I1215 07:06:47.372367 30344 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 366844ns
I1215 07:06:47.372396 30344 replica.cpp:712] Persisted action at 0
I1215 07:06:47.373558 30348 replica.cpp:537] Replica received write request for position 0 from (12019)@172.17.0.3:41203
I1215 07:06:47.373631 30348 leveldb.cpp:436] Reading position from leveldb took 33667ns
I1215 07:06:47.374104 30348 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 417442ns
I1215 07:06:47.374135 30348 replica.cpp:712] Persisted action at 0
I1215 07:06:47.374876 30351 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1215 07:06:47.375363 30351 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 443706ns
I1215 07:06:47.375396 30351 replica.cpp:712] Persisted action at 0
I1215 07:06:47.375423 30351 replica.cpp:697] Replica learned NOP action at position 0
I1215 07:06:47.376075 30346 log.cpp:675] Writer started with ending position 0
I1215 07:06:47.377192 30339 leveldb.cpp:436] Reading position from leveldb took 34697ns
I1215 07:06:47.378223 30351 registrar.cpp:340] Successfully fetched the registry (0B) in 11.014912ms
I1215 07:06:47.378342 30351 registrar.cpp:439] Applied 1 operations in 26192ns; attempting to update the 'registry'
I1215 07:06:47.379175 30352 log.cpp:683] Attempting to append 170 bytes to the log
I1215 07:06:47.379441 30347 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1215 07:06:47.380419 30347 replica.cpp:537] Replica received write request for position 1 from (12020)@172.17.0.3:41203
I1215 07:06:47.380856 30347 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 390831ns
I1215 07:06:47.380889 30347 replica.cpp:712] Persisted action at 1
I1215 07:06:47.381578 30342 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1215 07:06:47.382041 30342 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 425217ns
I1215 07:06:47.382072 30342 replica.cpp:712] Persisted action at 1
I1215 07:06:47.382094 30342 replica.cpp:697] Replica learned APPEND action at position 1
I1215 07:06:47.383138 30345 registrar.cpp:484] Successfully updated the 'registry' in 4.732928ms
I1215 07:06:47.383297 30345 registrar.cpp:370] Successfully recovered registrar
I1215 07:06:47.383450 30340 log.cpp:702] Attempting to truncate the log to 1
I1215 07:06:47.383803 30353 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1215 07:06:47.384098 30342 master.cpp:1446] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1215 07:06:47.384141 30344 hierarchical.cpp:181] Skipping recovery of hierarchical allocator: nothing to recover
I1215 07:06:47.385047 30345 replica.cpp:537] Replica received write request for position 2 from (12021)@172.17.0.3:41203
I1215 07:06:47.385499 30345 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 404245ns
I1215 07:06:47.385531 30345 replica.cpp:712] Persisted action at 2
I1215 07:06:47.386291 30349 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1215 07:06:47.386759 30349 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 429835ns
I1215 07:06:47.386869 30349 leveldb.cpp:399] Deleting ~1 keys from leveldb took 77078ns
I1215 07:06:47.386940 30349 replica.cpp:712] Persisted action at 2
I1215 07:06:47.386970 30349 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1215 07:06:47.394920 30319 scheduler.cpp:154] Version: 0.27.0
I1215 07:06:47.395627 30347 scheduler.cpp:236] New master detected at master@172.17.0.3:41203
I1215 07:06:47.396786 30344 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:41203
I1215 07:06:47.399353 30338 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 07:06:47.399425 30338 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:53135
I1215 07:06:47.399634 30338 master.cpp:1898] Received subscription request for HTTP framework 'default'
I1215 07:06:47.399706 30338 master.cpp:1675] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1215 07:06:47.400017 30338 master.cpp:1990] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1215 07:06:47.400415 30349 hierarchical.cpp:267] Added framework 7f4368c7-fef6-49b9-b9a3-f11491afd4d3-0000
I1215 07:06:47.400485 30344 master.hpp:1588] Sending heartbeat to 7f4368c7-fef6-49b9-b9a3-f11491afd4d3-0000
I1215 07:06:47.400490 30349 hierarchical.cpp:1317] No resources available to allocate!
I1215 07:06:47.400547 30349 hierarchical.cpp:1410] No inverse offers to send out!
I1215 07:06:47.400579 30349 hierarchical.cpp:1063] Performed allocation for 0 slaves in 129212ns
I1215 07:06:47.401494 30349 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:41203
I1215 07:06:47.402266 30349 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:41203
I1215 07:06:47.403326 30345 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1215 07:06:47.403427 30349 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:41203
I1215 07:06:47.405683 30341 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 07:06:47.405757 30341 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:53136
I1215 07:06:47.405941 30341 master.cpp:2645] Processing REQUEST call for framework 7f4368c7-fef6-49b9-b9a3-f11491afd4d3-0000 (default)
I1215 07:06:47.406322 30339 hierarchical.cpp:562] Received resource request from framework 7f4368c7-fef6-49b9-b9a3-f11491afd4d3-0000
I1215 07:06:47.406975 30352 master.cpp:937] Master terminating
I1215 07:06:47.407188 30349 hierarchical.cpp:308] Removed framework 7f4368c7-fef6-49b9-b9a3-f11491afd4d3-0000
E1215 07:06:47.408236 30338 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (61 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1215 07:06:47.417385 30319 leveldb.cpp:174] Opened db in 2.617747ms
I1215 07:06:47.418432 30319 leveldb.cpp:181] Compacted db in 1.007171ms
I1215 07:06:47.418493 30319 leveldb.cpp:196] Created db iterator in 19287ns
I1215 07:06:47.418514 30319 leveldb.cpp:202] Seeked to beginning of db in 1990ns
I1215 07:06:47.418525 30319 leveldb.cpp:271] Iterated through 0 keys in the db in 293ns
I1215 07:06:47.418562 30319 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1215 07:06:47.419282 30339 recover.cpp:447] Starting replica recovery
I1215 07:06:47.419538 30339 recover.cpp:473] Replica is in EMPTY status
I1215 07:06:47.420791 30345 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12028)@172.17.0.3:41203
I1215 07:06:47.421617 30340 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1215 07:06:47.422232 30345 recover.cpp:564] Updating replica status to STARTING
I1215 07:06:47.422626 30346 master.cpp:366] Master fe9e11c8-2d15-436a-863f-e79525f727e8 (18f774228f04) started on 172.17.0.3:41203
I1215 07:06:47.422659 30346 master.cpp:368] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/XmkrbO/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/XmkrbO/master" --zk_session_timeout="10secs"
I1215 07:06:47.423073 30346 master.cpp:415] Master allowing unauthenticated frameworks to register
I1215 07:06:47.423079 30343 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 656017ns
I1215 07:06:47.423089 30346 master.cpp:418] Master only allowing authenticated slaves to register
I1215 07:06:47.423113 30343 replica.cpp:320] Persisted replica status to STARTING
I1215 07:06:47.423122 30346 credentials.hpp:35] Loading credentials for authentication from '/tmp/XmkrbO/credentials'
I1215 07:06:47.423357 30349 recover.cpp:473] Replica is in STARTING status
I1215 07:06:47.423441 30346 master.cpp:457] Using default 'crammd5' authenticator
I1215 07:06:47.423614 30346 master.cpp:494] Authorization enabled
I1215 07:06:47.423899 30347 whitelist_watcher.cpp:77] No whitelist given
I1215 07:06:47.423964 30338 hierarchical.cpp:163] Initialized hierarchical allocator process
I1215 07:06:47.424399 30341 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12029)@172.17.0.3:41203
I1215 07:06:47.424855 30348 recover.cpp:193] Received a recover response from a replica in STARTING status
I1215 07:06:47.425482 30353 recover.cpp:564] Updating replica status to VOTING
I1215 07:06:47.426167 30339 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 430257ns
I1215 07:06:47.426200 30339 replica.cpp:320] Persisted replica status to VOTING
I1215 07:06:47.426415 30347 recover.cpp:578] Successfully joined the Paxos group
I1215 07:06:47.426584 30344 master.cpp:1636] The newly elected leader is master@172.17.0.3:41203 with id fe9e11c8-2d15-436a-863f-e79525f727e8
I1215 07:06:47.426630 30344 master.cpp:1649] Elected as the leading master!
I1215 07:06:47.426658 30344 master.cpp:1394] Recovering from registrar
I1215 07:06:47.426746 30347 recover.cpp:462] Recover process terminated
I1215 07:06:47.426887 30348 registrar.cpp:307] Recovering registrar
I1215 07:06:47.427714 30343 log.cpp:659] Attempting to start the writer
I1215 07:06:47.429227 30350 replica.cpp:493] Replica received implicit promise request from (12030)@172.17.0.3:41203 with proposal 1
I1215 07:06:47.429636 30350 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 366106ns
I1215 07:06:47.429666 30350 replica.cpp:342] Persisted promised to 1
I1215 07:06:47.430398 30353 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1215 07:06:47.432308 30351 replica.cpp:388] Replica received explicit promise request from (12031)@172.17.0.3:41203 for position 0 with proposal 2
I1215 07:06:47.432766 30351 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 411855ns
I1215 07:06:47.432797 30351 replica.cpp:712] Persisted action at 0
I1215 07:06:47.433984 30353 replica.cpp:537] Replica received write request for position 0 from (12032)@172.17.0.3:41203
I1215 07:06:47.434065 30353 leveldb.cpp:436] Reading position from leveldb took 38492ns
I1215 07:06:47.434640 30353 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 512985ns
I1215 07:06:47.434676 30353 replica.cpp:712] Persisted action at 0
I1215 07:06:47.435529 30340 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1215 07:06:47.436075 30340 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 457944ns
I1215 07:06:47.436107 30340 replica.cpp:712] Persisted action at 0
I1215 07:06:47.436130 30340 replica.cpp:697] Replica learned NOP action at position 0
I1215 07:06:47.436756 30351 log.cpp:675] Writer started with ending position 0
I1215 07:06:47.437906 30341 leveldb.cpp:436] Reading position from leveldb took 36376ns
I1215 07:06:47.438956 30353 registrar.cpp:340] Successfully fetched the registry (0B) in 12.013056ms
I1215 07:06:47.439069 30353 registrar.cpp:439] Applied 1 operations in 24597ns; attempting to update the 'registry'
I1215 07:06:47.439893 30347 log.cpp:683] Attempting to append 170 bytes to the log
I1215 07:06:47.440037 30349 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1215 07:06:47.441010 30347 replica.cpp:537] Replica received write request for position 1 from (12033)@172.17.0.3:41203
I1215 07:06:47.441526 30347 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 468654ns
I1215 07:06:47.441560 30347 replica.cpp:712] Persisted action at 1
I1215 07:06:47.442374 30339 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1215 07:06:47.442875 30339 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 465959ns
I1215 07:06:47.442908 30339 replica.cpp:712] Persisted action at 1
I1215 07:06:47.442929 30339 replica.cpp:697] Replica learned APPEND action at position 1
I1215 07:06:47.443970 30342 registrar.cpp:484] Successfully updated the 'registry' in 4.830976ms
I1215 07:06:47.444128 30342 registrar.cpp:370] Successfully recovered registrar
I1215 07:06:47.444283 30345 log.cpp:702] Attempting to truncate the log to 1
I1215 07:06:47.444481 30346 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1215 07:06:47.444746 30349 master.cpp:1446] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1215 07:06:47.444785 30344 hierarchical.cpp:181] Skipping recovery of hierarchical allocator: nothing to recover
I1215 07:06:47.445523 30339 replica.cpp:537] Replica received write request for position 2 from (12034)@172.17.0.3:41203
I1215 07:06:47.446177 30339 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 610246ns
I1215 07:06:47.446210 30339 replica.cpp:712] Persisted action at 2
I1215 07:06:47.446907 30352 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1215 07:06:47.447466 30352 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 518148ns
I1215 07:06:47.447530 30352 leveldb.cpp:399] Deleting ~1 keys from leveldb took 33376ns
I1215 07:06:47.447554 30352 replica.cpp:712] Persisted action at 2
I1215 07:06:47.447576 30352 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1215 07:06:47.455343 30319 scheduler.cpp:154] Version: 0.27.0
I1215 07:06:47.456085 30347 scheduler.cpp:236] New master detected at master@172.17.0.3:41203
I1215 07:06:47.457255 30338 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:41203
I1215 07:06:47.459795 30352 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 07:06:47.459889 30352 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:53137
I1215 07:06:47.460261 30352 master.cpp:1898] Received subscription request for HTTP framework 'default'
I1215 07:06:47.460332 30352 master.cpp:1675] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1215 07:06:47.460654 30352 master.cpp:1990] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1215 07:06:47.461030 30353 hierarchical.cpp:267] Added framework fe9e11c8-2d15-436a-863f-e79525f727e8-0000
I1215 07:06:47.461099 30353 hierarchical.cpp:1317] No resources available to allocate!
I1215 07:06:47.461140 30353 hierarchical.cpp:1410] No inverse offers to send out!
I1215 07:06:47.461164 30348 master.hpp:1588] Sending heartbeat to fe9e11c8-2d15-436a-863f-e79525f727e8-0000
I1215 07:06:47.461174 30353 hierarchical.cpp:1063] Performed allocation for 0 slaves in 113740ns
I1215 07:06:47.462169 30341 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:41203
I1215 07:06:47.462810 30341 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:41203
I1215 07:06:47.463675 30350 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1215 07:06:47.463701 30352 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:41203
I1215 07:06:47.466568 30345 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 07:06:47.466646 30345 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:53138
I1215 07:06:47.466923 30345 master.cpp:2645] Processing REQUEST call for framework fe9e11c8-2d15-436a-863f-e79525f727e8-0000 (default)
I1215 07:06:47.467151 30349 hierarchical.cpp:562] Received resource request from framework fe9e11c8-2d15-436a-863f-e79525f727e8-0000
I1215 07:06:47.467561 30351 master.cpp:937] Master terminating
I1215 07:06:47.467785 30348 hierarchical.cpp:308] Removed framework fe9e11c8-2d15-436a-863f-e79525f727e8-0000
E1215 07:06:47.469395 30353 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (62 ms)
[----------] 22 tests from ContentType/SchedulerTest (4236 ms total)
[----------] Global test environment tear-down
[==========] 886 tests from 116 test cases ran. (335769 ms total)
[ PASSED ] 883 tests.
[ FAILED ] 3 tests, listed below:
[ FAILED ] HdfsTest.Rm
[ FAILED ] HdfsTest.CopyFromLocal
[ FAILED ] HdfsTest.CopyToLocal
3 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-1450161306-17008
Untagged: mesos-1450161306-17008:latest
Deleted: f7868c2b90148b0070985dc8e9c2a9b31c45b840613651e84f7eec34f16b9422
Deleted: cd92f380717cba8d461226d56369ef8646cefcfe7aebfa46f82205b72eaafaf5
Deleted: 0428656171a3dfde01a8636d5d36174fb2e26f61328d368fc5e7eec7f30fec8e
Deleted: 2bcf6c2bd3352d02563c432f1146937a8f49cdabce1a581a245d2bd9dc73c394
Deleted: 7735b4cab1c47ee28343d8c72374ebb86a2cefff7e25a64a0d0fdb1f941ea54d
Deleted: 513d6589373f9fd9883101a3c87d5bcaa77e6c8acf1651cb21a18fe677a7ae9f
Deleted: b3fa3e1fdfa23dcfbf4328a790a30ab202eecca553b5c7289c7233e805c433e9
Deleted: 530bca2e47ac19d04d7022252369bfe815f8b1638e93bdf6e06edb43e257cf29
Deleted: 30d2e41be8af5708f731906eb0bf113f6de36ec4b064429d930d37ffd1973f95
Deleted: 4ca88f37d3f62fd36e9fb7db2a9621f99a5fb0d27e7171a47915beea95c3cf50
Deleted: ba401f97a73b8638072d5a5af5e7d38ef0dd54193327860ab1005bb67d02169b
Deleted: 93e25d932ac91cf5b875cc678faf4d2b222635db45089bd86e394b111d372f39
Deleted: 7cb20edec6e4e817711ca906b7420ac9ab875470a94bbe80a415f590f6e73c15
Error handling URL https://reviews.apache.org/api/review-requests/41384/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard bdaa698e5fdd41c949bc2fbb372fe96710dc2d0e
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : mesos-reviewbot #10180
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10180/>
Build failed in Jenkins: mesos-reviewbot #10179
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10179/>
------------------------------------------
[...truncated 158492 lines...]
[ RUN ] ContentType/SchedulerTest.Request/0
I1215 10:47:51.866991 30323 leveldb.cpp:174] Opened db in 2.907748ms
I1215 10:47:51.868233 30323 leveldb.cpp:181] Compacted db in 1.193427ms
I1215 10:47:51.868326 30323 leveldb.cpp:196] Created db iterator in 28075ns
I1215 10:47:51.868348 30323 leveldb.cpp:202] Seeked to beginning of db in 2625ns
I1215 10:47:51.868360 30323 leveldb.cpp:271] Iterated through 0 keys in the db in 330ns
I1215 10:47:51.868413 30323 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1215 10:47:51.869029 30357 recover.cpp:447] Starting replica recovery
I1215 10:47:51.869315 30357 recover.cpp:473] Replica is in EMPTY status
I1215 10:47:51.870458 30347 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12017)@172.17.0.2:55236
I1215 10:47:51.870867 30354 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1215 10:47:51.871356 30356 recover.cpp:564] Updating replica status to STARTING
I1215 10:47:51.871935 30345 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 441844ns
I1215 10:47:51.871965 30345 replica.cpp:320] Persisted replica status to STARTING
I1215 10:47:51.872145 30347 recover.cpp:473] Replica is in STARTING status
I1215 10:47:51.872185 30349 master.cpp:366] Master 28006ea9-434b-4dc0-95fe-4738d74ac9e5 (45896de6a98e) started on 172.17.0.2:55236
I1215 10:47:51.872261 30349 master.cpp:368] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/TQPRAz/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/TQPRAz/master" --zk_session_timeout="10secs"
I1215 10:47:51.872558 30349 master.cpp:415] Master allowing unauthenticated frameworks to register
I1215 10:47:51.872570 30349 master.cpp:418] Master only allowing authenticated slaves to register
I1215 10:47:51.872576 30349 credentials.hpp:35] Loading credentials for authentication from '/tmp/TQPRAz/credentials'
I1215 10:47:51.872886 30349 master.cpp:457] Using default 'crammd5' authenticator
I1215 10:47:51.873144 30349 master.cpp:494] Authorization enabled
I1215 10:47:51.873430 30355 whitelist_watcher.cpp:77] No whitelist given
I1215 10:47:51.873479 30345 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12018)@172.17.0.2:55236
I1215 10:47:51.873517 30342 hierarchical.cpp:163] Initialized hierarchical allocator process
I1215 10:47:51.873715 30344 recover.cpp:193] Received a recover response from a replica in STARTING status
I1215 10:47:51.874477 30342 recover.cpp:564] Updating replica status to VOTING
I1215 10:47:51.875383 30348 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 434962ns
I1215 10:47:51.875418 30348 replica.cpp:320] Persisted replica status to VOTING
I1215 10:47:51.875674 30351 recover.cpp:578] Successfully joined the Paxos group
I1215 10:47:51.876030 30351 recover.cpp:462] Recover process terminated
I1215 10:47:51.876427 30353 master.cpp:1636] The newly elected leader is master@172.17.0.2:55236 with id 28006ea9-434b-4dc0-95fe-4738d74ac9e5
I1215 10:47:51.876549 30353 master.cpp:1649] Elected as the leading master!
I1215 10:47:51.876584 30353 master.cpp:1394] Recovering from registrar
I1215 10:47:51.876899 30345 registrar.cpp:307] Recovering registrar
I1215 10:47:51.877545 30351 log.cpp:659] Attempting to start the writer
I1215 10:47:51.879043 30351 replica.cpp:493] Replica received implicit promise request from (12019)@172.17.0.2:55236 with proposal 1
I1215 10:47:51.879401 30351 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 320025ns
I1215 10:47:51.879431 30351 replica.cpp:342] Persisted promised to 1
I1215 10:47:51.880122 30352 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1215 10:47:51.881116 30345 replica.cpp:388] Replica received explicit promise request from (12020)@172.17.0.2:55236 for position 0 with proposal 2
I1215 10:47:51.881448 30345 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 289086ns
I1215 10:47:51.881476 30345 replica.cpp:712] Persisted action at 0
I1215 10:47:51.882395 30347 replica.cpp:537] Replica received write request for position 0 from (12021)@172.17.0.2:55236
I1215 10:47:51.882462 30347 leveldb.cpp:436] Reading position from leveldb took 29202ns
I1215 10:47:51.882932 30347 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 422074ns
I1215 10:47:51.882961 30347 replica.cpp:712] Persisted action at 0
I1215 10:47:51.883522 30343 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1215 10:47:51.883877 30343 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 327549ns
I1215 10:47:51.883900 30343 replica.cpp:712] Persisted action at 0
I1215 10:47:51.883919 30343 replica.cpp:697] Replica learned NOP action at position 0
I1215 10:47:51.884374 30342 log.cpp:675] Writer started with ending position 0
I1215 10:47:51.885431 30350 leveldb.cpp:436] Reading position from leveldb took 22648ns
I1215 10:47:51.886245 30354 registrar.cpp:340] Successfully fetched the registry (0B) in 9.28896ms
I1215 10:47:51.886351 30354 registrar.cpp:439] Applied 1 operations in 24979ns; attempting to update the 'registry'
I1215 10:47:51.886986 30342 log.cpp:683] Attempting to append 170 bytes to the log
I1215 10:47:51.887114 30346 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1215 10:47:51.887737 30352 replica.cpp:537] Replica received write request for position 1 from (12022)@172.17.0.2:55236
I1215 10:47:51.888066 30352 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 293528ns
I1215 10:47:51.888088 30352 replica.cpp:712] Persisted action at 1
I1215 10:47:51.888618 30352 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1215 10:47:51.888986 30352 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 302045ns
I1215 10:47:51.889011 30352 replica.cpp:712] Persisted action at 1
I1215 10:47:51.889036 30352 replica.cpp:697] Replica learned APPEND action at position 1
I1215 10:47:51.889892 30351 registrar.cpp:484] Successfully updated the 'registry' in 3.489024ms
I1215 10:47:51.890015 30351 registrar.cpp:370] Successfully recovered registrar
I1215 10:47:51.890084 30344 log.cpp:702] Attempting to truncate the log to 1
I1215 10:47:51.890192 30350 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1215 10:47:51.890418 30347 master.cpp:1446] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1215 10:47:51.890437 30342 hierarchical.cpp:181] Skipping recovery of hierarchical allocator: nothing to recover
I1215 10:47:51.890938 30355 replica.cpp:537] Replica received write request for position 2 from (12023)@172.17.0.2:55236
I1215 10:47:51.891242 30355 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 266640ns
I1215 10:47:51.891264 30355 replica.cpp:712] Persisted action at 2
I1215 10:47:51.891866 30357 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1215 10:47:51.892166 30357 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 272489ns
I1215 10:47:51.892215 30357 leveldb.cpp:399] Deleting ~1 keys from leveldb took 26334ns
I1215 10:47:51.892256 30357 replica.cpp:712] Persisted action at 2
I1215 10:47:51.892277 30357 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1215 10:47:51.901329 30323 scheduler.cpp:154] Version: 0.27.0
I1215 10:47:51.901991 30352 scheduler.cpp:236] New master detected at master@172.17.0.2:55236
I1215 10:47:51.903225 30357 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:55236
I1215 10:47:51.905649 30356 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 10:47:51.905719 30356 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:38361
I1215 10:47:51.905953 30356 master.cpp:1898] Received subscription request for HTTP framework 'default'
I1215 10:47:51.906023 30356 master.cpp:1675] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1215 10:47:51.906294 30356 master.cpp:1990] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1215 10:47:51.906661 30343 hierarchical.cpp:267] Added framework 28006ea9-434b-4dc0-95fe-4738d74ac9e5-0000
I1215 10:47:51.906731 30343 hierarchical.cpp:1317] No resources available to allocate!
I1215 10:47:51.906760 30343 hierarchical.cpp:1410] No inverse offers to send out!
I1215 10:47:51.906766 30357 master.hpp:1588] Sending heartbeat to 28006ea9-434b-4dc0-95fe-4738d74ac9e5-0000
I1215 10:47:51.906781 30343 hierarchical.cpp:1063] Performed allocation for 0 slaves in 94568ns
I1215 10:47:51.907483 30344 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:55236
I1215 10:47:51.907908 30344 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:55236
I1215 10:47:51.908433 30343 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1215 10:47:51.908660 30347 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:55236
I1215 10:47:51.910405 30356 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 10:47:51.910472 30356 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:38362
I1215 10:47:51.910593 30356 master.cpp:2645] Processing REQUEST call for framework 28006ea9-434b-4dc0-95fe-4738d74ac9e5-0000 (default)
I1215 10:47:51.910784 30345 hierarchical.cpp:562] Received resource request from framework 28006ea9-434b-4dc0-95fe-4738d74ac9e5-0000
I1215 10:47:51.911187 30356 master.cpp:937] Master terminating
I1215 10:47:51.911484 30353 hierarchical.cpp:308] Removed framework 28006ea9-434b-4dc0-95fe-4738d74ac9e5-0000
E1215 10:47:51.912407 30351 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (55 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1215 10:47:51.921289 30323 leveldb.cpp:174] Opened db in 2.576767ms
I1215 10:47:51.921983 30323 leveldb.cpp:181] Compacted db in 661492ns
I1215 10:47:51.922025 30323 leveldb.cpp:196] Created db iterator in 18511ns
I1215 10:47:51.922047 30323 leveldb.cpp:202] Seeked to beginning of db in 2061ns
I1215 10:47:51.922060 30323 leveldb.cpp:271] Iterated through 0 keys in the db in 313ns
I1215 10:47:51.922122 30323 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1215 10:47:51.922628 30344 recover.cpp:447] Starting replica recovery
I1215 10:47:51.923059 30344 recover.cpp:473] Replica is in EMPTY status
I1215 10:47:51.924306 30350 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12030)@172.17.0.2:55236
I1215 10:47:51.924785 30343 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1215 10:47:51.925220 30351 recover.cpp:564] Updating replica status to STARTING
I1215 10:47:51.925879 30354 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 441160ns
I1215 10:47:51.925909 30354 replica.cpp:320] Persisted replica status to STARTING
I1215 10:47:51.926090 30357 master.cpp:366] Master 8f59788c-175d-4b2a-9a93-0eb69385a36c (45896de6a98e) started on 172.17.0.2:55236
I1215 10:47:51.926142 30356 recover.cpp:473] Replica is in STARTING status
I1215 10:47:51.926182 30357 master.cpp:368] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/iNhm6e/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/iNhm6e/master" --zk_session_timeout="10secs"
I1215 10:47:51.926578 30357 master.cpp:415] Master allowing unauthenticated frameworks to register
I1215 10:47:51.926594 30357 master.cpp:418] Master only allowing authenticated slaves to register
I1215 10:47:51.926604 30357 credentials.hpp:35] Loading credentials for authentication from '/tmp/iNhm6e/credentials'
I1215 10:47:51.926941 30357 master.cpp:457] Using default 'crammd5' authenticator
I1215 10:47:51.927086 30357 master.cpp:494] Authorization enabled
I1215 10:47:51.927208 30348 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12031)@172.17.0.2:55236
I1215 10:47:51.927357 30354 hierarchical.cpp:163] Initialized hierarchical allocator process
I1215 10:47:51.927399 30348 whitelist_watcher.cpp:77] No whitelist given
I1215 10:47:51.927729 30342 recover.cpp:193] Received a recover response from a replica in STARTING status
I1215 10:47:51.928210 30345 recover.cpp:564] Updating replica status to VOTING
I1215 10:47:51.928689 30347 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 354431ns
I1215 10:47:51.928711 30347 replica.cpp:320] Persisted replica status to VOTING
I1215 10:47:51.928886 30353 recover.cpp:578] Successfully joined the Paxos group
I1215 10:47:51.929117 30353 recover.cpp:462] Recover process terminated
I1215 10:47:51.930277 30349 master.cpp:1636] The newly elected leader is master@172.17.0.2:55236 with id 8f59788c-175d-4b2a-9a93-0eb69385a36c
I1215 10:47:51.930311 30349 master.cpp:1649] Elected as the leading master!
I1215 10:47:51.930333 30349 master.cpp:1394] Recovering from registrar
I1215 10:47:51.930454 30352 registrar.cpp:307] Recovering registrar
I1215 10:47:51.931053 30342 log.cpp:659] Attempting to start the writer
I1215 10:47:51.932211 30352 replica.cpp:493] Replica received implicit promise request from (12032)@172.17.0.2:55236 with proposal 1
I1215 10:47:51.932595 30352 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 352995ns
I1215 10:47:51.932616 30352 replica.cpp:342] Persisted promised to 1
I1215 10:47:51.933218 30354 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1215 10:47:51.934330 30353 replica.cpp:388] Replica received explicit promise request from (12033)@172.17.0.2:55236 for position 0 with proposal 2
I1215 10:47:51.934743 30353 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 370356ns
I1215 10:47:51.934767 30353 replica.cpp:712] Persisted action at 0
I1215 10:47:51.935690 30342 replica.cpp:537] Replica received write request for position 0 from (12034)@172.17.0.2:55236
I1215 10:47:51.935755 30342 leveldb.cpp:436] Reading position from leveldb took 32925ns
I1215 10:47:51.936113 30342 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 250437ns
I1215 10:47:51.936136 30342 replica.cpp:712] Persisted action at 0
I1215 10:47:51.936749 30343 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1215 10:47:51.936941 30343 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 158870ns
I1215 10:47:51.937011 30343 replica.cpp:712] Persisted action at 0
I1215 10:47:51.937038 30343 replica.cpp:697] Replica learned NOP action at position 0
I1215 10:47:51.937615 30350 log.cpp:675] Writer started with ending position 0
I1215 10:47:51.938736 30349 leveldb.cpp:436] Reading position from leveldb took 26931ns
I1215 10:47:51.940084 30346 registrar.cpp:340] Successfully fetched the registry (0B) in 9.572096ms
I1215 10:47:51.940206 30346 registrar.cpp:439] Applied 1 operations in 27246ns; attempting to update the 'registry'
I1215 10:47:51.940879 30352 log.cpp:683] Attempting to append 170 bytes to the log
I1215 10:47:51.941021 30356 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1215 10:47:51.941718 30348 replica.cpp:537] Replica received write request for position 1 from (12035)@172.17.0.2:55236
I1215 10:47:51.942170 30348 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 411831ns
I1215 10:47:51.942193 30348 replica.cpp:712] Persisted action at 1
I1215 10:47:51.942747 30352 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1215 10:47:51.943141 30352 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 366540ns
I1215 10:47:51.943164 30352 replica.cpp:712] Persisted action at 1
I1215 10:47:51.943181 30352 replica.cpp:697] Replica learned APPEND action at position 1
I1215 10:47:51.944044 30355 registrar.cpp:484] Successfully updated the 'registry' in 3.788032ms
I1215 10:47:51.944180 30355 registrar.cpp:370] Successfully recovered registrar
I1215 10:47:51.944306 30357 log.cpp:702] Attempting to truncate the log to 1
I1215 10:47:51.944437 30356 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1215 10:47:51.944684 30348 master.cpp:1446] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1215 10:47:51.944715 30344 hierarchical.cpp:181] Skipping recovery of hierarchical allocator: nothing to recover
I1215 10:47:51.945325 30350 replica.cpp:537] Replica received write request for position 2 from (12036)@172.17.0.2:55236
I1215 10:47:51.945683 30350 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 316953ns
I1215 10:47:51.945705 30350 replica.cpp:712] Persisted action at 2
I1215 10:47:51.946219 30354 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1215 10:47:51.946552 30354 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 301410ns
I1215 10:47:51.946609 30354 leveldb.cpp:399] Deleting ~1 keys from leveldb took 32752ns
I1215 10:47:51.946635 30354 replica.cpp:712] Persisted action at 2
I1215 10:47:51.946660 30354 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1215 10:47:51.955412 30323 scheduler.cpp:154] Version: 0.27.0
I1215 10:47:51.956090 30351 scheduler.cpp:236] New master detected at master@172.17.0.2:55236
I1215 10:47:51.956993 30351 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:55236
I1215 10:47:51.959372 30343 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 10:47:51.959441 30343 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:38363
I1215 10:47:51.959882 30343 master.cpp:1898] Received subscription request for HTTP framework 'default'
I1215 10:47:51.959967 30343 master.cpp:1675] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1215 10:47:51.960378 30343 master.cpp:1990] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1215 10:47:51.960763 30348 hierarchical.cpp:267] Added framework 8f59788c-175d-4b2a-9a93-0eb69385a36c-0000
I1215 10:47:51.960870 30348 hierarchical.cpp:1317] No resources available to allocate!
I1215 10:47:51.960875 30346 master.hpp:1588] Sending heartbeat to 8f59788c-175d-4b2a-9a93-0eb69385a36c-0000
I1215 10:47:51.960927 30348 hierarchical.cpp:1410] No inverse offers to send out!
I1215 10:47:51.960960 30348 hierarchical.cpp:1063] Performed allocation for 0 slaves in 171826ns
I1215 10:47:51.962285 30357 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:55236
I1215 10:47:51.962721 30357 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:55236
I1215 10:47:51.963243 30352 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:55236
I1215 10:47:51.964117 30349 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1215 10:47:51.965170 30346 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 10:47:51.965217 30346 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:38364
I1215 10:47:51.965420 30346 master.cpp:2645] Processing REQUEST call for framework 8f59788c-175d-4b2a-9a93-0eb69385a36c-0000 (default)
I1215 10:47:51.965545 30349 hierarchical.cpp:562] Received resource request from framework 8f59788c-175d-4b2a-9a93-0eb69385a36c-0000
I1215 10:47:51.965868 30357 master.cpp:937] Master terminating
I1215 10:47:51.966202 30353 hierarchical.cpp:308] Removed framework 8f59788c-175d-4b2a-9a93-0eb69385a36c-0000
E1215 10:47:51.967416 30351 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (55 ms)
[----------] 22 tests from ContentType/SchedulerTest (4069 ms total)
[----------] Global test environment tear-down
[==========] 886 tests from 116 test cases ran. (336983 ms total)
[ PASSED ] 883 tests.
[ FAILED ] 3 tests, listed below:
[ FAILED ] HdfsTest.Rm
[ FAILED ] HdfsTest.CopyFromLocal
[ FAILED ] HdfsTest.CopyToLocal
3 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-1450174749-22794
Untagged: mesos-1450174749-22794:latest
Deleted: ea2d31b22f0e2f10741d1900f9bbdb7d80ca41949e91c1c0d9efe1e824182476
Deleted: d24b05a72b898549235d635ced8e1a6e33cfd3ed2120d04edd52b047539f3fd0
Deleted: ee03d4db90cf1130fdbf90b4a9da99b10384c30f8027aef46379fbdb8b017c7b
Deleted: bd538038eceae1171eefb7f67b0d472fe7031d490cbaadc1855225e0a13a660e
Deleted: d24cfeaeefcc01faaf826e5826372d975473cc94debc6c6322e8121d67b466c7
Deleted: 73f3c421f8984010caa8d5de0c45ef8295be2a06e5fe01b8d66b816e3d0df4ea
Deleted: 5e984e0606b95b1051ce0546411300379ca81f17b64af0347a3f33c5946d59f6
Deleted: d7750397db73c7a20a373182a4071279488c5878506880c16b910f331528f4c9
Deleted: 190bdf5b58a1cc3e82dbaf10d547e679a13fb3ebf61e82773ff200cba6e34e71
Deleted: 92809b5f0430bc61ee83c427eac8bbc929aa107b24a425e24166d6b5806575c9
Deleted: 499d7f11cb06ede16845f9e9417f0f0d7490958c618e6fef3c8c507c0a73074b
Deleted: 55c7e83420e713422cea747afb9fd9357ab2777831bacdff97206abf08bf60b6
Deleted: ae35c6e5b6c9b7c601a58adf556e972072175f6045a4a11370f56b5f70feda93
Error handling URL https://reviews.apache.org/api/review-requests/41384/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard bdaa698e5fdd41c949bc2fbb372fe96710dc2d0e
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10178
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10178/>
------------------------------------------
[...truncated 158597 lines...]
[ RUN ] ContentType/SchedulerTest.Request/0
I1215 09:35:17.027253 30317 leveldb.cpp:174] Opened db in 2.900571ms
I1215 09:35:17.028272 30317 leveldb.cpp:181] Compacted db in 975860ns
I1215 09:35:17.028332 30317 leveldb.cpp:196] Created db iterator in 23077ns
I1215 09:35:17.028354 30317 leveldb.cpp:202] Seeked to beginning of db in 2413ns
I1215 09:35:17.028367 30317 leveldb.cpp:271] Iterated through 0 keys in the db in 405ns
I1215 09:35:17.028414 30317 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1215 09:35:17.029006 30344 recover.cpp:447] Starting replica recovery
I1215 09:35:17.029345 30344 recover.cpp:473] Replica is in EMPTY status
I1215 09:35:17.030616 30338 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12017)@172.17.0.2:47302
I1215 09:35:17.031129 30348 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1215 09:35:17.031714 30340 recover.cpp:564] Updating replica status to STARTING
I1215 09:35:17.032482 30346 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 522368ns
I1215 09:35:17.032517 30346 replica.cpp:320] Persisted replica status to STARTING
I1215 09:35:17.032729 30347 master.cpp:366] Master d52dbdcb-b4bb-4538-9235-abf6e653fdb0 (e7464b8f0040) started on 172.17.0.2:47302
I1215 09:35:17.032951 30348 recover.cpp:473] Replica is in STARTING status
I1215 09:35:17.032778 30347 master.cpp:368] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/tiKa4T/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/tiKa4T/master" --zk_session_timeout="10secs"
I1215 09:35:17.033241 30347 master.cpp:415] Master allowing unauthenticated frameworks to register
I1215 09:35:17.033257 30347 master.cpp:418] Master only allowing authenticated slaves to register
I1215 09:35:17.033267 30347 credentials.hpp:35] Loading credentials for authentication from '/tmp/tiKa4T/credentials'
I1215 09:35:17.033593 30347 master.cpp:457] Using default 'crammd5' authenticator
I1215 09:35:17.033741 30347 master.cpp:494] Authorization enabled
I1215 09:35:17.034128 30346 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12018)@172.17.0.2:47302
I1215 09:35:17.034139 30340 whitelist_watcher.cpp:77] No whitelist given
I1215 09:35:17.034200 30342 hierarchical.cpp:163] Initialized hierarchical allocator process
I1215 09:35:17.034534 30345 recover.cpp:193] Received a recover response from a replica in STARTING status
I1215 09:35:17.035082 30336 recover.cpp:564] Updating replica status to VOTING
I1215 09:35:17.035802 30340 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 516840ns
I1215 09:35:17.035852 30340 replica.cpp:320] Persisted replica status to VOTING
I1215 09:35:17.036048 30349 recover.cpp:578] Successfully joined the Paxos group
I1215 09:35:17.036305 30349 recover.cpp:462] Recover process terminated
I1215 09:35:17.036533 30336 master.cpp:1636] The newly elected leader is master@172.17.0.2:47302 with id d52dbdcb-b4bb-4538-9235-abf6e653fdb0
I1215 09:35:17.036574 30336 master.cpp:1649] Elected as the leading master!
I1215 09:35:17.036602 30336 master.cpp:1394] Recovering from registrar
I1215 09:35:17.036886 30351 registrar.cpp:307] Recovering registrar
I1215 09:35:17.037540 30345 log.cpp:659] Attempting to start the writer
I1215 09:35:17.038956 30344 replica.cpp:493] Replica received implicit promise request from (12019)@172.17.0.2:47302 with proposal 1
I1215 09:35:17.039453 30344 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 448192ns
I1215 09:35:17.039484 30344 replica.cpp:342] Persisted promised to 1
I1215 09:35:17.040153 30342 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1215 09:35:17.041779 30351 replica.cpp:388] Replica received explicit promise request from (12020)@172.17.0.2:47302 for position 0 with proposal 2
I1215 09:35:17.042302 30351 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 428690ns
I1215 09:35:17.042335 30351 replica.cpp:712] Persisted action at 0
I1215 09:35:17.043651 30347 replica.cpp:537] Replica received write request for position 0 from (12021)@172.17.0.2:47302
I1215 09:35:17.043730 30347 leveldb.cpp:436] Reading position from leveldb took 34217ns
I1215 09:35:17.044244 30347 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 461712ns
I1215 09:35:17.044275 30347 replica.cpp:712] Persisted action at 0
I1215 09:35:17.045094 30337 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1215 09:35:17.045526 30337 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 391326ns
I1215 09:35:17.045564 30337 replica.cpp:712] Persisted action at 0
I1215 09:35:17.045591 30337 replica.cpp:697] Replica learned NOP action at position 0
I1215 09:35:17.046298 30339 log.cpp:675] Writer started with ending position 0
I1215 09:35:17.047502 30342 leveldb.cpp:436] Reading position from leveldb took 30199ns
I1215 09:35:17.048660 30350 registrar.cpp:340] Successfully fetched the registry (0B) in 11.702016ms
I1215 09:35:17.048799 30350 registrar.cpp:439] Applied 1 operations in 31594ns; attempting to update the 'registry'
I1215 09:35:17.049643 30341 log.cpp:683] Attempting to append 170 bytes to the log
I1215 09:35:17.049799 30345 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1215 09:35:17.050724 30349 replica.cpp:537] Replica received write request for position 1 from (12022)@172.17.0.2:47302
I1215 09:35:17.051174 30349 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 403964ns
I1215 09:35:17.051208 30349 replica.cpp:712] Persisted action at 1
I1215 09:35:17.052032 30340 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1215 09:35:17.052469 30340 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 400604ns
I1215 09:35:17.052501 30340 replica.cpp:712] Persisted action at 1
I1215 09:35:17.052525 30340 replica.cpp:697] Replica learned APPEND action at position 1
I1215 09:35:17.053722 30347 registrar.cpp:484] Successfully updated the 'registry' in 4.826112ms
I1215 09:35:17.053993 30347 registrar.cpp:370] Successfully recovered registrar
I1215 09:35:17.054107 30340 log.cpp:702] Attempting to truncate the log to 1
I1215 09:35:17.054287 30336 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1215 09:35:17.054646 30338 master.cpp:1446] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1215 09:35:17.054707 30350 hierarchical.cpp:181] Skipping recovery of hierarchical allocator: nothing to recover
I1215 09:35:17.055527 30339 replica.cpp:537] Replica received write request for position 2 from (12023)@172.17.0.2:47302
I1215 09:35:17.056025 30339 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 445405ns
I1215 09:35:17.056056 30339 replica.cpp:712] Persisted action at 2
I1215 09:35:17.056725 30345 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1215 09:35:17.057236 30345 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 470707ns
I1215 09:35:17.057306 30345 leveldb.cpp:399] Deleting ~1 keys from leveldb took 38087ns
I1215 09:35:17.057332 30345 replica.cpp:712] Persisted action at 2
I1215 09:35:17.057355 30345 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1215 09:35:17.065433 30317 scheduler.cpp:154] Version: 0.27.0
I1215 09:35:17.066052 30350 scheduler.cpp:236] New master detected at master@172.17.0.2:47302
I1215 09:35:17.067384 30338 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:47302
I1215 09:35:17.069716 30342 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 09:35:17.069797 30342 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:51207
I1215 09:35:17.070183 30342 master.cpp:1898] Received subscription request for HTTP framework 'default'
I1215 09:35:17.070261 30342 master.cpp:1675] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1215 09:35:17.070591 30342 master.cpp:1990] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1215 09:35:17.071072 30344 hierarchical.cpp:267] Added framework d52dbdcb-b4bb-4538-9235-abf6e653fdb0-0000
I1215 09:35:17.071153 30344 hierarchical.cpp:1317] No resources available to allocate!
I1215 09:35:17.071197 30344 hierarchical.cpp:1410] No inverse offers to send out!
I1215 09:35:17.071230 30344 hierarchical.cpp:1063] Performed allocation for 0 slaves in 123082ns
I1215 09:35:17.071271 30344 master.hpp:1588] Sending heartbeat to d52dbdcb-b4bb-4538-9235-abf6e653fdb0-0000
I1215 09:35:17.072626 30343 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:47302
I1215 09:35:17.073089 30343 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:47302
I1215 09:35:17.074000 30346 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1215 09:35:17.074228 30347 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:47302
I1215 09:35:17.076716 30348 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 09:35:17.076782 30348 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:51208
I1215 09:35:17.076917 30348 master.cpp:2645] Processing REQUEST call for framework d52dbdcb-b4bb-4538-9235-abf6e653fdb0-0000 (default)
I1215 09:35:17.077128 30341 hierarchical.cpp:562] Received resource request from framework d52dbdcb-b4bb-4538-9235-abf6e653fdb0-0000
I1215 09:35:17.077436 30317 master.cpp:937] Master terminating
I1215 09:35:17.077648 30348 hierarchical.cpp:308] Removed framework d52dbdcb-b4bb-4538-9235-abf6e653fdb0-0000
E1215 09:35:17.079097 30351 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (62 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1215 09:35:17.089172 30317 leveldb.cpp:174] Opened db in 2.996561ms
I1215 09:35:17.090184 30317 leveldb.cpp:181] Compacted db in 971488ns
I1215 09:35:17.090239 30317 leveldb.cpp:196] Created db iterator in 17670ns
I1215 09:35:17.090260 30317 leveldb.cpp:202] Seeked to beginning of db in 2327ns
I1215 09:35:17.090270 30317 leveldb.cpp:271] Iterated through 0 keys in the db in 262ns
I1215 09:35:17.090308 30317 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1215 09:35:17.090740 30350 recover.cpp:447] Starting replica recovery
I1215 09:35:17.091030 30350 recover.cpp:473] Replica is in EMPTY status
I1215 09:35:17.092073 30350 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12030)@172.17.0.2:47302
I1215 09:35:17.092517 30345 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1215 09:35:17.093158 30348 recover.cpp:564] Updating replica status to STARTING
I1215 09:35:17.093936 30338 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 623049ns
I1215 09:35:17.093972 30338 replica.cpp:320] Persisted replica status to STARTING
I1215 09:35:17.094192 30337 recover.cpp:473] Replica is in STARTING status
I1215 09:35:17.094624 30350 master.cpp:366] Master a7a6f31b-774e-478d-8458-8cc61f2366ef (e7464b8f0040) started on 172.17.0.2:47302
I1215 09:35:17.094668 30350 master.cpp:368] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/Ue1gVy/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/Ue1gVy/master" --zk_session_timeout="10secs"
I1215 09:35:17.095144 30350 master.cpp:415] Master allowing unauthenticated frameworks to register
I1215 09:35:17.095263 30350 master.cpp:418] Master only allowing authenticated slaves to register
I1215 09:35:17.095286 30350 credentials.hpp:35] Loading credentials for authentication from '/tmp/Ue1gVy/credentials'
I1215 09:35:17.095387 30339 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12031)@172.17.0.2:47302
I1215 09:35:17.095607 30350 master.cpp:457] Using default 'crammd5' authenticator
I1215 09:35:17.095742 30350 master.cpp:494] Authorization enabled
I1215 09:35:17.095860 30337 recover.cpp:193] Received a recover response from a replica in STARTING status
I1215 09:35:17.096045 30344 whitelist_watcher.cpp:77] No whitelist given
I1215 09:35:17.096058 30341 hierarchical.cpp:163] Initialized hierarchical allocator process
I1215 09:35:17.096400 30344 recover.cpp:564] Updating replica status to VOTING
I1215 09:35:17.097136 30348 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 509218ns
I1215 09:35:17.097173 30348 replica.cpp:320] Persisted replica status to VOTING
I1215 09:35:17.097349 30351 recover.cpp:578] Successfully joined the Paxos group
I1215 09:35:17.097676 30351 recover.cpp:462] Recover process terminated
I1215 09:35:17.098584 30340 master.cpp:1636] The newly elected leader is master@172.17.0.2:47302 with id a7a6f31b-774e-478d-8458-8cc61f2366ef
I1215 09:35:17.098620 30340 master.cpp:1649] Elected as the leading master!
I1215 09:35:17.098639 30340 master.cpp:1394] Recovering from registrar
I1215 09:35:17.098840 30345 registrar.cpp:307] Recovering registrar
I1215 09:35:17.099499 30347 log.cpp:659] Attempting to start the writer
I1215 09:35:17.100893 30338 replica.cpp:493] Replica received implicit promise request from (12032)@172.17.0.2:47302 with proposal 1
I1215 09:35:17.101327 30338 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 396548ns
I1215 09:35:17.101357 30338 replica.cpp:342] Persisted promised to 1
I1215 09:35:17.102279 30347 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1215 09:35:17.103680 30345 replica.cpp:388] Replica received explicit promise request from (12033)@172.17.0.2:47302 for position 0 with proposal 2
I1215 09:35:17.104177 30345 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 447977ns
I1215 09:35:17.104207 30345 replica.cpp:712] Persisted action at 0
I1215 09:35:17.105666 30350 replica.cpp:537] Replica received write request for position 0 from (12034)@172.17.0.2:47302
I1215 09:35:17.105742 30350 leveldb.cpp:436] Reading position from leveldb took 30712ns
I1215 09:35:17.106245 30350 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 455550ns
I1215 09:35:17.106276 30350 replica.cpp:712] Persisted action at 0
I1215 09:35:17.107048 30350 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1215 09:35:17.107439 30350 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 352824ns
I1215 09:35:17.107470 30350 replica.cpp:712] Persisted action at 0
I1215 09:35:17.107491 30350 replica.cpp:697] Replica learned NOP action at position 0
I1215 09:35:17.108198 30347 log.cpp:675] Writer started with ending position 0
I1215 09:35:17.109411 30337 leveldb.cpp:436] Reading position from leveldb took 37702ns
I1215 09:35:17.110566 30337 registrar.cpp:340] Successfully fetched the registry (0B) in 11.666944ms
I1215 09:35:17.110690 30337 registrar.cpp:439] Applied 1 operations in 26564ns; attempting to update the 'registry'
I1215 09:35:17.111546 30349 log.cpp:683] Attempting to append 170 bytes to the log
I1215 09:35:17.111739 30347 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1215 09:35:17.112613 30344 replica.cpp:537] Replica received write request for position 1 from (12035)@172.17.0.2:47302
I1215 09:35:17.113132 30344 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 471952ns
I1215 09:35:17.113164 30344 replica.cpp:712] Persisted action at 1
I1215 09:35:17.114003 30349 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1215 09:35:17.114440 30349 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 398073ns
I1215 09:35:17.114472 30349 replica.cpp:712] Persisted action at 1
I1215 09:35:17.114495 30349 replica.cpp:697] Replica learned APPEND action at position 1
I1215 09:35:17.115514 30344 registrar.cpp:484] Successfully updated the 'registry' in 4.764928ms
I1215 09:35:17.115712 30344 registrar.cpp:370] Successfully recovered registrar
I1215 09:35:17.115779 30337 log.cpp:702] Attempting to truncate the log to 1
I1215 09:35:17.115991 30346 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1215 09:35:17.116350 30339 master.cpp:1446] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1215 09:35:17.116387 30340 hierarchical.cpp:181] Skipping recovery of hierarchical allocator: nothing to recover
I1215 09:35:17.117120 30338 replica.cpp:537] Replica received write request for position 2 from (12036)@172.17.0.2:47302
I1215 09:35:17.117604 30338 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 435025ns
I1215 09:35:17.117636 30338 replica.cpp:712] Persisted action at 2
I1215 09:35:17.118494 30351 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1215 09:35:17.119000 30351 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 464107ns
I1215 09:35:17.119071 30351 leveldb.cpp:399] Deleting ~1 keys from leveldb took 38754ns
I1215 09:35:17.119098 30351 replica.cpp:712] Persisted action at 2
I1215 09:35:17.119122 30351 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1215 09:35:17.127029 30317 scheduler.cpp:154] Version: 0.27.0
I1215 09:35:17.127699 30351 scheduler.cpp:236] New master detected at master@172.17.0.2:47302
I1215 09:35:17.128892 30344 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:47302
I1215 09:35:17.131975 30340 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 09:35:17.132041 30340 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:51209
I1215 09:35:17.132428 30340 master.cpp:1898] Received subscription request for HTTP framework 'default'
I1215 09:35:17.132503 30340 master.cpp:1675] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1215 09:35:17.132848 30340 master.cpp:1990] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1215 09:35:17.133251 30342 hierarchical.cpp:267] Added framework a7a6f31b-774e-478d-8458-8cc61f2366ef-0000
I1215 09:35:17.133322 30342 hierarchical.cpp:1317] No resources available to allocate!
I1215 09:35:17.133364 30342 hierarchical.cpp:1410] No inverse offers to send out!
I1215 09:35:17.133397 30342 hierarchical.cpp:1063] Performed allocation for 0 slaves in 115777ns
I1215 09:35:17.133409 30343 master.hpp:1588] Sending heartbeat to a7a6f31b-774e-478d-8458-8cc61f2366ef-0000
I1215 09:35:17.134358 30350 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:47302
I1215 09:35:17.134928 30350 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:47302
I1215 09:35:17.135574 30350 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:47302
I1215 09:35:17.135609 30347 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1215 09:35:17.137676 30341 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 09:35:17.137758 30341 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:51210
I1215 09:35:17.138072 30341 master.cpp:2645] Processing REQUEST call for framework a7a6f31b-774e-478d-8458-8cc61f2366ef-0000 (default)
I1215 09:35:17.138236 30349 hierarchical.cpp:562] Received resource request from framework a7a6f31b-774e-478d-8458-8cc61f2366ef-0000
I1215 09:35:17.138562 30350 master.cpp:937] Master terminating
I1215 09:35:17.138757 30341 hierarchical.cpp:308] Removed framework a7a6f31b-774e-478d-8458-8cc61f2366ef-0000
E1215 09:35:17.139931 30336 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (62 ms)
[----------] 22 tests from ContentType/SchedulerTest (4185 ms total)
[----------] Global test environment tear-down
[==========] 886 tests from 116 test cases ran. (334550 ms total)
[ PASSED ] 883 tests.
[ FAILED ] 3 tests, listed below:
[ FAILED ] HdfsTest.Rm
[ FAILED ] HdfsTest.CopyFromLocal
[ FAILED ] HdfsTest.CopyToLocal
3 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-1450170420-25988
Untagged: mesos-1450170420-25988:latest
Deleted: 93f961b747c1531f8760ec0028f9bab258ad75335f0c33a34e9bc6a124c271fe
Deleted: 4b77bdf81b28e0ef39c7be64e3a4afb499be6daecaf48c533acf5dab222eb14e
Deleted: 110bd17984407cfbe00825229b3006c354a2b5a5aec2b01863fdc681a4098907
Deleted: 6e801e1a7e775c31a60c90814a2ab3d2d65e6db6c976f929606e8820585bc7a7
Deleted: 8be5f463f43003aaad63e4f1fd4a1f9913d31d1f284a3a5552a50b75a1c5977b
Deleted: 2b3286ac3727cdf9a288577eb1ecbe4b2f24cbfc33d410ac6ff0efe75177a590
Deleted: 0c8de2c5ecda3960ddc25f1dd121f8ec15db99748373298a9a733a9c290e736c
Deleted: 905f22a5d1b9ece703df3e21ee1a7d4af3fa58ab308c78bda88d9fa94f236f58
Deleted: 308815259a25bee55a599f4c8c13883934ec702ebaa91b9adcb24de79fda748d
Deleted: a1473e22b3c2ed372c478ac85759a46fc3117773370daa8cab56ae2e19028886
Deleted: 651e5a94ed44679d180a02217b5ff0361c65ca9548b9ba64879293144e31707c
Deleted: ed8ac5c9f3cd55b220cd848723df83c82de349390d8a2e5d9eb753c5a45a03e6
Deleted: 6f912818875ae6c31e06a50724779f0220d4a50a7c7019a45d78cc8b2d4642c7
Error handling URL https://reviews.apache.org/api/review-requests/41384/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard bdaa698e5fdd41c949bc2fbb372fe96710dc2d0e
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10177
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10177/>
------------------------------------------
[...truncated 158681 lines...]
[ RUN ] ContentType/SchedulerTest.Request/0
I1215 08:08:50.977843 30319 leveldb.cpp:174] Opened db in 3.52334ms
I1215 08:08:50.978930 30319 leveldb.cpp:181] Compacted db in 1.048183ms
I1215 08:08:50.978991 30319 leveldb.cpp:196] Created db iterator in 21699ns
I1215 08:08:50.979012 30319 leveldb.cpp:202] Seeked to beginning of db in 2320ns
I1215 08:08:50.979023 30319 leveldb.cpp:271] Iterated through 0 keys in the db in 348ns
I1215 08:08:50.979070 30319 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1215 08:08:50.979812 30350 recover.cpp:447] Starting replica recovery
I1215 08:08:50.980121 30350 recover.cpp:473] Replica is in EMPTY status
I1215 08:08:50.981420 30353 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12013)@172.17.0.2:49245
I1215 08:08:50.982062 30348 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1215 08:08:50.982620 30343 recover.cpp:564] Updating replica status to STARTING
I1215 08:08:50.983489 30349 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 625233ns
I1215 08:08:50.983525 30349 replica.cpp:320] Persisted replica status to STARTING
I1215 08:08:50.983741 30350 recover.cpp:473] Replica is in STARTING status
I1215 08:08:50.983994 30347 master.cpp:366] Master 972ddeb3-4616-424e-9b55-df7304a654fb (64c86e9bc4a8) started on 172.17.0.2:49245
I1215 08:08:50.984028 30347 master.cpp:368] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/MOQ1xE/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/MOQ1xE/master" --zk_session_timeout="10secs"
I1215 08:08:50.984444 30347 master.cpp:415] Master allowing unauthenticated frameworks to register
I1215 08:08:50.984458 30347 master.cpp:418] Master only allowing authenticated slaves to register
I1215 08:08:50.984467 30347 credentials.hpp:35] Loading credentials for authentication from '/tmp/MOQ1xE/credentials'
I1215 08:08:50.984781 30347 master.cpp:457] Using default 'crammd5' authenticator
I1215 08:08:50.985011 30347 master.cpp:494] Authorization enabled
I1215 08:08:50.985239 30341 whitelist_watcher.cpp:77] No whitelist given
I1215 08:08:50.985292 30348 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12014)@172.17.0.2:49245
I1215 08:08:50.985314 30340 hierarchical.cpp:163] Initialized hierarchical allocator process
I1215 08:08:50.985587 30345 recover.cpp:193] Received a recover response from a replica in STARTING status
I1215 08:08:50.986166 30340 recover.cpp:564] Updating replica status to VOTING
I1215 08:08:50.986870 30352 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 467494ns
I1215 08:08:50.986904 30352 replica.cpp:320] Persisted replica status to VOTING
I1215 08:08:50.987067 30339 recover.cpp:578] Successfully joined the Paxos group
I1215 08:08:50.987335 30339 recover.cpp:462] Recover process terminated
I1215 08:08:50.987969 30353 master.cpp:1636] The newly elected leader is master@172.17.0.2:49245 with id 972ddeb3-4616-424e-9b55-df7304a654fb
I1215 08:08:50.988008 30353 master.cpp:1649] Elected as the leading master!
I1215 08:08:50.988029 30353 master.cpp:1394] Recovering from registrar
I1215 08:08:50.988193 30343 registrar.cpp:307] Recovering registrar
I1215 08:08:50.988838 30344 log.cpp:659] Attempting to start the writer
I1215 08:08:50.990247 30342 replica.cpp:493] Replica received implicit promise request from (12015)@172.17.0.2:49245 with proposal 1
I1215 08:08:50.990707 30342 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 423681ns
I1215 08:08:50.990736 30342 replica.cpp:342] Persisted promised to 1
I1215 08:08:50.991397 30350 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1215 08:08:50.992755 30339 replica.cpp:388] Replica received explicit promise request from (12016)@172.17.0.2:49245 for position 0 with proposal 2
I1215 08:08:50.993212 30339 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 405420ns
I1215 08:08:50.993242 30339 replica.cpp:712] Persisted action at 0
I1215 08:08:50.994385 30349 replica.cpp:537] Replica received write request for position 0 from (12017)@172.17.0.2:49245
I1215 08:08:50.994458 30349 leveldb.cpp:436] Reading position from leveldb took 31417ns
I1215 08:08:50.994926 30349 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 422483ns
I1215 08:08:50.994956 30349 replica.cpp:712] Persisted action at 0
I1215 08:08:50.995656 30353 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1215 08:08:50.996165 30353 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 469145ns
I1215 08:08:50.996193 30353 replica.cpp:712] Persisted action at 0
I1215 08:08:50.996213 30353 replica.cpp:697] Replica learned NOP action at position 0
I1215 08:08:50.996875 30352 log.cpp:675] Writer started with ending position 0
I1215 08:08:50.998105 30345 leveldb.cpp:436] Reading position from leveldb took 32271ns
I1215 08:08:50.999160 30339 registrar.cpp:340] Successfully fetched the registry (0B) in 10.90688ms
I1215 08:08:50.999284 30339 registrar.cpp:439] Applied 1 operations in 25860ns; attempting to update the 'registry'
I1215 08:08:51.000085 30348 log.cpp:683] Attempting to append 170 bytes to the log
I1215 08:08:51.000249 30350 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1215 08:08:51.001049 30348 replica.cpp:537] Replica received write request for position 1 from (12018)@172.17.0.2:49245
I1215 08:08:51.001685 30348 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 592927ns
I1215 08:08:51.001718 30348 replica.cpp:712] Persisted action at 1
I1215 08:08:51.002734 30346 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1215 08:08:51.003296 30346 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 513278ns
I1215 08:08:51.003339 30346 replica.cpp:712] Persisted action at 1
I1215 08:08:51.003376 30346 replica.cpp:697] Replica learned APPEND action at position 1
I1215 08:08:51.004776 30338 registrar.cpp:484] Successfully updated the 'registry' in 5.384192ms
I1215 08:08:51.005034 30338 registrar.cpp:370] Successfully recovered registrar
I1215 08:08:51.005137 30341 log.cpp:702] Attempting to truncate the log to 1
I1215 08:08:51.005308 30344 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1215 08:08:51.005705 30348 master.cpp:1446] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1215 08:08:51.005748 30346 hierarchical.cpp:181] Skipping recovery of hierarchical allocator: nothing to recover
I1215 08:08:51.006453 30347 replica.cpp:537] Replica received write request for position 2 from (12019)@172.17.0.2:49245
I1215 08:08:51.007092 30347 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 594016ns
I1215 08:08:51.007123 30347 replica.cpp:712] Persisted action at 2
I1215 08:08:51.008193 30343 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1215 08:08:51.008666 30343 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 433927ns
I1215 08:08:51.008728 30343 leveldb.cpp:399] Deleting ~1 keys from leveldb took 32850ns
I1215 08:08:51.008759 30343 replica.cpp:712] Persisted action at 2
I1215 08:08:51.008785 30343 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1215 08:08:51.016407 30319 scheduler.cpp:154] Version: 0.27.0
I1215 08:08:51.017104 30346 scheduler.cpp:236] New master detected at master@172.17.0.2:49245
I1215 08:08:51.018298 30343 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:49245
I1215 08:08:51.020903 30353 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 08:08:51.020978 30353 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:38410
I1215 08:08:51.021180 30353 master.cpp:1898] Received subscription request for HTTP framework 'default'
I1215 08:08:51.021252 30353 master.cpp:1675] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1215 08:08:51.021572 30341 master.cpp:1990] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1215 08:08:51.021996 30346 hierarchical.cpp:267] Added framework 972ddeb3-4616-424e-9b55-df7304a654fb-0000
I1215 08:08:51.022078 30346 hierarchical.cpp:1317] No resources available to allocate!
I1215 08:08:51.022078 30353 master.hpp:1588] Sending heartbeat to 972ddeb3-4616-424e-9b55-df7304a654fb-0000
I1215 08:08:51.022135 30346 hierarchical.cpp:1410] No inverse offers to send out!
I1215 08:08:51.022167 30346 hierarchical.cpp:1063] Performed allocation for 0 slaves in 138927ns
I1215 08:08:51.023089 30353 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:49245
I1215 08:08:51.023684 30353 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:49245
I1215 08:08:51.024533 30340 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1215 08:08:51.024699 30342 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:49245
I1215 08:08:51.026679 30350 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 08:08:51.026760 30350 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:38411
I1215 08:08:51.026924 30350 master.cpp:2645] Processing REQUEST call for framework 972ddeb3-4616-424e-9b55-df7304a654fb-0000 (default)
I1215 08:08:51.027158 30348 hierarchical.cpp:562] Received resource request from framework 972ddeb3-4616-424e-9b55-df7304a654fb-0000
I1215 08:08:51.027518 30349 master.cpp:937] Master terminating
I1215 08:08:51.027703 30351 hierarchical.cpp:308] Removed framework 972ddeb3-4616-424e-9b55-df7304a654fb-0000
E1215 08:08:51.029155 30338 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (62 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1215 08:08:51.039124 30319 leveldb.cpp:174] Opened db in 2.699435ms
I1215 08:08:51.040395 30319 leveldb.cpp:181] Compacted db in 1.230022ms
I1215 08:08:51.040459 30319 leveldb.cpp:196] Created db iterator in 18717ns
I1215 08:08:51.040480 30319 leveldb.cpp:202] Seeked to beginning of db in 2125ns
I1215 08:08:51.040493 30319 leveldb.cpp:271] Iterated through 0 keys in the db in 378ns
I1215 08:08:51.040527 30319 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1215 08:08:51.041044 30349 recover.cpp:447] Starting replica recovery
I1215 08:08:51.041417 30349 recover.cpp:473] Replica is in EMPTY status
I1215 08:08:51.042500 30345 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12026)@172.17.0.2:49245
I1215 08:08:51.042860 30352 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1215 08:08:51.043503 30349 recover.cpp:564] Updating replica status to STARTING
I1215 08:08:51.044337 30347 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 659830ns
I1215 08:08:51.044373 30347 replica.cpp:320] Persisted replica status to STARTING
I1215 08:08:51.044451 30353 master.cpp:366] Master 95b80ad5-5c88-44f0-8296-f7bfdd9fd3cb (64c86e9bc4a8) started on 172.17.0.2:49245
I1215 08:08:51.044687 30338 recover.cpp:473] Replica is in STARTING status
I1215 08:08:51.044483 30353 master.cpp:368] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/BB6U9a/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/BB6U9a/master" --zk_session_timeout="10secs"
I1215 08:08:51.045475 30353 master.cpp:415] Master allowing unauthenticated frameworks to register
I1215 08:08:51.045500 30353 master.cpp:418] Master only allowing authenticated slaves to register
I1215 08:08:51.045517 30353 credentials.hpp:35] Loading credentials for authentication from '/tmp/BB6U9a/credentials'
I1215 08:08:51.045641 30351 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12027)@172.17.0.2:49245
I1215 08:08:51.045899 30353 master.cpp:457] Using default 'crammd5' authenticator
I1215 08:08:51.046052 30353 master.cpp:494] Authorization enabled
I1215 08:08:51.046087 30344 recover.cpp:193] Received a recover response from a replica in STARTING status
I1215 08:08:51.046272 30341 whitelist_watcher.cpp:77] No whitelist given
I1215 08:08:51.046349 30348 hierarchical.cpp:163] Initialized hierarchical allocator process
I1215 08:08:51.046613 30340 recover.cpp:564] Updating replica status to VOTING
I1215 08:08:51.047248 30343 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 346464ns
I1215 08:08:51.047279 30343 replica.cpp:320] Persisted replica status to VOTING
I1215 08:08:51.047466 30342 recover.cpp:578] Successfully joined the Paxos group
I1215 08:08:51.047757 30342 recover.cpp:462] Recover process terminated
I1215 08:08:51.048921 30353 master.cpp:1636] The newly elected leader is master@172.17.0.2:49245 with id 95b80ad5-5c88-44f0-8296-f7bfdd9fd3cb
I1215 08:08:51.048956 30353 master.cpp:1649] Elected as the leading master!
I1215 08:08:51.048975 30353 master.cpp:1394] Recovering from registrar
I1215 08:08:51.049096 30341 registrar.cpp:307] Recovering registrar
I1215 08:08:51.049715 30344 log.cpp:659] Attempting to start the writer
I1215 08:08:51.051076 30349 replica.cpp:493] Replica received implicit promise request from (12028)@172.17.0.2:49245 with proposal 1
I1215 08:08:51.051602 30349 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 483161ns
I1215 08:08:51.051630 30349 replica.cpp:342] Persisted promised to 1
I1215 08:08:51.052227 30341 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1215 08:08:51.053467 30338 replica.cpp:388] Replica received explicit promise request from (12029)@172.17.0.2:49245 for position 0 with proposal 2
I1215 08:08:51.053952 30338 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 437434ns
I1215 08:08:51.053982 30338 replica.cpp:712] Persisted action at 0
I1215 08:08:51.055181 30349 replica.cpp:537] Replica received write request for position 0 from (12030)@172.17.0.2:49245
I1215 08:08:51.055256 30349 leveldb.cpp:436] Reading position from leveldb took 34679ns
I1215 08:08:51.055740 30349 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 427950ns
I1215 08:08:51.055770 30349 replica.cpp:712] Persisted action at 0
I1215 08:08:51.056427 30351 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1215 08:08:51.056926 30351 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 393297ns
I1215 08:08:51.056954 30351 replica.cpp:712] Persisted action at 0
I1215 08:08:51.056974 30351 replica.cpp:697] Replica learned NOP action at position 0
I1215 08:08:51.057582 30345 log.cpp:675] Writer started with ending position 0
I1215 08:08:51.058648 30348 leveldb.cpp:436] Reading position from leveldb took 33535ns
I1215 08:08:51.059571 30341 registrar.cpp:340] Successfully fetched the registry (0B) in 10.41408ms
I1215 08:08:51.059687 30341 registrar.cpp:439] Applied 1 operations in 23429ns; attempting to update the 'registry'
I1215 08:08:51.060518 30339 log.cpp:683] Attempting to append 170 bytes to the log
I1215 08:08:51.060689 30344 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1215 08:08:51.061522 30341 replica.cpp:537] Replica received write request for position 1 from (12031)@172.17.0.2:49245
I1215 08:08:51.062046 30341 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 472234ns
I1215 08:08:51.062077 30341 replica.cpp:712] Persisted action at 1
I1215 08:08:51.062777 30340 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1215 08:08:51.063339 30340 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 522428ns
I1215 08:08:51.063371 30340 replica.cpp:712] Persisted action at 1
I1215 08:08:51.063393 30340 replica.cpp:697] Replica learned APPEND action at position 1
I1215 08:08:51.064527 30345 registrar.cpp:484] Successfully updated the 'registry' in 4.774144ms
I1215 08:08:51.064695 30345 registrar.cpp:370] Successfully recovered registrar
I1215 08:08:51.064882 30339 log.cpp:702] Attempting to truncate the log to 1
I1215 08:08:51.065237 30349 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1215 08:08:51.065230 30338 master.cpp:1446] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1215 08:08:51.065266 30342 hierarchical.cpp:181] Skipping recovery of hierarchical allocator: nothing to recover
I1215 08:08:51.066347 30344 replica.cpp:537] Replica received write request for position 2 from (12032)@172.17.0.2:49245
I1215 08:08:51.066890 30344 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 497736ns
I1215 08:08:51.066923 30344 replica.cpp:712] Persisted action at 2
I1215 08:08:51.067572 30347 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1215 08:08:51.068084 30347 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 470077ns
I1215 08:08:51.068155 30347 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40326ns
I1215 08:08:51.068181 30347 replica.cpp:712] Persisted action at 2
I1215 08:08:51.068204 30347 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1215 08:08:51.075929 30319 scheduler.cpp:154] Version: 0.27.0
I1215 08:08:51.076536 30352 scheduler.cpp:236] New master detected at master@172.17.0.2:49245
I1215 08:08:51.077723 30352 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:49245
I1215 08:08:51.080497 30338 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 08:08:51.080631 30338 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:38412
I1215 08:08:51.081064 30338 master.cpp:1898] Received subscription request for HTTP framework 'default'
I1215 08:08:51.081159 30338 master.cpp:1675] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1215 08:08:51.081517 30338 master.cpp:1990] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1215 08:08:51.081912 30344 hierarchical.cpp:267] Added framework 95b80ad5-5c88-44f0-8296-f7bfdd9fd3cb-0000
I1215 08:08:51.081976 30344 hierarchical.cpp:1317] No resources available to allocate!
I1215 08:08:51.082010 30344 hierarchical.cpp:1410] No inverse offers to send out!
I1215 08:08:51.082037 30344 hierarchical.cpp:1063] Performed allocation for 0 slaves in 95885ns
I1215 08:08:51.082078 30349 master.hpp:1588] Sending heartbeat to 95b80ad5-5c88-44f0-8296-f7bfdd9fd3cb-0000
I1215 08:08:51.083328 30340 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:49245
I1215 08:08:51.083848 30340 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:49245
I1215 08:08:51.084728 30350 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1215 08:08:51.084841 30340 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:49245
I1215 08:08:51.087018 30351 process.cpp:3225] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1215 08:08:51.087092 30351 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:38413
I1215 08:08:51.087352 30351 master.cpp:2645] Processing REQUEST call for framework 95b80ad5-5c88-44f0-8296-f7bfdd9fd3cb-0000 (default)
I1215 08:08:51.087522 30344 hierarchical.cpp:562] Received resource request from framework 95b80ad5-5c88-44f0-8296-f7bfdd9fd3cb-0000
I1215 08:08:51.087875 30346 master.cpp:937] Master terminating
I1215 08:08:51.088090 30339 hierarchical.cpp:308] Removed framework 95b80ad5-5c88-44f0-8296-f7bfdd9fd3cb-0000
E1215 08:08:51.089427 30339 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (62 ms)
[----------] 22 tests from ContentType/SchedulerTest (4258 ms total)
[----------] Global test environment tear-down
[==========] 886 tests from 116 test cases ran. (340967 ms total)
[ PASSED ] 883 tests.
[ FAILED ] 3 tests, listed below:
[ FAILED ] HdfsTest.Rm
[ FAILED ] HdfsTest.CopyFromLocal
[ FAILED ] HdfsTest.CopyToLocal
3 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-1450165213-29840
Untagged: mesos-1450165213-29840:latest
Deleted: b018297671837d2bf99222a1461f749f922b91f00cb5775b009183e124dabde7
Deleted: 040fa08ff1deacfccdf65c57fae12bb299e9c19f50e1f181780ed16213495b0c
Deleted: 07a43b2ba0358e133c624f4516c935371d66f9fc7de9090e582bcfd2949332a3
Deleted: 06f54062cee855ac4e6f79e9077e3c58db670b5551d7626dc9b8cd7719f3fa11
Deleted: 2bc03c25a22f302da14f57733f6951afed738b091296ae95dbf528d9b1fa36f4
Deleted: 5b6238ba2287b784144cd1a98cb76bd654e4f3bc3200243d2cc48644a8f606f6
Deleted: 891bb898e9ec832fdf5063bc7f2b5cd0094bf2eae65100e69839bbdce7111217
Deleted: 076ae55978c2ad1d1bbb2ba272912505c35bfaff0b3650532c3d9b85bd04591c
Deleted: 020a38c21356d991ed43e11cd424e647bc61a85d2276aed3616564685cba0b59
Deleted: 37846cfc8cd806c519d1d48acf1c4202bba32b0db16240634027417ed67c0347
Deleted: 9541ad6818c30a608b17135918a479256718dbebb1ce21d31093f170f6392090
Deleted: e100689fdbbeddd2dfb14d755c1f8e847ecc6715d93f5c64df76f86e42788cf1
Deleted: 106c48ad18322c1ee7dba67b9851d6df6e198f93400e7c2d2bc8615f4ef6c0a2
Error handling URL https://reviews.apache.org/api/review-requests/41384/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard bdaa698e5fdd41c949bc2fbb372fe96710dc2d0e
Build step 'Execute shell' marked build as failure