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/08/26 00:10:41 UTC
Build failed in Jenkins: Mesos » clang,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #729
See <https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/729/changes>
Changes:
[joris.van.remoortere] Added -> operators for Option, Try, Result.
[joris.van.remoortere] Added try_tests.cpp to libprocess makefile.
------------------------------------------
[...truncated 118749 lines...]
I0825 22:09:13.861886 27629 hierarchical.hpp:428] Removed framework 20150825-220913-234885548-51219-27610-0000
I0825 22:09:13.862547 27640 slave.cpp:3143] master@172.17.0.14:51219 exited
W0825 22:09:13.862583 27640 slave.cpp:3146] Master disconnected! Waiting for a new master to be elected
E0825 22:09:13.862613 27634 scheduler.cpp:435] End-Of-File received from master. The master closed the event stream
I0825 22:09:13.865891 27630 slave.cpp:3399] Executor 'default' of framework 20150825-220913-234885548-51219-27610-0000 exited with status 0
I0825 22:09:13.867605 27630 slave.cpp:2696] Handling status update TASK_LOST (UUID: 2ad485a1-4ded-4287-8f08-fa8ab556c333) for task 87043e48-ad19-4d0b-8702-3ab0886c0d74 of framework 20150825-220913-234885548-51219-27610-0000 from @0.0.0.0:0
I0825 22:09:13.867723 27630 slave.cpp:5094] Terminating task 87043e48-ad19-4d0b-8702-3ab0886c0d74
I0825 22:09:13.868093 27630 slave.cpp:564] Slave terminating
I0825 22:09:13.868172 27630 slave.cpp:1959] Asked to shut down framework 20150825-220913-234885548-51219-27610-0000 by @0.0.0.0:0
I0825 22:09:13.868201 27630 slave.cpp:1984] Shutting down framework 20150825-220913-234885548-51219-27610-0000
I0825 22:09:13.868279 27630 slave.cpp:3503] Cleaning up executor 'default' of framework 20150825-220913-234885548-51219-27610-0000
I0825 22:09:13.868466 27643 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_s9tfok/slaves/20150825-220913-234885548-51219-27610-S0/frameworks/20150825-220913-234885548-51219-27610-0000/executors/default/runs/d0496a2d-f815-4f7c-85d5-bbe29cf4de83' for gc 6.99998994908444days in the future
I0825 22:09:13.868621 27630 slave.cpp:3592] Cleaning up framework 20150825-220913-234885548-51219-27610-0000
I0825 22:09:13.868671 27643 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_s9tfok/slaves/20150825-220913-234885548-51219-27610-S0/frameworks/20150825-220913-234885548-51219-27610-0000/executors/default' for gc 6.9999899470963days in the future
I0825 22:09:13.868772 27643 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_s9tfok/slaves/20150825-220913-234885548-51219-27610-S0/frameworks/20150825-220913-234885548-51219-27610-0000' for gc 6.99998994524444days in the future
I0825 22:09:13.868863 27630 status_update_manager.cpp:284] Closing status update streams for framework 20150825-220913-234885548-51219-27610-0000
I0825 22:09:13.869031 27630 status_update_manager.cpp:530] Cleaning up status update stream for task 87043e48-ad19-4d0b-8702-3ab0886c0d74 of framework 20150825-220913-234885548-51219-27610-0000
[ OK ] ContentType/SchedulerTest.Message/1 (127 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
Using temporary directory '/tmp/ContentType_SchedulerTest_Request_0_sq7REb'
I0825 22:09:13.875603 27610 leveldb.cpp:176] Opened db in 2.103165ms
I0825 22:09:13.876490 27610 leveldb.cpp:183] Compacted db in 863600ns
I0825 22:09:13.876540 27610 leveldb.cpp:198] Created db iterator in 32660ns
I0825 22:09:13.876580 27610 leveldb.cpp:204] Seeked to beginning of db in 12423ns
I0825 22:09:13.876597 27610 leveldb.cpp:273] Iterated through 0 keys in the db in 8721ns
I0825 22:09:13.876647 27610 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0825 22:09:13.877125 27643 recover.cpp:449] Starting replica recovery
I0825 22:09:13.877693 27638 recover.cpp:475] Replica is in EMPTY status
I0825 22:09:13.879178 27641 master.cpp:378] Master 20150825-220913-234885548-51219-27610 (09c6504e3a31) started on 172.17.0.14:51219
I0825 22:09:13.879428 27630 replica.cpp:641] Replica in EMPTY status received a broadcasted recover request
I0825 22:09:13.879216 27641 master.cpp:380] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ContentType_SchedulerTest_Request_0_sq7REb/credentials" --framework_sorter="drf" --help="false" --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.25.0/_inst/share/mesos/webui" --work_dir="/tmp/ContentType_SchedulerTest_Request_0_sq7REb/master" --zk_session_timeout="10secs"
I0825 22:09:13.879786 27641 master.cpp:427] Master allowing unauthenticated frameworks to register
I0825 22:09:13.879976 27641 master.cpp:430] Master only allowing authenticated slaves to register
I0825 22:09:13.879992 27641 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_Request_0_sq7REb/credentials'
I0825 22:09:13.880189 27640 recover.cpp:195] Received a recover response from a replica in EMPTY status
I0825 22:09:13.880612 27641 master.cpp:469] Using default 'crammd5' authenticator
I0825 22:09:13.880767 27641 master.cpp:506] Authorization enabled
I0825 22:09:13.880996 27643 whitelist_watcher.cpp:79] No whitelist given
I0825 22:09:13.881162 27638 hierarchical.hpp:346] Initialized hierarchical allocator process
I0825 22:09:13.881288 27638 recover.cpp:566] Updating replica status to STARTING
I0825 22:09:13.882040 27642 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 632331ns
I0825 22:09:13.882138 27642 replica.cpp:323] Persisted replica status to STARTING
I0825 22:09:13.882534 27632 recover.cpp:475] Replica is in STARTING status
I0825 22:09:13.882618 27638 master.cpp:1525] The newly elected leader is master@172.17.0.14:51219 with id 20150825-220913-234885548-51219-27610
I0825 22:09:13.882767 27638 master.cpp:1538] Elected as the leading master!
I0825 22:09:13.882807 27638 master.cpp:1308] Recovering from registrar
I0825 22:09:13.883013 27631 registrar.cpp:311] Recovering registrar
I0825 22:09:13.883785 27628 replica.cpp:641] Replica in STARTING status received a broadcasted recover request
I0825 22:09:13.884124 27635 recover.cpp:195] Received a recover response from a replica in STARTING status
I0825 22:09:13.884512 27643 recover.cpp:566] Updating replica status to VOTING
I0825 22:09:13.885002 27635 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 306520ns
I0825 22:09:13.885025 27635 replica.cpp:323] Persisted replica status to VOTING
I0825 22:09:13.885110 27643 recover.cpp:580] Successfully joined the Paxos group
I0825 22:09:13.885265 27643 recover.cpp:464] Recover process terminated
I0825 22:09:13.885674 27628 log.cpp:661] Attempting to start the writer
I0825 22:09:13.886636 27640 replica.cpp:477] Replica received implicit promise request with proposal 1
I0825 22:09:13.886986 27640 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 334609ns
I0825 22:09:13.887009 27640 replica.cpp:345] Persisted promised to 1
I0825 22:09:13.888054 27639 coordinator.cpp:231] Coordinator attemping to fill missing position
I0825 22:09:13.889037 27630 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2
I0825 22:09:13.889364 27630 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 303523ns
I0825 22:09:13.889386 27630 replica.cpp:679] Persisted action at 0
I0825 22:09:13.890342 27637 replica.cpp:511] Replica received write request for position 0
I0825 22:09:13.890398 27637 leveldb.cpp:438] Reading position from leveldb took 41597ns
I0825 22:09:13.890707 27637 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 280201ns
I0825 22:09:13.890730 27637 replica.cpp:679] Persisted action at 0
I0825 22:09:13.891255 27637 replica.cpp:658] Replica received learned notice for position 0
I0825 22:09:13.891583 27637 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 318193ns
I0825 22:09:13.891613 27637 replica.cpp:679] Persisted action at 0
I0825 22:09:13.891638 27637 replica.cpp:664] Replica learned NOP action at position 0
I0825 22:09:13.892102 27639 log.cpp:677] Writer started with ending position 0
I0825 22:09:13.893057 27641 leveldb.cpp:438] Reading position from leveldb took 43261ns
I0825 22:09:13.895298 27635 registrar.cpp:344] Successfully fetched the registry (0B) in 12.246016ms
I0825 22:09:13.895421 27635 registrar.cpp:443] Applied 1 operations in 38170ns; attempting to update the 'registry'
I0825 22:09:13.897363 27639 log.cpp:685] Attempting to append 174 bytes to the log
I0825 22:09:13.897528 27641 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I0825 22:09:13.898185 27643 replica.cpp:511] Replica received write request for position 1
I0825 22:09:13.898608 27643 leveldb.cpp:343] Persisting action (193 bytes) to leveldb took 399640ns
I0825 22:09:13.898635 27643 replica.cpp:679] Persisted action at 1
I0825 22:09:13.899137 27633 replica.cpp:658] Replica received learned notice for position 1
I0825 22:09:13.899494 27633 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 345421ns
I0825 22:09:13.899520 27633 replica.cpp:679] Persisted action at 1
I0825 22:09:13.899544 27633 replica.cpp:664] Replica learned APPEND action at position 1
I0825 22:09:13.900368 27634 registrar.cpp:488] Successfully updated the 'registry' in 4.890112ms
I0825 22:09:13.900547 27634 registrar.cpp:374] Successfully recovered registrar
I0825 22:09:13.900591 27643 log.cpp:704] Attempting to truncate the log to 1
I0825 22:09:13.900795 27643 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I0825 22:09:13.901029 27634 master.cpp:1335] Recovered 0 slaves from the Registry (135B) ; allowing 10mins for slaves to re-register
I0825 22:09:13.901621 27640 replica.cpp:511] Replica received write request for position 2
I0825 22:09:13.901944 27640 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 299875ns
I0825 22:09:13.901968 27640 replica.cpp:679] Persisted action at 2
I0825 22:09:13.902472 27636 replica.cpp:658] Replica received learned notice for position 2
I0825 22:09:13.902838 27636 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 352156ns
I0825 22:09:13.902897 27636 leveldb.cpp:401] Deleting ~1 keys from leveldb took 46622ns
I0825 22:09:13.902926 27636 replica.cpp:679] Persisted action at 2
I0825 22:09:13.902952 27636 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0825 22:09:13.911948 27610 scheduler.cpp:157] Version: 0.25.0
I0825 22:09:13.913947 27639 scheduler.cpp:240] New master detected at master@172.17.0.14:51219
I0825 22:09:13.914926 27640 scheduler.cpp:302] Sending SUBSCRIBE call to master@172.17.0.14:51219
I0825 22:09:13.917476 27633 process.cpp:3043] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0825 22:09:13.917757 27633 http.cpp:321] HTTP POST for /master/api/v1/scheduler from 172.17.0.14:53386
I0825 22:09:13.918051 27633 master.cpp:1783] Received subscription request for HTTP framework 'default'
I0825 22:09:13.918148 27633 master.cpp:1564] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0825 22:09:13.918601 27635 master.cpp:1875] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0825 22:09:13.918972 27628 hierarchical.hpp:391] Added framework 20150825-220913-234885548-51219-27610-0000
I0825 22:09:13.919013 27628 hierarchical.hpp:1010] No resources available to allocate!
I0825 22:09:13.919065 27628 hierarchical.hpp:910] Performed allocation for 0 slaves in 76310ns
I0825 22:09:13.918977 27638 master.hpp:1308] Sending heartbeat to 20150825-220913-234885548-51219-27610-0000
I0825 22:09:13.920267 27640 scheduler.cpp:461] Enqueuing event SUBSCRIBED received from master@172.17.0.14:51219
I0825 22:09:13.921052 27628 scheduler.cpp:461] Enqueuing event HEARTBEAT received from master@172.17.0.14:51219
I0825 22:09:13.921741 27630 scheduler_tests.cpp:113] Ignoring HEARTBEAT event
I0825 22:09:13.921830 27628 scheduler.cpp:302] Sending REQUEST call to master@172.17.0.14:51219
I0825 22:09:13.923214 27639 process.cpp:3043] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0825 22:09:13.923444 27639 http.cpp:321] HTTP POST for /master/api/v1/scheduler from 172.17.0.14:53387
I0825 22:09:13.923578 27639 master.cpp:2486] Processing REQUEST call for framework 20150825-220913-234885548-51219-27610-0000 (default)
I0825 22:09:13.923759 27631 hierarchical.hpp:668] Received resource request from framework 20150825-220913-234885548-51219-27610-0000
I0825 22:09:13.924083 27639 master.cpp:860] Master terminating
I0825 22:09:13.924222 27640 hierarchical.hpp:428] Removed framework 20150825-220913-234885548-51219-27610-0000
E0825 22:09:13.924842 27629 scheduler.cpp:435] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (57 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
Using temporary directory '/tmp/ContentType_SchedulerTest_Request_1_SADnGt'
I0825 22:09:13.932909 27610 leveldb.cpp:176] Opened db in 2.321244ms
I0825 22:09:13.933758 27610 leveldb.cpp:183] Compacted db in 824246ns
I0825 22:09:13.933809 27610 leveldb.cpp:198] Created db iterator in 32012ns
I0825 22:09:13.933836 27610 leveldb.cpp:204] Seeked to beginning of db in 11437ns
I0825 22:09:13.933854 27610 leveldb.cpp:273] Iterated through 0 keys in the db in 8829ns
I0825 22:09:13.933905 27610 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0825 22:09:13.934375 27643 recover.cpp:449] Starting replica recovery
I0825 22:09:13.934617 27643 recover.cpp:475] Replica is in EMPTY status
I0825 22:09:13.936271 27642 replica.cpp:641] Replica in EMPTY status received a broadcasted recover request
I0825 22:09:13.936769 27642 recover.cpp:195] Received a recover response from a replica in EMPTY status
I0825 22:09:13.937355 27638 master.cpp:378] Master 20150825-220913-234885548-51219-27610 (09c6504e3a31) started on 172.17.0.14:51219
I0825 22:09:13.937438 27642 recover.cpp:566] Updating replica status to STARTING
I0825 22:09:13.937474 27638 master.cpp:380] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ContentType_SchedulerTest_Request_1_SADnGt/credentials" --framework_sorter="drf" --help="false" --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.25.0/_inst/share/mesos/webui" --work_dir="/tmp/ContentType_SchedulerTest_Request_1_SADnGt/master" --zk_session_timeout="10secs"
I0825 22:09:13.937928 27638 master.cpp:427] Master allowing unauthenticated frameworks to register
I0825 22:09:13.938063 27638 master.cpp:430] Master only allowing authenticated slaves to register
I0825 22:09:13.938189 27638 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_Request_1_SADnGt/credentials'
I0825 22:09:13.938272 27641 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 570105ns
I0825 22:09:13.938328 27641 replica.cpp:323] Persisted replica status to STARTING
I0825 22:09:13.938534 27641 recover.cpp:475] Replica is in STARTING status
I0825 22:09:13.938783 27638 master.cpp:469] Using default 'crammd5' authenticator
I0825 22:09:13.939000 27638 master.cpp:506] Authorization enabled
I0825 22:09:13.939327 27643 whitelist_watcher.cpp:79] No whitelist given
I0825 22:09:13.939376 27639 hierarchical.hpp:346] Initialized hierarchical allocator process
I0825 22:09:13.939831 27630 replica.cpp:641] Replica in STARTING status received a broadcasted recover request
I0825 22:09:13.940085 27642 recover.cpp:195] Received a recover response from a replica in STARTING status
I0825 22:09:13.940639 27638 master.cpp:1525] The newly elected leader is master@172.17.0.14:51219 with id 20150825-220913-234885548-51219-27610
I0825 22:09:13.940671 27638 master.cpp:1538] Elected as the leading master!
I0825 22:09:13.940687 27638 master.cpp:1308] Recovering from registrar
I0825 22:09:13.940915 27629 registrar.cpp:311] Recovering registrar
I0825 22:09:13.941086 27643 recover.cpp:566] Updating replica status to VOTING
I0825 22:09:13.941609 27632 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 355183ns
I0825 22:09:13.941635 27632 replica.cpp:323] Persisted replica status to VOTING
I0825 22:09:13.941750 27632 recover.cpp:580] Successfully joined the Paxos group
I0825 22:09:13.941900 27632 recover.cpp:464] Recover process terminated
I0825 22:09:13.942282 27632 log.cpp:661] Attempting to start the writer
I0825 22:09:13.943426 27634 replica.cpp:477] Replica received implicit promise request with proposal 1
I0825 22:09:13.943758 27634 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 317824ns
I0825 22:09:13.943779 27634 replica.cpp:345] Persisted promised to 1
I0825 22:09:13.944403 27631 coordinator.cpp:231] Coordinator attemping to fill missing position
I0825 22:09:13.945358 27631 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2
I0825 22:09:13.945703 27631 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 321070ns
I0825 22:09:13.945726 27631 replica.cpp:679] Persisted action at 0
I0825 22:09:13.946526 27635 replica.cpp:511] Replica received write request for position 0
I0825 22:09:13.946657 27635 leveldb.cpp:438] Reading position from leveldb took 48307ns
I0825 22:09:13.946987 27635 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 294387ns
I0825 22:09:13.947010 27635 replica.cpp:679] Persisted action at 0
I0825 22:09:13.947520 27635 replica.cpp:658] Replica received learned notice for position 0
I0825 22:09:13.948109 27635 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 578626ns
I0825 22:09:13.948132 27635 replica.cpp:679] Persisted action at 0
I0825 22:09:13.948146 27635 replica.cpp:664] Replica learned NOP action at position 0
I0825 22:09:13.948643 27642 log.cpp:677] Writer started with ending position 0
I0825 22:09:13.949584 27640 leveldb.cpp:438] Reading position from leveldb took 65972ns
I0825 22:09:13.952926 27642 registrar.cpp:344] Successfully fetched the registry (0B) in 11.961856ms
I0825 22:09:13.953083 27642 registrar.cpp:443] Applied 1 operations in 57043ns; attempting to update the 'registry'
I0825 22:09:13.955358 27642 log.cpp:685] Attempting to append 174 bytes to the log
I0825 22:09:13.955634 27628 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I0825 22:09:13.956763 27639 replica.cpp:511] Replica received write request for position 1
I0825 22:09:13.957214 27639 leveldb.cpp:343] Persisting action (193 bytes) to leveldb took 426896ns
I0825 22:09:13.957245 27639 replica.cpp:679] Persisted action at 1
I0825 22:09:13.957931 27628 replica.cpp:658] Replica received learned notice for position 1
I0825 22:09:13.958309 27628 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 365487ns
I0825 22:09:13.958345 27628 replica.cpp:679] Persisted action at 1
I0825 22:09:13.958433 27628 replica.cpp:664] Replica learned APPEND action at position 1
I0825 22:09:13.959656 27643 registrar.cpp:488] Successfully updated the 'registry' in 6.381824ms
I0825 22:09:13.959893 27637 log.cpp:704] Attempting to truncate the log to 1
I0825 22:09:13.959972 27643 registrar.cpp:374] Successfully recovered registrar
I0825 22:09:13.960489 27630 master.cpp:1335] Recovered 0 slaves from the Registry (135B) ; allowing 10mins for slaves to re-register
I0825 22:09:13.960759 27641 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I0825 22:09:13.961493 27634 replica.cpp:511] Replica received write request for position 2
I0825 22:09:13.961920 27634 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 403604ns
I0825 22:09:13.961944 27634 replica.cpp:679] Persisted action at 2
I0825 22:09:13.962507 27634 replica.cpp:658] Replica received learned notice for position 2
I0825 22:09:13.962864 27634 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 345942ns
I0825 22:09:13.962930 27634 leveldb.cpp:401] Deleting ~1 keys from leveldb took 55125ns
I0825 22:09:13.962960 27634 replica.cpp:679] Persisted action at 2
I0825 22:09:13.962987 27634 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0825 22:09:13.971457 27610 scheduler.cpp:157] Version: 0.25.0
I0825 22:09:13.974419 27634 scheduler.cpp:240] New master detected at master@172.17.0.14:51219
I0825 22:09:13.975453 27632 scheduler.cpp:302] Sending SUBSCRIBE call to master@172.17.0.14:51219
I0825 22:09:13.977284 27633 process.cpp:3043] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0825 22:09:13.977653 27633 http.cpp:321] HTTP POST for /master/api/v1/scheduler from 172.17.0.14:53388
I0825 22:09:13.978005 27633 master.cpp:1783] Received subscription request for HTTP framework 'default'
I0825 22:09:13.978036 27633 master.cpp:1564] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0825 22:09:13.978327 27633 master.cpp:1875] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0825 22:09:13.978721 27632 hierarchical.hpp:391] Added framework 20150825-220913-234885548-51219-27610-0000
I0825 22:09:13.978759 27632 hierarchical.hpp:1010] No resources available to allocate!
I0825 22:09:13.978775 27632 hierarchical.hpp:910] Performed allocation for 0 slaves in 37630ns
I0825 22:09:13.978862 27633 master.hpp:1308] Sending heartbeat to 20150825-220913-234885548-51219-27610-0000
I0825 22:09:13.979598 27633 scheduler.cpp:461] Enqueuing event SUBSCRIBED received from master@172.17.0.14:51219
I0825 22:09:13.979974 27633 scheduler.cpp:461] Enqueuing event HEARTBEAT received from master@172.17.0.14:51219
I0825 22:09:13.980528 27636 scheduler_tests.cpp:113] Ignoring HEARTBEAT event
I0825 22:09:13.980619 27634 scheduler.cpp:302] Sending REQUEST call to master@172.17.0.14:51219
I0825 22:09:13.981947 27643 process.cpp:3043] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0825 22:09:13.982152 27643 http.cpp:321] HTTP POST for /master/api/v1/scheduler from 172.17.0.14:53389
I0825 22:09:13.982462 27643 master.cpp:2486] Processing REQUEST call for framework 20150825-220913-234885548-51219-27610-0000 (default)
I0825 22:09:13.983168 27643 hierarchical.hpp:668] Received resource request from framework 20150825-220913-234885548-51219-27610-0000
I0825 22:09:13.983490 27636 master.cpp:860] Master terminating
I0825 22:09:13.983759 27640 hierarchical.hpp:428] Removed framework 20150825-220913-234885548-51219-27610-0000
E0825 22:09:13.984733 27630 scheduler.cpp:435] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (59 ms)
[----------] 20 tests from ContentType/SchedulerTest (4009 ms total)
[----------] Global test environment tear-down
[==========] 737 tests from 101 test cases ran. (293700 ms total)
[ PASSED ] 736 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] SlaveTest.HTTPSchedulerSlaveRestart
1 FAILED TEST
YOU HAVE 8 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.25.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1440539455-8310
Untagged: mesos-1440539455-8310:latest
Deleted: acd12e9fe4f4685b34e7ed8350b8221b76acb8157376c9d68c7c968ee7bfa4b9
Deleted: ee33f9c54bdf5d6a61a0f82999b246ca00ec4a32b6aadf31d4df3ad27c1e2057
Deleted: caea2003404d29f724fa1e1d98f0b6b12e003d3a6875e3e53719c5aa384fbcbe
Deleted: 52d6374cc64df4e7fd759792d25615c774047fd39206f27b0d0a28f177185c98
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » clang,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #730
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/730/changes>
Re: Build failed in Jenkins: Mesos » clang,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #729
Posted by Vinod Kone <vi...@apache.org>.
no. filed https://issues.apache.org/jira/browse/MESOS-3311
@anand: can you triage this?
On Tue, Aug 25, 2015 at 3:15 PM, Joris Van Remoortere <
joris.van.remoortere@gmail.com> wrote:
> Have you seen this before?
>
> On Tue, Aug 25, 2015 at 6:10 PM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
>> See <
>> https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/729/changes
>> >
>>
>> Changes:
>>
>> [joris.van.remoortere] Added -> operators for Option, Try, Result.
>>
>> [joris.van.remoortere] Added try_tests.cpp to libprocess makefile.
>>
>> ------------------------------------------
>> [...truncated 118749 lines...]
>> I0825 22:09:13.861886 27629 hierarchical.hpp:428] Removed framework
>> 20150825-220913-234885548-51219-27610-0000
>> I0825 22:09:13.862547 27640 slave.cpp:3143] master@172.17.0.14:51219
>> exited
>> W0825 22:09:13.862583 27640 slave.cpp:3146] Master disconnected! Waiting
>> for a new master to be elected
>> E0825 22:09:13.862613 27634 scheduler.cpp:435] End-Of-File received from
>> master. The master closed the event stream
>> I0825 22:09:13.865891 27630 slave.cpp:3399] Executor 'default' of
>> framework 20150825-220913-234885548-51219-27610-0000 exited with status 0
>> I0825 22:09:13.867605 27630 slave.cpp:2696] Handling status update
>> TASK_LOST (UUID: 2ad485a1-4ded-4287-8f08-fa8ab556c333) for task
>> 87043e48-ad19-4d0b-8702-3ab0886c0d74 of framework
>> 20150825-220913-234885548-51219-27610-0000 from @0.0.0.0:0
>> I0825 22:09:13.867723 27630 slave.cpp:5094] Terminating task
>> 87043e48-ad19-4d0b-8702-3ab0886c0d74
>> I0825 22:09:13.868093 27630 slave.cpp:564] Slave terminating
>> I0825 22:09:13.868172 27630 slave.cpp:1959] Asked to shut down framework
>> 20150825-220913-234885548-51219-27610-0000 by @0.0.0.0:0
>> I0825 22:09:13.868201 27630 slave.cpp:1984] Shutting down framework
>> 20150825-220913-234885548-51219-27610-0000
>> I0825 22:09:13.868279 27630 slave.cpp:3503] Cleaning up executor
>> 'default' of framework 20150825-220913-234885548-51219-27610-0000
>> I0825 22:09:13.868466 27643 gc.cpp:56] Scheduling
>> '/tmp/ContentType_SchedulerTest_Message_1_s9tfok/slaves/20150825-220913-234885548-51219-27610-S0/frameworks/20150825-220913-234885548-51219-27610-0000/executors/default/runs/d0496a2d-f815-4f7c-85d5-bbe29cf4de83'
>> for gc 6.99998994908444days in the future
>> I0825 22:09:13.868621 27630 slave.cpp:3592] Cleaning up framework
>> 20150825-220913-234885548-51219-27610-0000
>> I0825 22:09:13.868671 27643 gc.cpp:56] Scheduling
>> '/tmp/ContentType_SchedulerTest_Message_1_s9tfok/slaves/20150825-220913-234885548-51219-27610-S0/frameworks/20150825-220913-234885548-51219-27610-0000/executors/default'
>> for gc 6.9999899470963days in the future
>> I0825 22:09:13.868772 27643 gc.cpp:56] Scheduling
>> '/tmp/ContentType_SchedulerTest_Message_1_s9tfok/slaves/20150825-220913-234885548-51219-27610-S0/frameworks/20150825-220913-234885548-51219-27610-0000'
>> for gc 6.99998994524444days in the future
>> I0825 22:09:13.868863 27630 status_update_manager.cpp:284] Closing status
>> update streams for framework 20150825-220913-234885548-51219-27610-0000
>> I0825 22:09:13.869031 27630 status_update_manager.cpp:530] Cleaning up
>> status update stream for task 87043e48-ad19-4d0b-8702-3ab0886c0d74 of
>> framework 20150825-220913-234885548-51219-27610-0000
>> [ OK ] ContentType/SchedulerTest.Message/1 (127 ms)
>> [ RUN ] ContentType/SchedulerTest.Request/0
>> Using temporary directory
>> '/tmp/ContentType_SchedulerTest_Request_0_sq7REb'
>> I0825 22:09:13.875603 27610 leveldb.cpp:176] Opened db in 2.103165ms
>> I0825 22:09:13.876490 27610 leveldb.cpp:183] Compacted db in 863600ns
>> I0825 22:09:13.876540 27610 leveldb.cpp:198] Created db iterator in
>> 32660ns
>> I0825 22:09:13.876580 27610 leveldb.cpp:204] Seeked to beginning of db in
>> 12423ns
>> I0825 22:09:13.876597 27610 leveldb.cpp:273] Iterated through 0 keys in
>> the db in 8721ns
>> I0825 22:09:13.876647 27610 replica.cpp:744] Replica recovered with log
>> positions 0 -> 0 with 1 holes and 0 unlearned
>> I0825 22:09:13.877125 27643 recover.cpp:449] Starting replica recovery
>> I0825 22:09:13.877693 27638 recover.cpp:475] Replica is in EMPTY status
>> I0825 22:09:13.879178 27641 master.cpp:378] Master
>> 20150825-220913-234885548-51219-27610 (09c6504e3a31) started on
>> 172.17.0.14:51219
>> I0825 22:09:13.879428 27630 replica.cpp:641] Replica in EMPTY status
>> received a broadcasted recover request
>> I0825 22:09:13.879216 27641 master.cpp:380] Flags at startup: --acls=""
>> --allocation_interval="1secs" --allocator="HierarchicalDRF"
>> --authenticate="false" --authenticate_slaves="true"
>> --authenticators="crammd5" --authorizers="local"
>> --credentials="/tmp/ContentType_SchedulerTest_Request_0_sq7REb/credentials"
>> --framework_sorter="drf" --help="false" --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.25.0/_inst/share/mesos/webui"
>> --work_dir="/tmp/ContentType_SchedulerTest_Request_0_sq7REb/master"
>> --zk_session_timeout="10secs"
>> I0825 22:09:13.879786 27641 master.cpp:427] Master allowing
>> unauthenticated frameworks to register
>> I0825 22:09:13.879976 27641 master.cpp:430] Master only allowing
>> authenticated slaves to register
>> I0825 22:09:13.879992 27641 credentials.hpp:37] Loading credentials for
>> authentication from
>> '/tmp/ContentType_SchedulerTest_Request_0_sq7REb/credentials'
>> I0825 22:09:13.880189 27640 recover.cpp:195] Received a recover response
>> from a replica in EMPTY status
>> I0825 22:09:13.880612 27641 master.cpp:469] Using default 'crammd5'
>> authenticator
>> I0825 22:09:13.880767 27641 master.cpp:506] Authorization enabled
>> I0825 22:09:13.880996 27643 whitelist_watcher.cpp:79] No whitelist given
>> I0825 22:09:13.881162 27638 hierarchical.hpp:346] Initialized
>> hierarchical allocator process
>> I0825 22:09:13.881288 27638 recover.cpp:566] Updating replica status to
>> STARTING
>> I0825 22:09:13.882040 27642 leveldb.cpp:306] Persisting metadata (8
>> bytes) to leveldb took 632331ns
>> I0825 22:09:13.882138 27642 replica.cpp:323] Persisted replica status to
>> STARTING
>> I0825 22:09:13.882534 27632 recover.cpp:475] Replica is in STARTING status
>> I0825 22:09:13.882618 27638 master.cpp:1525] The newly elected leader is
>> master@172.17.0.14:51219 with id 20150825-220913-234885548-51219-27610
>> I0825 22:09:13.882767 27638 master.cpp:1538] Elected as the leading
>> master!
>> I0825 22:09:13.882807 27638 master.cpp:1308] Recovering from registrar
>> I0825 22:09:13.883013 27631 registrar.cpp:311] Recovering registrar
>> I0825 22:09:13.883785 27628 replica.cpp:641] Replica in STARTING status
>> received a broadcasted recover request
>> I0825 22:09:13.884124 27635 recover.cpp:195] Received a recover response
>> from a replica in STARTING status
>> I0825 22:09:13.884512 27643 recover.cpp:566] Updating replica status to
>> VOTING
>> I0825 22:09:13.885002 27635 leveldb.cpp:306] Persisting metadata (8
>> bytes) to leveldb took 306520ns
>> I0825 22:09:13.885025 27635 replica.cpp:323] Persisted replica status to
>> VOTING
>> I0825 22:09:13.885110 27643 recover.cpp:580] Successfully joined the
>> Paxos group
>> I0825 22:09:13.885265 27643 recover.cpp:464] Recover process terminated
>> I0825 22:09:13.885674 27628 log.cpp:661] Attempting to start the writer
>> I0825 22:09:13.886636 27640 replica.cpp:477] Replica received implicit
>> promise request with proposal 1
>> I0825 22:09:13.886986 27640 leveldb.cpp:306] Persisting metadata (8
>> bytes) to leveldb took 334609ns
>> I0825 22:09:13.887009 27640 replica.cpp:345] Persisted promised to 1
>> I0825 22:09:13.888054 27639 coordinator.cpp:231] Coordinator attemping to
>> fill missing position
>> I0825 22:09:13.889037 27630 replica.cpp:378] Replica received explicit
>> promise request for position 0 with proposal 2
>> I0825 22:09:13.889364 27630 leveldb.cpp:343] Persisting action (8 bytes)
>> to leveldb took 303523ns
>> I0825 22:09:13.889386 27630 replica.cpp:679] Persisted action at 0
>> I0825 22:09:13.890342 27637 replica.cpp:511] Replica received write
>> request for position 0
>> I0825 22:09:13.890398 27637 leveldb.cpp:438] Reading position from
>> leveldb took 41597ns
>> I0825 22:09:13.890707 27637 leveldb.cpp:343] Persisting action (14 bytes)
>> to leveldb took 280201ns
>> I0825 22:09:13.890730 27637 replica.cpp:679] Persisted action at 0
>> I0825 22:09:13.891255 27637 replica.cpp:658] Replica received learned
>> notice for position 0
>> I0825 22:09:13.891583 27637 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 318193ns
>> I0825 22:09:13.891613 27637 replica.cpp:679] Persisted action at 0
>> I0825 22:09:13.891638 27637 replica.cpp:664] Replica learned NOP action
>> at position 0
>> I0825 22:09:13.892102 27639 log.cpp:677] Writer started with ending
>> position 0
>> I0825 22:09:13.893057 27641 leveldb.cpp:438] Reading position from
>> leveldb took 43261ns
>> I0825 22:09:13.895298 27635 registrar.cpp:344] Successfully fetched the
>> registry (0B) in 12.246016ms
>> I0825 22:09:13.895421 27635 registrar.cpp:443] Applied 1 operations in
>> 38170ns; attempting to update the 'registry'
>> I0825 22:09:13.897363 27639 log.cpp:685] Attempting to append 174 bytes
>> to the log
>> I0825 22:09:13.897528 27641 coordinator.cpp:341] Coordinator attempting
>> to write APPEND action at position 1
>> I0825 22:09:13.898185 27643 replica.cpp:511] Replica received write
>> request for position 1
>> I0825 22:09:13.898608 27643 leveldb.cpp:343] Persisting action (193
>> bytes) to leveldb took 399640ns
>> I0825 22:09:13.898635 27643 replica.cpp:679] Persisted action at 1
>> I0825 22:09:13.899137 27633 replica.cpp:658] Replica received learned
>> notice for position 1
>> I0825 22:09:13.899494 27633 leveldb.cpp:343] Persisting action (195
>> bytes) to leveldb took 345421ns
>> I0825 22:09:13.899520 27633 replica.cpp:679] Persisted action at 1
>> I0825 22:09:13.899544 27633 replica.cpp:664] Replica learned APPEND
>> action at position 1
>> I0825 22:09:13.900368 27634 registrar.cpp:488] Successfully updated the
>> 'registry' in 4.890112ms
>> I0825 22:09:13.900547 27634 registrar.cpp:374] Successfully recovered
>> registrar
>> I0825 22:09:13.900591 27643 log.cpp:704] Attempting to truncate the log
>> to 1
>> I0825 22:09:13.900795 27643 coordinator.cpp:341] Coordinator attempting
>> to write TRUNCATE action at position 2
>> I0825 22:09:13.901029 27634 master.cpp:1335] Recovered 0 slaves from the
>> Registry (135B) ; allowing 10mins for slaves to re-register
>> I0825 22:09:13.901621 27640 replica.cpp:511] Replica received write
>> request for position 2
>> I0825 22:09:13.901944 27640 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 299875ns
>> I0825 22:09:13.901968 27640 replica.cpp:679] Persisted action at 2
>> I0825 22:09:13.902472 27636 replica.cpp:658] Replica received learned
>> notice for position 2
>> I0825 22:09:13.902838 27636 leveldb.cpp:343] Persisting action (18 bytes)
>> to leveldb took 352156ns
>> I0825 22:09:13.902897 27636 leveldb.cpp:401] Deleting ~1 keys from
>> leveldb took 46622ns
>> I0825 22:09:13.902926 27636 replica.cpp:679] Persisted action at 2
>> I0825 22:09:13.902952 27636 replica.cpp:664] Replica learned TRUNCATE
>> action at position 2
>> I0825 22:09:13.911948 27610 scheduler.cpp:157] Version: 0.25.0
>> I0825 22:09:13.913947 27639 scheduler.cpp:240] New master detected at
>> master@172.17.0.14:51219
>> I0825 22:09:13.914926 27640 scheduler.cpp:302] Sending SUBSCRIBE call to
>> master@172.17.0.14:51219
>> I0825 22:09:13.917476 27633 process.cpp:3043] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I0825 22:09:13.917757 27633 http.cpp:321] HTTP POST for
>> /master/api/v1/scheduler from 172.17.0.14:53386
>> I0825 22:09:13.918051 27633 master.cpp:1783] Received subscription
>> request for HTTP framework 'default'
>> I0825 22:09:13.918148 27633 master.cpp:1564] Authorizing framework
>> principal 'test-principal' to receive offers for role '*'
>> I0825 22:09:13.918601 27635 master.cpp:1875] Subscribing framework
>> 'default' with checkpointing disabled and capabilities [ ]
>> I0825 22:09:13.918972 27628 hierarchical.hpp:391] Added framework
>> 20150825-220913-234885548-51219-27610-0000
>> I0825 22:09:13.919013 27628 hierarchical.hpp:1010] No resources available
>> to allocate!
>> I0825 22:09:13.919065 27628 hierarchical.hpp:910] Performed allocation
>> for 0 slaves in 76310ns
>> I0825 22:09:13.918977 27638 master.hpp:1308] Sending heartbeat to
>> 20150825-220913-234885548-51219-27610-0000
>> I0825 22:09:13.920267 27640 scheduler.cpp:461] Enqueuing event SUBSCRIBED
>> received from master@172.17.0.14:51219
>> I0825 22:09:13.921052 27628 scheduler.cpp:461] Enqueuing event HEARTBEAT
>> received from master@172.17.0.14:51219
>> I0825 22:09:13.921741 27630 scheduler_tests.cpp:113] Ignoring HEARTBEAT
>> event
>> I0825 22:09:13.921830 27628 scheduler.cpp:302] Sending REQUEST call to
>> master@172.17.0.14:51219
>> I0825 22:09:13.923214 27639 process.cpp:3043] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I0825 22:09:13.923444 27639 http.cpp:321] HTTP POST for
>> /master/api/v1/scheduler from 172.17.0.14:53387
>> I0825 22:09:13.923578 27639 master.cpp:2486] Processing REQUEST call for
>> framework 20150825-220913-234885548-51219-27610-0000 (default)
>> I0825 22:09:13.923759 27631 hierarchical.hpp:668] Received resource
>> request from framework 20150825-220913-234885548-51219-27610-0000
>> I0825 22:09:13.924083 27639 master.cpp:860] Master terminating
>> I0825 22:09:13.924222 27640 hierarchical.hpp:428] Removed framework
>> 20150825-220913-234885548-51219-27610-0000
>> E0825 22:09:13.924842 27629 scheduler.cpp:435] End-Of-File received from
>> master. The master closed the event stream
>> [ OK ] ContentType/SchedulerTest.Request/0 (57 ms)
>> [ RUN ] ContentType/SchedulerTest.Request/1
>> Using temporary directory
>> '/tmp/ContentType_SchedulerTest_Request_1_SADnGt'
>> I0825 22:09:13.932909 27610 leveldb.cpp:176] Opened db in 2.321244ms
>> I0825 22:09:13.933758 27610 leveldb.cpp:183] Compacted db in 824246ns
>> I0825 22:09:13.933809 27610 leveldb.cpp:198] Created db iterator in
>> 32012ns
>> I0825 22:09:13.933836 27610 leveldb.cpp:204] Seeked to beginning of db in
>> 11437ns
>> I0825 22:09:13.933854 27610 leveldb.cpp:273] Iterated through 0 keys in
>> the db in 8829ns
>> I0825 22:09:13.933905 27610 replica.cpp:744] Replica recovered with log
>> positions 0 -> 0 with 1 holes and 0 unlearned
>> I0825 22:09:13.934375 27643 recover.cpp:449] Starting replica recovery
>> I0825 22:09:13.934617 27643 recover.cpp:475] Replica is in EMPTY status
>> I0825 22:09:13.936271 27642 replica.cpp:641] Replica in EMPTY status
>> received a broadcasted recover request
>> I0825 22:09:13.936769 27642 recover.cpp:195] Received a recover response
>> from a replica in EMPTY status
>> I0825 22:09:13.937355 27638 master.cpp:378] Master
>> 20150825-220913-234885548-51219-27610 (09c6504e3a31) started on
>> 172.17.0.14:51219
>> I0825 22:09:13.937438 27642 recover.cpp:566] Updating replica status to
>> STARTING
>> I0825 22:09:13.937474 27638 master.cpp:380] Flags at startup: --acls=""
>> --allocation_interval="1secs" --allocator="HierarchicalDRF"
>> --authenticate="false" --authenticate_slaves="true"
>> --authenticators="crammd5" --authorizers="local"
>> --credentials="/tmp/ContentType_SchedulerTest_Request_1_SADnGt/credentials"
>> --framework_sorter="drf" --help="false" --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.25.0/_inst/share/mesos/webui"
>> --work_dir="/tmp/ContentType_SchedulerTest_Request_1_SADnGt/master"
>> --zk_session_timeout="10secs"
>> I0825 22:09:13.937928 27638 master.cpp:427] Master allowing
>> unauthenticated frameworks to register
>> I0825 22:09:13.938063 27638 master.cpp:430] Master only allowing
>> authenticated slaves to register
>> I0825 22:09:13.938189 27638 credentials.hpp:37] Loading credentials for
>> authentication from
>> '/tmp/ContentType_SchedulerTest_Request_1_SADnGt/credentials'
>> I0825 22:09:13.938272 27641 leveldb.cpp:306] Persisting metadata (8
>> bytes) to leveldb took 570105ns
>> I0825 22:09:13.938328 27641 replica.cpp:323] Persisted replica status to
>> STARTING
>> I0825 22:09:13.938534 27641 recover.cpp:475] Replica is in STARTING status
>> I0825 22:09:13.938783 27638 master.cpp:469] Using default 'crammd5'
>> authenticator
>> I0825 22:09:13.939000 27638 master.cpp:506] Authorization enabled
>> I0825 22:09:13.939327 27643 whitelist_watcher.cpp:79] No whitelist given
>> I0825 22:09:13.939376 27639 hierarchical.hpp:346] Initialized
>> hierarchical allocator process
>> I0825 22:09:13.939831 27630 replica.cpp:641] Replica in STARTING status
>> received a broadcasted recover request
>> I0825 22:09:13.940085 27642 recover.cpp:195] Received a recover response
>> from a replica in STARTING status
>> I0825 22:09:13.940639 27638 master.cpp:1525] The newly elected leader is
>> master@172.17.0.14:51219 with id 20150825-220913-234885548-51219-27610
>> I0825 22:09:13.940671 27638 master.cpp:1538] Elected as the leading
>> master!
>> I0825 22:09:13.940687 27638 master.cpp:1308] Recovering from registrar
>> I0825 22:09:13.940915 27629 registrar.cpp:311] Recovering registrar
>> I0825 22:09:13.941086 27643 recover.cpp:566] Updating replica status to
>> VOTING
>> I0825 22:09:13.941609 27632 leveldb.cpp:306] Persisting metadata (8
>> bytes) to leveldb took 355183ns
>> I0825 22:09:13.941635 27632 replica.cpp:323] Persisted replica status to
>> VOTING
>> I0825 22:09:13.941750 27632 recover.cpp:580] Successfully joined the
>> Paxos group
>> I0825 22:09:13.941900 27632 recover.cpp:464] Recover process terminated
>> I0825 22:09:13.942282 27632 log.cpp:661] Attempting to start the writer
>> I0825 22:09:13.943426 27634 replica.cpp:477] Replica received implicit
>> promise request with proposal 1
>> I0825 22:09:13.943758 27634 leveldb.cpp:306] Persisting metadata (8
>> bytes) to leveldb took 317824ns
>> I0825 22:09:13.943779 27634 replica.cpp:345] Persisted promised to 1
>> I0825 22:09:13.944403 27631 coordinator.cpp:231] Coordinator attemping to
>> fill missing position
>> I0825 22:09:13.945358 27631 replica.cpp:378] Replica received explicit
>> promise request for position 0 with proposal 2
>> I0825 22:09:13.945703 27631 leveldb.cpp:343] Persisting action (8 bytes)
>> to leveldb took 321070ns
>> I0825 22:09:13.945726 27631 replica.cpp:679] Persisted action at 0
>> I0825 22:09:13.946526 27635 replica.cpp:511] Replica received write
>> request for position 0
>> I0825 22:09:13.946657 27635 leveldb.cpp:438] Reading position from
>> leveldb took 48307ns
>> I0825 22:09:13.946987 27635 leveldb.cpp:343] Persisting action (14 bytes)
>> to leveldb took 294387ns
>> I0825 22:09:13.947010 27635 replica.cpp:679] Persisted action at 0
>> I0825 22:09:13.947520 27635 replica.cpp:658] Replica received learned
>> notice for position 0
>> I0825 22:09:13.948109 27635 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 578626ns
>> I0825 22:09:13.948132 27635 replica.cpp:679] Persisted action at 0
>> I0825 22:09:13.948146 27635 replica.cpp:664] Replica learned NOP action
>> at position 0
>> I0825 22:09:13.948643 27642 log.cpp:677] Writer started with ending
>> position 0
>> I0825 22:09:13.949584 27640 leveldb.cpp:438] Reading position from
>> leveldb took 65972ns
>> I0825 22:09:13.952926 27642 registrar.cpp:344] Successfully fetched the
>> registry (0B) in 11.961856ms
>> I0825 22:09:13.953083 27642 registrar.cpp:443] Applied 1 operations in
>> 57043ns; attempting to update the 'registry'
>> I0825 22:09:13.955358 27642 log.cpp:685] Attempting to append 174 bytes
>> to the log
>> I0825 22:09:13.955634 27628 coordinator.cpp:341] Coordinator attempting
>> to write APPEND action at position 1
>> I0825 22:09:13.956763 27639 replica.cpp:511] Replica received write
>> request for position 1
>> I0825 22:09:13.957214 27639 leveldb.cpp:343] Persisting action (193
>> bytes) to leveldb took 426896ns
>> I0825 22:09:13.957245 27639 replica.cpp:679] Persisted action at 1
>> I0825 22:09:13.957931 27628 replica.cpp:658] Replica received learned
>> notice for position 1
>> I0825 22:09:13.958309 27628 leveldb.cpp:343] Persisting action (195
>> bytes) to leveldb took 365487ns
>> I0825 22:09:13.958345 27628 replica.cpp:679] Persisted action at 1
>> I0825 22:09:13.958433 27628 replica.cpp:664] Replica learned APPEND
>> action at position 1
>> I0825 22:09:13.959656 27643 registrar.cpp:488] Successfully updated the
>> 'registry' in 6.381824ms
>> I0825 22:09:13.959893 27637 log.cpp:704] Attempting to truncate the log
>> to 1
>> I0825 22:09:13.959972 27643 registrar.cpp:374] Successfully recovered
>> registrar
>> I0825 22:09:13.960489 27630 master.cpp:1335] Recovered 0 slaves from the
>> Registry (135B) ; allowing 10mins for slaves to re-register
>> I0825 22:09:13.960759 27641 coordinator.cpp:341] Coordinator attempting
>> to write TRUNCATE action at position 2
>> I0825 22:09:13.961493 27634 replica.cpp:511] Replica received write
>> request for position 2
>> I0825 22:09:13.961920 27634 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 403604ns
>> I0825 22:09:13.961944 27634 replica.cpp:679] Persisted action at 2
>> I0825 22:09:13.962507 27634 replica.cpp:658] Replica received learned
>> notice for position 2
>> I0825 22:09:13.962864 27634 leveldb.cpp:343] Persisting action (18 bytes)
>> to leveldb took 345942ns
>> I0825 22:09:13.962930 27634 leveldb.cpp:401] Deleting ~1 keys from
>> leveldb took 55125ns
>> I0825 22:09:13.962960 27634 replica.cpp:679] Persisted action at 2
>> I0825 22:09:13.962987 27634 replica.cpp:664] Replica learned TRUNCATE
>> action at position 2
>> I0825 22:09:13.971457 27610 scheduler.cpp:157] Version: 0.25.0
>> I0825 22:09:13.974419 27634 scheduler.cpp:240] New master detected at
>> master@172.17.0.14:51219
>> I0825 22:09:13.975453 27632 scheduler.cpp:302] Sending SUBSCRIBE call to
>> master@172.17.0.14:51219
>> I0825 22:09:13.977284 27633 process.cpp:3043] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I0825 22:09:13.977653 27633 http.cpp:321] HTTP POST for
>> /master/api/v1/scheduler from 172.17.0.14:53388
>> I0825 22:09:13.978005 27633 master.cpp:1783] Received subscription
>> request for HTTP framework 'default'
>> I0825 22:09:13.978036 27633 master.cpp:1564] Authorizing framework
>> principal 'test-principal' to receive offers for role '*'
>> I0825 22:09:13.978327 27633 master.cpp:1875] Subscribing framework
>> 'default' with checkpointing disabled and capabilities [ ]
>> I0825 22:09:13.978721 27632 hierarchical.hpp:391] Added framework
>> 20150825-220913-234885548-51219-27610-0000
>> I0825 22:09:13.978759 27632 hierarchical.hpp:1010] No resources available
>> to allocate!
>> I0825 22:09:13.978775 27632 hierarchical.hpp:910] Performed allocation
>> for 0 slaves in 37630ns
>> I0825 22:09:13.978862 27633 master.hpp:1308] Sending heartbeat to
>> 20150825-220913-234885548-51219-27610-0000
>> I0825 22:09:13.979598 27633 scheduler.cpp:461] Enqueuing event SUBSCRIBED
>> received from master@172.17.0.14:51219
>> I0825 22:09:13.979974 27633 scheduler.cpp:461] Enqueuing event HEARTBEAT
>> received from master@172.17.0.14:51219
>> I0825 22:09:13.980528 27636 scheduler_tests.cpp:113] Ignoring HEARTBEAT
>> event
>> I0825 22:09:13.980619 27634 scheduler.cpp:302] Sending REQUEST call to
>> master@172.17.0.14:51219
>> I0825 22:09:13.981947 27643 process.cpp:3043] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I0825 22:09:13.982152 27643 http.cpp:321] HTTP POST for
>> /master/api/v1/scheduler from 172.17.0.14:53389
>> I0825 22:09:13.982462 27643 master.cpp:2486] Processing REQUEST call for
>> framework 20150825-220913-234885548-51219-27610-0000 (default)
>> I0825 22:09:13.983168 27643 hierarchical.hpp:668] Received resource
>> request from framework 20150825-220913-234885548-51219-27610-0000
>> I0825 22:09:13.983490 27636 master.cpp:860] Master terminating
>> I0825 22:09:13.983759 27640 hierarchical.hpp:428] Removed framework
>> 20150825-220913-234885548-51219-27610-0000
>> E0825 22:09:13.984733 27630 scheduler.cpp:435] End-Of-File received from
>> master. The master closed the event stream
>> [ OK ] ContentType/SchedulerTest.Request/1 (59 ms)
>> [----------] 20 tests from ContentType/SchedulerTest (4009 ms total)
>>
>> [----------] Global test environment tear-down
>> [==========] 737 tests from 101 test cases ran. (293700 ms total)
>> [ PASSED ] 736 tests.
>> [ FAILED ] 1 test, listed below:
>> [ FAILED ] SlaveTest.HTTPSchedulerSlaveRestart
>>
>> 1 FAILED TEST
>> YOU HAVE 8 DISABLED TESTS
>>
>> make[4]: *** [check-local] Error 1
>> make[4]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
>> make[3]: *** [check-am] Error 2
>> make[3]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
>> make[2]: *** [check] Error 2
>> make[2]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
>> make[1]: *** [check-recursive] Error 1
>> make[1]: Leaving directory `/mesos/mesos-0.25.0/_build'
>> make: *** [distcheck] Error 1
>> + docker rmi mesos-1440539455-8310
>> Untagged: mesos-1440539455-8310:latest
>> Deleted: acd12e9fe4f4685b34e7ed8350b8221b76acb8157376c9d68c7c968ee7bfa4b9
>> Deleted: ee33f9c54bdf5d6a61a0f82999b246ca00ec4a32b6aadf31d4df3ad27c1e2057
>> Deleted: caea2003404d29f724fa1e1d98f0b6b12e003d3a6875e3e53719c5aa384fbcbe
>> Deleted: 52d6374cc64df4e7fd759792d25615c774047fd39206f27b0d0a28f177185c98
>> Build step 'Execute shell' marked build as failure
>>
>
>
Re: Build failed in Jenkins: Mesos » clang,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #729
Posted by Joris Van Remoortere <jo...@gmail.com>.
Have you seen this before?
On Tue, Aug 25, 2015 at 6:10 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/729/changes
> >
>
> Changes:
>
> [joris.van.remoortere] Added -> operators for Option, Try, Result.
>
> [joris.van.remoortere] Added try_tests.cpp to libprocess makefile.
>
> ------------------------------------------
> [...truncated 118749 lines...]
> I0825 22:09:13.861886 27629 hierarchical.hpp:428] Removed framework
> 20150825-220913-234885548-51219-27610-0000
> I0825 22:09:13.862547 27640 slave.cpp:3143] master@172.17.0.14:51219
> exited
> W0825 22:09:13.862583 27640 slave.cpp:3146] Master disconnected! Waiting
> for a new master to be elected
> E0825 22:09:13.862613 27634 scheduler.cpp:435] End-Of-File received from
> master. The master closed the event stream
> I0825 22:09:13.865891 27630 slave.cpp:3399] Executor 'default' of
> framework 20150825-220913-234885548-51219-27610-0000 exited with status 0
> I0825 22:09:13.867605 27630 slave.cpp:2696] Handling status update
> TASK_LOST (UUID: 2ad485a1-4ded-4287-8f08-fa8ab556c333) for task
> 87043e48-ad19-4d0b-8702-3ab0886c0d74 of framework
> 20150825-220913-234885548-51219-27610-0000 from @0.0.0.0:0
> I0825 22:09:13.867723 27630 slave.cpp:5094] Terminating task
> 87043e48-ad19-4d0b-8702-3ab0886c0d74
> I0825 22:09:13.868093 27630 slave.cpp:564] Slave terminating
> I0825 22:09:13.868172 27630 slave.cpp:1959] Asked to shut down framework
> 20150825-220913-234885548-51219-27610-0000 by @0.0.0.0:0
> I0825 22:09:13.868201 27630 slave.cpp:1984] Shutting down framework
> 20150825-220913-234885548-51219-27610-0000
> I0825 22:09:13.868279 27630 slave.cpp:3503] Cleaning up executor 'default'
> of framework 20150825-220913-234885548-51219-27610-0000
> I0825 22:09:13.868466 27643 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_s9tfok/slaves/20150825-220913-234885548-51219-27610-S0/frameworks/20150825-220913-234885548-51219-27610-0000/executors/default/runs/d0496a2d-f815-4f7c-85d5-bbe29cf4de83'
> for gc 6.99998994908444days in the future
> I0825 22:09:13.868621 27630 slave.cpp:3592] Cleaning up framework
> 20150825-220913-234885548-51219-27610-0000
> I0825 22:09:13.868671 27643 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_s9tfok/slaves/20150825-220913-234885548-51219-27610-S0/frameworks/20150825-220913-234885548-51219-27610-0000/executors/default'
> for gc 6.9999899470963days in the future
> I0825 22:09:13.868772 27643 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_s9tfok/slaves/20150825-220913-234885548-51219-27610-S0/frameworks/20150825-220913-234885548-51219-27610-0000'
> for gc 6.99998994524444days in the future
> I0825 22:09:13.868863 27630 status_update_manager.cpp:284] Closing status
> update streams for framework 20150825-220913-234885548-51219-27610-0000
> I0825 22:09:13.869031 27630 status_update_manager.cpp:530] Cleaning up
> status update stream for task 87043e48-ad19-4d0b-8702-3ab0886c0d74 of
> framework 20150825-220913-234885548-51219-27610-0000
> [ OK ] ContentType/SchedulerTest.Message/1 (127 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> Using temporary directory '/tmp/ContentType_SchedulerTest_Request_0_sq7REb'
> I0825 22:09:13.875603 27610 leveldb.cpp:176] Opened db in 2.103165ms
> I0825 22:09:13.876490 27610 leveldb.cpp:183] Compacted db in 863600ns
> I0825 22:09:13.876540 27610 leveldb.cpp:198] Created db iterator in 32660ns
> I0825 22:09:13.876580 27610 leveldb.cpp:204] Seeked to beginning of db in
> 12423ns
> I0825 22:09:13.876597 27610 leveldb.cpp:273] Iterated through 0 keys in
> the db in 8721ns
> I0825 22:09:13.876647 27610 replica.cpp:744] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0825 22:09:13.877125 27643 recover.cpp:449] Starting replica recovery
> I0825 22:09:13.877693 27638 recover.cpp:475] Replica is in EMPTY status
> I0825 22:09:13.879178 27641 master.cpp:378] Master
> 20150825-220913-234885548-51219-27610 (09c6504e3a31) started on
> 172.17.0.14:51219
> I0825 22:09:13.879428 27630 replica.cpp:641] Replica in EMPTY status
> received a broadcasted recover request
> I0825 22:09:13.879216 27641 master.cpp:380] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/ContentType_SchedulerTest_Request_0_sq7REb/credentials"
> --framework_sorter="drf" --help="false" --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.25.0/_inst/share/mesos/webui"
> --work_dir="/tmp/ContentType_SchedulerTest_Request_0_sq7REb/master"
> --zk_session_timeout="10secs"
> I0825 22:09:13.879786 27641 master.cpp:427] Master allowing
> unauthenticated frameworks to register
> I0825 22:09:13.879976 27641 master.cpp:430] Master only allowing
> authenticated slaves to register
> I0825 22:09:13.879992 27641 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_SchedulerTest_Request_0_sq7REb/credentials'
> I0825 22:09:13.880189 27640 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I0825 22:09:13.880612 27641 master.cpp:469] Using default 'crammd5'
> authenticator
> I0825 22:09:13.880767 27641 master.cpp:506] Authorization enabled
> I0825 22:09:13.880996 27643 whitelist_watcher.cpp:79] No whitelist given
> I0825 22:09:13.881162 27638 hierarchical.hpp:346] Initialized hierarchical
> allocator process
> I0825 22:09:13.881288 27638 recover.cpp:566] Updating replica status to
> STARTING
> I0825 22:09:13.882040 27642 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 632331ns
> I0825 22:09:13.882138 27642 replica.cpp:323] Persisted replica status to
> STARTING
> I0825 22:09:13.882534 27632 recover.cpp:475] Replica is in STARTING status
> I0825 22:09:13.882618 27638 master.cpp:1525] The newly elected leader is
> master@172.17.0.14:51219 with id 20150825-220913-234885548-51219-27610
> I0825 22:09:13.882767 27638 master.cpp:1538] Elected as the leading master!
> I0825 22:09:13.882807 27638 master.cpp:1308] Recovering from registrar
> I0825 22:09:13.883013 27631 registrar.cpp:311] Recovering registrar
> I0825 22:09:13.883785 27628 replica.cpp:641] Replica in STARTING status
> received a broadcasted recover request
> I0825 22:09:13.884124 27635 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I0825 22:09:13.884512 27643 recover.cpp:566] Updating replica status to
> VOTING
> I0825 22:09:13.885002 27635 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 306520ns
> I0825 22:09:13.885025 27635 replica.cpp:323] Persisted replica status to
> VOTING
> I0825 22:09:13.885110 27643 recover.cpp:580] Successfully joined the Paxos
> group
> I0825 22:09:13.885265 27643 recover.cpp:464] Recover process terminated
> I0825 22:09:13.885674 27628 log.cpp:661] Attempting to start the writer
> I0825 22:09:13.886636 27640 replica.cpp:477] Replica received implicit
> promise request with proposal 1
> I0825 22:09:13.886986 27640 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 334609ns
> I0825 22:09:13.887009 27640 replica.cpp:345] Persisted promised to 1
> I0825 22:09:13.888054 27639 coordinator.cpp:231] Coordinator attemping to
> fill missing position
> I0825 22:09:13.889037 27630 replica.cpp:378] Replica received explicit
> promise request for position 0 with proposal 2
> I0825 22:09:13.889364 27630 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 303523ns
> I0825 22:09:13.889386 27630 replica.cpp:679] Persisted action at 0
> I0825 22:09:13.890342 27637 replica.cpp:511] Replica received write
> request for position 0
> I0825 22:09:13.890398 27637 leveldb.cpp:438] Reading position from leveldb
> took 41597ns
> I0825 22:09:13.890707 27637 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 280201ns
> I0825 22:09:13.890730 27637 replica.cpp:679] Persisted action at 0
> I0825 22:09:13.891255 27637 replica.cpp:658] Replica received learned
> notice for position 0
> I0825 22:09:13.891583 27637 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 318193ns
> I0825 22:09:13.891613 27637 replica.cpp:679] Persisted action at 0
> I0825 22:09:13.891638 27637 replica.cpp:664] Replica learned NOP action at
> position 0
> I0825 22:09:13.892102 27639 log.cpp:677] Writer started with ending
> position 0
> I0825 22:09:13.893057 27641 leveldb.cpp:438] Reading position from leveldb
> took 43261ns
> I0825 22:09:13.895298 27635 registrar.cpp:344] Successfully fetched the
> registry (0B) in 12.246016ms
> I0825 22:09:13.895421 27635 registrar.cpp:443] Applied 1 operations in
> 38170ns; attempting to update the 'registry'
> I0825 22:09:13.897363 27639 log.cpp:685] Attempting to append 174 bytes to
> the log
> I0825 22:09:13.897528 27641 coordinator.cpp:341] Coordinator attempting to
> write APPEND action at position 1
> I0825 22:09:13.898185 27643 replica.cpp:511] Replica received write
> request for position 1
> I0825 22:09:13.898608 27643 leveldb.cpp:343] Persisting action (193 bytes)
> to leveldb took 399640ns
> I0825 22:09:13.898635 27643 replica.cpp:679] Persisted action at 1
> I0825 22:09:13.899137 27633 replica.cpp:658] Replica received learned
> notice for position 1
> I0825 22:09:13.899494 27633 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 345421ns
> I0825 22:09:13.899520 27633 replica.cpp:679] Persisted action at 1
> I0825 22:09:13.899544 27633 replica.cpp:664] Replica learned APPEND action
> at position 1
> I0825 22:09:13.900368 27634 registrar.cpp:488] Successfully updated the
> 'registry' in 4.890112ms
> I0825 22:09:13.900547 27634 registrar.cpp:374] Successfully recovered
> registrar
> I0825 22:09:13.900591 27643 log.cpp:704] Attempting to truncate the log to
> 1
> I0825 22:09:13.900795 27643 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I0825 22:09:13.901029 27634 master.cpp:1335] Recovered 0 slaves from the
> Registry (135B) ; allowing 10mins for slaves to re-register
> I0825 22:09:13.901621 27640 replica.cpp:511] Replica received write
> request for position 2
> I0825 22:09:13.901944 27640 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 299875ns
> I0825 22:09:13.901968 27640 replica.cpp:679] Persisted action at 2
> I0825 22:09:13.902472 27636 replica.cpp:658] Replica received learned
> notice for position 2
> I0825 22:09:13.902838 27636 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 352156ns
> I0825 22:09:13.902897 27636 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 46622ns
> I0825 22:09:13.902926 27636 replica.cpp:679] Persisted action at 2
> I0825 22:09:13.902952 27636 replica.cpp:664] Replica learned TRUNCATE
> action at position 2
> I0825 22:09:13.911948 27610 scheduler.cpp:157] Version: 0.25.0
> I0825 22:09:13.913947 27639 scheduler.cpp:240] New master detected at
> master@172.17.0.14:51219
> I0825 22:09:13.914926 27640 scheduler.cpp:302] Sending SUBSCRIBE call to
> master@172.17.0.14:51219
> I0825 22:09:13.917476 27633 process.cpp:3043] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0825 22:09:13.917757 27633 http.cpp:321] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.14:53386
> I0825 22:09:13.918051 27633 master.cpp:1783] Received subscription request
> for HTTP framework 'default'
> I0825 22:09:13.918148 27633 master.cpp:1564] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0825 22:09:13.918601 27635 master.cpp:1875] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0825 22:09:13.918972 27628 hierarchical.hpp:391] Added framework
> 20150825-220913-234885548-51219-27610-0000
> I0825 22:09:13.919013 27628 hierarchical.hpp:1010] No resources available
> to allocate!
> I0825 22:09:13.919065 27628 hierarchical.hpp:910] Performed allocation for
> 0 slaves in 76310ns
> I0825 22:09:13.918977 27638 master.hpp:1308] Sending heartbeat to
> 20150825-220913-234885548-51219-27610-0000
> I0825 22:09:13.920267 27640 scheduler.cpp:461] Enqueuing event SUBSCRIBED
> received from master@172.17.0.14:51219
> I0825 22:09:13.921052 27628 scheduler.cpp:461] Enqueuing event HEARTBEAT
> received from master@172.17.0.14:51219
> I0825 22:09:13.921741 27630 scheduler_tests.cpp:113] Ignoring HEARTBEAT
> event
> I0825 22:09:13.921830 27628 scheduler.cpp:302] Sending REQUEST call to
> master@172.17.0.14:51219
> I0825 22:09:13.923214 27639 process.cpp:3043] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0825 22:09:13.923444 27639 http.cpp:321] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.14:53387
> I0825 22:09:13.923578 27639 master.cpp:2486] Processing REQUEST call for
> framework 20150825-220913-234885548-51219-27610-0000 (default)
> I0825 22:09:13.923759 27631 hierarchical.hpp:668] Received resource
> request from framework 20150825-220913-234885548-51219-27610-0000
> I0825 22:09:13.924083 27639 master.cpp:860] Master terminating
> I0825 22:09:13.924222 27640 hierarchical.hpp:428] Removed framework
> 20150825-220913-234885548-51219-27610-0000
> E0825 22:09:13.924842 27629 scheduler.cpp:435] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/0 (57 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> Using temporary directory '/tmp/ContentType_SchedulerTest_Request_1_SADnGt'
> I0825 22:09:13.932909 27610 leveldb.cpp:176] Opened db in 2.321244ms
> I0825 22:09:13.933758 27610 leveldb.cpp:183] Compacted db in 824246ns
> I0825 22:09:13.933809 27610 leveldb.cpp:198] Created db iterator in 32012ns
> I0825 22:09:13.933836 27610 leveldb.cpp:204] Seeked to beginning of db in
> 11437ns
> I0825 22:09:13.933854 27610 leveldb.cpp:273] Iterated through 0 keys in
> the db in 8829ns
> I0825 22:09:13.933905 27610 replica.cpp:744] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0825 22:09:13.934375 27643 recover.cpp:449] Starting replica recovery
> I0825 22:09:13.934617 27643 recover.cpp:475] Replica is in EMPTY status
> I0825 22:09:13.936271 27642 replica.cpp:641] Replica in EMPTY status
> received a broadcasted recover request
> I0825 22:09:13.936769 27642 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I0825 22:09:13.937355 27638 master.cpp:378] Master
> 20150825-220913-234885548-51219-27610 (09c6504e3a31) started on
> 172.17.0.14:51219
> I0825 22:09:13.937438 27642 recover.cpp:566] Updating replica status to
> STARTING
> I0825 22:09:13.937474 27638 master.cpp:380] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/ContentType_SchedulerTest_Request_1_SADnGt/credentials"
> --framework_sorter="drf" --help="false" --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.25.0/_inst/share/mesos/webui"
> --work_dir="/tmp/ContentType_SchedulerTest_Request_1_SADnGt/master"
> --zk_session_timeout="10secs"
> I0825 22:09:13.937928 27638 master.cpp:427] Master allowing
> unauthenticated frameworks to register
> I0825 22:09:13.938063 27638 master.cpp:430] Master only allowing
> authenticated slaves to register
> I0825 22:09:13.938189 27638 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_SchedulerTest_Request_1_SADnGt/credentials'
> I0825 22:09:13.938272 27641 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 570105ns
> I0825 22:09:13.938328 27641 replica.cpp:323] Persisted replica status to
> STARTING
> I0825 22:09:13.938534 27641 recover.cpp:475] Replica is in STARTING status
> I0825 22:09:13.938783 27638 master.cpp:469] Using default 'crammd5'
> authenticator
> I0825 22:09:13.939000 27638 master.cpp:506] Authorization enabled
> I0825 22:09:13.939327 27643 whitelist_watcher.cpp:79] No whitelist given
> I0825 22:09:13.939376 27639 hierarchical.hpp:346] Initialized hierarchical
> allocator process
> I0825 22:09:13.939831 27630 replica.cpp:641] Replica in STARTING status
> received a broadcasted recover request
> I0825 22:09:13.940085 27642 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I0825 22:09:13.940639 27638 master.cpp:1525] The newly elected leader is
> master@172.17.0.14:51219 with id 20150825-220913-234885548-51219-27610
> I0825 22:09:13.940671 27638 master.cpp:1538] Elected as the leading master!
> I0825 22:09:13.940687 27638 master.cpp:1308] Recovering from registrar
> I0825 22:09:13.940915 27629 registrar.cpp:311] Recovering registrar
> I0825 22:09:13.941086 27643 recover.cpp:566] Updating replica status to
> VOTING
> I0825 22:09:13.941609 27632 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 355183ns
> I0825 22:09:13.941635 27632 replica.cpp:323] Persisted replica status to
> VOTING
> I0825 22:09:13.941750 27632 recover.cpp:580] Successfully joined the Paxos
> group
> I0825 22:09:13.941900 27632 recover.cpp:464] Recover process terminated
> I0825 22:09:13.942282 27632 log.cpp:661] Attempting to start the writer
> I0825 22:09:13.943426 27634 replica.cpp:477] Replica received implicit
> promise request with proposal 1
> I0825 22:09:13.943758 27634 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 317824ns
> I0825 22:09:13.943779 27634 replica.cpp:345] Persisted promised to 1
> I0825 22:09:13.944403 27631 coordinator.cpp:231] Coordinator attemping to
> fill missing position
> I0825 22:09:13.945358 27631 replica.cpp:378] Replica received explicit
> promise request for position 0 with proposal 2
> I0825 22:09:13.945703 27631 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 321070ns
> I0825 22:09:13.945726 27631 replica.cpp:679] Persisted action at 0
> I0825 22:09:13.946526 27635 replica.cpp:511] Replica received write
> request for position 0
> I0825 22:09:13.946657 27635 leveldb.cpp:438] Reading position from leveldb
> took 48307ns
> I0825 22:09:13.946987 27635 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 294387ns
> I0825 22:09:13.947010 27635 replica.cpp:679] Persisted action at 0
> I0825 22:09:13.947520 27635 replica.cpp:658] Replica received learned
> notice for position 0
> I0825 22:09:13.948109 27635 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 578626ns
> I0825 22:09:13.948132 27635 replica.cpp:679] Persisted action at 0
> I0825 22:09:13.948146 27635 replica.cpp:664] Replica learned NOP action at
> position 0
> I0825 22:09:13.948643 27642 log.cpp:677] Writer started with ending
> position 0
> I0825 22:09:13.949584 27640 leveldb.cpp:438] Reading position from leveldb
> took 65972ns
> I0825 22:09:13.952926 27642 registrar.cpp:344] Successfully fetched the
> registry (0B) in 11.961856ms
> I0825 22:09:13.953083 27642 registrar.cpp:443] Applied 1 operations in
> 57043ns; attempting to update the 'registry'
> I0825 22:09:13.955358 27642 log.cpp:685] Attempting to append 174 bytes to
> the log
> I0825 22:09:13.955634 27628 coordinator.cpp:341] Coordinator attempting to
> write APPEND action at position 1
> I0825 22:09:13.956763 27639 replica.cpp:511] Replica received write
> request for position 1
> I0825 22:09:13.957214 27639 leveldb.cpp:343] Persisting action (193 bytes)
> to leveldb took 426896ns
> I0825 22:09:13.957245 27639 replica.cpp:679] Persisted action at 1
> I0825 22:09:13.957931 27628 replica.cpp:658] Replica received learned
> notice for position 1
> I0825 22:09:13.958309 27628 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 365487ns
> I0825 22:09:13.958345 27628 replica.cpp:679] Persisted action at 1
> I0825 22:09:13.958433 27628 replica.cpp:664] Replica learned APPEND action
> at position 1
> I0825 22:09:13.959656 27643 registrar.cpp:488] Successfully updated the
> 'registry' in 6.381824ms
> I0825 22:09:13.959893 27637 log.cpp:704] Attempting to truncate the log to
> 1
> I0825 22:09:13.959972 27643 registrar.cpp:374] Successfully recovered
> registrar
> I0825 22:09:13.960489 27630 master.cpp:1335] Recovered 0 slaves from the
> Registry (135B) ; allowing 10mins for slaves to re-register
> I0825 22:09:13.960759 27641 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I0825 22:09:13.961493 27634 replica.cpp:511] Replica received write
> request for position 2
> I0825 22:09:13.961920 27634 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 403604ns
> I0825 22:09:13.961944 27634 replica.cpp:679] Persisted action at 2
> I0825 22:09:13.962507 27634 replica.cpp:658] Replica received learned
> notice for position 2
> I0825 22:09:13.962864 27634 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 345942ns
> I0825 22:09:13.962930 27634 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 55125ns
> I0825 22:09:13.962960 27634 replica.cpp:679] Persisted action at 2
> I0825 22:09:13.962987 27634 replica.cpp:664] Replica learned TRUNCATE
> action at position 2
> I0825 22:09:13.971457 27610 scheduler.cpp:157] Version: 0.25.0
> I0825 22:09:13.974419 27634 scheduler.cpp:240] New master detected at
> master@172.17.0.14:51219
> I0825 22:09:13.975453 27632 scheduler.cpp:302] Sending SUBSCRIBE call to
> master@172.17.0.14:51219
> I0825 22:09:13.977284 27633 process.cpp:3043] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0825 22:09:13.977653 27633 http.cpp:321] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.14:53388
> I0825 22:09:13.978005 27633 master.cpp:1783] Received subscription request
> for HTTP framework 'default'
> I0825 22:09:13.978036 27633 master.cpp:1564] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0825 22:09:13.978327 27633 master.cpp:1875] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0825 22:09:13.978721 27632 hierarchical.hpp:391] Added framework
> 20150825-220913-234885548-51219-27610-0000
> I0825 22:09:13.978759 27632 hierarchical.hpp:1010] No resources available
> to allocate!
> I0825 22:09:13.978775 27632 hierarchical.hpp:910] Performed allocation for
> 0 slaves in 37630ns
> I0825 22:09:13.978862 27633 master.hpp:1308] Sending heartbeat to
> 20150825-220913-234885548-51219-27610-0000
> I0825 22:09:13.979598 27633 scheduler.cpp:461] Enqueuing event SUBSCRIBED
> received from master@172.17.0.14:51219
> I0825 22:09:13.979974 27633 scheduler.cpp:461] Enqueuing event HEARTBEAT
> received from master@172.17.0.14:51219
> I0825 22:09:13.980528 27636 scheduler_tests.cpp:113] Ignoring HEARTBEAT
> event
> I0825 22:09:13.980619 27634 scheduler.cpp:302] Sending REQUEST call to
> master@172.17.0.14:51219
> I0825 22:09:13.981947 27643 process.cpp:3043] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0825 22:09:13.982152 27643 http.cpp:321] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.14:53389
> I0825 22:09:13.982462 27643 master.cpp:2486] Processing REQUEST call for
> framework 20150825-220913-234885548-51219-27610-0000 (default)
> I0825 22:09:13.983168 27643 hierarchical.hpp:668] Received resource
> request from framework 20150825-220913-234885548-51219-27610-0000
> I0825 22:09:13.983490 27636 master.cpp:860] Master terminating
> I0825 22:09:13.983759 27640 hierarchical.hpp:428] Removed framework
> 20150825-220913-234885548-51219-27610-0000
> E0825 22:09:13.984733 27630 scheduler.cpp:435] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (59 ms)
> [----------] 20 tests from ContentType/SchedulerTest (4009 ms total)
>
> [----------] Global test environment tear-down
> [==========] 737 tests from 101 test cases ran. (293700 ms total)
> [ PASSED ] 736 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] SlaveTest.HTTPSchedulerSlaveRestart
>
> 1 FAILED TEST
> YOU HAVE 8 DISABLED TESTS
>
> make[4]: *** [check-local] Error 1
> make[4]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory `/mesos/mesos-0.25.0/_build'
> make: *** [distcheck] Error 1
> + docker rmi mesos-1440539455-8310
> Untagged: mesos-1440539455-8310:latest
> Deleted: acd12e9fe4f4685b34e7ed8350b8221b76acb8157376c9d68c7c968ee7bfa4b9
> Deleted: ee33f9c54bdf5d6a61a0f82999b246ca00ec4a32b6aadf31d4df3ad27c1e2057
> Deleted: caea2003404d29f724fa1e1d98f0b6b12e003d3a6875e3e53719c5aa384fbcbe
> Deleted: 52d6374cc64df4e7fd759792d25615c774047fd39206f27b0d0a28f177185c98
> Build step 'Execute shell' marked build as failure
>