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/13 21:08:15 UTC
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent,centos:7,docker||Hadoop #704
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent,OS=centos%3A7,label_exp=docker%7C%7CHadoop/704/changes>
Changes:
[vinodkone] Added Heartbeater to master to send periodic heartbeats to HTTP schedulers.
[vinodkone] Fixed style issue in master/main.cpp.
------------------------------------------
[...truncated 85348 lines...]
I0813 19:08:48.632869 28175 registrar.cpp:443] Applied 1 operations in 21288ns; attempting to update the 'registry'
I0813 19:08:48.635229 28170 log.cpp:685] Attempting to append 178 bytes to the log
I0813 19:08:48.635393 28181 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I0813 19:08:48.636042 28172 replica.cpp:511] Replica received write request for position 1
I0813 19:08:48.670603 28172 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 34.527132ms
I0813 19:08:48.670649 28172 replica.cpp:679] Persisted action at 1
I0813 19:08:48.671303 28172 replica.cpp:658] Replica received learned notice for position 1
I0813 19:08:48.708654 28172 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 37.28203ms
I0813 19:08:48.708699 28172 replica.cpp:679] Persisted action at 1
I0813 19:08:48.708724 28172 replica.cpp:664] Replica learned APPEND action at position 1
I0813 19:08:48.709902 28170 registrar.cpp:488] Successfully updated the 'registry' in 76.958976ms
I0813 19:08:48.710078 28170 registrar.cpp:374] Successfully recovered registrar
I0813 19:08:48.710151 28169 log.cpp:704] Attempting to truncate the log to 1
I0813 19:08:48.710311 28171 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I0813 19:08:48.710618 28183 master.cpp:1334] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I0813 19:08:48.711560 28180 replica.cpp:511] Replica received write request for position 2
I0813 19:08:48.745764 28180 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 34.162243ms
I0813 19:08:48.745803 28180 replica.cpp:679] Persisted action at 2
I0813 19:08:48.746690 28179 replica.cpp:658] Replica received learned notice for position 2
I0813 19:08:48.783854 28179 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 37.134026ms
I0813 19:08:48.783941 28179 leveldb.cpp:401] Deleting ~1 keys from leveldb took 41971ns
I0813 19:08:48.783964 28179 replica.cpp:679] Persisted action at 2
I0813 19:08:48.783987 28179 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0813 19:08:48.792191 28150 scheduler.cpp:157] Version: 0.24.0
I0813 19:08:48.795454 28174 scheduler.cpp:272] New master detected at master@172.17.1.212:48387
I0813 19:08:48.798694 28176 process.cpp:3043] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0813 19:08:48.799140 28176 master.cpp:1782] Received subscription request for HTTP framework 'default'
I0813 19:08:48.799299 28176 master.cpp:1563] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0813 19:08:48.799720 28176 master.cpp:1874] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0813 19:08:48.800200 28182 hierarchical.hpp:391] Added framework 20150813-190848-3556839852-48387-28150-0000
I0813 19:08:48.800230 28182 hierarchical.hpp:1008] No resources available to allocate!
I0813 19:08:48.800241 28182 hierarchical.hpp:908] Performed allocation for 0 slaves in 19263ns
I0813 19:08:48.800487 28181 master.hpp:1305] Sending heartbeat to 20150813-190848-3556839852-48387-28150-0000
../../src/tests/scheduler_tests.cpp:168: Failure
Value of: event.get().type()
Actual: HEARTBEAT
Expected: Event::SUBSCRIBED
Which is: SUBSCRIBED
../../src/tests/scheduler_tests.cpp:169: Failure
Value of: event.get().subscribed().framework_id()
Actual:
Expected: id
Which is: 20150813-190848-3556839852-48387-28150-0000
I0813 19:08:48.803643 28175 master.cpp:859] Master terminating
I0813 19:08:48.803848 28170 hierarchical.hpp:428] Removed framework 20150813-190848-3556839852-48387-28150-0000
I0813 19:08:48.804025 28169 scheduler.cpp:381] Ignoring event from old stale connection
I0813 19:08:48.805471 28185 process.cpp:2319] Returning '404 Not Found' for '/master/api/v1/scheduler'
I0813 19:08:48.806886 28182 scheduler.cpp:421] Enqueuing locally injected event ERROR
[ FAILED ] SchedulerTest.Subscribe (520 ms)
[ RUN ] SchedulerTest.TaskRunning
Using temporary directory '/tmp/SchedulerTest_TaskRunning_3mHUGy'
I0813 19:08:48.916472 28150 leveldb.cpp:176] Opened db in 105.250713ms
I0813 19:08:48.958474 28150 leveldb.cpp:183] Compacted db in 41.957481ms
I0813 19:08:48.958569 28150 leveldb.cpp:198] Created db iterator in 48565ns
I0813 19:08:48.958602 28150 leveldb.cpp:204] Seeked to beginning of db in 2158ns
I0813 19:08:48.958614 28150 leveldb.cpp:273] Iterated through 0 keys in the db in 342ns
I0813 19:08:48.958663 28150 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0813 19:08:48.959383 28179 recover.cpp:449] Starting replica recovery
I0813 19:08:48.959897 28179 recover.cpp:475] Replica is in EMPTY status
I0813 19:08:48.961062 28174 replica.cpp:641] Replica in EMPTY status received a broadcasted recover request
I0813 19:08:48.961495 28178 recover.cpp:195] Received a recover response from a replica in EMPTY status
I0813 19:08:48.962077 28169 recover.cpp:566] Updating replica status to STARTING
I0813 19:08:48.962764 28174 master.cpp:378] Master 20150813-190848-3556839852-48387-28150 (aff52502309c) started on 172.17.1.212:48387
I0813 19:08:48.962793 28174 master.cpp:380] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --credentials="/tmp/SchedulerTest_TaskRunning_3mHUGy/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.24.0/_inst/share/mesos/webui" --work_dir="/tmp/SchedulerTest_TaskRunning_3mHUGy/master" --zk_session_timeout="10secs"
I0813 19:08:48.963181 28174 master.cpp:427] Master allowing unauthenticated frameworks to register
I0813 19:08:48.963196 28174 master.cpp:430] Master only allowing authenticated slaves to register
I0813 19:08:48.963207 28174 credentials.hpp:37] Loading credentials for authentication from '/tmp/SchedulerTest_TaskRunning_3mHUGy/credentials'
I0813 19:08:48.963498 28174 master.cpp:469] Using default 'crammd5' authenticator
I0813 19:08:48.963666 28174 master.cpp:506] Authorization enabled
I0813 19:08:48.963984 28171 whitelist_watcher.cpp:79] No whitelist given
I0813 19:08:48.963984 28182 hierarchical.hpp:346] Initialized hierarchical allocator process
I0813 19:08:48.965253 28169 master.cpp:1524] The newly elected leader is master@172.17.1.212:48387 with id 20150813-190848-3556839852-48387-28150
I0813 19:08:48.965291 28169 master.cpp:1537] Elected as the leading master!
I0813 19:08:48.965317 28169 master.cpp:1307] Recovering from registrar
I0813 19:08:48.965471 28173 registrar.cpp:311] Recovering registrar
I0813 19:08:48.983306 28178 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 21.101333ms
I0813 19:08:48.983350 28178 replica.cpp:323] Persisted replica status to STARTING
I0813 19:08:48.983654 28180 recover.cpp:475] Replica is in STARTING status
I0813 19:08:48.984902 28176 replica.cpp:641] Replica in STARTING status received a broadcasted recover request
I0813 19:08:48.985115 28184 recover.cpp:195] Received a recover response from a replica in STARTING status
I0813 19:08:48.985488 28180 recover.cpp:566] Updating replica status to VOTING
I0813 19:08:49.008463 28171 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 22.709672ms
I0813 19:08:49.008497 28171 replica.cpp:323] Persisted replica status to VOTING
I0813 19:08:49.008671 28172 recover.cpp:580] Successfully joined the Paxos group
I0813 19:08:49.009106 28172 recover.cpp:464] Recover process terminated
I0813 19:08:49.009258 28171 log.cpp:661] Attempting to start the writer
I0813 19:08:49.010246 28180 replica.cpp:477] Replica received implicit promise request with proposal 1
I0813 19:08:49.033494 28180 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 23.219095ms
I0813 19:08:49.033522 28180 replica.cpp:345] Persisted promised to 1
I0813 19:08:49.034028 28171 coordinator.cpp:231] Coordinator attemping to fill missing position
I0813 19:08:49.035038 28179 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2
I0813 19:08:49.050400 28179 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 15.323028ms
I0813 19:08:49.050439 28179 replica.cpp:679] Persisted action at 0
I0813 19:08:49.051694 28181 replica.cpp:511] Replica received write request for position 0
I0813 19:08:49.051836 28181 leveldb.cpp:438] Reading position from leveldb took 45010ns
I0813 19:08:49.075487 28181 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 23.595405ms
I0813 19:08:49.075516 28181 replica.cpp:679] Persisted action at 0
I0813 19:08:49.076308 28177 replica.cpp:658] Replica received learned notice for position 0
I0813 19:08:49.092154 28177 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 15.818563ms
I0813 19:08:49.092182 28177 replica.cpp:679] Persisted action at 0
I0813 19:08:49.092197 28177 replica.cpp:664] Replica learned NOP action at position 0
I0813 19:08:49.092866 28180 log.cpp:677] Writer started with ending position 0
I0813 19:08:49.094108 28176 leveldb.cpp:438] Reading position from leveldb took 30749ns
I0813 19:08:49.096876 28174 registrar.cpp:344] Successfully fetched the registry (0B) in 131.348992ms
I0813 19:08:49.096972 28174 registrar.cpp:443] Applied 1 operations in 18363ns; attempting to update the 'registry'
I0813 19:08:49.099225 28181 log.cpp:685] Attempting to append 178 bytes to the log
I0813 19:08:49.099370 28170 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I0813 19:08:49.100088 28172 replica.cpp:511] Replica received write request for position 1
I0813 19:08:49.117347 28172 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 17.220997ms
I0813 19:08:49.117389 28172 replica.cpp:679] Persisted action at 1
I0813 19:08:49.118203 28171 replica.cpp:658] Replica received learned notice for position 1
I0813 19:08:49.134176 28171 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 15.878202ms
I0813 19:08:49.134222 28171 replica.cpp:679] Persisted action at 1
I0813 19:08:49.134248 28171 replica.cpp:664] Replica learned APPEND action at position 1
I0813 19:08:49.135310 28184 registrar.cpp:488] Successfully updated the 'registry' in 38.279936ms
I0813 19:08:49.135437 28184 registrar.cpp:374] Successfully recovered registrar
I0813 19:08:49.135823 28173 master.cpp:1334] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I0813 19:08:49.136152 28175 log.cpp:704] Attempting to truncate the log to 1
I0813 19:08:49.136330 28173 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I0813 19:08:49.137275 28178 replica.cpp:511] Replica received write request for position 2
I0813 19:08:49.159287 28178 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 21.973195ms
I0813 19:08:49.159332 28178 replica.cpp:679] Persisted action at 2
I0813 19:08:49.160249 28183 replica.cpp:658] Replica received learned notice for position 2
I0813 19:08:49.193629 28183 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 33.348179ms
I0813 19:08:49.193711 28183 leveldb.cpp:401] Deleting ~1 keys from leveldb took 41868ns
I0813 19:08:49.193742 28183 replica.cpp:679] Persisted action at 2
I0813 19:08:49.193766 28183 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0813 19:08:49.203047 28176 slave.cpp:190] Slave started on 211)@172.17.1.212:48387
I0813 19:08:49.203193 28176 slave.cpp:191] Flags at startup: --authenticatee="crammd5" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SchedulerTest_TaskRunning_n3T55M/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SchedulerTest_TaskRunning_n3T55M/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher_dir="/mesos/mesos-0.24.0/_build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_monitoring_interval="1secs" --resources="cpus:2;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --version="false" --work_dir="/tmp/SchedulerTest_TaskRunning_n3T55M"
I0813 19:08:49.203629 28176 credentials.hpp:85] Loading credential for authentication from '/tmp/SchedulerTest_TaskRunning_n3T55M/credential'
I0813 19:08:49.203816 28176 slave.cpp:321] Slave using credential for: test-principal
I0813 19:08:49.204376 28176 slave.cpp:354] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0813 19:08:49.204509 28176 slave.cpp:384] Slave hostname: aff52502309c
I0813 19:08:49.204556 28176 slave.cpp:389] Slave checkpoint: true
I0813 19:08:49.204709 28150 scheduler.cpp:157] Version: 0.24.0
I0813 19:08:49.205394 28182 state.cpp:54] Recovering state from '/tmp/SchedulerTest_TaskRunning_n3T55M/meta'
I0813 19:08:49.205735 28176 status_update_manager.cpp:202] Recovering status update manager
I0813 19:08:49.205979 28173 slave.cpp:4069] Finished recovery
I0813 19:08:49.206333 28173 slave.cpp:4226] Querying resource estimator for oversubscribable resources
I0813 19:08:49.206657 28172 status_update_manager.cpp:176] Pausing sending status updates
I0813 19:08:49.206661 28178 slave.cpp:684] New master detected at master@172.17.1.212:48387
I0813 19:08:49.206753 28178 slave.cpp:747] Authenticating with master master@172.17.1.212:48387
I0813 19:08:49.206776 28178 slave.cpp:752] Using default CRAM-MD5 authenticatee
I0813 19:08:49.206949 28178 slave.cpp:720] Detecting new master
I0813 19:08:49.207012 28171 authenticatee.cpp:115] Creating new client SASL connection
I0813 19:08:49.207166 28178 slave.cpp:4240] Received oversubscribable resources from the resource estimator
I0813 19:08:49.207223 28176 scheduler.cpp:272] New master detected at master@172.17.1.212:48387
I0813 19:08:49.207444 28174 master.cpp:4693] Authenticating slave(211)@172.17.1.212:48387
I0813 19:08:49.207569 28177 authenticator.cpp:407] Starting authentication session for crammd5_authenticatee(513)@172.17.1.212:48387
I0813 19:08:49.207902 28179 authenticator.cpp:92] Creating new server SASL connection
I0813 19:08:49.208133 28169 authenticatee.cpp:206] Received SASL authentication mechanisms: CRAM-MD5
I0813 19:08:49.208199 28169 authenticatee.cpp:232] Attempting to authenticate with mechanism 'CRAM-MD5'
I0813 19:08:49.208310 28169 authenticator.cpp:197] Received SASL authentication start
I0813 19:08:49.208355 28169 authenticator.cpp:319] Authentication requires more steps
I0813 19:08:49.208462 28184 authenticatee.cpp:252] Received SASL authentication step
I0813 19:08:49.208586 28179 authenticator.cpp:225] Received SASL authentication step
I0813 19:08:49.208619 28179 auxprop.cpp:102] Request to lookup properties for user: 'test-principal' realm: 'aff52502309c' server FQDN: 'aff52502309c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0813 19:08:49.208631 28179 auxprop.cpp:174] Looking up auxiliary property '*userPassword'
I0813 19:08:49.208667 28179 auxprop.cpp:174] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0813 19:08:49.208684 28179 auxprop.cpp:102] Request to lookup properties for user: 'test-principal' realm: 'aff52502309c' server FQDN: 'aff52502309c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0813 19:08:49.208693 28179 auxprop.cpp:124] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0813 19:08:49.208699 28179 auxprop.cpp:124] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0813 19:08:49.208714 28179 authenticator.cpp:311] Authentication success
I0813 19:08:49.208794 28184 authenticatee.cpp:292] Authentication success
I0813 19:08:49.208832 28173 master.cpp:4723] Successfully authenticated principal 'test-principal' at slave(211)@172.17.1.212:48387
I0813 19:08:49.208863 28179 authenticator.cpp:425] Authentication session cleanup for crammd5_authenticatee(513)@172.17.1.212:48387
I0813 19:08:49.209065 28184 slave.cpp:815] Successfully authenticated with master master@172.17.1.212:48387
I0813 19:08:49.209179 28184 slave.cpp:1209] Will retry registration in 15.990074ms if necessary
I0813 19:08:49.209347 28178 master.cpp:3635] Registering slave at slave(211)@172.17.1.212:48387 (aff52502309c) with id 20150813-190848-3556839852-48387-28150-S0
I0813 19:08:49.209640 28178 process.cpp:3043] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0813 19:08:49.209756 28172 registrar.cpp:443] Applied 1 operations in 49626ns; attempting to update the 'registry'
I0813 19:08:49.210069 28178 master.cpp:1782] Received subscription request for HTTP framework 'default'
I0813 19:08:49.210134 28178 master.cpp:1563] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0813 19:08:49.210353 28178 master.cpp:1874] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0813 19:08:49.210789 28174 hierarchical.hpp:391] Added framework 20150813-190848-3556839852-48387-28150-0000
I0813 19:08:49.210820 28174 hierarchical.hpp:1008] No resources available to allocate!
I0813 19:08:49.210836 28174 hierarchical.hpp:908] Performed allocation for 0 slaves in 24664ns
I0813 19:08:49.210862 28174 master.hpp:1305] Sending heartbeat to 20150813-190848-3556839852-48387-28150-0000
I0813 19:08:49.212929 28173 log.cpp:685] Attempting to append 349 bytes to the log
I0813 19:08:49.213423 28182 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 3
../../src/tests/scheduler_tests.cpp:227: Failure
Value of: event.get().type()
Actual: HEARTBEAT
Expected: Event::OFFERS
Which is: OFFERS
../../src/tests/scheduler_tests.cpp:228: Failure
Expected: (0) != (event.get().offers().offers().size()), actual: 0 vs 0
[libprotobuf FATAL ../3rdparty/libprocess/3rdparty/protobuf-2.5.0/src/google/protobuf/repeated_field.h:824] CHECK failed: (index) < (size()):
I0813 19:08:49.214499 28182 replica.cpp:511] Replica received write request for position 3
../../src/tests/scheduler_tests.cpp:237: Failure
Actual function call count doesn't match EXPECT_CALL(containerizer, update(_, _))...
Expected: to be called at least once
Actual: never called - unsatisfied and active
../../src/tests/scheduler_tests.cpp:233: Failure
Actual function call count doesn't match EXPECT_CALL(exec, launchTask(_, _))...
Expected: to be called once
Actual: never called - unsatisfied and active
../../src/tests/scheduler_tests.cpp:230: Failure
Actual function call count doesn't match EXPECT_CALL(exec, registered(_, _, _, _))...
Expected: to be called once
Actual: never called - unsatisfied and active
unknown file: Failure
C++ exception with description "CHECK failed: (index) < (size()): " thrown in the test body.
I0813 19:08:49.216063 28184 master.cpp:859] Master terminating
I0813 19:08:49.216239 28173 hierarchical.hpp:428] Removed framework 20150813-190848-3556839852-48387-28150-0000
I0813 19:08:49.216831 28180 slave.cpp:3143] master@172.17.1.212:48387 exited
W0813 19:08:49.216863 28180 slave.cpp:3146] Master disconnected! Waiting for a new master to be elected
I0813 19:08:49.226332 28180 slave.cpp:1209] Will retry registration in 21.795247ms if necessary
I0813 19:08:49.248834 28179 slave.cpp:1209] Will retry registration in 57.286886ms if necessary
I0813 19:08:49.252660 28182 leveldb.cpp:343] Persisting action (368 bytes) to leveldb took 38.089232ms
I0813 19:08:49.252707 28182 replica.cpp:679] Persisted action at 3
F0813 19:08:49.252707 28150 logging.cpp:57] RAW: Pure virtual method called
@ 0x7f6b2a7599ae google::LogMessage::Fail()
@ 0x7f6b2a75ee90 google::RawLog__()
@ 0x7f6b29bb407a __cxa_pure_virtual
@ 0x8e281c mesos::internal::tests::Cluster::Slaves::shutdown()
@ 0xe2240e mesos::internal::tests::MesosTest::ShutdownSlaves()
@ 0xe223d0 mesos::internal::tests::MesosTest::Shutdown()
@ 0xe1e9b5 mesos::internal::tests::MesosTest::TearDown()
@ 0x131c0cc testing::internal::HandleSehExceptionsInMethodIfSupported<>()
I0813 19:08:49.307256 28175 slave.cpp:1209] Will retry registration in 68.974247ms if necessary
@ 0x1316f42 testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x12f85d2 testing::Test::Run()
@ 0x12f8d0c testing::TestInfo::Run()
@ 0x12f9352 testing::TestCase::Run()
@ 0x12ffc2c testing::internal::UnitTestImpl::RunAllTests()
@ 0x131ccf1 testing::internal::HandleSehExceptionsInMethodIfSupported<>()
@ 0x1317ab8 testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x12fe972 testing::UnitTest::Run()
@ 0xc8ec0f RUN_ALL_TESTS()
@ 0xc8e904 main
@ 0x7f6b25b27af5 __libc_start_main
@ 0x8d85e9 (unknown)
make[4]: *** [check-local] Aborted
make[4]: Leaving directory `/mesos/mesos-0.24.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.24.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.24.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.24.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1439491484-32520
Untagged: mesos-1439491484-32520:latest
Deleted: b48b79e09b9415c51a24cda5100a11cb8170818e0a71786c68d165ea4db74b6b
Deleted: 4636e993e5710f98e22656b9f1a003c5f6eb61cf3dae05a64f077d19678a8487
Deleted: fae447651b2c785bcd4c7d0381def1d8bbaf316653a36ba2b2c5bde09ae08819
Deleted: e3608c048f08c8a23ee3176606bc38d20aa78e07d960347a1971654e5b95d10a
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose --enable-libevent,centos:7,docker||Hadoop #706
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent,OS=centos%3A7,label_exp=docker%7C%7CHadoop/706/changes>
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent,centos:7,docker||Hadoop #705
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent,OS=centos%3A7,label_exp=docker%7C%7CHadoop/705/changes>
Changes:
[benjamin.mahler] Updated /scheduler endopint to use Request::acceptsMediaType.
[benjamin.mahler] Removed unnecessary std:: prefix in http_api_tests.cpp.
[benjamin.mahler] Ensure the Content-Type is set for the streaming scheduler endpoint.
[benjamin.mahler] Only accept POST requests for /scheduler endpoint.
------------------------------------------
[...truncated 86082 lines...]
I0813 20:02:11.164082 28165 replica.cpp:679] Persisted action at 2
I0813 20:02:11.164657 28173 replica.cpp:658] Replica received learned notice for position 2
I0813 20:02:11.165037 28173 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 356005ns
I0813 20:02:11.165110 28173 leveldb.cpp:401] Deleting ~1 keys from leveldb took 39035ns
I0813 20:02:11.165139 28173 replica.cpp:679] Persisted action at 2
I0813 20:02:11.165169 28173 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0813 20:02:11.173490 28141 scheduler.cpp:157] Version: 0.24.0
I0813 20:02:11.176462 28169 scheduler.cpp:272] New master detected at master@172.17.2.147:60576
I0813 20:02:11.179206 28161 process.cpp:3043] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0813 20:02:11.179620 28161 master.cpp:1782] Received subscription request for HTTP framework 'default'
I0813 20:02:11.179762 28161 master.cpp:1563] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0813 20:02:11.180390 28170 master.cpp:1874] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0813 20:02:11.180958 28173 hierarchical.hpp:391] Added framework 20150813-200211-2466386348-60576-28141-0000
I0813 20:02:11.180989 28173 hierarchical.hpp:1008] No resources available to allocate!
I0813 20:02:11.181002 28173 hierarchical.hpp:908] Performed allocation for 0 slaves in 19415ns
I0813 20:02:11.181350 28160 master.hpp:1305] Sending heartbeat to 20150813-200211-2466386348-60576-28141-0000
../../src/tests/scheduler_tests.cpp:168: Failure
Value of: event.get().type()
Actual: HEARTBEAT
Expected: Event::SUBSCRIBED
Which is: SUBSCRIBED
../../src/tests/scheduler_tests.cpp:169: Failure
Value of: event.get().subscribed().framework_id()
Actual:
Expected: id
Which is: 20150813-200211-2466386348-60576-28141-0000
I0813 20:02:11.183928 28163 master.cpp:859] Master terminating
I0813 20:02:11.184216 28172 hierarchical.hpp:428] Removed framework 20150813-200211-2466386348-60576-28141-0000
I0813 20:02:11.184322 28173 scheduler.cpp:381] Ignoring event from old stale connection
I0813 20:02:11.185564 28176 process.cpp:2319] Returning '404 Not Found' for '/master/api/v1/scheduler'
I0813 20:02:11.186532 28166 scheduler.cpp:421] Enqueuing locally injected event ERROR
[ FAILED ] SchedulerTest.Subscribe (62 ms)
[ RUN ] SchedulerTest.TaskRunning
Using temporary directory '/tmp/SchedulerTest_TaskRunning_1RHkGC'
I0813 20:02:11.193609 28141 leveldb.cpp:176] Opened db in 2.62104ms
I0813 20:02:11.194526 28141 leveldb.cpp:183] Compacted db in 877466ns
I0813 20:02:11.194572 28141 leveldb.cpp:198] Created db iterator in 18349ns
I0813 20:02:11.194588 28141 leveldb.cpp:204] Seeked to beginning of db in 1763ns
I0813 20:02:11.194597 28141 leveldb.cpp:273] Iterated through 0 keys in the db in 255ns
I0813 20:02:11.194636 28141 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0813 20:02:11.195144 28172 recover.cpp:449] Starting replica recovery
I0813 20:02:11.195443 28172 recover.cpp:475] Replica is in EMPTY status
I0813 20:02:11.196663 28173 replica.cpp:641] Replica in EMPTY status received a broadcasted recover request
I0813 20:02:11.197120 28167 recover.cpp:195] Received a recover response from a replica in EMPTY status
I0813 20:02:11.197602 28162 recover.cpp:566] Updating replica status to STARTING
I0813 20:02:11.198321 28165 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 537060ns
I0813 20:02:11.198348 28165 replica.cpp:323] Persisted replica status to STARTING
I0813 20:02:11.198395 28169 master.cpp:378] Master 20150813-200211-2466386348-60576-28141 (2ee8d4ab1990) started on 172.17.2.147:60576
I0813 20:02:11.198423 28169 master.cpp:380] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --credentials="/tmp/SchedulerTest_TaskRunning_1RHkGC/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.24.0/_inst/share/mesos/webui" --work_dir="/tmp/SchedulerTest_TaskRunning_1RHkGC/master" --zk_session_timeout="10secs"
I0813 20:02:11.198772 28161 recover.cpp:475] Replica is in STARTING status
I0813 20:02:11.198781 28169 master.cpp:427] Master allowing unauthenticated frameworks to register
I0813 20:02:11.198817 28169 master.cpp:430] Master only allowing authenticated slaves to register
I0813 20:02:11.198828 28169 credentials.hpp:37] Loading credentials for authentication from '/tmp/SchedulerTest_TaskRunning_1RHkGC/credentials'
I0813 20:02:11.199122 28169 master.cpp:469] Using default 'crammd5' authenticator
I0813 20:02:11.199252 28169 master.cpp:506] Authorization enabled
I0813 20:02:11.199462 28170 whitelist_watcher.cpp:79] No whitelist given
I0813 20:02:11.199511 28165 hierarchical.hpp:346] Initialized hierarchical allocator process
I0813 20:02:11.199839 28175 replica.cpp:641] Replica in STARTING status received a broadcasted recover request
I0813 20:02:11.200342 28166 recover.cpp:195] Received a recover response from a replica in STARTING status
I0813 20:02:11.200832 28175 master.cpp:1524] The newly elected leader is master@172.17.2.147:60576 with id 20150813-200211-2466386348-60576-28141
I0813 20:02:11.200863 28175 master.cpp:1537] Elected as the leading master!
I0813 20:02:11.200888 28175 master.cpp:1307] Recovering from registrar
I0813 20:02:11.200960 28167 recover.cpp:566] Updating replica status to VOTING
I0813 20:02:11.201076 28164 registrar.cpp:311] Recovering registrar
I0813 20:02:11.201614 28161 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 421us
I0813 20:02:11.201644 28161 replica.cpp:323] Persisted replica status to VOTING
I0813 20:02:11.201745 28165 recover.cpp:580] Successfully joined the Paxos group
I0813 20:02:11.201962 28165 recover.cpp:464] Recover process terminated
I0813 20:02:11.202394 28167 log.cpp:661] Attempting to start the writer
I0813 20:02:11.203536 28165 replica.cpp:477] Replica received implicit promise request with proposal 1
I0813 20:02:11.203922 28165 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 360792ns
I0813 20:02:11.203943 28165 replica.cpp:345] Persisted promised to 1
I0813 20:02:11.204581 28163 coordinator.cpp:231] Coordinator attemping to fill missing position
I0813 20:02:11.206003 28173 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2
I0813 20:02:11.206481 28173 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 437959ns
I0813 20:02:11.206506 28173 replica.cpp:679] Persisted action at 0
I0813 20:02:11.207825 28160 replica.cpp:511] Replica received write request for position 0
I0813 20:02:11.207898 28160 leveldb.cpp:438] Reading position from leveldb took 34554ns
I0813 20:02:11.208362 28160 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 410346ns
I0813 20:02:11.208397 28160 replica.cpp:679] Persisted action at 0
I0813 20:02:11.209245 28173 replica.cpp:658] Replica received learned notice for position 0
I0813 20:02:11.209749 28173 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 466878ns
I0813 20:02:11.209780 28173 replica.cpp:679] Persisted action at 0
I0813 20:02:11.209802 28173 replica.cpp:664] Replica learned NOP action at position 0
I0813 20:02:11.210458 28162 log.cpp:677] Writer started with ending position 0
I0813 20:02:11.211725 28168 leveldb.cpp:438] Reading position from leveldb took 30254ns
I0813 20:02:11.215116 28165 registrar.cpp:344] Successfully fetched the registry (0B) in 13.92896ms
I0813 20:02:11.215224 28165 registrar.cpp:443] Applied 1 operations in 21587ns; attempting to update the 'registry'
I0813 20:02:11.218530 28171 log.cpp:685] Attempting to append 178 bytes to the log
I0813 20:02:11.218744 28168 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I0813 20:02:11.219837 28165 replica.cpp:511] Replica received write request for position 1
I0813 20:02:11.220306 28165 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 428386ns
I0813 20:02:11.220330 28165 replica.cpp:679] Persisted action at 1
I0813 20:02:11.220873 28165 replica.cpp:658] Replica received learned notice for position 1
I0813 20:02:11.221276 28165 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 379363ns
I0813 20:02:11.221298 28165 replica.cpp:679] Persisted action at 1
I0813 20:02:11.221314 28165 replica.cpp:664] Replica learned APPEND action at position 1
I0813 20:02:11.222317 28168 registrar.cpp:488] Successfully updated the 'registry' in 6.953984ms
I0813 20:02:11.222448 28168 registrar.cpp:374] Successfully recovered registrar
I0813 20:02:11.222508 28162 log.cpp:704] Attempting to truncate the log to 1
I0813 20:02:11.222650 28174 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I0813 20:02:11.222811 28175 master.cpp:1334] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I0813 20:02:11.223445 28169 replica.cpp:511] Replica received write request for position 2
I0813 20:02:11.223891 28169 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 417487ns
I0813 20:02:11.223913 28169 replica.cpp:679] Persisted action at 2
I0813 20:02:11.224452 28163 replica.cpp:658] Replica received learned notice for position 2
I0813 20:02:11.224838 28163 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 359506ns
I0813 20:02:11.224889 28163 leveldb.cpp:401] Deleting ~1 keys from leveldb took 29554ns
I0813 20:02:11.224905 28163 replica.cpp:679] Persisted action at 2
I0813 20:02:11.224921 28163 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0813 20:02:11.239569 28163 slave.cpp:190] Slave started on 211)@172.17.2.147:60576
I0813 20:02:11.239598 28163 slave.cpp:191] Flags at startup: --authenticatee="crammd5" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SchedulerTest_TaskRunning_0MxV78/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SchedulerTest_TaskRunning_0MxV78/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher_dir="/mesos/mesos-0.24.0/_build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_monitoring_interval="1secs" --resources="cpus:2;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --version="false" --work_dir="/tmp/SchedulerTest_TaskRunning_0MxV78"
I0813 20:02:11.240008 28163 credentials.hpp:85] Loading credential for authentication from '/tmp/SchedulerTest_TaskRunning_0MxV78/credential'
I0813 20:02:11.240233 28163 slave.cpp:321] Slave using credential for: test-principal
I0813 20:02:11.240654 28163 slave.cpp:354] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0813 20:02:11.240749 28163 slave.cpp:384] Slave hostname: 2ee8d4ab1990
I0813 20:02:11.240768 28163 slave.cpp:389] Slave checkpoint: true
I0813 20:02:11.241502 28141 scheduler.cpp:157] Version: 0.24.0
I0813 20:02:11.241540 28170 state.cpp:54] Recovering state from '/tmp/SchedulerTest_TaskRunning_0MxV78/meta'
I0813 20:02:11.241891 28166 status_update_manager.cpp:202] Recovering status update manager
I0813 20:02:11.242292 28160 slave.cpp:4069] Finished recovery
I0813 20:02:11.242830 28160 slave.cpp:4226] Querying resource estimator for oversubscribable resources
I0813 20:02:11.243258 28164 status_update_manager.cpp:176] Pausing sending status updates
I0813 20:02:11.243258 28162 slave.cpp:684] New master detected at master@172.17.2.147:60576
I0813 20:02:11.243355 28162 slave.cpp:747] Authenticating with master master@172.17.2.147:60576
I0813 20:02:11.243376 28162 slave.cpp:752] Using default CRAM-MD5 authenticatee
I0813 20:02:11.243487 28162 slave.cpp:720] Detecting new master
I0813 20:02:11.243595 28172 authenticatee.cpp:115] Creating new client SASL connection
I0813 20:02:11.243676 28162 slave.cpp:4240] Received oversubscribable resources from the resource estimator
I0813 20:02:11.243825 28173 master.cpp:4693] Authenticating slave(211)@172.17.2.147:60576
I0813 20:02:11.243971 28174 authenticator.cpp:407] Starting authentication session for crammd5_authenticatee(514)@172.17.2.147:60576
I0813 20:02:11.244266 28172 authenticator.cpp:92] Creating new server SASL connection
I0813 20:02:11.244405 28169 scheduler.cpp:272] New master detected at master@172.17.2.147:60576
I0813 20:02:11.244490 28160 authenticatee.cpp:206] Received SASL authentication mechanisms: CRAM-MD5
I0813 20:02:11.244525 28160 authenticatee.cpp:232] Attempting to authenticate with mechanism 'CRAM-MD5'
I0813 20:02:11.244616 28172 authenticator.cpp:197] Received SASL authentication start
I0813 20:02:11.244675 28172 authenticator.cpp:319] Authentication requires more steps
I0813 20:02:11.244820 28166 authenticatee.cpp:252] Received SASL authentication step
I0813 20:02:11.244973 28173 authenticator.cpp:225] Received SASL authentication step
I0813 20:02:11.245085 28173 auxprop.cpp:102] Request to lookup properties for user: 'test-principal' realm: '2ee8d4ab1990' server FQDN: '2ee8d4ab1990' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0813 20:02:11.245097 28173 auxprop.cpp:174] Looking up auxiliary property '*userPassword'
I0813 20:02:11.245137 28173 auxprop.cpp:174] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0813 20:02:11.245157 28173 auxprop.cpp:102] Request to lookup properties for user: 'test-principal' realm: '2ee8d4ab1990' server FQDN: '2ee8d4ab1990' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0813 20:02:11.245165 28173 auxprop.cpp:124] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0813 20:02:11.245172 28173 auxprop.cpp:124] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0813 20:02:11.245184 28173 authenticator.cpp:311] Authentication success
I0813 20:02:11.245257 28171 authenticatee.cpp:292] Authentication success
I0813 20:02:11.245317 28162 master.cpp:4723] Successfully authenticated principal 'test-principal' at slave(211)@172.17.2.147:60576
I0813 20:02:11.245380 28164 authenticator.cpp:425] Authentication session cleanup for crammd5_authenticatee(514)@172.17.2.147:60576
I0813 20:02:11.245748 28169 slave.cpp:815] Successfully authenticated with master master@172.17.2.147:60576
I0813 20:02:11.245904 28169 slave.cpp:1209] Will retry registration in 14.100299ms if necessary
I0813 20:02:11.246101 28162 master.cpp:3635] Registering slave at slave(211)@172.17.2.147:60576 (2ee8d4ab1990) with id 20150813-200211-2466386348-60576-28141-S0
I0813 20:02:11.246536 28170 registrar.cpp:443] Applied 1 operations in 57347ns; attempting to update the 'registry'
I0813 20:02:11.246930 28167 process.cpp:3043] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0813 20:02:11.247246 28167 master.cpp:1782] Received subscription request for HTTP framework 'default'
I0813 20:02:11.247308 28167 master.cpp:1563] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0813 20:02:11.247647 28175 master.cpp:1874] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0813 20:02:11.248066 28174 hierarchical.hpp:391] Added framework 20150813-200211-2466386348-60576-28141-0000
I0813 20:02:11.248106 28174 hierarchical.hpp:1008] No resources available to allocate!
I0813 20:02:11.248128 28174 hierarchical.hpp:908] Performed allocation for 0 slaves in 30664ns
I0813 20:02:11.248190 28172 master.hpp:1305] Sending heartbeat to 20150813-200211-2466386348-60576-28141-0000
I0813 20:02:11.249675 28162 log.cpp:685] Attempting to append 349 bytes to the log
../../src/tests/scheduler_tests.cpp:227: Failure
Value of: event.get().type()
Actual: HEARTBEAT
Expected: Event::OFFERS
Which is: OFFERS
../../src/tests/scheduler_tests.cpp:228: Failure
Expected: (0) != (event.get().offers().offers().size()), actual: 0 vs 0
I0813 20:02:11.249964 28164 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 3
[libprotobuf FATAL ../3rdparty/libprocess/3rdparty/protobuf-2.5.0/src/google/protobuf/repeated_field.h:824] CHECK failed: (index) < (size()):
I0813 20:02:11.250907 28165 replica.cpp:511] Replica received write request for position 3
I0813 20:02:11.251133 28165 leveldb.cpp:343] Persisting action (368 bytes) to leveldb took 195906ns
I0813 20:02:11.251160 28165 replica.cpp:679] Persisted action at 3
../../src/tests/scheduler_tests.cpp:237: Failure
Actual function call count doesn't match EXPECT_CALL(containerizer, update(_, _))...
Expected: to be called at least once
Actual: never called - unsatisfied and active
../../src/tests/scheduler_tests.cpp:233: Failure
Actual function call count doesn't match EXPECT_CALL(exec, launchTask(_, _))...
Expected: to be called once
Actual: never called - unsatisfied and active
../../src/tests/scheduler_tests.cpp:230: Failure
Actual function call count doesn't match EXPECT_CALL(exec, registered(_, _, _, _))...
Expected: to be called once
Actual: never called - unsatisfied and active
unknown file: Failure
C++ exception with description "CHECK failed: (index) < (size()): " thrown in the test body.
I0813 20:02:11.251938 28166 replica.cpp:658] Replica received learned notice for position 3
I0813 20:02:11.252775 28172 master.cpp:859] Master terminating
I0813 20:02:11.252782 28166 leveldb.cpp:343] Persisting action (370 bytes) to leveldb took 779028ns
I0813 20:02:11.252806 28166 replica.cpp:679] Persisted action at 3
I0813 20:02:11.252823 28166 replica.cpp:664] Replica learned APPEND action at position 3
I0813 20:02:11.252967 28173 hierarchical.hpp:428] Removed framework 20150813-200211-2466386348-60576-28141-0000
I0813 20:02:11.253485 28169 slave.cpp:3143] master@172.17.2.147:60576 exited
W0813 20:02:11.253511 28169 slave.cpp:3146] Master disconnected! Waiting for a new master to be elected
I0813 20:02:11.254323 28166 registrar.cpp:488] Successfully updated the 'registry' in 7.804928ms
I0813 20:02:11.254698 28169 log.cpp:704] Attempting to truncate the log to 3
I0813 20:02:11.255136 28172 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 4
I0813 20:02:11.256557 28168 replica.cpp:511] Replica received write request for position 4
I0813 20:02:11.257201 28168 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 506755ns
I0813 20:02:11.257226 28168 replica.cpp:679] Persisted action at 4
F0813 20:02:11.257226 28141 logging.cpp:57] RAW: Pure virtual method called
I0813 20:02:11.261263 28161 slave.cpp:1209] Will retry registration in 18.751356ms if necessary
@ 0x7fa933f824c2 google::LogMessage::Fail()
@ 0x7fa933f879a4 google::RawLog__()
I0813 20:02:11.280647 28172 slave.cpp:1209] Will retry registration in 15.880689ms if necessary
@ 0x7fa9333dc54a __cxa_pure_virtual
@ 0x8e292c mesos::internal::tests::Cluster::Slaves::shutdown()
@ 0xe256f2 mesos::internal::tests::MesosTest::ShutdownSlaves()
@ 0xe256b4 mesos::internal::tests::MesosTest::Shutdown()
I0813 20:02:11.297019 28169 slave.cpp:1209] Will retry registration in 39.045502ms if necessary
@ 0xe21c99 mesos::internal::tests::MesosTest::TearDown()
@ 0x131f3b0 testing::internal::HandleSehExceptionsInMethodIfSupported<>()
@ 0x131a226 testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x12fb8b6 testing::Test::Run()
@ 0x12fbff0 testing::TestInfo::Run()
@ 0x12fc636 testing::TestCase::Run()
@ 0x1302f10 testing::internal::UnitTestImpl::RunAllTests()
@ 0x131ffd5 testing::internal::HandleSehExceptionsInMethodIfSupported<>()
@ 0x131ad9c testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x1301c56 testing::UnitTest::Run()
I0813 20:02:11.337594 28169 slave.cpp:1209] Will retry registration in 207.590345ms if necessary
@ 0xc91ef3 RUN_ALL_TESTS()
@ 0xc91be8 main
@ 0x7fa92f34faf5 __libc_start_main
@ 0x8d86f9 (unknown)
make[4]: *** [check-local] Aborted
make[4]: Leaving directory `/mesos/mesos-0.24.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.24.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.24.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.24.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1439494769-3818
Untagged: mesos-1439494769-3818:latest
Deleted: 768a073cc3b61257b211207e8e371cd3f689c5877ef22f17f7c997277ab4d904
Deleted: ad36d5b0287eb7e9f9a11eabda096453a65ac7606ff2d04fd5bb9d86ce0ae091
Deleted: 3ac1edcd2458ac80d539fa381b3da9348573d600bb7e4b5926783b68942c0004
Deleted: 7860da7bf18cbbc269d824b6dd7f87c6d4c2d937943071e947ed18881a6da51e
Deleted: 6a4882abe4145b0374173734983bb221473a969aacca2581bc23ce26f656bb28
Deleted: 0868f13c68aedac611dc3740fd361099f1774bdefa02ec6bd573a4139e79ca72
Deleted: 3d63f093f5d93b8cfc34dfa40fd7f4b014ac399f09fab7a2093bd7dd39a0fe5f
Deleted: 5ab42df1c2ffc74d2debe2faea4aa0a5dd494256fd7bf9e59e676d47ce2b231e
Deleted: 10647a21099b736a9c00415f3f1b2598fcf79c1dbe901b53bd8ef45d62e84e79
Deleted: 23f2686cb8d16f9736025f9c587e6c93da995a0b33943e5cb8131c3249ed8417
Build step 'Execute shell' marked build as failure