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/11/06 22:17:42 UTC
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1186
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1186/changes>
Changes:
[adam] Added documentation about roles.
------------------------------------------
[...truncated 138701 lines...]
I1106 21:17:22.306912 31089 replica.cpp:540] Replica received write request for position 1 from (10540)@172.17.15.143:43219
I1106 21:17:22.307524 31089 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 564899ns
I1106 21:17:22.307564 31089 replica.cpp:715] Persisted action at 1
I1106 21:17:22.308321 31085 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1106 21:17:22.308797 31085 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 433195ns
I1106 21:17:22.308843 31085 replica.cpp:715] Persisted action at 1
I1106 21:17:22.308866 31085 replica.cpp:700] Replica learned APPEND action at position 1
I1106 21:17:22.309995 31091 registrar.cpp:486] Successfully updated the 'registry' in 4.899072ms
I1106 21:17:22.310178 31091 registrar.cpp:372] Successfully recovered registrar
I1106 21:17:22.310338 31084 log.cpp:704] Attempting to truncate the log to 1
I1106 21:17:22.310672 31091 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1106 21:17:22.310755 31080 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1106 21:17:22.311636 31091 replica.cpp:540] Replica received write request for position 2 from (10541)@172.17.15.143:43219
I1106 21:17:22.312132 31091 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 452997ns
I1106 21:17:22.312165 31091 replica.cpp:715] Persisted action at 2
I1106 21:17:22.312860 31093 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1106 21:17:22.313308 31093 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 405068ns
I1106 21:17:22.313371 31093 leveldb.cpp:401] Deleting ~1 keys from leveldb took 32979ns
I1106 21:17:22.313396 31093 replica.cpp:715] Persisted action at 2
I1106 21:17:22.313418 31093 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1106 21:17:22.323144 31093 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1106 21:17:22.323865 31093 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.15.143:45200
I1106 21:17:22.324221 31093 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1106 21:17:22.324296 31093 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1106 21:17:22.324892 31081 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1106 21:17:22.325366 31082 hierarchical.cpp:185] Added framework b58878b2-fc76-41cf-8dc0-4dc789e041ef-0000
I1106 21:17:22.325431 31082 hierarchical.cpp:952] No resources available to allocate!
I1106 21:17:22.325551 31080 master.hpp:1439] Sending heartbeat to b58878b2-fc76-41cf-8dc0-4dc789e041ef-0000
I1106 21:17:22.325639 31082 hierarchical.cpp:1045] No inverse offers to send out!
I1106 21:17:22.325937 31082 hierarchical.cpp:851] Performed allocation for 0 slaves in 536390ns
I1106 21:17:22.326274 31085 master.cpp:922] Master terminating
I1106 21:17:22.326467 31091 hierarchical.cpp:220] Removed framework b58878b2-fc76-41cf-8dc0-4dc789e041ef-0000
[ OK ] ContentType/SchedulerHttpApiTest.NoAcceptHeader/1 (51 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/0
I1106 21:17:22.335861 31059 leveldb.cpp:176] Opened db in 3.223266ms
I1106 21:17:22.336918 31059 leveldb.cpp:183] Compacted db in 1.017618ms
I1106 21:17:22.336977 31059 leveldb.cpp:198] Created db iterator in 17449ns
I1106 21:17:22.337021 31059 leveldb.cpp:204] Seeked to beginning of db in 1845ns
I1106 21:17:22.337033 31059 leveldb.cpp:273] Iterated through 0 keys in the db in 235ns
I1106 21:17:22.337082 31059 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1106 21:17:22.337517 31081 recover.cpp:449] Starting replica recovery
I1106 21:17:22.338024 31092 recover.cpp:475] Replica is in EMPTY status
I1106 21:17:22.338974 31082 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10545)@172.17.15.143:43219
I1106 21:17:22.339639 31078 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1106 21:17:22.340101 31082 recover.cpp:566] Updating replica status to STARTING
I1106 21:17:22.340703 31081 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 474648ns
I1106 21:17:22.340728 31081 replica.cpp:323] Persisted replica status to STARTING
I1106 21:17:22.340898 31083 recover.cpp:475] Replica is in STARTING status
I1106 21:17:22.341084 31089 master.cpp:367] Master 760c7f14-0ecd-44b0-89f6-692da85e20ad (940affd60c07) started on 172.17.15.143:43219
I1106 21:17:22.341106 31089 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/5F9Lvm/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/5F9Lvm/master" --zk_session_timeout="10secs"
I1106 21:17:22.341328 31089 master.cpp:416] Master allowing unauthenticated frameworks to register
I1106 21:17:22.341346 31089 master.cpp:419] Master only allowing authenticated slaves to register
I1106 21:17:22.341361 31089 credentials.hpp:37] Loading credentials for authentication from '/tmp/5F9Lvm/credentials'
I1106 21:17:22.341572 31089 master.cpp:458] Using default 'crammd5' authenticator
I1106 21:17:22.341677 31089 master.cpp:495] Authorization enabled
I1106 21:17:22.341928 31092 hierarchical.cpp:140] Initialized hierarchical allocator process
I1106 21:17:22.341933 31085 whitelist_watcher.cpp:79] No whitelist given
I1106 21:17:22.342026 31091 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10546)@172.17.15.143:43219
I1106 21:17:22.342396 31080 recover.cpp:195] Received a recover response from a replica in STARTING status
I1106 21:17:22.342809 31085 recover.cpp:566] Updating replica status to VOTING
I1106 21:17:22.343379 31093 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 351306ns
I1106 21:17:22.343405 31093 replica.cpp:323] Persisted replica status to VOTING
I1106 21:17:22.343425 31081 master.cpp:1606] The newly elected leader is master@172.17.15.143:43219 with id 760c7f14-0ecd-44b0-89f6-692da85e20ad
I1106 21:17:22.343453 31081 master.cpp:1619] Elected as the leading master!
I1106 21:17:22.343468 31081 master.cpp:1379] Recovering from registrar
I1106 21:17:22.343513 31091 recover.cpp:580] Successfully joined the Paxos group
I1106 21:17:22.343580 31093 registrar.cpp:309] Recovering registrar
I1106 21:17:22.343920 31091 recover.cpp:464] Recover process terminated
I1106 21:17:22.344343 31082 log.cpp:661] Attempting to start the writer
I1106 21:17:22.345247 31092 replica.cpp:496] Replica received implicit promise request from (10547)@172.17.15.143:43219 with proposal 1
I1106 21:17:22.345624 31092 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 346343ns
I1106 21:17:22.345646 31092 replica.cpp:345] Persisted promised to 1
I1106 21:17:22.346174 31086 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1106 21:17:22.347101 31089 replica.cpp:391] Replica received explicit promise request from (10548)@172.17.15.143:43219 for position 0 with proposal 2
I1106 21:17:22.347440 31089 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 303791ns
I1106 21:17:22.347461 31089 replica.cpp:715] Persisted action at 0
I1106 21:17:22.348670 31083 replica.cpp:540] Replica received write request for position 0 from (10549)@172.17.15.143:43219
I1106 21:17:22.348743 31083 leveldb.cpp:438] Reading position from leveldb took 32247ns
I1106 21:17:22.349159 31083 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 357112ns
I1106 21:17:22.349201 31083 replica.cpp:715] Persisted action at 0
I1106 21:17:22.349920 31089 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1106 21:17:22.350338 31089 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 382378ns
I1106 21:17:22.350368 31089 replica.cpp:715] Persisted action at 0
I1106 21:17:22.350390 31089 replica.cpp:700] Replica learned NOP action at position 0
I1106 21:17:22.351016 31091 log.cpp:677] Writer started with ending position 0
I1106 21:17:22.352222 31079 leveldb.cpp:438] Reading position from leveldb took 39002ns
I1106 21:17:22.353183 31089 registrar.cpp:342] Successfully fetched the registry (0B) in 9.491968ms
I1106 21:17:22.353291 31089 registrar.cpp:441] Applied 1 operations in 24164ns; attempting to update the 'registry'
I1106 21:17:22.354063 31088 log.cpp:685] Attempting to append 178 bytes to the log
I1106 21:17:22.354241 31091 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1106 21:17:22.355099 31078 replica.cpp:540] Replica received write request for position 1 from (10550)@172.17.15.143:43219
I1106 21:17:22.355599 31078 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 447894ns
I1106 21:17:22.355629 31078 replica.cpp:715] Persisted action at 1
I1106 21:17:22.356381 31089 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1106 21:17:22.356801 31089 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 379159ns
I1106 21:17:22.356847 31089 replica.cpp:715] Persisted action at 1
I1106 21:17:22.356868 31089 replica.cpp:700] Replica learned APPEND action at position 1
I1106 21:17:22.357895 31093 registrar.cpp:486] Successfully updated the 'registry' in 4.532992ms
I1106 21:17:22.358048 31093 registrar.cpp:372] Successfully recovered registrar
I1106 21:17:22.358211 31088 log.cpp:704] Attempting to truncate the log to 1
I1106 21:17:22.358387 31085 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1106 21:17:22.358470 31086 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1106 21:17:22.359381 31087 replica.cpp:540] Replica received write request for position 2 from (10551)@172.17.15.143:43219
I1106 21:17:22.359777 31087 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 351926ns
I1106 21:17:22.359807 31087 replica.cpp:715] Persisted action at 2
I1106 21:17:22.360576 31085 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1106 21:17:22.360972 31085 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 360074ns
I1106 21:17:22.361040 31085 leveldb.cpp:401] Deleting ~1 keys from leveldb took 38379ns
I1106 21:17:22.361066 31085 replica.cpp:715] Persisted action at 2
I1106 21:17:22.361088 31085 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1106 21:17:22.370553 31092 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1106 21:17:22.370892 31092 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.15.143:45201
I1106 21:17:22.371095 31092 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1106 21:17:22.371166 31092 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1106 21:17:22.371428 31092 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1106 21:17:22.371785 31085 hierarchical.cpp:185] Added framework 760c7f14-0ecd-44b0-89f6-692da85e20ad-0000
I1106 21:17:22.371871 31085 hierarchical.cpp:952] No resources available to allocate!
I1106 21:17:22.371922 31085 hierarchical.cpp:1045] No inverse offers to send out!
I1106 21:17:22.371934 31078 master.hpp:1439] Sending heartbeat to 760c7f14-0ecd-44b0-89f6-692da85e20ad-0000
I1106 21:17:22.371959 31085 hierarchical.cpp:851] Performed allocation for 0 slaves in 116055ns
I1106 21:17:22.373482 31090 master.cpp:922] Master terminating
I1106 21:17:22.373658 31087 hierarchical.cpp:220] Removed framework 760c7f14-0ecd-44b0-89f6-692da85e20ad-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/0 (46 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/1
I1106 21:17:22.382235 31059 leveldb.cpp:176] Opened db in 2.895678ms
I1106 21:17:22.383540 31059 leveldb.cpp:183] Compacted db in 1.262375ms
I1106 21:17:22.383600 31059 leveldb.cpp:198] Created db iterator in 13847ns
I1106 21:17:22.383620 31059 leveldb.cpp:204] Seeked to beginning of db in 1868ns
I1106 21:17:22.383631 31059 leveldb.cpp:273] Iterated through 0 keys in the db in 228ns
I1106 21:17:22.383663 31059 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1106 21:17:22.384107 31088 recover.cpp:449] Starting replica recovery
I1106 21:17:22.384377 31088 recover.cpp:475] Replica is in EMPTY status
I1106 21:17:22.385440 31078 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10555)@172.17.15.143:43219
I1106 21:17:22.385953 31086 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1106 21:17:22.386514 31088 recover.cpp:566] Updating replica status to STARTING
I1106 21:17:22.387293 31089 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 529403ns
I1106 21:17:22.387328 31089 replica.cpp:323] Persisted replica status to STARTING
I1106 21:17:22.387537 31092 recover.cpp:475] Replica is in STARTING status
I1106 21:17:22.388506 31083 master.cpp:367] Master 21006cb9-b602-44d0-9297-c4cef4a171ed (940affd60c07) started on 172.17.15.143:43219
I1106 21:17:22.388728 31088 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10556)@172.17.15.143:43219
I1106 21:17:22.388670 31083 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/yCDVpI/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/yCDVpI/master" --zk_session_timeout="10secs"
I1106 21:17:22.389034 31083 master.cpp:416] Master allowing unauthenticated frameworks to register
I1106 21:17:22.389047 31083 master.cpp:419] Master only allowing authenticated slaves to register
I1106 21:17:22.389055 31083 credentials.hpp:37] Loading credentials for authentication from '/tmp/yCDVpI/credentials'
I1106 21:17:22.389053 31082 recover.cpp:195] Received a recover response from a replica in STARTING status
I1106 21:17:22.389341 31083 master.cpp:458] Using default 'crammd5' authenticator
I1106 21:17:22.389792 31090 recover.cpp:566] Updating replica status to VOTING
I1106 21:17:22.389981 31083 master.cpp:495] Authorization enabled
I1106 21:17:22.390224 31089 whitelist_watcher.cpp:79] No whitelist given
I1106 21:17:22.390250 31081 hierarchical.cpp:140] Initialized hierarchical allocator process
I1106 21:17:22.391327 31087 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 409345ns
I1106 21:17:22.391356 31087 replica.cpp:323] Persisted replica status to VOTING
I1106 21:17:22.391542 31092 recover.cpp:580] Successfully joined the Paxos group
I1106 21:17:22.391974 31092 recover.cpp:464] Recover process terminated
I1106 21:17:22.392112 31082 master.cpp:1606] The newly elected leader is master@172.17.15.143:43219 with id 21006cb9-b602-44d0-9297-c4cef4a171ed
I1106 21:17:22.392156 31082 master.cpp:1619] Elected as the leading master!
I1106 21:17:22.392184 31082 master.cpp:1379] Recovering from registrar
I1106 21:17:22.392467 31080 registrar.cpp:309] Recovering registrar
I1106 21:17:22.393188 31084 log.cpp:661] Attempting to start the writer
I1106 21:17:22.394496 31087 replica.cpp:496] Replica received implicit promise request from (10557)@172.17.15.143:43219 with proposal 1
I1106 21:17:22.394888 31087 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 353709ns
I1106 21:17:22.394917 31087 replica.cpp:345] Persisted promised to 1
I1106 21:17:22.395551 31082 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1106 21:17:22.397008 31079 replica.cpp:391] Replica received explicit promise request from (10558)@172.17.15.143:43219 for position 0 with proposal 2
I1106 21:17:22.397462 31079 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 400916ns
I1106 21:17:22.397495 31079 replica.cpp:715] Persisted action at 0
I1106 21:17:22.398712 31085 replica.cpp:540] Replica received write request for position 0 from (10559)@172.17.15.143:43219
I1106 21:17:22.398800 31085 leveldb.cpp:438] Reading position from leveldb took 29774ns
I1106 21:17:22.399377 31085 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 511568ns
I1106 21:17:22.399407 31085 replica.cpp:715] Persisted action at 0
I1106 21:17:22.400163 31088 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1106 21:17:22.400707 31088 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 500275ns
I1106 21:17:22.400740 31088 replica.cpp:715] Persisted action at 0
I1106 21:17:22.400774 31088 replica.cpp:700] Replica learned NOP action at position 0
I1106 21:17:22.401504 31088 log.cpp:677] Writer started with ending position 0
I1106 21:17:22.402698 31092 leveldb.cpp:438] Reading position from leveldb took 34051ns
I1106 21:17:22.403728 31083 registrar.cpp:342] Successfully fetched the registry (0B) in 11.201024ms
I1106 21:17:22.403868 31083 registrar.cpp:441] Applied 1 operations in 51136ns; attempting to update the 'registry'
I1106 21:17:22.404667 31086 log.cpp:685] Attempting to append 178 bytes to the log
I1106 21:17:22.404845 31090 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1106 21:17:22.405700 31078 replica.cpp:540] Replica received write request for position 1 from (10560)@172.17.15.143:43219
I1106 21:17:22.406149 31078 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 406645ns
I1106 21:17:22.406179 31078 replica.cpp:715] Persisted action at 1
I1106 21:17:22.406901 31080 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1106 21:17:22.407413 31080 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 474657ns
I1106 21:17:22.407444 31080 replica.cpp:715] Persisted action at 1
I1106 21:17:22.407464 31080 replica.cpp:700] Replica learned APPEND action at position 1
I1106 21:17:22.408453 31088 registrar.cpp:486] Successfully updated the 'registry' in 4.519936ms
I1106 21:17:22.408643 31088 registrar.cpp:372] Successfully recovered registrar
I1106 21:17:22.408741 31092 log.cpp:704] Attempting to truncate the log to 1
I1106 21:17:22.408917 31087 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1106 21:17:22.409119 31081 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1106 21:17:22.410063 31085 replica.cpp:540] Replica received write request for position 2 from (10561)@172.17.15.143:43219
I1106 21:17:22.410565 31085 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 459804ns
I1106 21:17:22.410595 31085 replica.cpp:715] Persisted action at 2
I1106 21:17:22.411253 31089 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1106 21:17:22.411733 31089 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 441857ns
I1106 21:17:22.411794 31089 leveldb.cpp:401] Deleting ~1 keys from leveldb took 32002ns
I1106 21:17:22.411839 31089 replica.cpp:715] Persisted action at 2
I1106 21:17:22.411864 31089 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1106 21:17:22.421846 31086 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1106 21:17:22.422209 31086 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.15.143:45202
I1106 21:17:22.422619 31086 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1106 21:17:22.422711 31086 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1106 21:17:22.423070 31086 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1106 21:17:22.423450 31078 hierarchical.cpp:185] Added framework 21006cb9-b602-44d0-9297-c4cef4a171ed-0000
I1106 21:17:22.423498 31078 hierarchical.cpp:952] No resources available to allocate!
I1106 21:17:22.423527 31078 hierarchical.cpp:1045] No inverse offers to send out!
I1106 21:17:22.423547 31078 hierarchical.cpp:851] Performed allocation for 0 slaves in 70766ns
I1106 21:17:22.423626 31084 master.hpp:1439] Sending heartbeat to 21006cb9-b602-44d0-9297-c4cef4a171ed-0000
I1106 21:17:22.424971 31093 master.cpp:922] Master terminating
I1106 21:17:22.425148 31078 hierarchical.cpp:220] Removed framework 21006cb9-b602-44d0-9297-c4cef4a171ed-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/1 (52 ms)
[----------] 20 tests from ContentType/SchedulerHttpApiTest (1091 ms total)
[----------] Global test environment tear-down
make[4]: *** [check-local] Error 1[==========] 828 tests from 113 test cases ran. (322163 ms total)
[ PASSED ] 827 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] RegistryClientTest.BadRequest
1 FAILED TEST
YOU HAVE 8 DISABLED TESTS
make[4]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[3]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[2]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[1]: Leaving directory `/mesos/mesos-0.26.0/_build'
make[3]: *** [check-am] Error 2
make[2]: *** [check] Error 2
make[1]: *** [check-recursive] Error 1
make: *** [distcheck] Error 1
+ docker rmi mesos-1446842891-15412
Untagged: mesos-1446842891-15412:latest
Deleted: 6c4b47b3eb2eb00c12b8e8d05ab664e02b86b100413d9a3d06da9b641fc7e426
Deleted: 0c7eed11b7d1bf7189663a7f608a339b6e63bdac0361564954bb4f8047e8d1fd
Deleted: 8779872f67fdabbcef5267f1c01df973f65a6e767e8fa2ef5a25e03c34412c38
Deleted: d05178bf457ee5911bb3e040892eead8ba622c28f7807926f26b80b0f87919d5
Deleted: 588b0191645f49a32e5da4fe1a6de4ca07ff9193d37dc449bb00becfe2d0992f
Deleted: 6984e9e00c62b0f30d6774703eba947e7a7e7070e94b44dd9ffa347e4bdb2544
Deleted: 59fd50fddca9d75d22380b9c689c4351b3c2ec5ab232e910828e4fca0a0ae054
Deleted: 38083deb4c610dc45c49e3ae4aeecddd0fb8c1388f06648b8ef7fce0105b3d80
Deleted: 9aa064915bfd9936f62c14a21fe0c3784f18a5d36fabc8a3b6462f642fbfbf1e
Deleted: 7545f7f6c1b918bd6b6a80e9dc49e03f0884cfb2595c726d95efd0a5ec144621
Deleted: c411f7c3e95eb675ac9b596515058280d8bafcce224f6ee439e6f1383edec1f5
Deleted: 7ad024ce477f27f82a5ef84b96d275a5108e582e0ce4d3816066d18b08327caa
Deleted: db2e54aed224e1e52a9a2a576bac0e7eb7d28a340ab0f0c3f53e7ca83b2552b2
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1190
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1190/changes>
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1189
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1189/changes>
Changes:
[yujie.jay] TemporaryDirectoryTest Merge: Elevate `TemporaryDirectoryTest::sandbox`
[yujie.jay] TemporaryDirectoryTest Merge: Point tests to the Stout version of the
[yujie.jay] TemporaryDirectoryTest Merge: Remove non-Stout version of
------------------------------------------
[...truncated 138669 lines...]
I1107 02:19:36.132156 31081 replica.cpp:540] Replica received write request for position 1 from (10539)@172.17.15.220:36095
I1107 02:19:36.132735 31081 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 536430ns
I1107 02:19:36.132768 31081 replica.cpp:715] Persisted action at 1
I1107 02:19:36.133456 31087 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 02:19:36.134016 31087 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 516158ns
I1107 02:19:36.134053 31087 replica.cpp:715] Persisted action at 1
I1107 02:19:36.134078 31087 replica.cpp:700] Replica learned APPEND action at position 1
I1107 02:19:36.135493 31080 log.cpp:704] Attempting to truncate the log to 1
I1107 02:19:36.135604 31078 registrar.cpp:486] Successfully updated the 'registry' in 5.094144ms
I1107 02:19:36.135678 31076 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 02:19:36.135892 31078 registrar.cpp:372] Successfully recovered registrar
I1107 02:19:36.136379 31079 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1107 02:19:36.136987 31090 replica.cpp:540] Replica received write request for position 2 from (10540)@172.17.15.220:36095
I1107 02:19:36.137382 31090 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 346499ns
I1107 02:19:36.137413 31090 replica.cpp:715] Persisted action at 2
I1107 02:19:36.138270 31086 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 02:19:36.138762 31086 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 394346ns
I1107 02:19:36.138861 31086 leveldb.cpp:401] Deleting ~1 keys from leveldb took 66811ns
I1107 02:19:36.138898 31086 replica.cpp:715] Persisted action at 2
I1107 02:19:36.138924 31086 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 02:19:36.148921 31083 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 02:19:36.149257 31083 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.15.220:57440
I1107 02:19:36.149646 31083 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 02:19:36.149724 31083 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 02:19:36.150028 31083 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 02:19:36.150421 31081 hierarchical.cpp:185] Added framework 3ee0776c-54cd-460d-bcb0-7bdc011360bd-0000
I1107 02:19:36.150481 31081 hierarchical.cpp:952] No resources available to allocate!
I1107 02:19:36.150521 31081 hierarchical.cpp:1045] No inverse offers to send out!
I1107 02:19:36.150548 31081 hierarchical.cpp:851] Performed allocation for 0 slaves in 99337ns
I1107 02:19:36.150552 31084 master.hpp:1439] Sending heartbeat to 3ee0776c-54cd-460d-bcb0-7bdc011360bd-0000
I1107 02:19:36.151525 31089 master.cpp:922] Master terminating
I1107 02:19:36.151747 31082 hierarchical.cpp:220] Removed framework 3ee0776c-54cd-460d-bcb0-7bdc011360bd-0000
[ OK ] ContentType/SchedulerHttpApiTest.NoAcceptHeader/1 (49 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/0
I1107 02:19:36.160017 31057 leveldb.cpp:176] Opened db in 2.946566ms
I1107 02:19:36.161139 31057 leveldb.cpp:183] Compacted db in 1.08501ms
I1107 02:19:36.161201 31057 leveldb.cpp:198] Created db iterator in 17959ns
I1107 02:19:36.161222 31057 leveldb.cpp:204] Seeked to beginning of db in 1910ns
I1107 02:19:36.161233 31057 leveldb.cpp:273] Iterated through 0 keys in the db in 283ns
I1107 02:19:36.161269 31057 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1107 02:19:36.161672 31089 recover.cpp:449] Starting replica recovery
I1107 02:19:36.162150 31089 recover.cpp:475] Replica is in EMPTY status
I1107 02:19:36.163136 31080 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10544)@172.17.15.220:36095
I1107 02:19:36.163722 31082 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1107 02:19:36.164317 31076 recover.cpp:566] Updating replica status to STARTING
I1107 02:19:36.165099 31090 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 575519ns
I1107 02:19:36.165132 31090 replica.cpp:323] Persisted replica status to STARTING
I1107 02:19:36.165254 31086 master.cpp:367] Master 7debce83-47bc-4489-ae39-293dcab2590e (90e2cf46b1a2) started on 172.17.15.220:36095
I1107 02:19:36.165285 31086 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/56vIl4/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/56vIl4/master" --zk_session_timeout="10secs"
I1107 02:19:36.165655 31086 master.cpp:416] Master allowing unauthenticated frameworks to register
I1107 02:19:36.165673 31086 master.cpp:419] Master only allowing authenticated slaves to register
I1107 02:19:36.165688 31086 credentials.hpp:37] Loading credentials for authentication from '/tmp/56vIl4/credentials'
I1107 02:19:36.166062 31084 recover.cpp:475] Replica is in STARTING status
I1107 02:19:36.166160 31086 master.cpp:458] Using default 'crammd5' authenticator
I1107 02:19:36.166311 31086 master.cpp:495] Authorization enabled
I1107 02:19:36.166577 31080 whitelist_watcher.cpp:79] No whitelist given
I1107 02:19:36.166637 31076 hierarchical.cpp:140] Initialized hierarchical allocator process
I1107 02:19:36.167068 31089 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10545)@172.17.15.220:36095
I1107 02:19:36.167656 31090 recover.cpp:195] Received a recover response from a replica in STARTING status
I1107 02:19:36.168193 31086 master.cpp:1606] The newly elected leader is master@172.17.15.220:36095 with id 7debce83-47bc-4489-ae39-293dcab2590e
I1107 02:19:36.168226 31086 master.cpp:1619] Elected as the leading master!
I1107 02:19:36.168247 31086 master.cpp:1379] Recovering from registrar
I1107 02:19:36.168341 31085 recover.cpp:566] Updating replica status to VOTING
I1107 02:19:36.168452 31076 registrar.cpp:309] Recovering registrar
I1107 02:19:36.169214 31083 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 519446ns
I1107 02:19:36.169239 31083 replica.cpp:323] Persisted replica status to VOTING
I1107 02:19:36.169342 31078 recover.cpp:580] Successfully joined the Paxos group
I1107 02:19:36.169545 31078 recover.cpp:464] Recover process terminated
I1107 02:19:36.169947 31082 log.cpp:661] Attempting to start the writer
I1107 02:19:36.171097 31086 replica.cpp:496] Replica received implicit promise request from (10546)@172.17.15.220:36095 with proposal 1
I1107 02:19:36.171497 31086 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 368770ns
I1107 02:19:36.171520 31086 replica.cpp:345] Persisted promised to 1
I1107 02:19:36.172076 31087 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1107 02:19:36.173130 31077 replica.cpp:391] Replica received explicit promise request from (10547)@172.17.15.220:36095 for position 0 with proposal 2
I1107 02:19:36.173616 31077 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 448867ns
I1107 02:19:36.173640 31077 replica.cpp:715] Persisted action at 0
I1107 02:19:36.174576 31079 replica.cpp:540] Replica received write request for position 0 from (10548)@172.17.15.220:36095
I1107 02:19:36.174639 31079 leveldb.cpp:438] Reading position from leveldb took 29731ns
I1107 02:19:36.175156 31079 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 468142ns
I1107 02:19:36.175185 31079 replica.cpp:715] Persisted action at 0
I1107 02:19:36.175705 31091 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1107 02:19:36.176156 31091 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 422081ns
I1107 02:19:36.176182 31091 replica.cpp:715] Persisted action at 0
I1107 02:19:36.176208 31091 replica.cpp:700] Replica learned NOP action at position 0
I1107 02:19:36.176846 31090 log.cpp:677] Writer started with ending position 0
I1107 02:19:36.177922 31084 leveldb.cpp:438] Reading position from leveldb took 28337ns
I1107 02:19:36.178869 31083 registrar.cpp:342] Successfully fetched the registry (0B) in 10.151168ms
I1107 02:19:36.179000 31083 registrar.cpp:441] Applied 1 operations in 34606ns; attempting to update the 'registry'
I1107 02:19:36.179725 31084 log.cpp:685] Attempting to append 178 bytes to the log
I1107 02:19:36.179885 31078 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1107 02:19:36.180750 31091 replica.cpp:540] Replica received write request for position 1 from (10549)@172.17.15.220:36095
I1107 02:19:36.181368 31091 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 563285ns
I1107 02:19:36.181402 31091 replica.cpp:715] Persisted action at 1
I1107 02:19:36.182426 31085 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 02:19:36.182858 31085 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 388244ns
I1107 02:19:36.182890 31085 replica.cpp:715] Persisted action at 1
I1107 02:19:36.182914 31085 replica.cpp:700] Replica learned APPEND action at position 1
I1107 02:19:36.184402 31089 registrar.cpp:486] Successfully updated the 'registry' in 5.332224ms
I1107 02:19:36.184571 31089 registrar.cpp:372] Successfully recovered registrar
I1107 02:19:36.184695 31083 log.cpp:704] Attempting to truncate the log to 1
I1107 02:19:36.184983 31080 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 02:19:36.185078 31081 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1107 02:19:36.186056 31081 replica.cpp:540] Replica received write request for position 2 from (10550)@172.17.15.220:36095
I1107 02:19:36.186485 31081 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 379519ns
I1107 02:19:36.186516 31081 replica.cpp:715] Persisted action at 2
I1107 02:19:36.187361 31078 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 02:19:36.187851 31078 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 446625ns
I1107 02:19:36.187923 31078 leveldb.cpp:401] Deleting ~1 keys from leveldb took 40771ns
I1107 02:19:36.187949 31078 replica.cpp:715] Persisted action at 2
I1107 02:19:36.187973 31078 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 02:19:36.197038 31090 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 02:19:36.197304 31090 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.15.220:57441
I1107 02:19:36.197504 31090 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 02:19:36.197576 31090 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 02:19:36.197952 31090 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 02:19:36.198498 31087 hierarchical.cpp:185] Added framework 7debce83-47bc-4489-ae39-293dcab2590e-0000
I1107 02:19:36.198557 31090 master.hpp:1439] Sending heartbeat to 7debce83-47bc-4489-ae39-293dcab2590e-0000
I1107 02:19:36.198632 31087 hierarchical.cpp:952] No resources available to allocate!
I1107 02:19:36.198683 31087 hierarchical.cpp:1045] No inverse offers to send out!
I1107 02:19:36.198721 31087 hierarchical.cpp:851] Performed allocation for 0 slaves in 127364ns
I1107 02:19:36.199772 31081 master.cpp:922] Master terminating
I1107 02:19:36.200027 31090 hierarchical.cpp:220] Removed framework 7debce83-47bc-4489-ae39-293dcab2590e-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/0 (49 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/1
I1107 02:19:36.208304 31057 leveldb.cpp:176] Opened db in 2.837527ms
I1107 02:19:36.209295 31057 leveldb.cpp:183] Compacted db in 944239ns
I1107 02:19:36.209343 31057 leveldb.cpp:198] Created db iterator in 14838ns
I1107 02:19:36.209362 31057 leveldb.cpp:204] Seeked to beginning of db in 1840ns
I1107 02:19:36.209370 31057 leveldb.cpp:273] Iterated through 0 keys in the db in 213ns
I1107 02:19:36.209403 31057 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1107 02:19:36.209803 31083 recover.cpp:449] Starting replica recovery
I1107 02:19:36.210072 31083 recover.cpp:475] Replica is in EMPTY status
I1107 02:19:36.211066 31080 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10554)@172.17.15.220:36095
I1107 02:19:36.211459 31089 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1107 02:19:36.212081 31080 recover.cpp:566] Updating replica status to STARTING
I1107 02:19:36.213023 31084 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 598603ns
I1107 02:19:36.213062 31084 replica.cpp:323] Persisted replica status to STARTING
I1107 02:19:36.213243 31084 recover.cpp:475] Replica is in STARTING status
I1107 02:19:36.214202 31088 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10555)@172.17.15.220:36095
I1107 02:19:36.214761 31082 recover.cpp:195] Received a recover response from a replica in STARTING status
I1107 02:19:36.215302 31088 recover.cpp:566] Updating replica status to VOTING
I1107 02:19:36.215860 31084 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 373126ns
I1107 02:19:36.215891 31084 replica.cpp:323] Persisted replica status to VOTING
I1107 02:19:36.215951 31086 master.cpp:367] Master 8b3112ea-94d2-406c-951c-860778134c23 (90e2cf46b1a2) started on 172.17.15.220:36095
I1107 02:19:36.216059 31076 recover.cpp:580] Successfully joined the Paxos group
I1107 02:19:36.216320 31076 recover.cpp:464] Recover process terminated
I1107 02:19:36.215975 31086 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/IlDiGE/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/IlDiGE/master" --zk_session_timeout="10secs"
I1107 02:19:36.216378 31086 master.cpp:416] Master allowing unauthenticated frameworks to register
I1107 02:19:36.216392 31086 master.cpp:419] Master only allowing authenticated slaves to register
I1107 02:19:36.216401 31086 credentials.hpp:37] Loading credentials for authentication from '/tmp/IlDiGE/credentials'
I1107 02:19:36.216711 31086 master.cpp:458] Using default 'crammd5' authenticator
I1107 02:19:36.216873 31086 master.cpp:495] Authorization enabled
I1107 02:19:36.217090 31082 whitelist_watcher.cpp:79] No whitelist given
I1107 02:19:36.217144 31084 hierarchical.cpp:140] Initialized hierarchical allocator process
I1107 02:19:36.218699 31086 master.cpp:1606] The newly elected leader is master@172.17.15.220:36095 with id 8b3112ea-94d2-406c-951c-860778134c23
I1107 02:19:36.218729 31086 master.cpp:1619] Elected as the leading master!
I1107 02:19:36.218744 31086 master.cpp:1379] Recovering from registrar
I1107 02:19:36.218864 31088 registrar.cpp:309] Recovering registrar
I1107 02:19:36.219637 31086 log.cpp:661] Attempting to start the writer
I1107 02:19:36.220978 31086 replica.cpp:496] Replica received implicit promise request from (10556)@172.17.15.220:36095 with proposal 1
I1107 02:19:36.221479 31086 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 393741ns
I1107 02:19:36.221509 31086 replica.cpp:345] Persisted promised to 1
I1107 02:19:36.222187 31087 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1107 02:19:36.223577 31083 replica.cpp:391] Replica received explicit promise request from (10557)@172.17.15.220:36095 for position 0 with proposal 2
I1107 02:19:36.224051 31083 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 428217ns
I1107 02:19:36.224083 31083 replica.cpp:715] Persisted action at 0
I1107 02:19:36.225285 31076 replica.cpp:540] Replica received write request for position 0 from (10558)@172.17.15.220:36095
I1107 02:19:36.225350 31076 leveldb.cpp:438] Reading position from leveldb took 29247ns
I1107 02:19:36.225766 31076 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 362004ns
I1107 02:19:36.225797 31076 replica.cpp:715] Persisted action at 0
I1107 02:19:36.226589 31090 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1107 02:19:36.227038 31090 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 408040ns
I1107 02:19:36.227066 31090 replica.cpp:715] Persisted action at 0
I1107 02:19:36.227090 31090 replica.cpp:700] Replica learned NOP action at position 0
I1107 02:19:36.227615 31091 log.cpp:677] Writer started with ending position 0
I1107 02:19:36.228626 31091 leveldb.cpp:438] Reading position from leveldb took 34121ns
I1107 02:19:36.229593 31087 registrar.cpp:342] Successfully fetched the registry (0B) in 10.678016ms
I1107 02:19:36.229732 31087 registrar.cpp:441] Applied 1 operations in 40852ns; attempting to update the 'registry'
I1107 02:19:36.230478 31083 log.cpp:685] Attempting to append 178 bytes to the log
I1107 02:19:36.230643 31076 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1107 02:19:36.231636 31087 replica.cpp:540] Replica received write request for position 1 from (10559)@172.17.15.220:36095
I1107 02:19:36.232070 31087 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 385241ns
I1107 02:19:36.232102 31087 replica.cpp:715] Persisted action at 1
I1107 02:19:36.232727 31089 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 02:19:36.233186 31089 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 421103ns
I1107 02:19:36.233217 31089 replica.cpp:715] Persisted action at 1
I1107 02:19:36.233239 31089 replica.cpp:700] Replica learned APPEND action at position 1
I1107 02:19:36.234380 31084 registrar.cpp:486] Successfully updated the 'registry' in 4576us
I1107 02:19:36.234570 31084 registrar.cpp:372] Successfully recovered registrar
I1107 02:19:36.234767 31076 log.cpp:704] Attempting to truncate the log to 1
I1107 02:19:36.235035 31080 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 02:19:36.235091 31088 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1107 02:19:36.236196 31089 replica.cpp:540] Replica received write request for position 2 from (10560)@172.17.15.220:36095
I1107 02:19:36.236688 31089 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 438287ns
I1107 02:19:36.236721 31089 replica.cpp:715] Persisted action at 2
I1107 02:19:36.237509 31086 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 02:19:36.238108 31086 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 470602ns
I1107 02:19:36.238180 31086 leveldb.cpp:401] Deleting ~1 keys from leveldb took 39854ns
I1107 02:19:36.238206 31086 replica.cpp:715] Persisted action at 2
I1107 02:19:36.238229 31086 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 02:19:36.247963 31083 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 02:19:36.248162 31083 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.15.220:57442
I1107 02:19:36.248664 31083 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 02:19:36.248738 31083 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 02:19:36.249028 31083 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 02:19:36.249390 31082 hierarchical.cpp:185] Added framework 8b3112ea-94d2-406c-951c-860778134c23-0000
I1107 02:19:36.249462 31082 hierarchical.cpp:952] No resources available to allocate!
I1107 02:19:36.249498 31082 hierarchical.cpp:1045] No inverse offers to send out!
I1107 02:19:36.249526 31082 hierarchical.cpp:851] Performed allocation for 0 slaves in 97423ns
I1107 02:19:36.249558 31082 master.hpp:1439] Sending heartbeat to 8b3112ea-94d2-406c-951c-860778134c23-0000
I1107 02:19:36.250452 31077 master.cpp:922] Master terminating
I1107 02:19:36.250676 31089 hierarchical.cpp:220] Removed framework 8b3112ea-94d2-406c-951c-860778134c23-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/1 (50 ms)
[----------] 20 tests from ContentType/SchedulerHttpApiTest (1096 ms total)
[----------] Global test environment tear-down
[==========] 830 tests from 113 test cases ran. (318595 ms total)
[ PASSED ] 829 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] RegistryClientTest.BadRequest
1 FAILED TEST
YOU HAVE 8 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-1446861015-28318
Untagged: mesos-1446861015-28318:latest
Deleted: 9ddd5b12a989e8ce4b48516f434a0f99eee1affd7543dbbbd0034b3c8e650b35
Deleted: a4aed9239a43c73b441461cce8be3599d9a12fb29acc334a1371e8e8c1401f6a
Deleted: da9962f3b219757cfabec906b80d07f007bce0c4359412eebd325a3a8a7cd1f5
Deleted: 0efb29d11e204594c264c865fa1313e76e65e5e8b29be724e653dc584176aa48
Deleted: 37e121e7139b0736017153f44407ac9880ca78550f757dcbbb266fa1b525d989
Deleted: 390c0afd768e57836525fe8bced60d07d2325b168549d2c3b49e9281ea3b856d
Deleted: 30ba69c5ec609e5b0d2d1a45d2c9ea684808dbd537ff182bbd2293bb56180933
Deleted: 27c9e6eb34bdacafea13743604d5b46d6fa00998ce5dbdfbe100b521cb31c2ec
Deleted: dd460cc775d006ed230b7b479cba4928fb355c014276500d1a7c9e045147796b
Deleted: 09b0c6dba3bf712ca1ee18cc1bc17ea0beff53bdc42ab53c2dc860b267bd0156
Deleted: b8636dacc05ca471d779c2b5f04d6b0cc95e10cb28c3012b5c7f2263f004f631
Deleted: 69752fb713dfa2445d08220da8a1acf4390f9a9f91aa8d46ce7329e66957f85e
Deleted: f40314fb746ece261c56add48b457dbc239430df0d5480d0aa59472779abc051
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1188
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1188/changes>
Changes:
[kapil] Include ContainerInfo in command ExecutorInfo
[tnachen] Fixed some style issues in docker containerizer and tests.
[tnachen] Added Docker Image type to Container Image for v1 API.
[tnachen] Fixed Rootfs in tests to handle symlink directories.
[yujie.jay] Fixed a few style issues in slave tests.
------------------------------------------
[...truncated 138684 lines...]
I1107 01:31:05.374747 31094 replica.cpp:540] Replica received write request for position 1 from (10544)@172.17.2.0:49247
I1107 01:31:05.375208 31094 leveldb.cpp:343] Persisting action (187 bytes) to leveldb took 411714ns
I1107 01:31:05.375241 31094 replica.cpp:715] Persisted action at 1
I1107 01:31:05.376055 31079 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 01:31:05.376520 31079 leveldb.cpp:343] Persisting action (189 bytes) to leveldb took 422978ns
I1107 01:31:05.376550 31079 replica.cpp:715] Persisted action at 1
I1107 01:31:05.376572 31079 replica.cpp:700] Replica learned APPEND action at position 1
I1107 01:31:05.377595 31087 registrar.cpp:486] Successfully updated the 'registry' in 4.516864ms
I1107 01:31:05.377774 31087 registrar.cpp:372] Successfully recovered registrar
I1107 01:31:05.377873 31082 log.cpp:704] Attempting to truncate the log to 1
I1107 01:31:05.378074 31093 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 01:31:05.378299 31090 master.cpp:1416] Recovered 0 slaves from the Registry (129B) ; allowing 10mins for slaves to re-register
I1107 01:31:05.379253 31091 replica.cpp:540] Replica received write request for position 2 from (10545)@172.17.2.0:49247
I1107 01:31:05.379699 31091 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 400451ns
I1107 01:31:05.379731 31091 replica.cpp:715] Persisted action at 2
I1107 01:31:05.380393 31091 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 01:31:05.380775 31091 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 344187ns
I1107 01:31:05.380852 31091 leveldb.cpp:401] Deleting ~1 keys from leveldb took 43072ns
I1107 01:31:05.380892 31091 replica.cpp:715] Persisted action at 2
I1107 01:31:05.380923 31091 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 01:31:05.390308 31090 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 01:31:05.390558 31090 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.2.0:37872
I1107 01:31:05.390902 31090 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 01:31:05.391001 31090 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 01:31:05.391306 31090 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 01:31:05.391921 31092 master.hpp:1439] Sending heartbeat to a4639fe4-f880-4833-bf96-fb67f762f352-0000
I1107 01:31:05.391993 31093 hierarchical.cpp:185] Added framework a4639fe4-f880-4833-bf96-fb67f762f352-0000
I1107 01:31:05.392247 31093 hierarchical.cpp:952] No resources available to allocate!
I1107 01:31:05.392297 31093 hierarchical.cpp:1045] No inverse offers to send out!
I1107 01:31:05.392333 31093 hierarchical.cpp:851] Performed allocation for 0 slaves in 118372ns
I1107 01:31:05.392894 31084 master.cpp:922] Master terminating
I1107 01:31:05.393173 31094 hierarchical.cpp:220] Removed framework a4639fe4-f880-4833-bf96-fb67f762f352-0000
[ OK ] ContentType/SchedulerHttpApiTest.NoAcceptHeader/1 (50 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/0
I1107 01:31:05.402179 31060 leveldb.cpp:176] Opened db in 2.878251ms
I1107 01:31:05.403349 31060 leveldb.cpp:183] Compacted db in 1.130966ms
I1107 01:31:05.403409 31060 leveldb.cpp:198] Created db iterator in 18742ns
I1107 01:31:05.403430 31060 leveldb.cpp:204] Seeked to beginning of db in 2240ns
I1107 01:31:05.403441 31060 leveldb.cpp:273] Iterated through 0 keys in the db in 302ns
I1107 01:31:05.403476 31060 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1107 01:31:05.404057 31090 recover.cpp:449] Starting replica recovery
I1107 01:31:05.404314 31090 recover.cpp:475] Replica is in EMPTY status
I1107 01:31:05.405401 31084 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10549)@172.17.2.0:49247
I1107 01:31:05.405813 31081 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1107 01:31:05.406363 31086 recover.cpp:566] Updating replica status to STARTING
I1107 01:31:05.407011 31092 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 445385ns
I1107 01:31:05.407049 31092 replica.cpp:323] Persisted replica status to STARTING
I1107 01:31:05.407284 31091 recover.cpp:475] Replica is in STARTING status
I1107 01:31:05.408234 31085 master.cpp:367] Master ef4ea696-4b92-478b-9ad6-05fb68b0347c (ec3b83ec3522) started on 172.17.2.0:49247
I1107 01:31:05.408263 31085 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/LC5YWZ/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/LC5YWZ/master" --zk_session_timeout="10secs"
I1107 01:31:05.408627 31085 master.cpp:416] Master allowing unauthenticated frameworks to register
I1107 01:31:05.408640 31085 master.cpp:419] Master only allowing authenticated slaves to register
I1107 01:31:05.408648 31085 credentials.hpp:37] Loading credentials for authentication from '/tmp/LC5YWZ/credentials'
I1107 01:31:05.408656 31091 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10550)@172.17.2.0:49247
I1107 01:31:05.408913 31085 master.cpp:458] Using default 'crammd5' authenticator
I1107 01:31:05.409085 31085 master.cpp:495] Authorization enabled
I1107 01:31:05.409131 31081 recover.cpp:195] Received a recover response from a replica in STARTING status
I1107 01:31:05.409353 31087 whitelist_watcher.cpp:79] No whitelist given
I1107 01:31:05.409557 31086 hierarchical.cpp:140] Initialized hierarchical allocator process
I1107 01:31:05.409600 31087 recover.cpp:566] Updating replica status to VOTING
I1107 01:31:05.410202 31089 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 351817ns
I1107 01:31:05.410233 31089 replica.cpp:323] Persisted replica status to VOTING
I1107 01:31:05.410400 31084 recover.cpp:580] Successfully joined the Paxos group
I1107 01:31:05.410764 31084 recover.cpp:464] Recover process terminated
I1107 01:31:05.411301 31085 master.cpp:1606] The newly elected leader is master@172.17.2.0:49247 with id ef4ea696-4b92-478b-9ad6-05fb68b0347c
I1107 01:31:05.411336 31085 master.cpp:1619] Elected as the leading master!
I1107 01:31:05.411355 31085 master.cpp:1379] Recovering from registrar
I1107 01:31:05.411490 31088 registrar.cpp:309] Recovering registrar
I1107 01:31:05.412103 31079 log.cpp:661] Attempting to start the writer
I1107 01:31:05.413523 31083 replica.cpp:496] Replica received implicit promise request from (10551)@172.17.2.0:49247 with proposal 1
I1107 01:31:05.413988 31083 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 427248ns
I1107 01:31:05.414017 31083 replica.cpp:345] Persisted promised to 1
I1107 01:31:05.414717 31094 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1107 01:31:05.416043 31092 replica.cpp:391] Replica received explicit promise request from (10552)@172.17.2.0:49247 for position 0 with proposal 2
I1107 01:31:05.416518 31092 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 430560ns
I1107 01:31:05.416548 31092 replica.cpp:715] Persisted action at 0
I1107 01:31:05.417690 31094 replica.cpp:540] Replica received write request for position 0 from (10553)@172.17.2.0:49247
I1107 01:31:05.417773 31094 leveldb.cpp:438] Reading position from leveldb took 42317ns
I1107 01:31:05.418169 31094 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 351967ns
I1107 01:31:05.418198 31094 replica.cpp:715] Persisted action at 0
I1107 01:31:05.418849 31083 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1107 01:31:05.419258 31083 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 370300ns
I1107 01:31:05.419287 31083 replica.cpp:715] Persisted action at 0
I1107 01:31:05.419308 31083 replica.cpp:700] Replica learned NOP action at position 0
I1107 01:31:05.419967 31079 log.cpp:677] Writer started with ending position 0
I1107 01:31:05.421039 31094 leveldb.cpp:438] Reading position from leveldb took 33939ns
I1107 01:31:05.421982 31093 registrar.cpp:342] Successfully fetched the registry (0B) in 10.423808ms
I1107 01:31:05.422097 31093 registrar.cpp:441] Applied 1 operations in 23127ns; attempting to update the 'registry'
I1107 01:31:05.422849 31091 log.cpp:685] Attempting to append 168 bytes to the log
I1107 01:31:05.423177 31087 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1107 01:31:05.424032 31086 replica.cpp:540] Replica received write request for position 1 from (10554)@172.17.2.0:49247
I1107 01:31:05.424453 31086 leveldb.cpp:343] Persisting action (187 bytes) to leveldb took 375397ns
I1107 01:31:05.424482 31086 replica.cpp:715] Persisted action at 1
I1107 01:31:05.425195 31087 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 01:31:05.425603 31087 leveldb.cpp:343] Persisting action (189 bytes) to leveldb took 371757ns
I1107 01:31:05.425637 31087 replica.cpp:715] Persisted action at 1
I1107 01:31:05.425668 31087 replica.cpp:700] Replica learned APPEND action at position 1
I1107 01:31:05.426656 31084 registrar.cpp:486] Successfully updated the 'registry' in 4.494848ms
I1107 01:31:05.426826 31084 registrar.cpp:372] Successfully recovered registrar
I1107 01:31:05.426915 31093 log.cpp:704] Attempting to truncate the log to 1
I1107 01:31:05.427178 31089 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 01:31:05.427213 31094 master.cpp:1416] Recovered 0 slaves from the Registry (129B) ; allowing 10mins for slaves to re-register
I1107 01:31:05.428251 31089 replica.cpp:540] Replica received write request for position 2 from (10555)@172.17.2.0:49247
I1107 01:31:05.428611 31089 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 318863ns
I1107 01:31:05.428639 31089 replica.cpp:715] Persisted action at 2
I1107 01:31:05.429397 31093 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 01:31:05.429801 31093 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 340576ns
I1107 01:31:05.429863 31093 leveldb.cpp:401] Deleting ~1 keys from leveldb took 34284ns
I1107 01:31:05.429883 31093 replica.cpp:715] Persisted action at 2
I1107 01:31:05.429906 31093 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 01:31:05.439353 31086 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 01:31:05.439548 31086 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.2.0:37873
I1107 01:31:05.439749 31086 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 01:31:05.439815 31086 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 01:31:05.440178 31086 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 01:31:05.440598 31093 hierarchical.cpp:185] Added framework ef4ea696-4b92-478b-9ad6-05fb68b0347c-0000
I1107 01:31:05.440655 31093 hierarchical.cpp:952] No resources available to allocate!
I1107 01:31:05.440701 31093 hierarchical.cpp:1045] No inverse offers to send out!
I1107 01:31:05.440733 31093 hierarchical.cpp:851] Performed allocation for 0 slaves in 104639ns
I1107 01:31:05.440819 31086 master.hpp:1439] Sending heartbeat to ef4ea696-4b92-478b-9ad6-05fb68b0347c-0000
I1107 01:31:05.442009 31086 master.cpp:922] Master terminating
I1107 01:31:05.442214 31083 hierarchical.cpp:220] Removed framework ef4ea696-4b92-478b-9ad6-05fb68b0347c-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/0 (49 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/1
I1107 01:31:05.451012 31060 leveldb.cpp:176] Opened db in 2.807206ms
I1107 01:31:05.452229 31060 leveldb.cpp:183] Compacted db in 1.176659ms
I1107 01:31:05.452286 31060 leveldb.cpp:198] Created db iterator in 16002ns
I1107 01:31:05.452311 31060 leveldb.cpp:204] Seeked to beginning of db in 2135ns
I1107 01:31:05.452323 31060 leveldb.cpp:273] Iterated through 0 keys in the db in 220ns
I1107 01:31:05.452358 31060 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1107 01:31:05.452806 31081 recover.cpp:449] Starting replica recovery
I1107 01:31:05.453125 31081 recover.cpp:475] Replica is in EMPTY status
I1107 01:31:05.454195 31092 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10559)@172.17.2.0:49247
I1107 01:31:05.454617 31086 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1107 01:31:05.455134 31091 recover.cpp:566] Updating replica status to STARTING
I1107 01:31:05.455852 31092 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 576196ns
I1107 01:31:05.455883 31092 replica.cpp:323] Persisted replica status to STARTING
I1107 01:31:05.456076 31087 recover.cpp:475] Replica is in STARTING status
I1107 01:31:05.456290 31081 master.cpp:367] Master 7faa5c66-5d95-4fc6-a9a2-a0704772db10 (ec3b83ec3522) started on 172.17.2.0:49247
I1107 01:31:05.456317 31081 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/tpa4Qc/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/tpa4Qc/master" --zk_session_timeout="10secs"
I1107 01:31:05.456604 31081 master.cpp:416] Master allowing unauthenticated frameworks to register
I1107 01:31:05.456620 31081 master.cpp:419] Master only allowing authenticated slaves to register
I1107 01:31:05.456634 31081 credentials.hpp:37] Loading credentials for authentication from '/tmp/tpa4Qc/credentials'
I1107 01:31:05.456902 31080 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10560)@172.17.2.0:49247
I1107 01:31:05.456929 31081 master.cpp:458] Using default 'crammd5' authenticator
I1107 01:31:05.457089 31081 master.cpp:495] Authorization enabled
I1107 01:31:05.457298 31082 recover.cpp:195] Received a recover response from a replica in STARTING status
I1107 01:31:05.457327 31079 hierarchical.cpp:140] Initialized hierarchical allocator process
I1107 01:31:05.457342 31085 whitelist_watcher.cpp:79] No whitelist given
I1107 01:31:05.457713 31094 recover.cpp:566] Updating replica status to VOTING
I1107 01:31:05.458268 31082 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 384332ns
I1107 01:31:05.458295 31082 replica.cpp:323] Persisted replica status to VOTING
I1107 01:31:05.458407 31082 recover.cpp:580] Successfully joined the Paxos group
I1107 01:31:05.458669 31082 recover.cpp:464] Recover process terminated
I1107 01:31:05.459125 31081 master.cpp:1606] The newly elected leader is master@172.17.2.0:49247 with id 7faa5c66-5d95-4fc6-a9a2-a0704772db10
I1107 01:31:05.459164 31081 master.cpp:1619] Elected as the leading master!
I1107 01:31:05.459182 31081 master.cpp:1379] Recovering from registrar
I1107 01:31:05.459357 31090 registrar.cpp:309] Recovering registrar
I1107 01:31:05.459993 31083 log.cpp:661] Attempting to start the writer
I1107 01:31:05.461351 31087 replica.cpp:496] Replica received implicit promise request from (10561)@172.17.2.0:49247 with proposal 1
I1107 01:31:05.461858 31087 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 465732ns
I1107 01:31:05.461891 31087 replica.cpp:345] Persisted promised to 1
I1107 01:31:05.462720 31082 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1107 01:31:05.464284 31081 replica.cpp:391] Replica received explicit promise request from (10562)@172.17.2.0:49247 for position 0 with proposal 2
I1107 01:31:05.464834 31081 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 499311ns
I1107 01:31:05.464869 31081 replica.cpp:715] Persisted action at 0
I1107 01:31:05.466101 31093 replica.cpp:540] Replica received write request for position 0 from (10563)@172.17.2.0:49247
I1107 01:31:05.466172 31093 leveldb.cpp:438] Reading position from leveldb took 30809ns
I1107 01:31:05.466722 31093 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 479209ns
I1107 01:31:05.466752 31093 replica.cpp:715] Persisted action at 0
I1107 01:31:05.467514 31085 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1107 01:31:05.468034 31085 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 420351ns
I1107 01:31:05.468066 31085 replica.cpp:715] Persisted action at 0
I1107 01:31:05.468088 31085 replica.cpp:700] Replica learned NOP action at position 0
I1107 01:31:05.468860 31093 log.cpp:677] Writer started with ending position 0
I1107 01:31:05.470036 31082 leveldb.cpp:438] Reading position from leveldb took 35699ns
I1107 01:31:05.471005 31089 registrar.cpp:342] Successfully fetched the registry (0B) in 11.595008ms
I1107 01:31:05.471123 31089 registrar.cpp:441] Applied 1 operations in 25064ns; attempting to update the 'registry'
I1107 01:31:05.471879 31092 log.cpp:685] Attempting to append 168 bytes to the log
I1107 01:31:05.472066 31082 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1107 01:31:05.472970 31080 replica.cpp:540] Replica received write request for position 1 from (10564)@172.17.2.0:49247
I1107 01:31:05.473568 31080 leveldb.cpp:343] Persisting action (187 bytes) to leveldb took 555295ns
I1107 01:31:05.473599 31080 replica.cpp:715] Persisted action at 1
I1107 01:31:05.474545 31083 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 01:31:05.475078 31083 leveldb.cpp:343] Persisting action (189 bytes) to leveldb took 498576ns
I1107 01:31:05.475106 31083 replica.cpp:715] Persisted action at 1
I1107 01:31:05.475126 31083 replica.cpp:700] Replica learned APPEND action at position 1
I1107 01:31:05.476197 31085 registrar.cpp:486] Successfully updated the 'registry' in 5.010944ms
I1107 01:31:05.476407 31085 registrar.cpp:372] Successfully recovered registrar
I1107 01:31:05.476639 31088 log.cpp:704] Attempting to truncate the log to 1
I1107 01:31:05.476928 31089 master.cpp:1416] Recovered 0 slaves from the Registry (129B) ; allowing 10mins for slaves to re-register
I1107 01:31:05.476948 31085 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 01:31:05.477881 31084 replica.cpp:540] Replica received write request for position 2 from (10565)@172.17.2.0:49247
I1107 01:31:05.478410 31084 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 479134ns
I1107 01:31:05.478440 31084 replica.cpp:715] Persisted action at 2
I1107 01:31:05.479270 31088 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 01:31:05.479689 31088 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 377719ns
I1107 01:31:05.479753 31088 leveldb.cpp:401] Deleting ~1 keys from leveldb took 33552ns
I1107 01:31:05.479779 31088 replica.cpp:715] Persisted action at 2
I1107 01:31:05.479801 31088 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 01:31:05.489153 31090 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 01:31:05.489440 31090 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.2.0:37874
I1107 01:31:05.489863 31090 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 01:31:05.489936 31090 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 01:31:05.490289 31090 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 01:31:05.490669 31079 hierarchical.cpp:185] Added framework 7faa5c66-5d95-4fc6-a9a2-a0704772db10-0000
I1107 01:31:05.490835 31079 hierarchical.cpp:952] No resources available to allocate!
I1107 01:31:05.490887 31079 hierarchical.cpp:1045] No inverse offers to send out!
I1107 01:31:05.490887 31083 master.hpp:1439] Sending heartbeat to 7faa5c66-5d95-4fc6-a9a2-a0704772db10-0000
I1107 01:31:05.490933 31079 hierarchical.cpp:851] Performed allocation for 0 slaves in 231579ns
I1107 01:31:05.492096 31085 master.cpp:922] Master terminating
I1107 01:31:05.492295 31088 hierarchical.cpp:220] Removed framework 7faa5c66-5d95-4fc6-a9a2-a0704772db10-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/1 (50 ms)
[----------] 20 tests from ContentType/SchedulerHttpApiTest (1112 ms total)
[----------] Global test environment tear-down
[==========] 830 tests from 113 test cases ran. (328579 ms total)
[ PASSED ] 829 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] RegistryClientTest.BadRequest
1 FAILED TEST
YOU HAVE 8 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-1446858158-18525
Untagged: mesos-1446858158-18525:latest
Deleted: ae2693e1144d1cd4c1b2d40af3315ef8e265cbfbddd5521c7b8d2acd2ecf3f49
Deleted: 51d702b36fd097d2a134df36c890dcd0a14014a6a38bddc0f73166749768fb60
Deleted: 38fe9f04215c693b3abe11a149d42f231bf821d44e0e12c8b82f541f2fff8326
Deleted: d74f701312ebe0b309a2fc39064349de1f7ddeefd56971397e3cac238a92bd88
Deleted: 5f840e1dffebe3a7f5986cee9f45bf6f36dcdebdf7ca17bfb906288c57474df8
Deleted: d553fbb1d81f5f88ef00fc2f4af920d48a375661d8862abe9be1966771beb237
Deleted: df7315abf4fb290c61b39ab39a6fb6986ead10690a594601ec62ab2c9973c253
Deleted: 26553f298bfcd535163bcd3f7656ae911abadadd5a869e263ce0ecef421e8933
Deleted: 09ccc6b78e125abb39b39e61a050d43add814567b3e8b6bc8343c0a5e354bccf
Deleted: 67c9c541ea8a0dbd1892a2b8aea8a2c07e51627a68b49e2d49e6360052502c97
Deleted: 6e645af5d1d80f202360f58df39a0cf5b3aea33c56368d16430d8c4968aa9eeb
Deleted: 2f47c3b52fbc0cdf85646705f80375b1210cfbb77550196c4bc78d5d7f3e87ab
Deleted: 8ab2eb070b518d79a1c4af6550257dc764a8799799730cd447935c8c058df3f9
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1187
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1187/changes>
Changes:
[tnachen] Fixed typo in comments from slave.
------------------------------------------
[...truncated 138758 lines...]
I1107 00:35:09.708431 31074 replica.cpp:540] Replica received write request for position 1 from (10526)@172.17.9.255:50833
I1107 00:35:09.708899 31074 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 434094ns
I1107 00:35:09.708923 31074 replica.cpp:715] Persisted action at 1
I1107 00:35:09.709565 31084 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 00:35:09.710053 31084 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 457998ns
I1107 00:35:09.710078 31084 replica.cpp:715] Persisted action at 1
I1107 00:35:09.710093 31084 replica.cpp:700] Replica learned APPEND action at position 1
I1107 00:35:09.710970 31081 registrar.cpp:486] Successfully updated the 'registry' in 4.203008ms
I1107 00:35:09.711083 31081 registrar.cpp:372] Successfully recovered registrar
I1107 00:35:09.711408 31082 log.cpp:704] Attempting to truncate the log to 1
I1107 00:35:09.711519 31088 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 00:35:09.711567 31084 master.cpp:1416] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1107 00:35:09.712294 31074 replica.cpp:540] Replica received write request for position 2 from (10527)@172.17.9.255:50833
I1107 00:35:09.712766 31074 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 434387ns
I1107 00:35:09.712790 31074 replica.cpp:715] Persisted action at 2
I1107 00:35:09.713373 31081 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 00:35:09.715016 31081 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 1.609162ms
I1107 00:35:09.715198 31081 leveldb.cpp:401] Deleting ~1 keys from leveldb took 55475ns
I1107 00:35:09.715317 31081 replica.cpp:715] Persisted action at 2
I1107 00:35:09.715451 31081 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 00:35:09.724175 31082 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 00:35:09.724508 31082 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.9.255:48876
I1107 00:35:09.725107 31082 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 00:35:09.725285 31082 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 00:35:09.725875 31082 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 00:35:09.726312 31085 hierarchical.cpp:185] Added framework 1b761723-d747-4117-be8c-1fe36e83efcb-0000
I1107 00:35:09.726373 31085 hierarchical.cpp:952] No resources available to allocate!
I1107 00:35:09.726418 31085 hierarchical.cpp:1045] No inverse offers to send out!
I1107 00:35:09.726445 31085 hierarchical.cpp:851] Performed allocation for 0 slaves in 104655ns
I1107 00:35:09.726475 31085 master.hpp:1439] Sending heartbeat to 1b761723-d747-4117-be8c-1fe36e83efcb-0000
I1107 00:35:09.727481 31075 master.cpp:922] Master terminating
I1107 00:35:09.727650 31081 hierarchical.cpp:220] Removed framework 1b761723-d747-4117-be8c-1fe36e83efcb-0000
[ OK ] ContentType/SchedulerHttpApiTest.NoAcceptHeader/1 (50 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/0
I1107 00:35:09.737926 31054 leveldb.cpp:176] Opened db in 2.519865ms
I1107 00:35:09.738808 31054 leveldb.cpp:183] Compacted db in 846802ns
I1107 00:35:09.738854 31054 leveldb.cpp:198] Created db iterator in 17614ns
I1107 00:35:09.738870 31054 leveldb.cpp:204] Seeked to beginning of db in 1750ns
I1107 00:35:09.738878 31054 leveldb.cpp:273] Iterated through 0 keys in the db in 235ns
I1107 00:35:09.738914 31054 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1107 00:35:09.739416 31086 recover.cpp:449] Starting replica recovery
I1107 00:35:09.739665 31086 recover.cpp:475] Replica is in EMPTY status
I1107 00:35:09.741049 31083 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10531)@172.17.9.255:50833
I1107 00:35:09.741552 31075 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1107 00:35:09.742084 31074 recover.cpp:566] Updating replica status to STARTING
I1107 00:35:09.742493 31085 master.cpp:367] Master eedc7b5d-c26d-446d-adbb-b17696ae8425 (f8866e5f2aa9) started on 172.17.9.255:50833
I1107 00:35:09.742698 31073 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 483416ns
I1107 00:35:09.742724 31073 replica.cpp:323] Persisted replica status to STARTING
I1107 00:35:09.742516 31085 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/LUOQsF/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/LUOQsF/master" --zk_session_timeout="10secs"
I1107 00:35:09.742856 31085 master.cpp:416] Master allowing unauthenticated frameworks to register
I1107 00:35:09.742871 31085 master.cpp:419] Master only allowing authenticated slaves to register
I1107 00:35:09.742880 31085 credentials.hpp:37] Loading credentials for authentication from '/tmp/LUOQsF/credentials'
I1107 00:35:09.742946 31074 recover.cpp:475] Replica is in STARTING status
I1107 00:35:09.743245 31085 master.cpp:458] Using default 'crammd5' authenticator
I1107 00:35:09.743386 31085 master.cpp:495] Authorization enabled
I1107 00:35:09.743610 31080 whitelist_watcher.cpp:79] No whitelist given
I1107 00:35:09.743726 31081 hierarchical.cpp:140] Initialized hierarchical allocator process
I1107 00:35:09.743932 31075 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10532)@172.17.9.255:50833
I1107 00:35:09.744163 31082 recover.cpp:195] Received a recover response from a replica in STARTING status
I1107 00:35:09.744963 31084 recover.cpp:566] Updating replica status to VOTING
I1107 00:35:09.745643 31074 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 402373ns
I1107 00:35:09.745687 31074 replica.cpp:323] Persisted replica status to VOTING
I1107 00:35:09.745837 31082 recover.cpp:580] Successfully joined the Paxos group
I1107 00:35:09.746206 31082 recover.cpp:464] Recover process terminated
I1107 00:35:09.746331 31081 master.cpp:1606] The newly elected leader is master@172.17.9.255:50833 with id eedc7b5d-c26d-446d-adbb-b17696ae8425
I1107 00:35:09.746366 31081 master.cpp:1619] Elected as the leading master!
I1107 00:35:09.746389 31081 master.cpp:1379] Recovering from registrar
I1107 00:35:09.746575 31079 registrar.cpp:309] Recovering registrar
I1107 00:35:09.747225 31081 log.cpp:661] Attempting to start the writer
I1107 00:35:09.748656 31077 replica.cpp:496] Replica received implicit promise request from (10533)@172.17.9.255:50833 with proposal 1
I1107 00:35:09.749032 31077 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 338950ns
I1107 00:35:09.749055 31077 replica.cpp:345] Persisted promised to 1
I1107 00:35:09.749852 31081 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1107 00:35:09.751570 31087 replica.cpp:391] Replica received explicit promise request from (10534)@172.17.9.255:50833 for position 0 with proposal 2
I1107 00:35:09.752111 31087 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 462868ns
I1107 00:35:09.752272 31087 replica.cpp:715] Persisted action at 0
I1107 00:35:09.755614 31075 replica.cpp:540] Replica received write request for position 0 from (10535)@172.17.9.255:50833
I1107 00:35:09.755708 31075 leveldb.cpp:438] Reading position from leveldb took 44859ns
I1107 00:35:09.756139 31075 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 376035ns
I1107 00:35:09.756165 31075 replica.cpp:715] Persisted action at 0
I1107 00:35:09.756989 31086 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1107 00:35:09.757400 31086 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 355852ns
I1107 00:35:09.757426 31086 replica.cpp:715] Persisted action at 0
I1107 00:35:09.757447 31086 replica.cpp:700] Replica learned NOP action at position 0
I1107 00:35:09.758376 31088 log.cpp:677] Writer started with ending position 0
I1107 00:35:09.759677 31083 leveldb.cpp:438] Reading position from leveldb took 32679ns
I1107 00:35:09.760926 31086 registrar.cpp:342] Successfully fetched the registry (0B) in 14.189056ms
I1107 00:35:09.761045 31086 registrar.cpp:441] Applied 1 operations in 30934ns; attempting to update the 'registry'
I1107 00:35:09.762146 31074 log.cpp:685] Attempting to append 176 bytes to the log
I1107 00:35:09.762284 31075 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1107 00:35:09.763175 31083 replica.cpp:540] Replica received write request for position 1 from (10536)@172.17.9.255:50833
I1107 00:35:09.763587 31083 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 374876ns
I1107 00:35:09.763625 31083 replica.cpp:715] Persisted action at 1
I1107 00:35:09.764243 31079 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 00:35:09.764571 31079 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 298583ns
I1107 00:35:09.764619 31079 replica.cpp:715] Persisted action at 1
I1107 00:35:09.764647 31079 replica.cpp:700] Replica learned APPEND action at position 1
I1107 00:35:09.765635 31075 registrar.cpp:486] Successfully updated the 'registry' in 4.528896ms
I1107 00:35:09.765831 31075 registrar.cpp:372] Successfully recovered registrar
I1107 00:35:09.766027 31079 log.cpp:704] Attempting to truncate the log to 1
I1107 00:35:09.766208 31075 master.cpp:1416] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1107 00:35:09.766301 31075 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 00:35:09.767153 31074 replica.cpp:540] Replica received write request for position 2 from (10537)@172.17.9.255:50833
I1107 00:35:09.767592 31074 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 393506ns
I1107 00:35:09.767628 31074 replica.cpp:715] Persisted action at 2
I1107 00:35:09.768519 31074 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 00:35:09.768898 31074 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 348807ns
I1107 00:35:09.768962 31074 leveldb.cpp:401] Deleting ~1 keys from leveldb took 39455ns
I1107 00:35:09.768990 31074 replica.cpp:715] Persisted action at 2
I1107 00:35:09.769017 31074 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 00:35:09.779139 31083 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 00:35:09.779408 31083 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.9.255:48877
I1107 00:35:09.779598 31083 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 00:35:09.779662 31083 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 00:35:09.779958 31083 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 00:35:09.780329 31077 hierarchical.cpp:185] Added framework eedc7b5d-c26d-446d-adbb-b17696ae8425-0000
I1107 00:35:09.780429 31083 master.hpp:1439] Sending heartbeat to eedc7b5d-c26d-446d-adbb-b17696ae8425-0000
I1107 00:35:09.780918 31077 hierarchical.cpp:952] No resources available to allocate!
I1107 00:35:09.781035 31077 hierarchical.cpp:1045] No inverse offers to send out!
I1107 00:35:09.781146 31077 hierarchical.cpp:851] Performed allocation for 0 slaves in 298187ns
I1107 00:35:09.781913 31077 master.cpp:922] Master terminating
I1107 00:35:09.782133 31076 hierarchical.cpp:220] Removed framework eedc7b5d-c26d-446d-adbb-b17696ae8425-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/0 (52 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/1
I1107 00:35:09.790222 31054 leveldb.cpp:176] Opened db in 2.09103ms
I1107 00:35:09.790897 31054 leveldb.cpp:183] Compacted db in 640561ns
I1107 00:35:09.790936 31054 leveldb.cpp:198] Created db iterator in 16302ns
I1107 00:35:09.790953 31054 leveldb.cpp:204] Seeked to beginning of db in 1540ns
I1107 00:35:09.790961 31054 leveldb.cpp:273] Iterated through 0 keys in the db in 215ns
I1107 00:35:09.790997 31054 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1107 00:35:09.791597 31075 recover.cpp:449] Starting replica recovery
I1107 00:35:09.793133 31081 master.cpp:367] Master ed03379d-a565-4141-9672-bf3ddbfcea7a (f8866e5f2aa9) started on 172.17.9.255:50833
I1107 00:35:09.793160 31087 recover.cpp:475] Replica is in EMPTY status
I1107 00:35:09.793156 31081 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/zmkPeD/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/zmkPeD/master" --zk_session_timeout="10secs"
I1107 00:35:09.793484 31081 master.cpp:416] Master allowing unauthenticated frameworks to register
I1107 00:35:09.793503 31081 master.cpp:419] Master only allowing authenticated slaves to register
I1107 00:35:09.793515 31081 credentials.hpp:37] Loading credentials for authentication from '/tmp/zmkPeD/credentials'
I1107 00:35:09.793846 31081 master.cpp:458] Using default 'crammd5' authenticator
I1107 00:35:09.793990 31081 master.cpp:495] Authorization enabled
I1107 00:35:09.794229 31080 whitelist_watcher.cpp:79] No whitelist given
I1107 00:35:09.794242 31087 hierarchical.cpp:140] Initialized hierarchical allocator process
I1107 00:35:09.795299 31083 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10541)@172.17.9.255:50833
I1107 00:35:09.796043 31080 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1107 00:35:09.796778 31073 master.cpp:1606] The newly elected leader is master@172.17.9.255:50833 with id ed03379d-a565-4141-9672-bf3ddbfcea7a
I1107 00:35:09.796830 31073 master.cpp:1619] Elected as the leading master!
I1107 00:35:09.796854 31073 master.cpp:1379] Recovering from registrar
I1107 00:35:09.796982 31086 recover.cpp:566] Updating replica status to STARTING
I1107 00:35:09.796993 31079 registrar.cpp:309] Recovering registrar
I1107 00:35:09.797888 31073 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 654876ns
I1107 00:35:09.797912 31073 replica.cpp:323] Persisted replica status to STARTING
I1107 00:35:09.798115 31074 recover.cpp:475] Replica is in STARTING status
I1107 00:35:09.798972 31088 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10542)@172.17.9.255:50833
I1107 00:35:09.799199 31079 recover.cpp:195] Received a recover response from a replica in STARTING status
I1107 00:35:09.799603 31088 recover.cpp:566] Updating replica status to VOTING
I1107 00:35:09.800065 31079 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 306815ns
I1107 00:35:09.800089 31079 replica.cpp:323] Persisted replica status to VOTING
I1107 00:35:09.800205 31088 recover.cpp:580] Successfully joined the Paxos group
I1107 00:35:09.800415 31088 recover.cpp:464] Recover process terminated
I1107 00:35:09.800879 31078 log.cpp:661] Attempting to start the writer
I1107 00:35:09.802124 31076 replica.cpp:496] Replica received implicit promise request from (10543)@172.17.9.255:50833 with proposal 1
I1107 00:35:09.802462 31076 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 303940ns
I1107 00:35:09.802487 31076 replica.cpp:345] Persisted promised to 1
I1107 00:35:09.803077 31084 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1107 00:35:09.804327 31083 replica.cpp:391] Replica received explicit promise request from (10544)@172.17.9.255:50833 for position 0 with proposal 2
I1107 00:35:09.804673 31083 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 306822ns
I1107 00:35:09.804711 31083 replica.cpp:715] Persisted action at 0
I1107 00:35:09.805678 31077 replica.cpp:540] Replica received write request for position 0 from (10545)@172.17.9.255:50833
I1107 00:35:09.805768 31077 leveldb.cpp:438] Reading position from leveldb took 42689ns
I1107 00:35:09.806148 31077 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 304195ns
I1107 00:35:09.806172 31077 replica.cpp:715] Persisted action at 0
I1107 00:35:09.806754 31084 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1107 00:35:09.807112 31084 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 326013ns
I1107 00:35:09.807140 31084 replica.cpp:715] Persisted action at 0
I1107 00:35:09.807162 31084 replica.cpp:700] Replica learned NOP action at position 0
I1107 00:35:09.807755 31082 log.cpp:677] Writer started with ending position 0
I1107 00:35:09.808874 31079 leveldb.cpp:438] Reading position from leveldb took 28140ns
I1107 00:35:09.809846 31087 registrar.cpp:342] Successfully fetched the registry (0B) in 12.722944ms
I1107 00:35:09.809984 31087 registrar.cpp:441] Applied 1 operations in 37264ns; attempting to update the 'registry'
I1107 00:35:09.810756 31087 log.cpp:685] Attempting to append 176 bytes to the log
I1107 00:35:09.810889 31088 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1107 00:35:09.811672 31081 replica.cpp:540] Replica received write request for position 1 from (10546)@172.17.9.255:50833
I1107 00:35:09.812039 31081 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 329411ns
I1107 00:35:09.812062 31081 replica.cpp:715] Persisted action at 1
I1107 00:35:09.812664 31088 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 00:35:09.813007 31088 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 312975ns
I1107 00:35:09.813035 31088 replica.cpp:715] Persisted action at 1
I1107 00:35:09.813055 31088 replica.cpp:700] Replica learned APPEND action at position 1
I1107 00:35:09.813942 31075 registrar.cpp:486] Successfully updated the 'registry' in 3.8912ms
I1107 00:35:09.814081 31075 registrar.cpp:372] Successfully recovered registrar
I1107 00:35:09.814254 31088 log.cpp:704] Attempting to truncate the log to 1
I1107 00:35:09.814435 31088 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 00:35:09.814446 31075 master.cpp:1416] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1107 00:35:09.815619 31088 replica.cpp:540] Replica received write request for position 2 from (10547)@172.17.9.255:50833
I1107 00:35:09.815999 31088 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 340333ns
I1107 00:35:09.816027 31088 replica.cpp:715] Persisted action at 2
I1107 00:35:09.816887 31075 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 00:35:09.817253 31075 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 338240ns
I1107 00:35:09.817312 31075 leveldb.cpp:401] Deleting ~1 keys from leveldb took 33153ns
I1107 00:35:09.817338 31075 replica.cpp:715] Persisted action at 2
I1107 00:35:09.817364 31075 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 00:35:09.826526 31083 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 00:35:09.826778 31083 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.9.255:48878
I1107 00:35:09.827183 31083 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 00:35:09.827277 31083 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 00:35:09.827641 31084 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 00:35:09.828022 31077 hierarchical.cpp:185] Added framework ed03379d-a565-4141-9672-bf3ddbfcea7a-0000
I1107 00:35:09.828079 31077 hierarchical.cpp:952] No resources available to allocate!
I1107 00:35:09.828117 31077 hierarchical.cpp:1045] No inverse offers to send out!
I1107 00:35:09.828142 31077 hierarchical.cpp:851] Performed allocation for 0 slaves in 94086ns
I1107 00:35:09.828188 31080 master.hpp:1439] Sending heartbeat to ed03379d-a565-4141-9672-bf3ddbfcea7a-0000
I1107 00:35:09.829170 31080 master.cpp:922] Master terminating
I1107 00:35:09.829447 31088 hierarchical.cpp:220] Removed framework ed03379d-a565-4141-9672-bf3ddbfcea7a-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/1 (46 ms)
[----------] 20 tests from ContentType/SchedulerHttpApiTest (1165 ms total)
[----------] Global test environment tear-down
[==========] 828 tests from 113 test cases ran. (332274 ms total)
[ PASSED ] 827 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] RegistryClientTest.BadRequest
1 FAILED TEST
YOU HAVE 8 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-1446854629-17936
Untagged: mesos-1446854629-17936:latest
Deleted: 5b69622122a7b5a85a9e61dd92732362a9df66b22ac6b21f1c8c9794a70f67d3
Deleted: 1ace6ed201a87e0e51369a0750634d6b4899c97bbd6d8ab14f6df3b92252cd4d
Deleted: c805fb06b8203d84e2fed1145cc3f67131d17b130288639dcfed987a2ad8bb32
Deleted: 4ea00c3fbee04c0e8eddcac36b7006360bd6bd4445c4d31a9d6e04336aecbe1a
Deleted: a99a63658e2f523b24f7e8a0fdfea15929d08d27f0619d18eaed2d1faf7057f2
Deleted: af640a25562205a1ec7e75759fac8442d5cf48907496b3ed5539cbef44065d31
Deleted: 96dc2724b50c101849d8d66feaea356bd9372ab89fd39ed2529add26284707f4
Deleted: 3783baac81f1d7c47780242be7b5114ec0067f285c287679fd59b223b50b27d7
Deleted: fdf085ffb5ddd6ed326b0a12c9bee42ee1028773eb622124f98cc09bb6d1b01f
Deleted: f5c1f97b545efbda52a350f6e711ce786d208d8ca58c9c93b89c89057d3349b6
Deleted: 68e5f7f8c2a545e6a4776533855aaf59a83f9b7bccba52ac1b5b86031070b82c
Deleted: 0242156d79eafb8680205ad34275a8151d422b072dd63a3fc55df229e2842442
Deleted: 4b6e7cd2b24a879b23e4d9ebb7cf280444fac73961af8ee29413df77b2b07cf7
Build step 'Execute shell' marked build as failure