You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2016/01/21 19:10:06 UTC
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,centos:7,docker||Hadoop #1527
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1527/changes>
Changes:
[yujie.jay] Added tests for the Docker URI fetcher plugin.
------------------------------------------
[...truncated 155562 lines...]
I0121 18:10:14.692754 1923 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_woi5jD/slaves/0851deec-a714-4385-a421-5fa8c00c9a88-S0/frameworks/0851deec-a714-4385-a421-5fa8c00c9a88-0000/executors/default' for gc 6.99999198320593days in the future
I0121 18:10:14.692880 1932 status_update_manager.cpp:282] Closing status update streams for framework 0851deec-a714-4385-a421-5fa8c00c9a88-0000
I0121 18:10:14.692925 1923 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_woi5jD/slaves/0851deec-a714-4385-a421-5fa8c00c9a88-S0/frameworks/0851deec-a714-4385-a421-5fa8c00c9a88-0000' for gc 6.99999198138963days in the future
I0121 18:10:14.693023 1932 status_update_manager.cpp:528] Cleaning up status update stream for task 7b0dd572-f0ce-47a8-ad99-ff5ad96f5bb0 of framework 0851deec-a714-4385-a421-5fa8c00c9a88-0000
[ OK ] ContentType/SchedulerTest.Message/1 (101 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0121 18:10:14.699286 1898 leveldb.cpp:174] Opened db in 2.253522ms
I0121 18:10:14.700472 1898 leveldb.cpp:181] Compacted db in 1.141335ms
I0121 18:10:14.700557 1898 leveldb.cpp:196] Created db iterator in 25472ns
I0121 18:10:14.700577 1898 leveldb.cpp:202] Seeked to beginning of db in 2141ns
I0121 18:10:14.700587 1898 leveldb.cpp:271] Iterated through 0 keys in the db in 255ns
I0121 18:10:14.700637 1898 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0121 18:10:14.701287 1921 recover.cpp:447] Starting replica recovery
I0121 18:10:14.701582 1929 recover.cpp:473] Replica is in EMPTY status
I0121 18:10:14.702826 1929 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13729)@172.17.0.4:58758
I0121 18:10:14.703475 1917 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0121 18:10:14.703953 1929 master.cpp:374] Master baebf4e0-997d-44d4-962d-664ca6b5f779 (5fba7e84f7c1) started on 172.17.0.4:58758
I0121 18:10:14.704131 1922 recover.cpp:564] Updating replica status to STARTING
I0121 18:10:14.703977 1929 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/gzHsez/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/gzHsez/master" --zk_session_timeout="10secs"
I0121 18:10:14.704457 1929 master.cpp:423] Master allowing unauthenticated frameworks to register
I0121 18:10:14.704475 1929 master.cpp:426] Master only allowing authenticated slaves to register
I0121 18:10:14.704488 1929 credentials.hpp:35] Loading credentials for authentication from '/tmp/gzHsez/credentials'
I0121 18:10:14.704936 1929 master.cpp:466] Using default 'crammd5' authenticator
I0121 18:10:14.705107 1929 master.cpp:535] Using default 'basic' HTTP authenticator
I0121 18:10:14.705173 1922 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 723118ns
I0121 18:10:14.705199 1922 replica.cpp:320] Persisted replica status to STARTING
I0121 18:10:14.705314 1929 master.cpp:569] Authorization enabled
I0121 18:10:14.705494 1926 recover.cpp:473] Replica is in STARTING status
I0121 18:10:14.705658 1923 hierarchical.cpp:145] Initialized hierarchical allocator process
I0121 18:10:14.705765 1926 whitelist_watcher.cpp:77] No whitelist given
I0121 18:10:14.706622 1926 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13731)@172.17.0.4:58758
I0121 18:10:14.707176 1932 recover.cpp:193] Received a recover response from a replica in STARTING status
I0121 18:10:14.707669 1923 recover.cpp:564] Updating replica status to VOTING
I0121 18:10:14.708727 1923 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 529931ns
I0121 18:10:14.708755 1923 replica.cpp:320] Persisted replica status to VOTING
I0121 18:10:14.708798 1929 master.cpp:1710] The newly elected leader is master@172.17.0.4:58758 with id baebf4e0-997d-44d4-962d-664ca6b5f779
I0121 18:10:14.708842 1929 master.cpp:1723] Elected as the leading master!
I0121 18:10:14.708868 1929 master.cpp:1468] Recovering from registrar
I0121 18:10:14.709071 1923 recover.cpp:578] Successfully joined the Paxos group
I0121 18:10:14.709273 1931 registrar.cpp:307] Recovering registrar
I0121 18:10:14.709390 1923 recover.cpp:462] Recover process terminated
I0121 18:10:14.710141 1919 log.cpp:659] Attempting to start the writer
I0121 18:10:14.711411 1924 replica.cpp:493] Replica received implicit promise request from (13732)@172.17.0.4:58758 with proposal 1
I0121 18:10:14.711879 1924 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 433950ns
I0121 18:10:14.711902 1924 replica.cpp:342] Persisted promised to 1
I0121 18:10:14.712477 1925 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0121 18:10:14.713608 1926 replica.cpp:388] Replica received explicit promise request from (13733)@172.17.0.4:58758 for position 0 with proposal 2
I0121 18:10:14.714025 1926 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 377232ns
I0121 18:10:14.714048 1926 replica.cpp:712] Persisted action at 0
I0121 18:10:14.715108 1917 replica.cpp:537] Replica received write request for position 0 from (13734)@172.17.0.4:58758
I0121 18:10:14.715173 1917 leveldb.cpp:436] Reading position from leveldb took 35151ns
I0121 18:10:14.715543 1917 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 328224ns
I0121 18:10:14.715565 1917 replica.cpp:712] Persisted action at 0
I0121 18:10:14.716136 1930 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0121 18:10:14.716534 1930 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 365273ns
I0121 18:10:14.716564 1930 replica.cpp:712] Persisted action at 0
I0121 18:10:14.716584 1930 replica.cpp:697] Replica learned NOP action at position 0
I0121 18:10:14.717372 1921 log.cpp:675] Writer started with ending position 0
I0121 18:10:14.718384 1926 leveldb.cpp:436] Reading position from leveldb took 50018ns
I0121 18:10:14.719277 1927 registrar.cpp:340] Successfully fetched the registry (0B) in 9.939968ms
I0121 18:10:14.719389 1927 registrar.cpp:439] Applied 1 operations in 30773ns; attempting to update the 'registry'
I0121 18:10:14.720100 1925 log.cpp:683] Attempting to append 170 bytes to the log
I0121 18:10:14.720268 1920 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0121 18:10:14.720993 1930 replica.cpp:537] Replica received write request for position 1 from (13735)@172.17.0.4:58758
I0121 18:10:14.721485 1930 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 452776ns
I0121 18:10:14.721508 1930 replica.cpp:712] Persisted action at 1
I0121 18:10:14.722069 1925 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0121 18:10:14.722440 1925 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 344503ns
I0121 18:10:14.722463 1925 replica.cpp:712] Persisted action at 1
I0121 18:10:14.722482 1925 replica.cpp:697] Replica learned APPEND action at position 1
I0121 18:10:14.723397 1924 registrar.cpp:484] Successfully updated the 'registry' in 3.949056ms
I0121 18:10:14.723536 1924 registrar.cpp:370] Successfully recovered registrar
I0121 18:10:14.723608 1917 log.cpp:702] Attempting to truncate the log to 1
I0121 18:10:14.723731 1930 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0121 18:10:14.724021 1927 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0121 18:10:14.724042 1932 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0121 18:10:14.724702 1922 replica.cpp:537] Replica received write request for position 2 from (13736)@172.17.0.4:58758
I0121 18:10:14.725067 1922 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 329381ns
I0121 18:10:14.725091 1922 replica.cpp:712] Persisted action at 2
I0121 18:10:14.725538 1925 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0121 18:10:14.725898 1925 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 328657ns
I0121 18:10:14.725952 1925 leveldb.cpp:399] Deleting ~1 keys from leveldb took 30240ns
I0121 18:10:14.725975 1925 replica.cpp:712] Persisted action at 2
I0121 18:10:14.725992 1925 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0121 18:10:14.734984 1898 scheduler.cpp:154] Version: 0.27.0
I0121 18:10:14.736330 1922 scheduler.cpp:236] New master detected at master@172.17.0.4:58758
I0121 18:10:14.741005 1919 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:58758
I0121 18:10:14.743896 1922 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0121 18:10:14.744557 1929 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:45711
I0121 18:10:14.744874 1929 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0121 18:10:14.744957 1929 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0121 18:10:14.745899 1922 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0121 18:10:14.746623 1922 hierarchical.cpp:266] Added framework baebf4e0-997d-44d4-962d-664ca6b5f779-0000
I0121 18:10:14.746707 1922 hierarchical.cpp:1345] No resources available to allocate!
I0121 18:10:14.746753 1922 hierarchical.cpp:1439] No inverse offers to send out!
I0121 18:10:14.746788 1922 hierarchical.cpp:1086] Performed allocation for 0 slaves in 135897ns
I0121 18:10:14.746870 1928 master.hpp:1658] Sending heartbeat to baebf4e0-997d-44d4-962d-664ca6b5f779-0000
I0121 18:10:14.747697 1929 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:58758
I0121 18:10:14.748282 1929 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:58758
I0121 18:10:14.749143 1919 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0121 18:10:14.749569 1918 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:58758
I0121 18:10:14.751554 1928 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0121 18:10:14.752331 1919 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:45712
I0121 18:10:14.752480 1919 master.cpp:2717] Processing REQUEST call for framework baebf4e0-997d-44d4-962d-664ca6b5f779-0000 (default)
I0121 18:10:14.752652 1930 hierarchical.cpp:586] Received resource request from framework baebf4e0-997d-44d4-962d-664ca6b5f779-0000
I0121 18:10:14.753047 1898 master.cpp:1025] Master terminating
I0121 18:10:14.754041 1922 hierarchical.cpp:327] Removed framework baebf4e0-997d-44d4-962d-664ca6b5f779-0000
E0121 18:10:14.755328 1926 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (65 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0121 18:10:14.765249 1898 leveldb.cpp:174] Opened db in 2.736504ms
I0121 18:10:14.766029 1898 leveldb.cpp:181] Compacted db in 726770ns
I0121 18:10:14.766085 1898 leveldb.cpp:196] Created db iterator in 25131ns
I0121 18:10:14.766103 1898 leveldb.cpp:202] Seeked to beginning of db in 2034ns
I0121 18:10:14.766110 1898 leveldb.cpp:271] Iterated through 0 keys in the db in 282ns
I0121 18:10:14.766162 1898 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0121 18:10:14.766798 1919 recover.cpp:447] Starting replica recovery
I0121 18:10:14.767094 1921 recover.cpp:473] Replica is in EMPTY status
I0121 18:10:14.768481 1922 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13744)@172.17.0.4:58758
I0121 18:10:14.768908 1926 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0121 18:10:14.769428 1922 recover.cpp:564] Updating replica status to STARTING
I0121 18:10:14.769858 1924 master.cpp:374] Master 023a310b-f670-4c6c-9b08-6ff437fe267a (5fba7e84f7c1) started on 172.17.0.4:58758
I0121 18:10:14.769888 1924 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/a5xU7x/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/a5xU7x/master" --zk_session_timeout="10secs"
I0121 18:10:14.770293 1924 master.cpp:423] Master allowing unauthenticated frameworks to register
I0121 18:10:14.770309 1924 master.cpp:426] Master only allowing authenticated slaves to register
I0121 18:10:14.770321 1924 credentials.hpp:35] Loading credentials for authentication from '/tmp/a5xU7x/credentials'
I0121 18:10:14.770388 1922 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 660418ns
I0121 18:10:14.770416 1922 replica.cpp:320] Persisted replica status to STARTING
I0121 18:10:14.770675 1926 recover.cpp:473] Replica is in STARTING status
I0121 18:10:14.770740 1924 master.cpp:466] Using default 'crammd5' authenticator
I0121 18:10:14.771488 1924 master.cpp:535] Using default 'basic' HTTP authenticator
I0121 18:10:14.771664 1924 master.cpp:569] Authorization enabled
I0121 18:10:14.771659 1929 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13745)@172.17.0.4:58758
I0121 18:10:14.771883 1927 whitelist_watcher.cpp:77] No whitelist given
I0121 18:10:14.771975 1926 recover.cpp:193] Received a recover response from a replica in STARTING status
I0121 18:10:14.772368 1932 hierarchical.cpp:145] Initialized hierarchical allocator process
I0121 18:10:14.772544 1927 recover.cpp:564] Updating replica status to VOTING
I0121 18:10:14.773059 1920 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 299773ns
I0121 18:10:14.773082 1920 replica.cpp:320] Persisted replica status to VOTING
I0121 18:10:14.773202 1920 recover.cpp:578] Successfully joined the Paxos group
I0121 18:10:14.773443 1920 recover.cpp:462] Recover process terminated
I0121 18:10:14.774312 1925 master.cpp:1710] The newly elected leader is master@172.17.0.4:58758 with id 023a310b-f670-4c6c-9b08-6ff437fe267a
I0121 18:10:14.774432 1925 master.cpp:1723] Elected as the leading master!
I0121 18:10:14.774467 1925 master.cpp:1468] Recovering from registrar
I0121 18:10:14.774617 1929 registrar.cpp:307] Recovering registrar
I0121 18:10:14.775212 1931 log.cpp:659] Attempting to start the writer
I0121 18:10:14.776401 1927 replica.cpp:493] Replica received implicit promise request from (13747)@172.17.0.4:58758 with proposal 1
I0121 18:10:14.776722 1927 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 290344ns
I0121 18:10:14.776744 1927 replica.cpp:342] Persisted promised to 1
I0121 18:10:14.777271 1924 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0121 18:10:14.778292 1931 replica.cpp:388] Replica received explicit promise request from (13748)@172.17.0.4:58758 for position 0 with proposal 2
I0121 18:10:14.778631 1931 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 301403ns
I0121 18:10:14.778655 1931 replica.cpp:712] Persisted action at 0
I0121 18:10:14.779567 1919 replica.cpp:537] Replica received write request for position 0 from (13749)@172.17.0.4:58758
I0121 18:10:14.779633 1919 leveldb.cpp:436] Reading position from leveldb took 33463ns
I0121 18:10:14.782363 1919 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 2.680892ms
I0121 18:10:14.782395 1919 replica.cpp:712] Persisted action at 0
I0121 18:10:14.782948 1932 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0121 18:10:14.783330 1932 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 354049ns
I0121 18:10:14.783352 1932 replica.cpp:712] Persisted action at 0
I0121 18:10:14.783367 1932 replica.cpp:697] Replica learned NOP action at position 0
I0121 18:10:14.783946 1923 log.cpp:675] Writer started with ending position 0
I0121 18:10:14.785066 1928 leveldb.cpp:436] Reading position from leveldb took 23746ns
I0121 18:10:14.785943 1924 registrar.cpp:340] Successfully fetched the registry (0B) in 11.279104ms
I0121 18:10:14.786056 1924 registrar.cpp:439] Applied 1 operations in 31354ns; attempting to update the 'registry'
I0121 18:10:14.786736 1920 log.cpp:683] Attempting to append 170 bytes to the log
I0121 18:10:14.786916 1925 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0121 18:10:14.787575 1922 replica.cpp:537] Replica received write request for position 1 from (13750)@172.17.0.4:58758
I0121 18:10:14.787941 1922 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 331858ns
I0121 18:10:14.787964 1922 replica.cpp:712] Persisted action at 1
I0121 18:10:14.788509 1930 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0121 18:10:14.788874 1930 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 331737ns
I0121 18:10:14.788898 1930 replica.cpp:712] Persisted action at 1
I0121 18:10:14.788918 1930 replica.cpp:697] Replica learned APPEND action at position 1
I0121 18:10:14.789809 1917 registrar.cpp:484] Successfully updated the 'registry' in 3.684864ms
I0121 18:10:14.789979 1917 registrar.cpp:370] Successfully recovered registrar
I0121 18:10:14.790077 1921 log.cpp:702] Attempting to truncate the log to 1
I0121 18:10:14.790277 1917 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0121 18:10:14.790375 1923 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0121 18:10:14.790524 1923 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0121 18:10:14.791081 1927 replica.cpp:537] Replica received write request for position 2 from (13751)@172.17.0.4:58758
I0121 18:10:14.791438 1927 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 314400ns
I0121 18:10:14.791461 1927 replica.cpp:712] Persisted action at 2
I0121 18:10:14.792137 1918 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0121 18:10:14.792470 1918 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 302376ns
I0121 18:10:14.792522 1918 leveldb.cpp:399] Deleting ~1 keys from leveldb took 29024ns
I0121 18:10:14.792542 1918 replica.cpp:712] Persisted action at 2
I0121 18:10:14.792558 1918 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0121 18:10:14.801365 1898 scheduler.cpp:154] Version: 0.27.0
I0121 18:10:14.802073 1921 scheduler.cpp:236] New master detected at master@172.17.0.4:58758
I0121 18:10:14.803088 1917 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:58758
I0121 18:10:14.804975 1932 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0121 18:10:14.805469 1922 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:45713
I0121 18:10:14.805878 1922 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0121 18:10:14.805948 1922 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0121 18:10:14.806216 1922 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0121 18:10:14.806692 1917 hierarchical.cpp:266] Added framework 023a310b-f670-4c6c-9b08-6ff437fe267a-0000
I0121 18:10:14.806779 1917 hierarchical.cpp:1345] No resources available to allocate!
I0121 18:10:14.806785 1922 master.hpp:1658] Sending heartbeat to 023a310b-f670-4c6c-9b08-6ff437fe267a-0000
I0121 18:10:14.807076 1917 hierarchical.cpp:1439] No inverse offers to send out!
I0121 18:10:14.807114 1917 hierarchical.cpp:1086] Performed allocation for 0 slaves in 395630ns
I0121 18:10:14.807653 1917 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:58758
I0121 18:10:14.808151 1917 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:58758
I0121 18:10:14.808873 1928 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0121 18:10:14.808897 1917 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:58758
I0121 18:10:14.810317 1918 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0121 18:10:14.810724 1925 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:45714
I0121 18:10:14.810992 1925 master.cpp:2717] Processing REQUEST call for framework 023a310b-f670-4c6c-9b08-6ff437fe267a-0000 (default)
I0121 18:10:14.811187 1927 hierarchical.cpp:586] Received resource request from framework 023a310b-f670-4c6c-9b08-6ff437fe267a-0000
I0121 18:10:14.811547 1930 master.cpp:1025] Master terminating
I0121 18:10:14.811887 1919 hierarchical.cpp:327] Removed framework 023a310b-f670-4c6c-9b08-6ff437fe267a-0000
E0121 18:10:14.812597 1926 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (56 ms)
[----------] 22 tests from ContentType/SchedulerTest (4381 ms total)
[----------] Global test environment tear-down
[==========] 941 tests from 125 test cases ran. (373705 ms total)
[ PASSED ] 940 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] MasterTest.MaxCompletedTasksPerFrameworkFlag
1 FAILED TEST
YOU HAVE 8 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1453398088-21856
Untagged: mesos-1453398088-21856:latest
Deleted: 4e815bcacc52d81cdbe6f6246081d9a929a471b4ea158a62486a15071446ef6e
Deleted: 3733e1a854564df036c2e5d9551b29fd89d70fe6fa963e36c63050b913205a97
Deleted: 92d23c8dd69db00ce8364b384ffb67abd26ae418b3493b8b6438294e4aea3f73
Deleted: bc38ac42f61f69932c774cc63f7e63d1f1b12695ef803b1ffa3a218b3e62dc28
Deleted: 000a8466ae344a1dff4b3fa7ea5575759cbe836760550643cc912e56cce99658
Deleted: 1b7caf15bd49162dca605d9eff0eca4f48821181a4e524c0eafc2ff1f7e18770
Deleted: 80703cee9f117966e6437a45ebfaff2d38a0b05da315a5554c166a82d3379d11
Deleted: fbac4e562c55ea4fb5d14711910c49ea43f5e11b1b34e949c35d2d077aa66ce4
Deleted: 5724abda592b93716515817713e49efed05fcdaee78e519656c6143e50a9b436
Deleted: f2a8b04b70df17931316ff85b8140fe4ff24e5d3c26fe9ef03cc5b62b049e630
Deleted: 72e64c86c8911cb8ac6062e837106816bb92998377088053484dfa77dc97ef50
Deleted: 7e0706018e762ed04d1f0546e7883edbb1a933c5d0f15f0448f3e0a9712e7bba
Deleted: 0f260feb47bc6e00f5602b736ae60a6503cef301aba7278a56c1d60eeee16ea3
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose --enable-libevent --enable-ssl,centos:7,docker||Hadoop #1528
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=centos%3A7,label_exp=docker%7C%7CHadoop/1528/changes>
Re: Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,centos:7,docker||Hadoop #1527
Posted by Benjamin Mahler <bm...@apache.org>.
Fix is coming for this one.
On Thu, Jan 21, 2016 at 10:10 AM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1527/changes
> >
>
> Changes:
>
> [yujie.jay] Added tests for the Docker URI fetcher plugin.
>
> ------------------------------------------
> [...truncated 155562 lines...]
> I0121 18:10:14.692754 1923 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_woi5jD/slaves/0851deec-a714-4385-a421-5fa8c00c9a88-S0/frameworks/0851deec-a714-4385-a421-5fa8c00c9a88-0000/executors/default'
> for gc 6.99999198320593days in the future
> I0121 18:10:14.692880 1932 status_update_manager.cpp:282] Closing status
> update streams for framework 0851deec-a714-4385-a421-5fa8c00c9a88-0000
> I0121 18:10:14.692925 1923 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_woi5jD/slaves/0851deec-a714-4385-a421-5fa8c00c9a88-S0/frameworks/0851deec-a714-4385-a421-5fa8c00c9a88-0000'
> for gc 6.99999198138963days in the future
> I0121 18:10:14.693023 1932 status_update_manager.cpp:528] Cleaning up
> status update stream for task 7b0dd572-f0ce-47a8-ad99-ff5ad96f5bb0 of
> framework 0851deec-a714-4385-a421-5fa8c00c9a88-0000
> [ OK ] ContentType/SchedulerTest.Message/1 (101 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> I0121 18:10:14.699286 1898 leveldb.cpp:174] Opened db in 2.253522ms
> I0121 18:10:14.700472 1898 leveldb.cpp:181] Compacted db in 1.141335ms
> I0121 18:10:14.700557 1898 leveldb.cpp:196] Created db iterator in 25472ns
> I0121 18:10:14.700577 1898 leveldb.cpp:202] Seeked to beginning of db in
> 2141ns
> I0121 18:10:14.700587 1898 leveldb.cpp:271] Iterated through 0 keys in
> the db in 255ns
> I0121 18:10:14.700637 1898 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0121 18:10:14.701287 1921 recover.cpp:447] Starting replica recovery
> I0121 18:10:14.701582 1929 recover.cpp:473] Replica is in EMPTY status
> I0121 18:10:14.702826 1929 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (13729)@172.17.0.4:58758
> I0121 18:10:14.703475 1917 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0121 18:10:14.703953 1929 master.cpp:374] Master
> baebf4e0-997d-44d4-962d-664ca6b5f779 (5fba7e84f7c1) started on
> 172.17.0.4:58758
> I0121 18:10:14.704131 1922 recover.cpp:564] Updating replica status to
> STARTING
> I0121 18:10:14.703977 1929 master.cpp:376] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/gzHsez/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="25secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui"
> --work_dir="/tmp/gzHsez/master" --zk_session_timeout="10secs"
> I0121 18:10:14.704457 1929 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0121 18:10:14.704475 1929 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0121 18:10:14.704488 1929 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/gzHsez/credentials'
> I0121 18:10:14.704936 1929 master.cpp:466] Using default 'crammd5'
> authenticator
> I0121 18:10:14.705107 1929 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0121 18:10:14.705173 1922 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 723118ns
> I0121 18:10:14.705199 1922 replica.cpp:320] Persisted replica status to
> STARTING
> I0121 18:10:14.705314 1929 master.cpp:569] Authorization enabled
> I0121 18:10:14.705494 1926 recover.cpp:473] Replica is in STARTING status
> I0121 18:10:14.705658 1923 hierarchical.cpp:145] Initialized hierarchical
> allocator process
> I0121 18:10:14.705765 1926 whitelist_watcher.cpp:77] No whitelist given
> I0121 18:10:14.706622 1926 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (13731)@172.17.0.4:58758
> I0121 18:10:14.707176 1932 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0121 18:10:14.707669 1923 recover.cpp:564] Updating replica status to
> VOTING
> I0121 18:10:14.708727 1923 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 529931ns
> I0121 18:10:14.708755 1923 replica.cpp:320] Persisted replica status to
> VOTING
> I0121 18:10:14.708798 1929 master.cpp:1710] The newly elected leader is
> master@172.17.0.4:58758 with id baebf4e0-997d-44d4-962d-664ca6b5f779
> I0121 18:10:14.708842 1929 master.cpp:1723] Elected as the leading master!
> I0121 18:10:14.708868 1929 master.cpp:1468] Recovering from registrar
> I0121 18:10:14.709071 1923 recover.cpp:578] Successfully joined the Paxos
> group
> I0121 18:10:14.709273 1931 registrar.cpp:307] Recovering registrar
> I0121 18:10:14.709390 1923 recover.cpp:462] Recover process terminated
> I0121 18:10:14.710141 1919 log.cpp:659] Attempting to start the writer
> I0121 18:10:14.711411 1924 replica.cpp:493] Replica received implicit
> promise request from (13732)@172.17.0.4:58758 with proposal 1
> I0121 18:10:14.711879 1924 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 433950ns
> I0121 18:10:14.711902 1924 replica.cpp:342] Persisted promised to 1
> I0121 18:10:14.712477 1925 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0121 18:10:14.713608 1926 replica.cpp:388] Replica received explicit
> promise request from (13733)@172.17.0.4:58758 for position 0 with
> proposal 2
> I0121 18:10:14.714025 1926 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 377232ns
> I0121 18:10:14.714048 1926 replica.cpp:712] Persisted action at 0
> I0121 18:10:14.715108 1917 replica.cpp:537] Replica received write
> request for position 0 from (13734)@172.17.0.4:58758
> I0121 18:10:14.715173 1917 leveldb.cpp:436] Reading position from leveldb
> took 35151ns
> I0121 18:10:14.715543 1917 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 328224ns
> I0121 18:10:14.715565 1917 replica.cpp:712] Persisted action at 0
> I0121 18:10:14.716136 1930 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0121 18:10:14.716534 1930 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 365273ns
> I0121 18:10:14.716564 1930 replica.cpp:712] Persisted action at 0
> I0121 18:10:14.716584 1930 replica.cpp:697] Replica learned NOP action at
> position 0
> I0121 18:10:14.717372 1921 log.cpp:675] Writer started with ending
> position 0
> I0121 18:10:14.718384 1926 leveldb.cpp:436] Reading position from leveldb
> took 50018ns
> I0121 18:10:14.719277 1927 registrar.cpp:340] Successfully fetched the
> registry (0B) in 9.939968ms
> I0121 18:10:14.719389 1927 registrar.cpp:439] Applied 1 operations in
> 30773ns; attempting to update the 'registry'
> I0121 18:10:14.720100 1925 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0121 18:10:14.720268 1920 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0121 18:10:14.720993 1930 replica.cpp:537] Replica received write
> request for position 1 from (13735)@172.17.0.4:58758
> I0121 18:10:14.721485 1930 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 452776ns
> I0121 18:10:14.721508 1930 replica.cpp:712] Persisted action at 1
> I0121 18:10:14.722069 1925 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0121 18:10:14.722440 1925 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 344503ns
> I0121 18:10:14.722463 1925 replica.cpp:712] Persisted action at 1
> I0121 18:10:14.722482 1925 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0121 18:10:14.723397 1924 registrar.cpp:484] Successfully updated the
> 'registry' in 3.949056ms
> I0121 18:10:14.723536 1924 registrar.cpp:370] Successfully recovered
> registrar
> I0121 18:10:14.723608 1917 log.cpp:702] Attempting to truncate the log to
> 1
> I0121 18:10:14.723731 1930 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0121 18:10:14.724021 1927 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0121 18:10:14.724042 1932 hierarchical.cpp:172] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0121 18:10:14.724702 1922 replica.cpp:537] Replica received write
> request for position 2 from (13736)@172.17.0.4:58758
> I0121 18:10:14.725067 1922 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 329381ns
> I0121 18:10:14.725091 1922 replica.cpp:712] Persisted action at 2
> I0121 18:10:14.725538 1925 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0121 18:10:14.725898 1925 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 328657ns
> I0121 18:10:14.725952 1925 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 30240ns
> I0121 18:10:14.725975 1925 replica.cpp:712] Persisted action at 2
> I0121 18:10:14.725992 1925 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0121 18:10:14.734984 1898 scheduler.cpp:154] Version: 0.27.0
> I0121 18:10:14.736330 1922 scheduler.cpp:236] New master detected at
> master@172.17.0.4:58758
> I0121 18:10:14.741005 1919 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.4:58758
> I0121 18:10:14.743896 1922 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0121 18:10:14.744557 1929 http.cpp:503] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:45711
> I0121 18:10:14.744874 1929 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0121 18:10:14.744957 1929 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0121 18:10:14.745899 1922 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0121 18:10:14.746623 1922 hierarchical.cpp:266] Added framework
> baebf4e0-997d-44d4-962d-664ca6b5f779-0000
> I0121 18:10:14.746707 1922 hierarchical.cpp:1345] No resources available
> to allocate!
> I0121 18:10:14.746753 1922 hierarchical.cpp:1439] No inverse offers to
> send out!
> I0121 18:10:14.746788 1922 hierarchical.cpp:1086] Performed allocation
> for 0 slaves in 135897ns
> I0121 18:10:14.746870 1928 master.hpp:1658] Sending heartbeat to
> baebf4e0-997d-44d4-962d-664ca6b5f779-0000
> I0121 18:10:14.747697 1929 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.4:58758
> I0121 18:10:14.748282 1929 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.4:58758
> I0121 18:10:14.749143 1919 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0121 18:10:14.749569 1918 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.4:58758
> I0121 18:10:14.751554 1928 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0121 18:10:14.752331 1919 http.cpp:503] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:45712
> I0121 18:10:14.752480 1919 master.cpp:2717] Processing REQUEST call for
> framework baebf4e0-997d-44d4-962d-664ca6b5f779-0000 (default)
> I0121 18:10:14.752652 1930 hierarchical.cpp:586] Received resource
> request from framework baebf4e0-997d-44d4-962d-664ca6b5f779-0000
> I0121 18:10:14.753047 1898 master.cpp:1025] Master terminating
> I0121 18:10:14.754041 1922 hierarchical.cpp:327] Removed framework
> baebf4e0-997d-44d4-962d-664ca6b5f779-0000
> E0121 18:10:14.755328 1926 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/0 (65 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> I0121 18:10:14.765249 1898 leveldb.cpp:174] Opened db in 2.736504ms
> I0121 18:10:14.766029 1898 leveldb.cpp:181] Compacted db in 726770ns
> I0121 18:10:14.766085 1898 leveldb.cpp:196] Created db iterator in 25131ns
> I0121 18:10:14.766103 1898 leveldb.cpp:202] Seeked to beginning of db in
> 2034ns
> I0121 18:10:14.766110 1898 leveldb.cpp:271] Iterated through 0 keys in
> the db in 282ns
> I0121 18:10:14.766162 1898 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0121 18:10:14.766798 1919 recover.cpp:447] Starting replica recovery
> I0121 18:10:14.767094 1921 recover.cpp:473] Replica is in EMPTY status
> I0121 18:10:14.768481 1922 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (13744)@172.17.0.4:58758
> I0121 18:10:14.768908 1926 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0121 18:10:14.769428 1922 recover.cpp:564] Updating replica status to
> STARTING
> I0121 18:10:14.769858 1924 master.cpp:374] Master
> 023a310b-f670-4c6c-9b08-6ff437fe267a (5fba7e84f7c1) started on
> 172.17.0.4:58758
> I0121 18:10:14.769888 1924 master.cpp:376] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/a5xU7x/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="25secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui"
> --work_dir="/tmp/a5xU7x/master" --zk_session_timeout="10secs"
> I0121 18:10:14.770293 1924 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0121 18:10:14.770309 1924 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0121 18:10:14.770321 1924 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/a5xU7x/credentials'
> I0121 18:10:14.770388 1922 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 660418ns
> I0121 18:10:14.770416 1922 replica.cpp:320] Persisted replica status to
> STARTING
> I0121 18:10:14.770675 1926 recover.cpp:473] Replica is in STARTING status
> I0121 18:10:14.770740 1924 master.cpp:466] Using default 'crammd5'
> authenticator
> I0121 18:10:14.771488 1924 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0121 18:10:14.771664 1924 master.cpp:569] Authorization enabled
> I0121 18:10:14.771659 1929 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (13745)@172.17.0.4:58758
> I0121 18:10:14.771883 1927 whitelist_watcher.cpp:77] No whitelist given
> I0121 18:10:14.771975 1926 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0121 18:10:14.772368 1932 hierarchical.cpp:145] Initialized hierarchical
> allocator process
> I0121 18:10:14.772544 1927 recover.cpp:564] Updating replica status to
> VOTING
> I0121 18:10:14.773059 1920 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 299773ns
> I0121 18:10:14.773082 1920 replica.cpp:320] Persisted replica status to
> VOTING
> I0121 18:10:14.773202 1920 recover.cpp:578] Successfully joined the Paxos
> group
> I0121 18:10:14.773443 1920 recover.cpp:462] Recover process terminated
> I0121 18:10:14.774312 1925 master.cpp:1710] The newly elected leader is
> master@172.17.0.4:58758 with id 023a310b-f670-4c6c-9b08-6ff437fe267a
> I0121 18:10:14.774432 1925 master.cpp:1723] Elected as the leading master!
> I0121 18:10:14.774467 1925 master.cpp:1468] Recovering from registrar
> I0121 18:10:14.774617 1929 registrar.cpp:307] Recovering registrar
> I0121 18:10:14.775212 1931 log.cpp:659] Attempting to start the writer
> I0121 18:10:14.776401 1927 replica.cpp:493] Replica received implicit
> promise request from (13747)@172.17.0.4:58758 with proposal 1
> I0121 18:10:14.776722 1927 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 290344ns
> I0121 18:10:14.776744 1927 replica.cpp:342] Persisted promised to 1
> I0121 18:10:14.777271 1924 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0121 18:10:14.778292 1931 replica.cpp:388] Replica received explicit
> promise request from (13748)@172.17.0.4:58758 for position 0 with
> proposal 2
> I0121 18:10:14.778631 1931 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 301403ns
> I0121 18:10:14.778655 1931 replica.cpp:712] Persisted action at 0
> I0121 18:10:14.779567 1919 replica.cpp:537] Replica received write
> request for position 0 from (13749)@172.17.0.4:58758
> I0121 18:10:14.779633 1919 leveldb.cpp:436] Reading position from leveldb
> took 33463ns
> I0121 18:10:14.782363 1919 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 2.680892ms
> I0121 18:10:14.782395 1919 replica.cpp:712] Persisted action at 0
> I0121 18:10:14.782948 1932 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0121 18:10:14.783330 1932 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 354049ns
> I0121 18:10:14.783352 1932 replica.cpp:712] Persisted action at 0
> I0121 18:10:14.783367 1932 replica.cpp:697] Replica learned NOP action at
> position 0
> I0121 18:10:14.783946 1923 log.cpp:675] Writer started with ending
> position 0
> I0121 18:10:14.785066 1928 leveldb.cpp:436] Reading position from leveldb
> took 23746ns
> I0121 18:10:14.785943 1924 registrar.cpp:340] Successfully fetched the
> registry (0B) in 11.279104ms
> I0121 18:10:14.786056 1924 registrar.cpp:439] Applied 1 operations in
> 31354ns; attempting to update the 'registry'
> I0121 18:10:14.786736 1920 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0121 18:10:14.786916 1925 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0121 18:10:14.787575 1922 replica.cpp:537] Replica received write
> request for position 1 from (13750)@172.17.0.4:58758
> I0121 18:10:14.787941 1922 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 331858ns
> I0121 18:10:14.787964 1922 replica.cpp:712] Persisted action at 1
> I0121 18:10:14.788509 1930 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0121 18:10:14.788874 1930 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 331737ns
> I0121 18:10:14.788898 1930 replica.cpp:712] Persisted action at 1
> I0121 18:10:14.788918 1930 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0121 18:10:14.789809 1917 registrar.cpp:484] Successfully updated the
> 'registry' in 3.684864ms
> I0121 18:10:14.789979 1917 registrar.cpp:370] Successfully recovered
> registrar
> I0121 18:10:14.790077 1921 log.cpp:702] Attempting to truncate the log to
> 1
> I0121 18:10:14.790277 1917 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0121 18:10:14.790375 1923 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0121 18:10:14.790524 1923 hierarchical.cpp:172] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0121 18:10:14.791081 1927 replica.cpp:537] Replica received write
> request for position 2 from (13751)@172.17.0.4:58758
> I0121 18:10:14.791438 1927 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 314400ns
> I0121 18:10:14.791461 1927 replica.cpp:712] Persisted action at 2
> I0121 18:10:14.792137 1918 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0121 18:10:14.792470 1918 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 302376ns
> I0121 18:10:14.792522 1918 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 29024ns
> I0121 18:10:14.792542 1918 replica.cpp:712] Persisted action at 2
> I0121 18:10:14.792558 1918 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0121 18:10:14.801365 1898 scheduler.cpp:154] Version: 0.27.0
> I0121 18:10:14.802073 1921 scheduler.cpp:236] New master detected at
> master@172.17.0.4:58758
> I0121 18:10:14.803088 1917 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.4:58758
> I0121 18:10:14.804975 1932 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0121 18:10:14.805469 1922 http.cpp:503] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:45713
> I0121 18:10:14.805878 1922 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0121 18:10:14.805948 1922 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0121 18:10:14.806216 1922 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0121 18:10:14.806692 1917 hierarchical.cpp:266] Added framework
> 023a310b-f670-4c6c-9b08-6ff437fe267a-0000
> I0121 18:10:14.806779 1917 hierarchical.cpp:1345] No resources available
> to allocate!
> I0121 18:10:14.806785 1922 master.hpp:1658] Sending heartbeat to
> 023a310b-f670-4c6c-9b08-6ff437fe267a-0000
> I0121 18:10:14.807076 1917 hierarchical.cpp:1439] No inverse offers to
> send out!
> I0121 18:10:14.807114 1917 hierarchical.cpp:1086] Performed allocation
> for 0 slaves in 395630ns
> I0121 18:10:14.807653 1917 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.4:58758
> I0121 18:10:14.808151 1917 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.4:58758
> I0121 18:10:14.808873 1928 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0121 18:10:14.808897 1917 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.4:58758
> I0121 18:10:14.810317 1918 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0121 18:10:14.810724 1925 http.cpp:503] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:45714
> I0121 18:10:14.810992 1925 master.cpp:2717] Processing REQUEST call for
> framework 023a310b-f670-4c6c-9b08-6ff437fe267a-0000 (default)
> I0121 18:10:14.811187 1927 hierarchical.cpp:586] Received resource
> request from framework 023a310b-f670-4c6c-9b08-6ff437fe267a-0000
> I0121 18:10:14.811547 1930 master.cpp:1025] Master terminating
> I0121 18:10:14.811887 1919 hierarchical.cpp:327] Removed framework
> 023a310b-f670-4c6c-9b08-6ff437fe267a-0000
> E0121 18:10:14.812597 1926 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (56 ms)
> [----------] 22 tests from ContentType/SchedulerTest (4381 ms total)
>
> [----------] Global test environment tear-down
> [==========] 941 tests from 125 test cases ran. (373705 ms total)
> [ PASSED ] 940 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] MasterTest.MaxCompletedTasksPerFrameworkFlag
>
> 1 FAILED TEST
> YOU HAVE 8 DISABLED TESTS
>
> make[4]: *** [check-local] Error 1
> make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
> make: *** [distcheck] Error 1
> + docker rmi mesos-1453398088-21856
> Untagged: mesos-1453398088-21856:latest
> Deleted: 4e815bcacc52d81cdbe6f6246081d9a929a471b4ea158a62486a15071446ef6e
> Deleted: 3733e1a854564df036c2e5d9551b29fd89d70fe6fa963e36c63050b913205a97
> Deleted: 92d23c8dd69db00ce8364b384ffb67abd26ae418b3493b8b6438294e4aea3f73
> Deleted: bc38ac42f61f69932c774cc63f7e63d1f1b12695ef803b1ffa3a218b3e62dc28
> Deleted: 000a8466ae344a1dff4b3fa7ea5575759cbe836760550643cc912e56cce99658
> Deleted: 1b7caf15bd49162dca605d9eff0eca4f48821181a4e524c0eafc2ff1f7e18770
> Deleted: 80703cee9f117966e6437a45ebfaff2d38a0b05da315a5554c166a82d3379d11
> Deleted: fbac4e562c55ea4fb5d14711910c49ea43f5e11b1b34e949c35d2d077aa66ce4
> Deleted: 5724abda592b93716515817713e49efed05fcdaee78e519656c6143e50a9b436
> Deleted: f2a8b04b70df17931316ff85b8140fe4ff24e5d3c26fe9ef03cc5b62b049e630
> Deleted: 72e64c86c8911cb8ac6062e837106816bb92998377088053484dfa77dc97ef50
> Deleted: 7e0706018e762ed04d1f0546e7883edbb1a933c5d0f15f0448f3e0a9712e7bba
> Deleted: 0f260feb47bc6e00f5602b736ae60a6503cef301aba7278a56c1d60eeee16ea3
> Build step 'Execute shell' marked build as failure
>