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/10/16 14:52:06 UTC
Build failed in Jenkins: Mesos » gcc,--verbose,centos:7,docker||Hadoop #942
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=centos%3A7,label_exp=docker%7C%7CHadoop/942/changes>
Changes:
[bernd] Added code that appends the fetcher log to the agent log upon fetcher
[bernd] Added additional diagnostic output when a fetcher cache test fails.
[tnachen] Added serialization of Docker Image Spec as protobuf.
[tnachen] Added validation of Docker Image Manifests.
------------------------------------------
[...truncated 136512 lines...]
I1016 12:52:00.709342 30362 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 28.154615ms
I1016 12:52:00.709380 30362 replica.cpp:681] Persisted action at 1
I1016 12:52:00.709955 30362 replica.cpp:660] Replica received learned notice for position 1 from @0.0.0.0:0
I1016 12:52:00.738996 30362 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 28.989067ms
I1016 12:52:00.739039 30362 replica.cpp:681] Persisted action at 1
I1016 12:52:00.739075 30362 replica.cpp:666] Replica learned APPEND action at position 1
I1016 12:52:00.740181 30368 registrar.cpp:486] Successfully updated the 'registry' in 61.030144ms
I1016 12:52:00.740370 30368 registrar.cpp:372] Successfully recovered registrar
I1016 12:52:00.740471 30370 log.cpp:704] Attempting to truncate the log to 1
I1016 12:52:00.740772 30355 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I1016 12:52:00.740779 30359 master.cpp:1419] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1016 12:52:00.741694 30362 replica.cpp:512] Replica received write request for position 2 from (10385)@172.17.7.238:34368
I1016 12:52:00.772438 30362 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 30.694099ms
I1016 12:52:00.772481 30362 replica.cpp:681] Persisted action at 2
I1016 12:52:00.773205 30363 replica.cpp:660] Replica received learned notice for position 2 from @0.0.0.0:0
I1016 12:52:00.801530 30363 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 28.219221ms
I1016 12:52:00.801620 30363 leveldb.cpp:401] Deleting ~1 keys from leveldb took 43203ns
I1016 12:52:00.801646 30363 replica.cpp:681] Persisted action at 2
I1016 12:52:00.801671 30363 replica.cpp:666] Replica learned TRUNCATE action at position 2
I1016 12:52:00.813771 30363 process.cpp:3078] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1016 12:52:00.814069 30363 http.cpp:338] HTTP POST for /master/api/v1/scheduler from 172.17.7.238:53336
I1016 12:52:00.814436 30363 master.cpp:1871] Received subscription request for HTTP framework 'default'
I1016 12:52:00.814508 30363 master.cpp:1648] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1016 12:52:00.814810 30363 master.cpp:1963] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1016 12:52:00.815225 30365 hierarchical.cpp:185] Added framework 7c9cdcc3-f9f6-41c1-854a-2490caf8b2d3-0000
I1016 12:52:00.815289 30365 hierarchical.cpp:952] No resources available to allocate!
I1016 12:52:00.815363 30369 master.hpp:1436] Sending heartbeat to 7c9cdcc3-f9f6-41c1-854a-2490caf8b2d3-0000
I1016 12:52:00.815465 30365 hierarchical.cpp:1045] No inverse offers to send out!
I1016 12:52:00.815501 30365 hierarchical.cpp:851] Performed allocation for 0 slaves in 240750ns
I1016 12:52:00.816459 30355 master.cpp:925] Master terminating
I1016 12:52:00.816622 30363 hierarchical.cpp:220] Removed framework 7c9cdcc3-f9f6-41c1-854a-2490caf8b2d3-0000
[ OK ] ContentType/SchedulerHttpApiTest.NoAcceptHeader/1 (485 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/0
Using temporary directory '/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_0_Uq0Qy8'
I1016 12:52:00.894842 30336 leveldb.cpp:176] Opened db in 73.380078ms
I1016 12:52:00.934165 30336 leveldb.cpp:183] Compacted db in 39.279654ms
I1016 12:52:00.934229 30336 leveldb.cpp:198] Created db iterator in 17676ns
I1016 12:52:00.934249 30336 leveldb.cpp:204] Seeked to beginning of db in 1962ns
I1016 12:52:00.934262 30336 leveldb.cpp:273] Iterated through 0 keys in the db in 372ns
I1016 12:52:00.934303 30336 replica.cpp:746] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1016 12:52:00.934860 30363 recover.cpp:449] Starting replica recovery
I1016 12:52:00.935374 30363 recover.cpp:475] Replica is in EMPTY status
I1016 12:52:00.937597 30363 master.cpp:376] Master e79b718d-eda1-42a8-b953-9f126a85f79e (635f798fc895) started on 172.17.7.238:34368
I1016 12:52:00.937623 30363 master.cpp:378] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_0_Uq0Qy8/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.26.0/_inst/share/mesos/webui" --work_dir="/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_0_Uq0Qy8/master" --zk_session_timeout="10secs"
I1016 12:52:00.937872 30363 master.cpp:425] Master allowing unauthenticated frameworks to register
I1016 12:52:00.937883 30363 master.cpp:428] Master only allowing authenticated slaves to register
I1016 12:52:00.937890 30363 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_0_Uq0Qy8/credentials'
I1016 12:52:00.937937 30364 replica.cpp:642] Replica in EMPTY status received a broadcasted recover request from (10389)@172.17.7.238:34368
I1016 12:52:00.938127 30363 master.cpp:467] Using default 'crammd5' authenticator
I1016 12:52:00.938230 30363 master.cpp:504] Authorization enabled
I1016 12:52:00.938274 30359 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1016 12:52:00.938429 30357 whitelist_watcher.cpp:79] No whitelist given
I1016 12:52:00.938454 30365 hierarchical.cpp:140] Initialized hierarchical allocator process
I1016 12:52:00.938740 30361 recover.cpp:566] Updating replica status to STARTING
I1016 12:52:00.939926 30366 master.cpp:1609] The newly elected leader is master@172.17.7.238:34368 with id e79b718d-eda1-42a8-b953-9f126a85f79e
I1016 12:52:00.939980 30366 master.cpp:1622] Elected as the leading master!
I1016 12:52:00.939999 30366 master.cpp:1382] Recovering from registrar
I1016 12:52:00.940176 30362 registrar.cpp:309] Recovering registrar
I1016 12:52:00.967425 30359 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 28.54865ms
I1016 12:52:00.967505 30359 replica.cpp:323] Persisted replica status to STARTING
I1016 12:52:00.967840 30355 recover.cpp:475] Replica is in STARTING status
I1016 12:52:00.968999 30359 replica.cpp:642] Replica in STARTING status received a broadcasted recover request from (10390)@172.17.7.238:34368
I1016 12:52:00.969334 30356 recover.cpp:195] Received a recover response from a replica in STARTING status
I1016 12:52:00.969738 30363 recover.cpp:566] Updating replica status to VOTING
I1016 12:52:00.995200 30370 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 25.262131ms
I1016 12:52:00.995240 30370 replica.cpp:323] Persisted replica status to VOTING
I1016 12:52:00.995375 30360 recover.cpp:580] Successfully joined the Paxos group
I1016 12:52:00.995610 30360 recover.cpp:464] Recover process terminated
I1016 12:52:00.996094 30361 log.cpp:661] Attempting to start the writer
I1016 12:52:00.997359 30369 replica.cpp:478] Replica received implicit promise request from (10391)@172.17.7.238:34368 with proposal 1
I1016 12:52:01.020423 30369 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 23.023526ms
I1016 12:52:01.020469 30369 replica.cpp:345] Persisted promised to 1
I1016 12:52:01.021204 30367 coordinator.cpp:231] Coordinator attemping to fill missing position
I1016 12:52:01.022456 30357 replica.cpp:378] Replica received explicit promise request from (10392)@172.17.7.238:34368 for position 0 with proposal 2
I1016 12:52:01.045469 30357 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 22.969365ms
I1016 12:52:01.045516 30357 replica.cpp:681] Persisted action at 0
I1016 12:52:01.046861 30363 replica.cpp:512] Replica received write request for position 0 from (10393)@172.17.7.238:34368
I1016 12:52:01.046929 30363 leveldb.cpp:438] Reading position from leveldb took 30411ns
I1016 12:52:01.070576 30363 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 23.576457ms
I1016 12:52:01.070621 30363 replica.cpp:681] Persisted action at 0
I1016 12:52:01.071305 30356 replica.cpp:660] Replica received learned notice for position 0 from @0.0.0.0:0
I1016 12:52:01.095710 30356 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 24.363385ms
I1016 12:52:01.095760 30356 replica.cpp:681] Persisted action at 0
I1016 12:52:01.095798 30356 replica.cpp:666] Replica learned NOP action at position 0
I1016 12:52:01.096567 30356 log.cpp:677] Writer started with ending position 0
I1016 12:52:01.097769 30365 leveldb.cpp:438] Reading position from leveldb took 31543ns
I1016 12:52:01.098783 30360 registrar.cpp:342] Successfully fetched the registry (0B) in 158.563072ms
I1016 12:52:01.098929 30360 registrar.cpp:441] Applied 1 operations in 40505ns; attempting to update the 'registry'
I1016 12:52:01.099859 30364 log.cpp:685] Attempting to append 176 bytes to the log
I1016 12:52:01.100019 30369 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I1016 12:52:01.100810 30364 replica.cpp:512] Replica received write request for position 1 from (10394)@172.17.7.238:34368
I1016 12:52:01.126477 30364 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 25.623082ms
I1016 12:52:01.126521 30364 replica.cpp:681] Persisted action at 1
I1016 12:52:01.127246 30364 replica.cpp:660] Replica received learned notice for position 1 from @0.0.0.0:0
I1016 12:52:01.151579 30364 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 24.292776ms
I1016 12:52:01.151623 30364 replica.cpp:681] Persisted action at 1
I1016 12:52:01.151660 30364 replica.cpp:666] Replica learned APPEND action at position 1
I1016 12:52:01.152915 30356 registrar.cpp:486] Successfully updated the 'registry' in 53.919232ms
I1016 12:52:01.153110 30356 registrar.cpp:372] Successfully recovered registrar
I1016 12:52:01.153187 30367 log.cpp:704] Attempting to truncate the log to 1
I1016 12:52:01.153331 30361 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I1016 12:52:01.153528 30366 master.cpp:1419] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1016 12:52:01.154300 30360 replica.cpp:512] Replica received write request for position 2 from (10395)@172.17.7.238:34368
I1016 12:52:01.179363 30360 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 25.023288ms
I1016 12:52:01.179401 30360 replica.cpp:681] Persisted action at 2
I1016 12:52:01.180150 30364 replica.cpp:660] Replica received learned notice for position 2 from @0.0.0.0:0
I1016 12:52:01.206841 30364 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 26.650847ms
I1016 12:52:01.206930 30364 leveldb.cpp:401] Deleting ~1 keys from leveldb took 43353ns
I1016 12:52:01.206954 30364 replica.cpp:681] Persisted action at 2
I1016 12:52:01.207007 30364 replica.cpp:666] Replica learned TRUNCATE action at position 2
I1016 12:52:01.216505 30368 process.cpp:3078] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1016 12:52:01.217017 30368 http.cpp:338] HTTP POST for /master/api/v1/scheduler from 172.17.7.238:53337
I1016 12:52:01.217223 30368 master.cpp:1871] Received subscription request for HTTP framework 'default'
I1016 12:52:01.217314 30368 master.cpp:1648] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1016 12:52:01.217639 30368 master.cpp:1963] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1016 12:52:01.218047 30367 hierarchical.cpp:185] Added framework e79b718d-eda1-42a8-b953-9f126a85f79e-0000
I1016 12:52:01.218111 30367 hierarchical.cpp:952] No resources available to allocate!
I1016 12:52:01.218166 30367 hierarchical.cpp:1045] No inverse offers to send out!
I1016 12:52:01.218200 30368 master.hpp:1436] Sending heartbeat to e79b718d-eda1-42a8-b953-9f126a85f79e-0000
I1016 12:52:01.218205 30367 hierarchical.cpp:851] Performed allocation for 0 slaves in 126862ns
I1016 12:52:01.219396 30359 master.cpp:925] Master terminating
I1016 12:52:01.219599 30365 hierarchical.cpp:220] Removed framework e79b718d-eda1-42a8-b953-9f126a85f79e-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/0 (405 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/1
Using temporary directory '/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_1_W7CItq'
I1016 12:52:01.308313 30336 leveldb.cpp:176] Opened db in 81.425897ms
I1016 12:52:01.333714 30336 leveldb.cpp:183] Compacted db in 25.358761ms
I1016 12:52:01.333791 30336 leveldb.cpp:198] Created db iterator in 20812ns
I1016 12:52:01.333833 30336 leveldb.cpp:204] Seeked to beginning of db in 2435ns
I1016 12:52:01.333858 30336 leveldb.cpp:273] Iterated through 0 keys in the db in 540ns
I1016 12:52:01.333914 30336 replica.cpp:746] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1016 12:52:01.334406 30368 recover.cpp:449] Starting replica recovery
I1016 12:52:01.334823 30368 recover.cpp:475] Replica is in EMPTY status
I1016 12:52:01.335772 30367 replica.cpp:642] Replica in EMPTY status received a broadcasted recover request from (10399)@172.17.7.238:34368
I1016 12:52:01.336227 30358 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1016 12:52:01.336587 30355 recover.cpp:566] Updating replica status to STARTING
I1016 12:52:01.337579 30363 master.cpp:376] Master a66067e9-12ba-49f2-a980-a693a2e51efe (635f798fc895) started on 172.17.7.238:34368
I1016 12:52:01.337604 30363 master.cpp:378] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_1_W7CItq/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.26.0/_inst/share/mesos/webui" --work_dir="/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_1_W7CItq/master" --zk_session_timeout="10secs"
I1016 12:52:01.337826 30363 master.cpp:425] Master allowing unauthenticated frameworks to register
I1016 12:52:01.337836 30363 master.cpp:428] Master only allowing authenticated slaves to register
I1016 12:52:01.337842 30363 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_1_W7CItq/credentials'
I1016 12:52:01.338181 30363 master.cpp:467] Using default 'crammd5' authenticator
I1016 12:52:01.338289 30363 master.cpp:504] Authorization enabled
I1016 12:52:01.338502 30369 whitelist_watcher.cpp:79] No whitelist given
I1016 12:52:01.338515 30370 hierarchical.cpp:140] Initialized hierarchical allocator process
I1016 12:52:01.339929 30355 master.cpp:1609] The newly elected leader is master@172.17.7.238:34368 with id a66067e9-12ba-49f2-a980-a693a2e51efe
I1016 12:52:01.339989 30355 master.cpp:1622] Elected as the leading master!
I1016 12:52:01.340015 30355 master.cpp:1382] Recovering from registrar
I1016 12:52:01.340167 30367 registrar.cpp:309] Recovering registrar
I1016 12:52:01.371206 30359 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 34.484768ms
I1016 12:52:01.371253 30359 replica.cpp:323] Persisted replica status to STARTING
I1016 12:52:01.371484 30362 recover.cpp:475] Replica is in STARTING status
I1016 12:52:01.372367 30360 replica.cpp:642] Replica in STARTING status received a broadcasted recover request from (10400)@172.17.7.238:34368
I1016 12:52:01.372783 30359 recover.cpp:195] Received a recover response from a replica in STARTING status
I1016 12:52:01.373322 30358 recover.cpp:566] Updating replica status to VOTING
I1016 12:52:01.404683 30357 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 31.168607ms
I1016 12:52:01.404712 30357 replica.cpp:323] Persisted replica status to VOTING
I1016 12:52:01.404796 30368 recover.cpp:580] Successfully joined the Paxos group
I1016 12:52:01.405045 30368 recover.cpp:464] Recover process terminated
I1016 12:52:01.405513 30357 log.cpp:661] Attempting to start the writer
I1016 12:52:01.406522 30355 replica.cpp:478] Replica received implicit promise request from (10401)@172.17.7.238:34368 with proposal 1
I1016 12:52:01.429678 30355 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 23.125862ms
I1016 12:52:01.429710 30355 replica.cpp:345] Persisted promised to 1
I1016 12:52:01.430950 30366 coordinator.cpp:231] Coordinator attemping to fill missing position
I1016 12:52:01.432205 30362 replica.cpp:378] Replica received explicit promise request from (10402)@172.17.7.238:34368 for position 0 with proposal 2
I1016 12:52:01.479913 30362 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 47.665816ms
I1016 12:52:01.479960 30362 replica.cpp:681] Persisted action at 0
I1016 12:52:01.481022 30367 replica.cpp:512] Replica received write request for position 0 from (10403)@172.17.7.238:34368
I1016 12:52:01.481106 30367 leveldb.cpp:438] Reading position from leveldb took 36484ns
I1016 12:52:01.513360 30367 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 32.195389ms
I1016 12:52:01.513408 30367 replica.cpp:681] Persisted action at 0
I1016 12:52:01.514019 30369 replica.cpp:660] Replica received learned notice for position 0 from @0.0.0.0:0
I1016 12:52:01.555217 30369 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 41.140656ms
I1016 12:52:01.555248 30369 replica.cpp:681] Persisted action at 0
I1016 12:52:01.555264 30369 replica.cpp:666] Replica learned NOP action at position 0
I1016 12:52:01.555827 30361 log.cpp:677] Writer started with ending position 0
I1016 12:52:01.556764 30358 leveldb.cpp:438] Reading position from leveldb took 27918ns
I1016 12:52:01.557667 30358 registrar.cpp:342] Successfully fetched the registry (0B) in 217.442816ms
I1016 12:52:01.557788 30358 registrar.cpp:441] Applied 1 operations in 28902ns; attempting to update the 'registry'
I1016 12:52:01.558468 30366 log.cpp:685] Attempting to append 176 bytes to the log
I1016 12:52:01.558593 30367 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I1016 12:52:01.559384 30361 replica.cpp:512] Replica received write request for position 1 from (10404)@172.17.7.238:34368
I1016 12:52:01.588752 30361 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 29.32558ms
I1016 12:52:01.588803 30361 replica.cpp:681] Persisted action at 1
I1016 12:52:01.589679 30356 replica.cpp:660] Replica received learned notice for position 1 from @0.0.0.0:0
I1016 12:52:01.622161 30356 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 32.448705ms
I1016 12:52:01.622200 30356 replica.cpp:681] Persisted action at 1
I1016 12:52:01.622223 30356 replica.cpp:666] Replica learned APPEND action at position 1
I1016 12:52:01.623206 30369 registrar.cpp:486] Successfully updated the 'registry' in 65.35808ms
I1016 12:52:01.623343 30369 registrar.cpp:372] Successfully recovered registrar
I1016 12:52:01.623409 30355 log.cpp:704] Attempting to truncate the log to 1
I1016 12:52:01.623535 30360 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I1016 12:52:01.623847 30365 master.cpp:1419] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1016 12:52:01.624238 30363 replica.cpp:512] Replica received write request for position 2 from (10405)@172.17.7.238:34368
I1016 12:52:01.669742 30363 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 45.468175ms
I1016 12:52:01.669782 30363 replica.cpp:681] Persisted action at 2
I1016 12:52:01.670445 30361 replica.cpp:660] Replica received learned notice for position 2 from @0.0.0.0:0
I1016 12:52:01.714057 30361 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 43.58038ms
I1016 12:52:01.714134 30361 leveldb.cpp:401] Deleting ~1 keys from leveldb took 38012ns
I1016 12:52:01.714157 30361 replica.cpp:681] Persisted action at 2
I1016 12:52:01.714181 30361 replica.cpp:666] Replica learned TRUNCATE action at position 2
I1016 12:52:01.716847 30362 process.cpp:3078] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1016 12:52:01.717186 30362 http.cpp:338] HTTP POST for /master/api/v1/scheduler from 172.17.7.238:53338
I1016 12:52:01.717629 30362 master.cpp:1871] Received subscription request for HTTP framework 'default'
I1016 12:52:01.717706 30362 master.cpp:1648] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1016 12:52:01.717995 30358 master.cpp:1963] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1016 12:52:01.718330 30370 hierarchical.cpp:185] Added framework a66067e9-12ba-49f2-a980-a693a2e51efe-0000
I1016 12:52:01.718384 30370 hierarchical.cpp:952] No resources available to allocate!
I1016 12:52:01.718457 30358 master.hpp:1436] Sending heartbeat to a66067e9-12ba-49f2-a980-a693a2e51efe-0000
I1016 12:52:01.718641 30370 hierarchical.cpp:1045] No inverse offers to send out!
I1016 12:52:01.718675 30370 hierarchical.cpp:851] Performed allocation for 0 slaves in 321808ns
I1016 12:52:01.719614 30365 master.cpp:925] Master terminating
I1016 12:52:01.719816 30359 hierarchical.cpp:220] Removed framework a66067e9-12ba-49f2-a980-a693a2e51efe-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/1 (499 ms)
[----------] 18 tests from ContentType/SchedulerHttpApiTest (9466 ms total)
[----------] Global test environment tear-down
[==========] 812 tests from 111 test cases ran. (629715 ms total)
[ PASSED ] 811 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ContentType/SchedulerTest.ShutdownExecutor/0, where GetParam() = application/x-protobuf
1 FAILED TEST
YOU HAVE 7 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.26.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1444997822-10222
Untagged: mesos-1444997822-10222:latest
Deleted: f8ebde8899c9ed32d1e0bc2813dc91054ba31bbb0a12c7ad2bdc33c30b7059ee
Deleted: ee3e45c151280a0c8941be18527050f3d2fd64061f4bf4ed845430c1c592584e
Deleted: a0e8d846e39bd0e328a1178b5ab32ed9149b0c48d6b67c3fb986076784e9acf4
Deleted: 6a3ce441429b6b782b8989cccac96112e5f8274cc63093c6e123d3c467d20842
Deleted: 8db51f93ed90993531d62b8bafdd42102e4d50e55fff8eb82af51c07c9575826
Deleted: f70ec6f2726ff97e37ae5c47b6f78680ff3d9a6955a4bb35d165c425fd32b676
Deleted: 5251309379db5c66f5cb9cb40f2a214377e66f97c0fa7e1d2f6b7a3348792931
Deleted: cac21f7184d78f63456a6f56dc8466070f9fe545c10bb4cd082a26aa6955d22b
Deleted: efe3bbdde1a2bba2a5160be477e28c08b5d928747e18a3b94846e4d07b5f6e5a
Deleted: e115753ad5c3a48f3255e12c33d1159f2534f8b71043c92356f915444dd558bf
Deleted: 9de8af6a8b98623dabc1a13e4228451273f996b3f219665729d8db0fc96e3707
Deleted: 89464637c43acc62838bfaf2368584d161cf58a1557c604607184a124e66f7c4
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins: Mesos » gcc,--verbose,centos:7,docker||Hadoop #942
Posted by Anand Mazumdar <an...@mesosphere.io>.
Certainly not. Filing an issue and taking a look.
-anand
> On Oct 16, 2015, at 10:14 AM, Vinod Kone <vi...@apache.org> wrote:
>
> @anand, known issue?
>
> On Fri, Oct 16, 2015 at 5:52 AM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
>> See <
>> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=centos%3A7,label_exp=docker%7C%7CHadoop/942/changes
>>>
>>
>> Changes:
>>
>> [bernd] Added code that appends the fetcher log to the agent log upon
>> fetcher
>>
>> [bernd] Added additional diagnostic output when a fetcher cache test fails.
>>
>> [tnachen] Added serialization of Docker Image Spec as protobuf.
>>
>> [tnachen] Added validation of Docker Image Manifests.
>>
>> ------------------------------------------
>> [...truncated 136512 lines...]
>> I1016 12:52:00.709342 30362 leveldb.cpp:343] Persisting action (195 bytes)
>> to leveldb took 28.154615ms
>> I1016 12:52:00.709380 30362 replica.cpp:681] Persisted action at 1
>> I1016 12:52:00.709955 30362 replica.cpp:660] Replica received learned
>> notice for position 1 from @0.0.0.0:0
>> I1016 12:52:00.738996 30362 leveldb.cpp:343] Persisting action (197 bytes)
>> to leveldb took 28.989067ms
>> I1016 12:52:00.739039 30362 replica.cpp:681] Persisted action at 1
>> I1016 12:52:00.739075 30362 replica.cpp:666] Replica learned APPEND action
>> at position 1
>> I1016 12:52:00.740181 30368 registrar.cpp:486] Successfully updated the
>> 'registry' in 61.030144ms
>> I1016 12:52:00.740370 30368 registrar.cpp:372] Successfully recovered
>> registrar
>> I1016 12:52:00.740471 30370 log.cpp:704] Attempting to truncate the log to
>> 1
>> I1016 12:52:00.740772 30355 coordinator.cpp:341] Coordinator attempting to
>> write TRUNCATE action at position 2
>> I1016 12:52:00.740779 30359 master.cpp:1419] Recovered 0 slaves from the
>> Registry (137B) ; allowing 10mins for slaves to re-register
>> I1016 12:52:00.741694 30362 replica.cpp:512] Replica received write
>> request for position 2 from (10385)@172.17.7.238:34368
>> I1016 12:52:00.772438 30362 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 30.694099ms
>> I1016 12:52:00.772481 30362 replica.cpp:681] Persisted action at 2
>> I1016 12:52:00.773205 30363 replica.cpp:660] Replica received learned
>> notice for position 2 from @0.0.0.0:0
>> I1016 12:52:00.801530 30363 leveldb.cpp:343] Persisting action (18 bytes)
>> to leveldb took 28.219221ms
>> I1016 12:52:00.801620 30363 leveldb.cpp:401] Deleting ~1 keys from leveldb
>> took 43203ns
>> I1016 12:52:00.801646 30363 replica.cpp:681] Persisted action at 2
>> I1016 12:52:00.801671 30363 replica.cpp:666] Replica learned TRUNCATE
>> action at position 2
>> I1016 12:52:00.813771 30363 process.cpp:3078] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I1016 12:52:00.814069 30363 http.cpp:338] HTTP POST for
>> /master/api/v1/scheduler from 172.17.7.238:53336
>> I1016 12:52:00.814436 30363 master.cpp:1871] Received subscription request
>> for HTTP framework 'default'
>> I1016 12:52:00.814508 30363 master.cpp:1648] Authorizing framework
>> principal 'test-principal' to receive offers for role '*'
>> I1016 12:52:00.814810 30363 master.cpp:1963] Subscribing framework
>> 'default' with checkpointing disabled and capabilities [ ]
>> I1016 12:52:00.815225 30365 hierarchical.cpp:185] Added framework
>> 7c9cdcc3-f9f6-41c1-854a-2490caf8b2d3-0000
>> I1016 12:52:00.815289 30365 hierarchical.cpp:952] No resources available
>> to allocate!
>> I1016 12:52:00.815363 30369 master.hpp:1436] Sending heartbeat to
>> 7c9cdcc3-f9f6-41c1-854a-2490caf8b2d3-0000
>> I1016 12:52:00.815465 30365 hierarchical.cpp:1045] No inverse offers to
>> send out!
>> I1016 12:52:00.815501 30365 hierarchical.cpp:851] Performed allocation for
>> 0 slaves in 240750ns
>> I1016 12:52:00.816459 30355 master.cpp:925] Master terminating
>> I1016 12:52:00.816622 30363 hierarchical.cpp:220] Removed framework
>> 7c9cdcc3-f9f6-41c1-854a-2490caf8b2d3-0000
>> [ OK ] ContentType/SchedulerHttpApiTest.NoAcceptHeader/1 (485 ms)
>> [ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/0
>> Using temporary directory
>> '/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_0_Uq0Qy8'
>> I1016 12:52:00.894842 30336 leveldb.cpp:176] Opened db in 73.380078ms
>> I1016 12:52:00.934165 30336 leveldb.cpp:183] Compacted db in 39.279654ms
>> I1016 12:52:00.934229 30336 leveldb.cpp:198] Created db iterator in 17676ns
>> I1016 12:52:00.934249 30336 leveldb.cpp:204] Seeked to beginning of db in
>> 1962ns
>> I1016 12:52:00.934262 30336 leveldb.cpp:273] Iterated through 0 keys in
>> the db in 372ns
>> I1016 12:52:00.934303 30336 replica.cpp:746] Replica recovered with log
>> positions 0 -> 0 with 1 holes and 0 unlearned
>> I1016 12:52:00.934860 30363 recover.cpp:449] Starting replica recovery
>> I1016 12:52:00.935374 30363 recover.cpp:475] Replica is in EMPTY status
>> I1016 12:52:00.937597 30363 master.cpp:376] Master
>> e79b718d-eda1-42a8-b953-9f126a85f79e (635f798fc895) started on
>> 172.17.7.238:34368
>> I1016 12:52:00.937623 30363 master.cpp:378] Flags at startup: --acls=""
>> --allocation_interval="1secs" --allocator="HierarchicalDRF"
>> --authenticate="false" --authenticate_slaves="true"
>> --authenticators="crammd5" --authorizers="local"
>> --credentials="/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_0_Uq0Qy8/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.26.0/_inst/share/mesos/webui"
>> --work_dir="/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_0_Uq0Qy8/master"
>> --zk_session_timeout="10secs"
>> I1016 12:52:00.937872 30363 master.cpp:425] Master allowing
>> unauthenticated frameworks to register
>> I1016 12:52:00.937883 30363 master.cpp:428] Master only allowing
>> authenticated slaves to register
>> I1016 12:52:00.937890 30363 credentials.hpp:37] Loading credentials for
>> authentication from
>> '/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_0_Uq0Qy8/credentials'
>> I1016 12:52:00.937937 30364 replica.cpp:642] Replica in EMPTY status
>> received a broadcasted recover request from (10389)@172.17.7.238:34368
>> I1016 12:52:00.938127 30363 master.cpp:467] Using default 'crammd5'
>> authenticator
>> I1016 12:52:00.938230 30363 master.cpp:504] Authorization enabled
>> I1016 12:52:00.938274 30359 recover.cpp:195] Received a recover response
>> from a replica in EMPTY status
>> I1016 12:52:00.938429 30357 whitelist_watcher.cpp:79] No whitelist given
>> I1016 12:52:00.938454 30365 hierarchical.cpp:140] Initialized hierarchical
>> allocator process
>> I1016 12:52:00.938740 30361 recover.cpp:566] Updating replica status to
>> STARTING
>> I1016 12:52:00.939926 30366 master.cpp:1609] The newly elected leader is
>> master@172.17.7.238:34368 with id e79b718d-eda1-42a8-b953-9f126a85f79e
>> I1016 12:52:00.939980 30366 master.cpp:1622] Elected as the leading master!
>> I1016 12:52:00.939999 30366 master.cpp:1382] Recovering from registrar
>> I1016 12:52:00.940176 30362 registrar.cpp:309] Recovering registrar
>> I1016 12:52:00.967425 30359 leveldb.cpp:306] Persisting metadata (8 bytes)
>> to leveldb took 28.54865ms
>> I1016 12:52:00.967505 30359 replica.cpp:323] Persisted replica status to
>> STARTING
>> I1016 12:52:00.967840 30355 recover.cpp:475] Replica is in STARTING status
>> I1016 12:52:00.968999 30359 replica.cpp:642] Replica in STARTING status
>> received a broadcasted recover request from (10390)@172.17.7.238:34368
>> I1016 12:52:00.969334 30356 recover.cpp:195] Received a recover response
>> from a replica in STARTING status
>> I1016 12:52:00.969738 30363 recover.cpp:566] Updating replica status to
>> VOTING
>> I1016 12:52:00.995200 30370 leveldb.cpp:306] Persisting metadata (8 bytes)
>> to leveldb took 25.262131ms
>> I1016 12:52:00.995240 30370 replica.cpp:323] Persisted replica status to
>> VOTING
>> I1016 12:52:00.995375 30360 recover.cpp:580] Successfully joined the Paxos
>> group
>> I1016 12:52:00.995610 30360 recover.cpp:464] Recover process terminated
>> I1016 12:52:00.996094 30361 log.cpp:661] Attempting to start the writer
>> I1016 12:52:00.997359 30369 replica.cpp:478] Replica received implicit
>> promise request from (10391)@172.17.7.238:34368 with proposal 1
>> I1016 12:52:01.020423 30369 leveldb.cpp:306] Persisting metadata (8 bytes)
>> to leveldb took 23.023526ms
>> I1016 12:52:01.020469 30369 replica.cpp:345] Persisted promised to 1
>> I1016 12:52:01.021204 30367 coordinator.cpp:231] Coordinator attemping to
>> fill missing position
>> I1016 12:52:01.022456 30357 replica.cpp:378] Replica received explicit
>> promise request from (10392)@172.17.7.238:34368 for position 0 with
>> proposal 2
>> I1016 12:52:01.045469 30357 leveldb.cpp:343] Persisting action (8 bytes)
>> to leveldb took 22.969365ms
>> I1016 12:52:01.045516 30357 replica.cpp:681] Persisted action at 0
>> I1016 12:52:01.046861 30363 replica.cpp:512] Replica received write
>> request for position 0 from (10393)@172.17.7.238:34368
>> I1016 12:52:01.046929 30363 leveldb.cpp:438] Reading position from leveldb
>> took 30411ns
>> I1016 12:52:01.070576 30363 leveldb.cpp:343] Persisting action (14 bytes)
>> to leveldb took 23.576457ms
>> I1016 12:52:01.070621 30363 replica.cpp:681] Persisted action at 0
>> I1016 12:52:01.071305 30356 replica.cpp:660] Replica received learned
>> notice for position 0 from @0.0.0.0:0
>> I1016 12:52:01.095710 30356 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 24.363385ms
>> I1016 12:52:01.095760 30356 replica.cpp:681] Persisted action at 0
>> I1016 12:52:01.095798 30356 replica.cpp:666] Replica learned NOP action at
>> position 0
>> I1016 12:52:01.096567 30356 log.cpp:677] Writer started with ending
>> position 0
>> I1016 12:52:01.097769 30365 leveldb.cpp:438] Reading position from leveldb
>> took 31543ns
>> I1016 12:52:01.098783 30360 registrar.cpp:342] Successfully fetched the
>> registry (0B) in 158.563072ms
>> I1016 12:52:01.098929 30360 registrar.cpp:441] Applied 1 operations in
>> 40505ns; attempting to update the 'registry'
>> I1016 12:52:01.099859 30364 log.cpp:685] Attempting to append 176 bytes to
>> the log
>> I1016 12:52:01.100019 30369 coordinator.cpp:341] Coordinator attempting to
>> write APPEND action at position 1
>> I1016 12:52:01.100810 30364 replica.cpp:512] Replica received write
>> request for position 1 from (10394)@172.17.7.238:34368
>> I1016 12:52:01.126477 30364 leveldb.cpp:343] Persisting action (195 bytes)
>> to leveldb took 25.623082ms
>> I1016 12:52:01.126521 30364 replica.cpp:681] Persisted action at 1
>> I1016 12:52:01.127246 30364 replica.cpp:660] Replica received learned
>> notice for position 1 from @0.0.0.0:0
>> I1016 12:52:01.151579 30364 leveldb.cpp:343] Persisting action (197
>> bytes) to leveldb took 24.292776ms
>> I1016 12:52:01.151623 30364 replica.cpp:681] Persisted action at 1
>> I1016 12:52:01.151660 30364 replica.cpp:666] Replica learned APPEND action
>> at position 1
>> I1016 12:52:01.152915 30356 registrar.cpp:486] Successfully updated the
>> 'registry' in 53.919232ms
>> I1016 12:52:01.153110 30356 registrar.cpp:372] Successfully recovered
>> registrar
>> I1016 12:52:01.153187 30367 log.cpp:704] Attempting to truncate the log to
>> 1
>> I1016 12:52:01.153331 30361 coordinator.cpp:341] Coordinator attempting to
>> write TRUNCATE action at position 2
>> I1016 12:52:01.153528 30366 master.cpp:1419] Recovered 0 slaves from the
>> Registry (137B) ; allowing 10mins for slaves to re-register
>> I1016 12:52:01.154300 30360 replica.cpp:512] Replica received write
>> request for position 2 from (10395)@172.17.7.238:34368
>> I1016 12:52:01.179363 30360 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 25.023288ms
>> I1016 12:52:01.179401 30360 replica.cpp:681] Persisted action at 2
>> I1016 12:52:01.180150 30364 replica.cpp:660] Replica received learned
>> notice for position 2 from @0.0.0.0:0
>> I1016 12:52:01.206841 30364 leveldb.cpp:343] Persisting action (18 bytes)
>> to leveldb took 26.650847ms
>> I1016 12:52:01.206930 30364 leveldb.cpp:401] Deleting ~1 keys from leveldb
>> took 43353ns
>> I1016 12:52:01.206954 30364 replica.cpp:681] Persisted action at 2
>> I1016 12:52:01.207007 30364 replica.cpp:666] Replica learned TRUNCATE
>> action at position 2
>> I1016 12:52:01.216505 30368 process.cpp:3078] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I1016 12:52:01.217017 30368 http.cpp:338] HTTP POST for
>> /master/api/v1/scheduler from 172.17.7.238:53337
>> I1016 12:52:01.217223 30368 master.cpp:1871] Received subscription request
>> for HTTP framework 'default'
>> I1016 12:52:01.217314 30368 master.cpp:1648] Authorizing framework
>> principal 'test-principal' to receive offers for role '*'
>> I1016 12:52:01.217639 30368 master.cpp:1963] Subscribing framework
>> 'default' with checkpointing disabled and capabilities [ ]
>> I1016 12:52:01.218047 30367 hierarchical.cpp:185] Added framework
>> e79b718d-eda1-42a8-b953-9f126a85f79e-0000
>> I1016 12:52:01.218111 30367 hierarchical.cpp:952] No resources available
>> to allocate!
>> I1016 12:52:01.218166 30367 hierarchical.cpp:1045] No inverse offers to
>> send out!
>> I1016 12:52:01.218200 30368 master.hpp:1436] Sending heartbeat to
>> e79b718d-eda1-42a8-b953-9f126a85f79e-0000
>> I1016 12:52:01.218205 30367 hierarchical.cpp:851] Performed allocation for
>> 0 slaves in 126862ns
>> I1016 12:52:01.219396 30359 master.cpp:925] Master terminating
>> I1016 12:52:01.219599 30365 hierarchical.cpp:220] Removed framework
>> e79b718d-eda1-42a8-b953-9f126a85f79e-0000
>> [ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/0 (405 ms)
>> [ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/1
>> Using temporary directory
>> '/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_1_W7CItq'
>> I1016 12:52:01.308313 30336 leveldb.cpp:176] Opened db in 81.425897ms
>> I1016 12:52:01.333714 30336 leveldb.cpp:183] Compacted db in 25.358761ms
>> I1016 12:52:01.333791 30336 leveldb.cpp:198] Created db iterator in 20812ns
>> I1016 12:52:01.333833 30336 leveldb.cpp:204] Seeked to beginning of db in
>> 2435ns
>> I1016 12:52:01.333858 30336 leveldb.cpp:273] Iterated through 0 keys in
>> the db in 540ns
>> I1016 12:52:01.333914 30336 replica.cpp:746] Replica recovered with log
>> positions 0 -> 0 with 1 holes and 0 unlearned
>> I1016 12:52:01.334406 30368 recover.cpp:449] Starting replica recovery
>> I1016 12:52:01.334823 30368 recover.cpp:475] Replica is in EMPTY status
>> I1016 12:52:01.335772 30367 replica.cpp:642] Replica in EMPTY status
>> received a broadcasted recover request from (10399)@172.17.7.238:34368
>> I1016 12:52:01.336227 30358 recover.cpp:195] Received a recover response
>> from a replica in EMPTY status
>> I1016 12:52:01.336587 30355 recover.cpp:566] Updating replica status to
>> STARTING
>> I1016 12:52:01.337579 30363 master.cpp:376] Master
>> a66067e9-12ba-49f2-a980-a693a2e51efe (635f798fc895) started on
>> 172.17.7.238:34368
>> I1016 12:52:01.337604 30363 master.cpp:378] Flags at startup: --acls=""
>> --allocation_interval="1secs" --allocator="HierarchicalDRF"
>> --authenticate="false" --authenticate_slaves="true"
>> --authenticators="crammd5" --authorizers="local"
>> --credentials="/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_1_W7CItq/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.26.0/_inst/share/mesos/webui"
>> --work_dir="/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_1_W7CItq/master"
>> --zk_session_timeout="10secs"
>> I1016 12:52:01.337826 30363 master.cpp:425] Master allowing
>> unauthenticated frameworks to register
>> I1016 12:52:01.337836 30363 master.cpp:428] Master only allowing
>> authenticated slaves to register
>> I1016 12:52:01.337842 30363 credentials.hpp:37] Loading credentials for
>> authentication from
>> '/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_1_W7CItq/credentials'
>> I1016 12:52:01.338181 30363 master.cpp:467] Using default 'crammd5'
>> authenticator
>> I1016 12:52:01.338289 30363 master.cpp:504] Authorization enabled
>> I1016 12:52:01.338502 30369 whitelist_watcher.cpp:79] No whitelist given
>> I1016 12:52:01.338515 30370 hierarchical.cpp:140] Initialized hierarchical
>> allocator process
>> I1016 12:52:01.339929 30355 master.cpp:1609] The newly elected leader is
>> master@172.17.7.238:34368 with id a66067e9-12ba-49f2-a980-a693a2e51efe
>> I1016 12:52:01.339989 30355 master.cpp:1622] Elected as the leading master!
>> I1016 12:52:01.340015 30355 master.cpp:1382] Recovering from registrar
>> I1016 12:52:01.340167 30367 registrar.cpp:309] Recovering registrar
>> I1016 12:52:01.371206 30359 leveldb.cpp:306] Persisting metadata (8 bytes)
>> to leveldb took 34.484768ms
>> I1016 12:52:01.371253 30359 replica.cpp:323] Persisted replica status to
>> STARTING
>> I1016 12:52:01.371484 30362 recover.cpp:475] Replica is in STARTING status
>> I1016 12:52:01.372367 30360 replica.cpp:642] Replica in STARTING status
>> received a broadcasted recover request from (10400)@172.17.7.238:34368
>> I1016 12:52:01.372783 30359 recover.cpp:195] Received a recover response
>> from a replica in STARTING status
>> I1016 12:52:01.373322 30358 recover.cpp:566] Updating replica status to
>> VOTING
>> I1016 12:52:01.404683 30357 leveldb.cpp:306] Persisting metadata (8 bytes)
>> to leveldb took 31.168607ms
>> I1016 12:52:01.404712 30357 replica.cpp:323] Persisted replica status to
>> VOTING
>> I1016 12:52:01.404796 30368 recover.cpp:580] Successfully joined the Paxos
>> group
>> I1016 12:52:01.405045 30368 recover.cpp:464] Recover process terminated
>> I1016 12:52:01.405513 30357 log.cpp:661] Attempting to start the writer
>> I1016 12:52:01.406522 30355 replica.cpp:478] Replica received implicit
>> promise request from (10401)@172.17.7.238:34368 with proposal 1
>> I1016 12:52:01.429678 30355 leveldb.cpp:306] Persisting metadata (8 bytes)
>> to leveldb took 23.125862ms
>> I1016 12:52:01.429710 30355 replica.cpp:345] Persisted promised to 1
>> I1016 12:52:01.430950 30366 coordinator.cpp:231] Coordinator attemping to
>> fill missing position
>> I1016 12:52:01.432205 30362 replica.cpp:378] Replica received explicit
>> promise request from (10402)@172.17.7.238:34368 for position 0 with
>> proposal 2
>> I1016 12:52:01.479913 30362 leveldb.cpp:343] Persisting action (8 bytes)
>> to leveldb took 47.665816ms
>> I1016 12:52:01.479960 30362 replica.cpp:681] Persisted action at 0
>> I1016 12:52:01.481022 30367 replica.cpp:512] Replica received write
>> request for position 0 from (10403)@172.17.7.238:34368
>> I1016 12:52:01.481106 30367 leveldb.cpp:438] Reading position from leveldb
>> took 36484ns
>> I1016 12:52:01.513360 30367 leveldb.cpp:343] Persisting action (14 bytes)
>> to leveldb took 32.195389ms
>> I1016 12:52:01.513408 30367 replica.cpp:681] Persisted action at 0
>> I1016 12:52:01.514019 30369 replica.cpp:660] Replica received learned
>> notice for position 0 from @0.0.0.0:0
>> I1016 12:52:01.555217 30369 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 41.140656ms
>> I1016 12:52:01.555248 30369 replica.cpp:681] Persisted action at 0
>> I1016 12:52:01.555264 30369 replica.cpp:666] Replica learned NOP action at
>> position 0
>> I1016 12:52:01.555827 30361 log.cpp:677] Writer started with ending
>> position 0
>> I1016 12:52:01.556764 30358 leveldb.cpp:438] Reading position from leveldb
>> took 27918ns
>> I1016 12:52:01.557667 30358 registrar.cpp:342] Successfully fetched the
>> registry (0B) in 217.442816ms
>> I1016 12:52:01.557788 30358 registrar.cpp:441] Applied 1 operations in
>> 28902ns; attempting to update the 'registry'
>> I1016 12:52:01.558468 30366 log.cpp:685] Attempting to append 176 bytes to
>> the log
>> I1016 12:52:01.558593 30367 coordinator.cpp:341] Coordinator attempting to
>> write APPEND action at position 1
>> I1016 12:52:01.559384 30361 replica.cpp:512] Replica received write
>> request for position 1 from (10404)@172.17.7.238:34368
>> I1016 12:52:01.588752 30361 leveldb.cpp:343] Persisting action (195 bytes)
>> to leveldb took 29.32558ms
>> I1016 12:52:01.588803 30361 replica.cpp:681] Persisted action at 1
>> I1016 12:52:01.589679 30356 replica.cpp:660] Replica received learned
>> notice for position 1 from @0.0.0.0:0
>> I1016 12:52:01.622161 30356 leveldb.cpp:343] Persisting action (197 bytes)
>> to leveldb took 32.448705ms
>> I1016 12:52:01.622200 30356 replica.cpp:681] Persisted action at 1
>> I1016 12:52:01.622223 30356 replica.cpp:666] Replica learned APPEND action
>> at position 1
>> I1016 12:52:01.623206 30369 registrar.cpp:486] Successfully updated the
>> 'registry' in 65.35808ms
>> I1016 12:52:01.623343 30369 registrar.cpp:372] Successfully recovered
>> registrar
>> I1016 12:52:01.623409 30355 log.cpp:704] Attempting to truncate the log to
>> 1
>> I1016 12:52:01.623535 30360 coordinator.cpp:341] Coordinator attempting to
>> write TRUNCATE action at position 2
>> I1016 12:52:01.623847 30365 master.cpp:1419] Recovered 0 slaves from the
>> Registry (137B) ; allowing 10mins for slaves to re-register
>> I1016 12:52:01.624238 30363 replica.cpp:512] Replica received write
>> request for position 2 from (10405)@172.17.7.238:34368
>> I1016 12:52:01.669742 30363 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 45.468175ms
>> I1016 12:52:01.669782 30363 replica.cpp:681] Persisted action at 2
>> I1016 12:52:01.670445 30361 replica.cpp:660] Replica received learned
>> notice for position 2 from @0.0.0.0:0
>> I1016 12:52:01.714057 30361 leveldb.cpp:343] Persisting action (18 bytes)
>> to leveldb took 43.58038ms
>> I1016 12:52:01.714134 30361 leveldb.cpp:401] Deleting ~1 keys from leveldb
>> took 38012ns
>> I1016 12:52:01.714157 30361 replica.cpp:681] Persisted action at 2
>> I1016 12:52:01.714181 30361 replica.cpp:666] Replica learned TRUNCATE
>> action at position 2
>> I1016 12:52:01.716847 30362 process.cpp:3078] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I1016 12:52:01.717186 30362 http.cpp:338] HTTP POST for
>> /master/api/v1/scheduler from 172.17.7.238:53338
>> I1016 12:52:01.717629 30362 master.cpp:1871] Received subscription request
>> for HTTP framework 'default'
>> I1016 12:52:01.717706 30362 master.cpp:1648] Authorizing framework
>> principal 'test-principal' to receive offers for role '*'
>> I1016 12:52:01.717995 30358 master.cpp:1963] Subscribing framework
>> 'default' with checkpointing disabled and capabilities [ ]
>> I1016 12:52:01.718330 30370 hierarchical.cpp:185] Added framework
>> a66067e9-12ba-49f2-a980-a693a2e51efe-0000
>> I1016 12:52:01.718384 30370 hierarchical.cpp:952] No resources available
>> to allocate!
>> I1016 12:52:01.718457 30358 master.hpp:1436] Sending heartbeat to
>> a66067e9-12ba-49f2-a980-a693a2e51efe-0000
>> I1016 12:52:01.718641 30370 hierarchical.cpp:1045] No inverse offers to
>> send out!
>> I1016 12:52:01.718675 30370 hierarchical.cpp:851] Performed allocation for
>> 0 slaves in 321808ns
>> I1016 12:52:01.719614 30365 master.cpp:925] Master terminating
>> I1016 12:52:01.719816 30359 hierarchical.cpp:220] Removed framework
>> a66067e9-12ba-49f2-a980-a693a2e51efe-0000
>> [ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/1 (499 ms)
>> [----------] 18 tests from ContentType/SchedulerHttpApiTest (9466 ms total)
>>
>> [----------] Global test environment tear-down
>> [==========] 812 tests from 111 test cases ran. (629715 ms total)
>> [ PASSED ] 811 tests.
>> [ FAILED ] 1 test, listed below:
>> [ FAILED ] ContentType/SchedulerTest.ShutdownExecutor/0, where
>> GetParam() = application/x-protobuf
>>
>> 1 FAILED TEST
>> YOU HAVE 7 DISABLED TESTS
>>
>> make[4]: *** [check-local] Error 1
>> make[4]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
>> make[3]: *** [check-am] Error 2
>> make[3]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
>> make[2]: *** [check] Error 2
>> make[2]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
>> make[1]: *** [check-recursive] Error 1
>> make[1]: Leaving directory `/mesos/mesos-0.26.0/_build'
>> make: *** [distcheck] Error 1
>> + docker rmi mesos-1444997822-10222
>> Untagged: mesos-1444997822-10222:latest
>> Deleted: f8ebde8899c9ed32d1e0bc2813dc91054ba31bbb0a12c7ad2bdc33c30b7059ee
>> Deleted: ee3e45c151280a0c8941be18527050f3d2fd64061f4bf4ed845430c1c592584e
>> Deleted: a0e8d846e39bd0e328a1178b5ab32ed9149b0c48d6b67c3fb986076784e9acf4
>> Deleted: 6a3ce441429b6b782b8989cccac96112e5f8274cc63093c6e123d3c467d20842
>> Deleted: 8db51f93ed90993531d62b8bafdd42102e4d50e55fff8eb82af51c07c9575826
>> Deleted: f70ec6f2726ff97e37ae5c47b6f78680ff3d9a6955a4bb35d165c425fd32b676
>> Deleted: 5251309379db5c66f5cb9cb40f2a214377e66f97c0fa7e1d2f6b7a3348792931
>> Deleted: cac21f7184d78f63456a6f56dc8466070f9fe545c10bb4cd082a26aa6955d22b
>> Deleted: efe3bbdde1a2bba2a5160be477e28c08b5d928747e18a3b94846e4d07b5f6e5a
>> Deleted: e115753ad5c3a48f3255e12c33d1159f2534f8b71043c92356f915444dd558bf
>> Deleted: 9de8af6a8b98623dabc1a13e4228451273f996b3f219665729d8db0fc96e3707
>> Deleted: 89464637c43acc62838bfaf2368584d161cf58a1557c604607184a124e66f7c4
>> Build step 'Execute shell' marked build as failure
>>
Re: Build failed in Jenkins: Mesos » gcc,--verbose,centos:7,docker||Hadoop #942
Posted by Vinod Kone <vi...@apache.org>.
@anand, known issue?
On Fri, Oct 16, 2015 at 5:52 AM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=centos%3A7,label_exp=docker%7C%7CHadoop/942/changes
> >
>
> Changes:
>
> [bernd] Added code that appends the fetcher log to the agent log upon
> fetcher
>
> [bernd] Added additional diagnostic output when a fetcher cache test fails.
>
> [tnachen] Added serialization of Docker Image Spec as protobuf.
>
> [tnachen] Added validation of Docker Image Manifests.
>
> ------------------------------------------
> [...truncated 136512 lines...]
> I1016 12:52:00.709342 30362 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 28.154615ms
> I1016 12:52:00.709380 30362 replica.cpp:681] Persisted action at 1
> I1016 12:52:00.709955 30362 replica.cpp:660] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I1016 12:52:00.738996 30362 leveldb.cpp:343] Persisting action (197 bytes)
> to leveldb took 28.989067ms
> I1016 12:52:00.739039 30362 replica.cpp:681] Persisted action at 1
> I1016 12:52:00.739075 30362 replica.cpp:666] Replica learned APPEND action
> at position 1
> I1016 12:52:00.740181 30368 registrar.cpp:486] Successfully updated the
> 'registry' in 61.030144ms
> I1016 12:52:00.740370 30368 registrar.cpp:372] Successfully recovered
> registrar
> I1016 12:52:00.740471 30370 log.cpp:704] Attempting to truncate the log to
> 1
> I1016 12:52:00.740772 30355 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I1016 12:52:00.740779 30359 master.cpp:1419] Recovered 0 slaves from the
> Registry (137B) ; allowing 10mins for slaves to re-register
> I1016 12:52:00.741694 30362 replica.cpp:512] Replica received write
> request for position 2 from (10385)@172.17.7.238:34368
> I1016 12:52:00.772438 30362 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 30.694099ms
> I1016 12:52:00.772481 30362 replica.cpp:681] Persisted action at 2
> I1016 12:52:00.773205 30363 replica.cpp:660] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I1016 12:52:00.801530 30363 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 28.219221ms
> I1016 12:52:00.801620 30363 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 43203ns
> I1016 12:52:00.801646 30363 replica.cpp:681] Persisted action at 2
> I1016 12:52:00.801671 30363 replica.cpp:666] Replica learned TRUNCATE
> action at position 2
> I1016 12:52:00.813771 30363 process.cpp:3078] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1016 12:52:00.814069 30363 http.cpp:338] HTTP POST for
> /master/api/v1/scheduler from 172.17.7.238:53336
> I1016 12:52:00.814436 30363 master.cpp:1871] Received subscription request
> for HTTP framework 'default'
> I1016 12:52:00.814508 30363 master.cpp:1648] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I1016 12:52:00.814810 30363 master.cpp:1963] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I1016 12:52:00.815225 30365 hierarchical.cpp:185] Added framework
> 7c9cdcc3-f9f6-41c1-854a-2490caf8b2d3-0000
> I1016 12:52:00.815289 30365 hierarchical.cpp:952] No resources available
> to allocate!
> I1016 12:52:00.815363 30369 master.hpp:1436] Sending heartbeat to
> 7c9cdcc3-f9f6-41c1-854a-2490caf8b2d3-0000
> I1016 12:52:00.815465 30365 hierarchical.cpp:1045] No inverse offers to
> send out!
> I1016 12:52:00.815501 30365 hierarchical.cpp:851] Performed allocation for
> 0 slaves in 240750ns
> I1016 12:52:00.816459 30355 master.cpp:925] Master terminating
> I1016 12:52:00.816622 30363 hierarchical.cpp:220] Removed framework
> 7c9cdcc3-f9f6-41c1-854a-2490caf8b2d3-0000
> [ OK ] ContentType/SchedulerHttpApiTest.NoAcceptHeader/1 (485 ms)
> [ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/0
> Using temporary directory
> '/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_0_Uq0Qy8'
> I1016 12:52:00.894842 30336 leveldb.cpp:176] Opened db in 73.380078ms
> I1016 12:52:00.934165 30336 leveldb.cpp:183] Compacted db in 39.279654ms
> I1016 12:52:00.934229 30336 leveldb.cpp:198] Created db iterator in 17676ns
> I1016 12:52:00.934249 30336 leveldb.cpp:204] Seeked to beginning of db in
> 1962ns
> I1016 12:52:00.934262 30336 leveldb.cpp:273] Iterated through 0 keys in
> the db in 372ns
> I1016 12:52:00.934303 30336 replica.cpp:746] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I1016 12:52:00.934860 30363 recover.cpp:449] Starting replica recovery
> I1016 12:52:00.935374 30363 recover.cpp:475] Replica is in EMPTY status
> I1016 12:52:00.937597 30363 master.cpp:376] Master
> e79b718d-eda1-42a8-b953-9f126a85f79e (635f798fc895) started on
> 172.17.7.238:34368
> I1016 12:52:00.937623 30363 master.cpp:378] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_0_Uq0Qy8/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.26.0/_inst/share/mesos/webui"
> --work_dir="/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_0_Uq0Qy8/master"
> --zk_session_timeout="10secs"
> I1016 12:52:00.937872 30363 master.cpp:425] Master allowing
> unauthenticated frameworks to register
> I1016 12:52:00.937883 30363 master.cpp:428] Master only allowing
> authenticated slaves to register
> I1016 12:52:00.937890 30363 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_0_Uq0Qy8/credentials'
> I1016 12:52:00.937937 30364 replica.cpp:642] Replica in EMPTY status
> received a broadcasted recover request from (10389)@172.17.7.238:34368
> I1016 12:52:00.938127 30363 master.cpp:467] Using default 'crammd5'
> authenticator
> I1016 12:52:00.938230 30363 master.cpp:504] Authorization enabled
> I1016 12:52:00.938274 30359 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I1016 12:52:00.938429 30357 whitelist_watcher.cpp:79] No whitelist given
> I1016 12:52:00.938454 30365 hierarchical.cpp:140] Initialized hierarchical
> allocator process
> I1016 12:52:00.938740 30361 recover.cpp:566] Updating replica status to
> STARTING
> I1016 12:52:00.939926 30366 master.cpp:1609] The newly elected leader is
> master@172.17.7.238:34368 with id e79b718d-eda1-42a8-b953-9f126a85f79e
> I1016 12:52:00.939980 30366 master.cpp:1622] Elected as the leading master!
> I1016 12:52:00.939999 30366 master.cpp:1382] Recovering from registrar
> I1016 12:52:00.940176 30362 registrar.cpp:309] Recovering registrar
> I1016 12:52:00.967425 30359 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 28.54865ms
> I1016 12:52:00.967505 30359 replica.cpp:323] Persisted replica status to
> STARTING
> I1016 12:52:00.967840 30355 recover.cpp:475] Replica is in STARTING status
> I1016 12:52:00.968999 30359 replica.cpp:642] Replica in STARTING status
> received a broadcasted recover request from (10390)@172.17.7.238:34368
> I1016 12:52:00.969334 30356 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I1016 12:52:00.969738 30363 recover.cpp:566] Updating replica status to
> VOTING
> I1016 12:52:00.995200 30370 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 25.262131ms
> I1016 12:52:00.995240 30370 replica.cpp:323] Persisted replica status to
> VOTING
> I1016 12:52:00.995375 30360 recover.cpp:580] Successfully joined the Paxos
> group
> I1016 12:52:00.995610 30360 recover.cpp:464] Recover process terminated
> I1016 12:52:00.996094 30361 log.cpp:661] Attempting to start the writer
> I1016 12:52:00.997359 30369 replica.cpp:478] Replica received implicit
> promise request from (10391)@172.17.7.238:34368 with proposal 1
> I1016 12:52:01.020423 30369 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 23.023526ms
> I1016 12:52:01.020469 30369 replica.cpp:345] Persisted promised to 1
> I1016 12:52:01.021204 30367 coordinator.cpp:231] Coordinator attemping to
> fill missing position
> I1016 12:52:01.022456 30357 replica.cpp:378] Replica received explicit
> promise request from (10392)@172.17.7.238:34368 for position 0 with
> proposal 2
> I1016 12:52:01.045469 30357 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 22.969365ms
> I1016 12:52:01.045516 30357 replica.cpp:681] Persisted action at 0
> I1016 12:52:01.046861 30363 replica.cpp:512] Replica received write
> request for position 0 from (10393)@172.17.7.238:34368
> I1016 12:52:01.046929 30363 leveldb.cpp:438] Reading position from leveldb
> took 30411ns
> I1016 12:52:01.070576 30363 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 23.576457ms
> I1016 12:52:01.070621 30363 replica.cpp:681] Persisted action at 0
> I1016 12:52:01.071305 30356 replica.cpp:660] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I1016 12:52:01.095710 30356 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 24.363385ms
> I1016 12:52:01.095760 30356 replica.cpp:681] Persisted action at 0
> I1016 12:52:01.095798 30356 replica.cpp:666] Replica learned NOP action at
> position 0
> I1016 12:52:01.096567 30356 log.cpp:677] Writer started with ending
> position 0
> I1016 12:52:01.097769 30365 leveldb.cpp:438] Reading position from leveldb
> took 31543ns
> I1016 12:52:01.098783 30360 registrar.cpp:342] Successfully fetched the
> registry (0B) in 158.563072ms
> I1016 12:52:01.098929 30360 registrar.cpp:441] Applied 1 operations in
> 40505ns; attempting to update the 'registry'
> I1016 12:52:01.099859 30364 log.cpp:685] Attempting to append 176 bytes to
> the log
> I1016 12:52:01.100019 30369 coordinator.cpp:341] Coordinator attempting to
> write APPEND action at position 1
> I1016 12:52:01.100810 30364 replica.cpp:512] Replica received write
> request for position 1 from (10394)@172.17.7.238:34368
> I1016 12:52:01.126477 30364 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 25.623082ms
> I1016 12:52:01.126521 30364 replica.cpp:681] Persisted action at 1
> I1016 12:52:01.127246 30364 replica.cpp:660] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I1016 12:52:01.151579 30364 leveldb.cpp:343] Persisting action (197
> bytes) to leveldb took 24.292776ms
> I1016 12:52:01.151623 30364 replica.cpp:681] Persisted action at 1
> I1016 12:52:01.151660 30364 replica.cpp:666] Replica learned APPEND action
> at position 1
> I1016 12:52:01.152915 30356 registrar.cpp:486] Successfully updated the
> 'registry' in 53.919232ms
> I1016 12:52:01.153110 30356 registrar.cpp:372] Successfully recovered
> registrar
> I1016 12:52:01.153187 30367 log.cpp:704] Attempting to truncate the log to
> 1
> I1016 12:52:01.153331 30361 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I1016 12:52:01.153528 30366 master.cpp:1419] Recovered 0 slaves from the
> Registry (137B) ; allowing 10mins for slaves to re-register
> I1016 12:52:01.154300 30360 replica.cpp:512] Replica received write
> request for position 2 from (10395)@172.17.7.238:34368
> I1016 12:52:01.179363 30360 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 25.023288ms
> I1016 12:52:01.179401 30360 replica.cpp:681] Persisted action at 2
> I1016 12:52:01.180150 30364 replica.cpp:660] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I1016 12:52:01.206841 30364 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 26.650847ms
> I1016 12:52:01.206930 30364 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 43353ns
> I1016 12:52:01.206954 30364 replica.cpp:681] Persisted action at 2
> I1016 12:52:01.207007 30364 replica.cpp:666] Replica learned TRUNCATE
> action at position 2
> I1016 12:52:01.216505 30368 process.cpp:3078] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1016 12:52:01.217017 30368 http.cpp:338] HTTP POST for
> /master/api/v1/scheduler from 172.17.7.238:53337
> I1016 12:52:01.217223 30368 master.cpp:1871] Received subscription request
> for HTTP framework 'default'
> I1016 12:52:01.217314 30368 master.cpp:1648] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I1016 12:52:01.217639 30368 master.cpp:1963] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I1016 12:52:01.218047 30367 hierarchical.cpp:185] Added framework
> e79b718d-eda1-42a8-b953-9f126a85f79e-0000
> I1016 12:52:01.218111 30367 hierarchical.cpp:952] No resources available
> to allocate!
> I1016 12:52:01.218166 30367 hierarchical.cpp:1045] No inverse offers to
> send out!
> I1016 12:52:01.218200 30368 master.hpp:1436] Sending heartbeat to
> e79b718d-eda1-42a8-b953-9f126a85f79e-0000
> I1016 12:52:01.218205 30367 hierarchical.cpp:851] Performed allocation for
> 0 slaves in 126862ns
> I1016 12:52:01.219396 30359 master.cpp:925] Master terminating
> I1016 12:52:01.219599 30365 hierarchical.cpp:220] Removed framework
> e79b718d-eda1-42a8-b953-9f126a85f79e-0000
> [ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/0 (405 ms)
> [ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/1
> Using temporary directory
> '/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_1_W7CItq'
> I1016 12:52:01.308313 30336 leveldb.cpp:176] Opened db in 81.425897ms
> I1016 12:52:01.333714 30336 leveldb.cpp:183] Compacted db in 25.358761ms
> I1016 12:52:01.333791 30336 leveldb.cpp:198] Created db iterator in 20812ns
> I1016 12:52:01.333833 30336 leveldb.cpp:204] Seeked to beginning of db in
> 2435ns
> I1016 12:52:01.333858 30336 leveldb.cpp:273] Iterated through 0 keys in
> the db in 540ns
> I1016 12:52:01.333914 30336 replica.cpp:746] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I1016 12:52:01.334406 30368 recover.cpp:449] Starting replica recovery
> I1016 12:52:01.334823 30368 recover.cpp:475] Replica is in EMPTY status
> I1016 12:52:01.335772 30367 replica.cpp:642] Replica in EMPTY status
> received a broadcasted recover request from (10399)@172.17.7.238:34368
> I1016 12:52:01.336227 30358 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I1016 12:52:01.336587 30355 recover.cpp:566] Updating replica status to
> STARTING
> I1016 12:52:01.337579 30363 master.cpp:376] Master
> a66067e9-12ba-49f2-a980-a693a2e51efe (635f798fc895) started on
> 172.17.7.238:34368
> I1016 12:52:01.337604 30363 master.cpp:378] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_1_W7CItq/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.26.0/_inst/share/mesos/webui"
> --work_dir="/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_1_W7CItq/master"
> --zk_session_timeout="10secs"
> I1016 12:52:01.337826 30363 master.cpp:425] Master allowing
> unauthenticated frameworks to register
> I1016 12:52:01.337836 30363 master.cpp:428] Master only allowing
> authenticated slaves to register
> I1016 12:52:01.337842 30363 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_SchedulerHttpApiTest_DefaultAccept_1_W7CItq/credentials'
> I1016 12:52:01.338181 30363 master.cpp:467] Using default 'crammd5'
> authenticator
> I1016 12:52:01.338289 30363 master.cpp:504] Authorization enabled
> I1016 12:52:01.338502 30369 whitelist_watcher.cpp:79] No whitelist given
> I1016 12:52:01.338515 30370 hierarchical.cpp:140] Initialized hierarchical
> allocator process
> I1016 12:52:01.339929 30355 master.cpp:1609] The newly elected leader is
> master@172.17.7.238:34368 with id a66067e9-12ba-49f2-a980-a693a2e51efe
> I1016 12:52:01.339989 30355 master.cpp:1622] Elected as the leading master!
> I1016 12:52:01.340015 30355 master.cpp:1382] Recovering from registrar
> I1016 12:52:01.340167 30367 registrar.cpp:309] Recovering registrar
> I1016 12:52:01.371206 30359 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 34.484768ms
> I1016 12:52:01.371253 30359 replica.cpp:323] Persisted replica status to
> STARTING
> I1016 12:52:01.371484 30362 recover.cpp:475] Replica is in STARTING status
> I1016 12:52:01.372367 30360 replica.cpp:642] Replica in STARTING status
> received a broadcasted recover request from (10400)@172.17.7.238:34368
> I1016 12:52:01.372783 30359 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I1016 12:52:01.373322 30358 recover.cpp:566] Updating replica status to
> VOTING
> I1016 12:52:01.404683 30357 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 31.168607ms
> I1016 12:52:01.404712 30357 replica.cpp:323] Persisted replica status to
> VOTING
> I1016 12:52:01.404796 30368 recover.cpp:580] Successfully joined the Paxos
> group
> I1016 12:52:01.405045 30368 recover.cpp:464] Recover process terminated
> I1016 12:52:01.405513 30357 log.cpp:661] Attempting to start the writer
> I1016 12:52:01.406522 30355 replica.cpp:478] Replica received implicit
> promise request from (10401)@172.17.7.238:34368 with proposal 1
> I1016 12:52:01.429678 30355 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 23.125862ms
> I1016 12:52:01.429710 30355 replica.cpp:345] Persisted promised to 1
> I1016 12:52:01.430950 30366 coordinator.cpp:231] Coordinator attemping to
> fill missing position
> I1016 12:52:01.432205 30362 replica.cpp:378] Replica received explicit
> promise request from (10402)@172.17.7.238:34368 for position 0 with
> proposal 2
> I1016 12:52:01.479913 30362 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 47.665816ms
> I1016 12:52:01.479960 30362 replica.cpp:681] Persisted action at 0
> I1016 12:52:01.481022 30367 replica.cpp:512] Replica received write
> request for position 0 from (10403)@172.17.7.238:34368
> I1016 12:52:01.481106 30367 leveldb.cpp:438] Reading position from leveldb
> took 36484ns
> I1016 12:52:01.513360 30367 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 32.195389ms
> I1016 12:52:01.513408 30367 replica.cpp:681] Persisted action at 0
> I1016 12:52:01.514019 30369 replica.cpp:660] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I1016 12:52:01.555217 30369 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 41.140656ms
> I1016 12:52:01.555248 30369 replica.cpp:681] Persisted action at 0
> I1016 12:52:01.555264 30369 replica.cpp:666] Replica learned NOP action at
> position 0
> I1016 12:52:01.555827 30361 log.cpp:677] Writer started with ending
> position 0
> I1016 12:52:01.556764 30358 leveldb.cpp:438] Reading position from leveldb
> took 27918ns
> I1016 12:52:01.557667 30358 registrar.cpp:342] Successfully fetched the
> registry (0B) in 217.442816ms
> I1016 12:52:01.557788 30358 registrar.cpp:441] Applied 1 operations in
> 28902ns; attempting to update the 'registry'
> I1016 12:52:01.558468 30366 log.cpp:685] Attempting to append 176 bytes to
> the log
> I1016 12:52:01.558593 30367 coordinator.cpp:341] Coordinator attempting to
> write APPEND action at position 1
> I1016 12:52:01.559384 30361 replica.cpp:512] Replica received write
> request for position 1 from (10404)@172.17.7.238:34368
> I1016 12:52:01.588752 30361 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 29.32558ms
> I1016 12:52:01.588803 30361 replica.cpp:681] Persisted action at 1
> I1016 12:52:01.589679 30356 replica.cpp:660] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I1016 12:52:01.622161 30356 leveldb.cpp:343] Persisting action (197 bytes)
> to leveldb took 32.448705ms
> I1016 12:52:01.622200 30356 replica.cpp:681] Persisted action at 1
> I1016 12:52:01.622223 30356 replica.cpp:666] Replica learned APPEND action
> at position 1
> I1016 12:52:01.623206 30369 registrar.cpp:486] Successfully updated the
> 'registry' in 65.35808ms
> I1016 12:52:01.623343 30369 registrar.cpp:372] Successfully recovered
> registrar
> I1016 12:52:01.623409 30355 log.cpp:704] Attempting to truncate the log to
> 1
> I1016 12:52:01.623535 30360 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I1016 12:52:01.623847 30365 master.cpp:1419] Recovered 0 slaves from the
> Registry (137B) ; allowing 10mins for slaves to re-register
> I1016 12:52:01.624238 30363 replica.cpp:512] Replica received write
> request for position 2 from (10405)@172.17.7.238:34368
> I1016 12:52:01.669742 30363 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 45.468175ms
> I1016 12:52:01.669782 30363 replica.cpp:681] Persisted action at 2
> I1016 12:52:01.670445 30361 replica.cpp:660] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I1016 12:52:01.714057 30361 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 43.58038ms
> I1016 12:52:01.714134 30361 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 38012ns
> I1016 12:52:01.714157 30361 replica.cpp:681] Persisted action at 2
> I1016 12:52:01.714181 30361 replica.cpp:666] Replica learned TRUNCATE
> action at position 2
> I1016 12:52:01.716847 30362 process.cpp:3078] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1016 12:52:01.717186 30362 http.cpp:338] HTTP POST for
> /master/api/v1/scheduler from 172.17.7.238:53338
> I1016 12:52:01.717629 30362 master.cpp:1871] Received subscription request
> for HTTP framework 'default'
> I1016 12:52:01.717706 30362 master.cpp:1648] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I1016 12:52:01.717995 30358 master.cpp:1963] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I1016 12:52:01.718330 30370 hierarchical.cpp:185] Added framework
> a66067e9-12ba-49f2-a980-a693a2e51efe-0000
> I1016 12:52:01.718384 30370 hierarchical.cpp:952] No resources available
> to allocate!
> I1016 12:52:01.718457 30358 master.hpp:1436] Sending heartbeat to
> a66067e9-12ba-49f2-a980-a693a2e51efe-0000
> I1016 12:52:01.718641 30370 hierarchical.cpp:1045] No inverse offers to
> send out!
> I1016 12:52:01.718675 30370 hierarchical.cpp:851] Performed allocation for
> 0 slaves in 321808ns
> I1016 12:52:01.719614 30365 master.cpp:925] Master terminating
> I1016 12:52:01.719816 30359 hierarchical.cpp:220] Removed framework
> a66067e9-12ba-49f2-a980-a693a2e51efe-0000
> [ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/1 (499 ms)
> [----------] 18 tests from ContentType/SchedulerHttpApiTest (9466 ms total)
>
> [----------] Global test environment tear-down
> [==========] 812 tests from 111 test cases ran. (629715 ms total)
> [ PASSED ] 811 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] ContentType/SchedulerTest.ShutdownExecutor/0, where
> GetParam() = application/x-protobuf
>
> 1 FAILED TEST
> YOU HAVE 7 DISABLED TESTS
>
> make[4]: *** [check-local] Error 1
> make[4]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory `/mesos/mesos-0.26.0/_build'
> make: *** [distcheck] Error 1
> + docker rmi mesos-1444997822-10222
> Untagged: mesos-1444997822-10222:latest
> Deleted: f8ebde8899c9ed32d1e0bc2813dc91054ba31bbb0a12c7ad2bdc33c30b7059ee
> Deleted: ee3e45c151280a0c8941be18527050f3d2fd64061f4bf4ed845430c1c592584e
> Deleted: a0e8d846e39bd0e328a1178b5ab32ed9149b0c48d6b67c3fb986076784e9acf4
> Deleted: 6a3ce441429b6b782b8989cccac96112e5f8274cc63093c6e123d3c467d20842
> Deleted: 8db51f93ed90993531d62b8bafdd42102e4d50e55fff8eb82af51c07c9575826
> Deleted: f70ec6f2726ff97e37ae5c47b6f78680ff3d9a6955a4bb35d165c425fd32b676
> Deleted: 5251309379db5c66f5cb9cb40f2a214377e66f97c0fa7e1d2f6b7a3348792931
> Deleted: cac21f7184d78f63456a6f56dc8466070f9fe545c10bb4cd082a26aa6955d22b
> Deleted: efe3bbdde1a2bba2a5160be477e28c08b5d928747e18a3b94846e4d07b5f6e5a
> Deleted: e115753ad5c3a48f3255e12c33d1159f2534f8b71043c92356f915444dd558bf
> Deleted: 9de8af6a8b98623dabc1a13e4228451273f996b3f219665729d8db0fc96e3707
> Deleted: 89464637c43acc62838bfaf2368584d161cf58a1557c604607184a124e66f7c4
> Build step 'Execute shell' marked build as failure
>
Jenkins build is back to normal : Mesos » gcc,--verbose,centos:7,docker||Hadoop #943
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=centos%3A7,label_exp=docker%7C%7CHadoop/943/changes>