Sorry, I didn't realize the summary of this ticket had changed since this email was generated, and the plan is now to migrate the test to the new scheduler library.
On Mon, Mar 21, 2016 at 11:21 PM, Benjamin Mahler <bmah...@apache.org> wrote: > +joseph > > Have you seen this? > > On Tue, Mar 15, 2016 at 7:13 AM, Greg Mann (JIRA) <j...@apache.org> wrote: > >> Greg Mann created MESOS-4948: >> -------------------------------- >> >> Summary: MasterMaintenanceTest.InverseOffers is flaky >> Key: MESOS-4948 >> URL: https://issues.apache.org/jira/browse/MESOS-4948 >> Project: Mesos >> Issue Type: Bug >> Components: tests >> Environment: Ubuntu 14.04, using gcc, with libevent and SSL >> enabled (on ASF CI) >> Reporter: Greg Mann >> >> >> This seems to be an issue distinct from the other tickets that have been >> filed on this test. Failed log is included below; while the core dump >> appears just after the start of >> {{MasterMaintenanceTest.InverseOffersFilters}}, it looks to me like the >> segfault is triggered by one of the callbacks called at the end of >> {{MasterMaintenanceTest.InverseOffers}}. >> >> {code} >> [ RUN ] MasterMaintenanceTest.InverseOffers >> I0315 04:16:50.786032 2681 leveldb.cpp:174] Opened db in 125.361171ms >> I0315 04:16:50.836374 2681 leveldb.cpp:181] Compacted db in 50.254411ms >> I0315 04:16:50.836470 2681 leveldb.cpp:196] Created db iterator in >> 25917ns >> I0315 04:16:50.836488 2681 leveldb.cpp:202] Seeked to beginning of db in >> 3291ns >> I0315 04:16:50.836498 2681 leveldb.cpp:271] Iterated through 0 keys in >> the db in 253ns >> I0315 04:16:50.836549 2681 replica.cpp:779] Replica recovered with log >> positions 0 -> 0 with 1 holes and 0 unlearned >> I0315 04:16:50.837474 2702 recover.cpp:447] Starting replica recovery >> I0315 04:16:50.837565 2681 cluster.cpp:183] Creating default 'local' >> authorizer >> I0315 04:16:50.838191 2702 recover.cpp:473] Replica is in EMPTY status >> I0315 04:16:50.839532 2704 replica.cpp:673] Replica in EMPTY status >> received a broadcasted recover request from (4784)@172.17.0.4:39845 >> I0315 04:16:50.839754 2705 recover.cpp:193] Received a recover response >> from a replica in EMPTY status >> I0315 04:16:50.841893 2704 recover.cpp:564] Updating replica status to >> STARTING >> I0315 04:16:50.842566 2703 master.cpp:376] Master >> c326bc68-2581-48d4-9dc4-0d6f270bdda1 (01fcd642f65f) started on >> 172.17.0.4:39845 >> I0315 04:16:50.842644 2703 master.cpp:378] Flags at startup: --acls="" >> --allocation_interval="1secs" --allocator="HierarchicalDRF" >> --authenticate="false" --authenticate_http="true" >> --authenticate_slaves="true" --authenticators="crammd5" >> --authorizers="local" --credentials="/tmp/DE2Uaw/credentials" >> --framework_sorter="drf" --help="false" --hostname_lookup="true" >> --http_authenticators="basic" --initialize_driver_logging="true" >> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" >> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" >> --max_slave_ping_timeouts="5" --quiet="false" >> --recovery_slave_removal_limit="100%" --registry="replicated_log" >> --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" >> --registry_strict="true" --root_submissions="true" >> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" >> --user_sorter="drf" --version="false" >> --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui" >> --work_dir="/tmp/DE2Uaw/master" --zk_session_timeout="10secs" >> I0315 04:16:50.843168 2703 master.cpp:425] Master allowing >> unauthenticated frameworks to register >> I0315 04:16:50.843227 2703 master.cpp:428] Master only allowing >> authenticated slaves to register >> I0315 04:16:50.843302 2703 credentials.hpp:35] Loading credentials for >> authentication from '/tmp/DE2Uaw/credentials' >> I0315 04:16:50.843737 2703 master.cpp:468] Using default 'crammd5' >> authenticator >> I0315 04:16:50.843969 2703 master.cpp:537] Using default 'basic' HTTP >> authenticator >> I0315 04:16:50.844177 2703 master.cpp:571] Authorization enabled >> I0315 04:16:50.844360 2708 hierarchical.cpp:144] Initialized >> hierarchical allocator process >> I0315 04:16:50.844430 2708 whitelist_watcher.cpp:77] No whitelist given >> I0315 04:16:50.848227 2703 master.cpp:1806] The newly elected leader is >> master@172.17.0.4:39845 with id c326bc68-2581-48d4-9dc4-0d6f270bdda1 >> I0315 04:16:50.848269 2703 master.cpp:1819] Elected as the leading >> master! >> I0315 04:16:50.848292 2703 master.cpp:1508] Recovering from registrar >> I0315 04:16:50.848563 2703 registrar.cpp:307] Recovering registrar >> I0315 04:16:50.876277 2711 leveldb.cpp:304] Persisting metadata (8 >> bytes) to leveldb took 34.178445ms >> I0315 04:16:50.876365 2711 replica.cpp:320] Persisted replica status to >> STARTING >> I0315 04:16:50.876776 2711 recover.cpp:473] Replica is in STARTING status >> I0315 04:16:50.878779 2706 replica.cpp:673] Replica in STARTING status >> received a broadcasted recover request from (4786)@172.17.0.4:39845 >> I0315 04:16:50.879240 2706 recover.cpp:193] Received a recover response >> from a replica in STARTING status >> I0315 04:16:50.880100 2701 recover.cpp:564] Updating replica status to >> VOTING >> I0315 04:16:50.915776 2701 leveldb.cpp:304] Persisting metadata (8 >> bytes) to leveldb took 35.472106ms >> I0315 04:16:50.915868 2701 replica.cpp:320] Persisted replica status to >> VOTING >> I0315 04:16:50.916158 2701 recover.cpp:578] Successfully joined the >> Paxos group >> I0315 04:16:50.916363 2701 recover.cpp:462] Recover process terminated >> I0315 04:16:50.917192 2701 log.cpp:659] Attempting to start the writer >> I0315 04:16:50.919196 2714 replica.cpp:493] Replica received implicit >> promise request from (4787)@172.17.0.4:39845 with proposal 1 >> I0315 04:16:50.957757 2714 leveldb.cpp:304] Persisting metadata (8 >> bytes) to leveldb took 38.496305ms >> I0315 04:16:50.957844 2714 replica.cpp:342] Persisted promised to 1 >> I0315 04:16:50.959254 2714 coordinator.cpp:238] Coordinator attempting >> to fill missing positions >> I0315 04:16:50.960928 2712 replica.cpp:388] Replica received explicit >> promise request from (4788)@172.17.0.4:39845 for position 0 with >> proposal 2 >> I0315 04:16:51.000308 2712 leveldb.cpp:341] Persisting action (8 bytes) >> to leveldb took 39.300546ms >> I0315 04:16:51.000401 2712 replica.cpp:712] Persisted action at 0 >> I0315 04:16:51.002223 2707 replica.cpp:537] Replica received write >> request for position 0 from (4789)@172.17.0.4:39845 >> I0315 04:16:51.002362 2707 leveldb.cpp:436] Reading position from >> leveldb took 83026ns >> I0315 04:16:51.035646 2707 leveldb.cpp:341] Persisting action (14 bytes) >> to leveldb took 33.201925ms >> I0315 04:16:51.035750 2707 replica.cpp:712] Persisted action at 0 >> I0315 04:16:51.036618 2707 replica.cpp:691] Replica received learned >> notice for position 0 from @0.0.0.0:0 >> I0315 04:16:51.056340 2707 leveldb.cpp:341] Persisting action (16 bytes) >> to leveldb took 19.66721ms >> I0315 04:16:51.056438 2707 replica.cpp:712] Persisted action at 0 >> I0315 04:16:51.056480 2707 replica.cpp:697] Replica learned NOP action >> at position 0 >> I0315 04:16:51.057850 2715 log.cpp:675] Writer started with ending >> position 0 >> I0315 04:16:51.059509 2709 leveldb.cpp:436] Reading position from >> leveldb took 75281ns >> I0315 04:16:51.061115 2709 registrar.cpp:340] Successfully fetched the >> registry (0B) in 212.499968ms >> I0315 04:16:51.061276 2709 registrar.cpp:439] Applied 1 operations in >> 44901ns; attempting to update the 'registry' >> I0315 04:16:51.062515 2702 log.cpp:683] Attempting to append 170 bytes >> to the log >> I0315 04:16:51.062980 2709 coordinator.cpp:348] Coordinator attempting >> to write APPEND action at position 1 >> I0315 04:16:51.064456 2709 replica.cpp:537] Replica received write >> request for position 1 from (4790)@172.17.0.4:39845 >> I0315 04:16:51.098196 2709 leveldb.cpp:341] Persisting action (189 >> bytes) to leveldb took 33.666091ms >> I0315 04:16:51.098292 2709 replica.cpp:712] Persisted action at 1 >> I0315 04:16:51.099901 2709 replica.cpp:691] Replica received learned >> notice for position 1 from @0.0.0.0:0 >> I0315 04:16:51.142916 2709 leveldb.cpp:341] Persisting action (191 >> bytes) to leveldb took 42.95982ms >> I0315 04:16:51.143008 2709 replica.cpp:712] Persisted action at 1 >> I0315 04:16:51.143048 2709 replica.cpp:697] Replica learned APPEND >> action at position 1 >> I0315 04:16:51.145321 2709 registrar.cpp:484] Successfully updated the >> 'registry' in 83.969024ms >> I0315 04:16:51.145479 2709 registrar.cpp:370] Successfully recovered >> registrar >> I0315 04:16:51.145836 2702 log.cpp:702] Attempting to truncate the log >> to 1 >> I0315 04:16:51.146333 2706 master.cpp:1616] Recovered 0 slaves from the >> Registry (131B) ; allowing 10mins for slaves to re-register >> I0315 04:16:51.146528 2700 hierarchical.cpp:171] Skipping recovery of >> hierarchical allocator: nothing to recover >> I0315 04:16:51.147137 2700 coordinator.cpp:348] Coordinator attempting >> to write TRUNCATE action at position 2 >> I0315 04:16:51.148613 2700 replica.cpp:537] Replica received write >> request for position 2 from (4791)@172.17.0.4:39845 >> I0315 04:16:51.181690 2700 leveldb.cpp:341] Persisting action (16 bytes) >> to leveldb took 32.919462ms >> I0315 04:16:51.181779 2700 replica.cpp:712] Persisted action at 2 >> I0315 04:16:51.183358 2700 replica.cpp:691] Replica received learned >> notice for position 2 from @0.0.0.0:0 >> I0315 04:16:51.215826 2700 leveldb.cpp:341] Persisting action (18 bytes) >> to leveldb took 32.418101ms >> I0315 04:16:51.215983 2700 leveldb.cpp:399] Deleting ~1 keys from >> leveldb took 75363ns >> I0315 04:16:51.216012 2700 replica.cpp:712] Persisted action at 2 >> I0315 04:16:51.216049 2700 replica.cpp:697] Replica learned TRUNCATE >> action at position 2 >> I0315 04:16:51.230171 2700 slave.cpp:193] Slave started on 117)@ >> 172.17.0.4:39845 >> I0315 04:16:51.230217 2700 slave.cpp:194] Flags at startup: >> --appc_simple_discovery_uri_prefix="http://"; >> --appc_store_dir="/tmp/mesos/store/appc" --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/MasterMaintenanceTest_InverseOffers_7G6uyV/credential" >> --default_role="*" --disk_watch_interval="1mins" --docker="docker" >> --docker_kill_orphans="true" --docker_registry=" >> https://registry-1.docker.io"; --docker_remove_delay="6hrs" >> --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" >> --docker_store_dir="/tmp/mesos/store/docker" >> --enforce_container_disk_quota="false" >> --executor_registration_timeout="1mins" >> --executor_shutdown_grace_period="5secs" >> --fetcher_cache_dir="/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/fetch" >> --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" >> --gc_disk_headroom="0.1" --hadoop_home="" --help="false" >> --hostname="maintenance-host" --hostname_lookup="true" >> --image_provisioner_backend="copy" --initialize_driver_logging="true" >> --isolation="posix/cpu,posix/mem" >> --launcher_dir="/mesos/mesos-0.29.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" >> --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" --systemd_enable_support="true" >> --systemd_runtime_directory="/run/systemd/system" --version="false" >> --work_dir="/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV" >> I0315 04:16:51.230711 2700 credentials.hpp:83] Loading credential for >> authentication from >> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/credential' >> I0315 04:16:51.230989 2700 slave.cpp:324] Slave using credential for: >> test-principal >> I0315 04:16:51.231161 2700 resources.cpp:572] Parsing resources as JSON >> failed: cpus:2;mem:1024;disk:1024;ports:[31000-32000] >> Trying semicolon-delimited string format instead >> I0315 04:16:51.231653 2700 slave.cpp:464] Slave resources: cpus(*):2; >> mem(*):1024; disk(*):1024; ports(*):[31000-32000] >> I0315 04:16:51.232312 2700 slave.cpp:472] Slave attributes: [ ] >> I0315 04:16:51.232403 2700 slave.cpp:477] Slave hostname: >> maintenance-host >> I0315 04:16:51.235890 2705 state.cpp:58] Recovering state from >> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/meta' >> I0315 04:16:51.236862 2705 status_update_manager.cpp:200] Recovering >> status update manager >> I0315 04:16:51.237467 2705 slave.cpp:4565] Finished recovery >> I0315 04:16:51.237757 2715 process.cpp:3136] Handling HTTP event for >> process 'master' with path: '/master/maintenance/schedule' >> I0315 04:16:51.238085 2705 slave.cpp:4737] Querying resource estimator >> for oversubscribable resources >> I0315 04:16:51.239225 2715 http.cpp:312] HTTP POST for >> /master/maintenance/schedule from 172.17.0.4:53179 >> I0315 04:16:51.240380 2715 registrar.cpp:439] Applied 1 operations in >> 144666ns; attempting to update the 'registry' >> I0315 04:16:51.242146 2708 log.cpp:683] Attempting to append 292 bytes >> to the log >> I0315 04:16:51.242471 2708 coordinator.cpp:348] Coordinator attempting >> to write APPEND action at position 3 >> I0315 04:16:51.243657 2708 replica.cpp:537] Replica received write >> request for position 3 from (4798)@172.17.0.4:39845 >> I0315 04:16:51.244132 2705 slave.cpp:4751] Received oversubscribable >> resources from the resource estimator >> I0315 04:16:51.244442 2704 status_update_manager.cpp:174] Pausing >> sending status updates >> I0315 04:16:51.244591 2705 slave.cpp:796] New master detected at >> master@172.17.0.4:39845 >> I0315 04:16:51.244786 2705 slave.cpp:859] Authenticating with master >> master@172.17.0.4:39845 >> I0315 04:16:51.244886 2705 slave.cpp:864] Using default CRAM-MD5 >> authenticatee >> I0315 04:16:51.245357 2707 authenticatee.cpp:121] Creating new client >> SASL connection >> I0315 04:16:51.245787 2707 master.cpp:5659] Authenticating slave(117)@ >> 172.17.0.4:39845 >> I0315 04:16:51.246064 2707 authenticator.cpp:413] Starting >> authentication session for crammd5_authenticatee(301)@172.17.0.4:39845 >> I0315 04:16:51.246462 2707 authenticator.cpp:98] Creating new server >> SASL connection >> I0315 04:16:51.246776 2707 authenticatee.cpp:212] Received SASL >> authentication mechanisms: CRAM-MD5 >> I0315 04:16:51.246865 2707 authenticatee.cpp:238] Attempting to >> authenticate with mechanism 'CRAM-MD5' >> I0315 04:16:51.247047 2707 authenticator.cpp:203] Received SASL >> authentication start >> I0315 04:16:51.247180 2707 authenticator.cpp:325] Authentication >> requires more steps >> I0315 04:16:51.247341 2707 authenticatee.cpp:258] Received SASL >> authentication step >> I0315 04:16:51.247489 2707 authenticator.cpp:231] Received SASL >> authentication step >> I0315 04:16:51.247572 2707 auxprop.cpp:107] Request to lookup properties >> for user: 'test-principal' realm: '01fcd642f65f' server FQDN: >> '01fcd642f65f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false >> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false >> I0315 04:16:51.247640 2707 auxprop.cpp:179] Looking up auxiliary >> property '*userPassword' >> I0315 04:16:51.247807 2707 auxprop.cpp:179] Looking up auxiliary >> property '*cmusaslsecretCRAM-MD5' >> I0315 04:16:51.247920 2707 auxprop.cpp:107] Request to lookup properties >> for user: 'test-principal' realm: '01fcd642f65f' server FQDN: >> '01fcd642f65f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false >> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true >> I0315 04:16:51.248013 2707 auxprop.cpp:129] Skipping auxiliary property >> '*userPassword' since SASL_AUXPROP_AUTHZID == true >> I0315 04:16:51.248100 2707 auxprop.cpp:129] Skipping auxiliary property >> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true >> I0315 04:16:51.248196 2707 authenticator.cpp:317] Authentication success >> I0315 04:16:51.248461 2707 authenticatee.cpp:298] Authentication success >> I0315 04:16:51.248597 2707 master.cpp:5689] Successfully authenticated >> principal 'test-principal' at slave(117)@172.17.0.4:39845 >> I0315 04:16:51.248759 2700 authenticator.cpp:431] Authentication session >> cleanup for crammd5_authenticatee(301)@172.17.0.4:39845 >> I0315 04:16:51.248988 2705 slave.cpp:832] Detecting new master >> I0315 04:16:51.249363 2705 slave.cpp:927] Successfully authenticated >> with master master@172.17.0.4:39845 >> I0315 04:16:51.249506 2705 slave.cpp:1321] Will retry registration in >> 9.155413ms if necessary >> I0315 04:16:51.249981 2711 master.cpp:4370] Registering slave at >> slave(117)@172.17.0.4:39845 (maintenance-host) with id >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 >> I0315 04:16:51.261998 2711 slave.cpp:1321] Will retry registration in >> 10.936296ms if necessary >> I0315 04:16:51.262398 2711 master.cpp:4358] Ignoring register slave >> message from slave(117)@172.17.0.4:39845 (maintenance-host) as admission >> is already in progress >> I0315 04:16:51.275990 2711 slave.cpp:1321] Will retry registration in >> 3.200397ms if necessary >> I0315 04:16:51.276379 2711 master.cpp:4358] Ignoring register slave >> message from slave(117)@172.17.0.4:39845 (maintenance-host) as admission >> is already in progress >> I0315 04:16:51.277753 2708 leveldb.cpp:341] Persisting action (311 >> bytes) to leveldb took 33.976895ms >> I0315 04:16:51.277799 2708 replica.cpp:712] Persisted action at 3 >> I0315 04:16:51.279341 2708 replica.cpp:691] Replica received learned >> notice for position 3 from @0.0.0.0:0 >> I0315 04:16:51.281918 2711 slave.cpp:1321] Will retry registration in >> 131597ns if necessary >> I0315 04:16:51.282146 2700 master.cpp:4358] Ignoring register slave >> message from slave(117)@172.17.0.4:39845 (maintenance-host) as admission >> is already in progress >> I0315 04:16:51.283844 2711 slave.cpp:1321] Will retry registration in >> 245.466527ms if necessary >> I0315 04:16:51.284080 2711 master.cpp:4358] Ignoring register slave >> message from slave(117)@172.17.0.4:39845 (maintenance-host) as admission >> is already in progress >> I0315 04:16:51.318001 2708 leveldb.cpp:341] Persisting action (313 >> bytes) to leveldb took 38.528659ms >> I0315 04:16:51.318091 2708 replica.cpp:712] Persisted action at 3 >> I0315 04:16:51.318123 2708 replica.cpp:697] Replica learned APPEND >> action at position 3 >> I0315 04:16:51.320458 2711 registrar.cpp:484] Successfully updated the >> 'registry' in 79.843072ms >> I0315 04:16:51.320747 2714 log.cpp:702] Attempting to truncate the log >> to 3 >> I0315 04:16:51.320879 2704 coordinator.cpp:348] Coordinator attempting >> to write TRUNCATE action at position 4 >> I0315 04:16:51.320919 2711 registrar.cpp:439] Applied 1 operations in >> 118795ns; attempting to update the 'registry' >> I0315 04:16:51.322357 2704 replica.cpp:537] Replica received write >> request for position 4 from (4799)@172.17.0.4:39845 >> I0315 04:16:51.324488 2702 process.cpp:3136] Handling HTTP event for >> process 'master' with path: '/master/maintenance/status' >> I0315 04:16:51.325279 2702 http.cpp:312] HTTP GET for >> /master/maintenance/status from 172.17.0.4:53180 >> I0315 04:16:51.328512 2681 scheduler.cpp:172] Version: 0.29.0 >> I0315 04:16:51.329731 2703 scheduler.cpp:437] New master detected at >> master@172.17.0.4:39845 >> I0315 04:16:51.332334 2702 scheduler.cpp:337] Connected with the master >> at http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> >> 04:16:51.333514 2714 scheduler.cpp:230] Sending SUBSCRIBE call to >> http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> 04:16:51.334751 >> 2708 process.cpp:3136] Handling HTTP event for process 'master' with >> path: '/master/api/v1/scheduler' >> I0315 04:16:51.335245 2702 http.cpp:312] HTTP POST for >> /master/api/v1/scheduler from 172.17.0.4:53181 >> I0315 04:16:51.335464 2702 master.cpp:2068] Received subscription >> request for HTTP framework 'default' >> I0315 04:16:51.335528 2702 master.cpp:1845] Authorizing framework >> principal 'test-principal' to receive offers for role '*' >> I0315 04:16:51.335896 2713 master.cpp:2159] Subscribing framework >> 'default' with checkpointing disabled and capabilities [ ] >> I0315 04:16:51.337347 2700 hierarchical.cpp:265] Added framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.337435 2700 hierarchical.cpp:1453] No resources available >> to allocate! >> I0315 04:16:51.337471 2700 hierarchical.cpp:1548] No inverse offers to >> send out! >> I0315 04:16:51.337496 2700 hierarchical.cpp:1130] Performed allocation >> for 0 slaves in 122430ns >> I0315 04:16:51.337657 2700 master.hpp:1715] Sending heartbeat to >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.338486 2711 scheduler.cpp:612] Enqueuing event SUBSCRIBED >> received from http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> >> 04:16:51.339167 2711 scheduler.cpp:612] Enqueuing event HEARTBEAT received >> from http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> 04:16:51.339838 >> 2714 master_maintenance_tests.cpp:179] Ignoring HEARTBEAT event >> I0315 04:16:51.359691 2704 leveldb.cpp:341] Persisting action (16 bytes) >> to leveldb took 37.255846ms >> I0315 04:16:51.359787 2704 replica.cpp:712] Persisted action at 4 >> I0315 04:16:51.361541 2702 replica.cpp:691] Replica received learned >> notice for position 4 from @0.0.0.0:0 >> I0315 04:16:51.393460 2702 leveldb.cpp:341] Persisting action (18 bytes) >> to leveldb took 31.826446ms >> I0315 04:16:51.393631 2702 leveldb.cpp:399] Deleting ~2 keys from >> leveldb took 82223ns >> I0315 04:16:51.393667 2702 replica.cpp:712] Persisted action at 4 >> I0315 04:16:51.393718 2702 replica.cpp:697] Replica learned TRUNCATE >> action at position 4 >> I0315 04:16:51.395421 2702 log.cpp:683] Attempting to append 465 bytes >> to the log >> I0315 04:16:51.395716 2702 coordinator.cpp:348] Coordinator attempting >> to write APPEND action at position 5 >> I0315 04:16:51.397063 2702 replica.cpp:537] Replica received write >> request for position 5 from (4803)@172.17.0.4:39845 >> I0315 04:16:51.430773 2702 leveldb.cpp:341] Persisting action (484 >> bytes) to leveldb took 33.553652ms >> I0315 04:16:51.430871 2702 replica.cpp:712] Persisted action at 5 >> I0315 04:16:51.432451 2702 replica.cpp:691] Replica received learned >> notice for position 5 from @0.0.0.0:0 >> I0315 04:16:51.473805 2702 leveldb.cpp:341] Persisting action (486 >> bytes) to leveldb took 41.212274ms >> I0315 04:16:51.473908 2702 replica.cpp:712] Persisted action at 5 >> I0315 04:16:51.473949 2702 replica.cpp:697] Replica learned APPEND >> action at position 5 >> I0315 04:16:51.476976 2703 registrar.cpp:484] Successfully updated the >> 'registry' in 155.968768ms >> I0315 04:16:51.477423 2703 log.cpp:702] Attempting to truncate the log >> to 5 >> I0315 04:16:51.477689 2703 coordinator.cpp:348] Coordinator attempting >> to write TRUNCATE action at position 6 >> I0315 04:16:51.478329 2702 master.cpp:4438] Registered slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845 >> (maintenance-host) with cpus(*):2; mem(*):1024; disk(*):1024; >> ports(*):[31000-32000] >> I0315 04:16:51.478806 2713 hierarchical.cpp:473] Added slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 (maintenance-host) with cpus(*):2; >> mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: ) >> I0315 04:16:51.479184 2702 replica.cpp:537] Replica received write >> request for position 6 from (4804)@172.17.0.4:39845 >> I0315 04:16:51.478400 2703 slave.cpp:3482] Received ping from >> slave-observer(117)@172.17.0.4:39845 >> I0315 04:16:51.479872 2703 slave.cpp:971] Registered with master >> master@172.17.0.4:39845; given slave ID >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 >> I0315 04:16:51.479902 2703 fetcher.cpp:81] Clearing fetcher cache >> I0315 04:16:51.480332 2703 slave.cpp:994] Checkpointing SlaveInfo to >> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/meta/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/ >> slave.info' >> I0315 04:16:51.480789 2712 status_update_manager.cpp:181] Resuming >> sending status updates >> I0315 04:16:51.481290 2713 hierarchical.cpp:1150] Performed allocation >> for slave c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 in 2.431536ms >> I0315 04:16:51.481817 2703 slave.cpp:1030] Forwarding total >> oversubscribed resources >> I0315 04:16:51.482067 2713 master.cpp:5488] Sending 1 offers to >> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) >> I0315 04:16:51.483192 2713 master.cpp:5578] Sending 1 inverse offers to >> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) >> I0315 04:16:51.483569 2713 master.cpp:4782] Received update of slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845 >> (maintenance-host) with total oversubscribed resources >> I0315 04:16:51.484576 2713 hierarchical.cpp:531] Slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 (maintenance-host) updated with >> oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024; >> ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024; >> ports(*):[31000-32000]) >> I0315 04:16:51.484849 2713 hierarchical.cpp:1453] No resources available >> to allocate! >> I0315 04:16:51.484966 2701 scheduler.cpp:612] Enqueuing event OFFERS >> received from http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> >> 04:16:51.485061 2713 hierarchical.cpp:1150] Performed allocation for slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 in 414324ns >> I0315 04:16:51.485884 2701 scheduler.cpp:612] Enqueuing event OFFERS >> received from http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> >> 04:16:51.491091 2701 scheduler.cpp:230] Sending ACCEPT call to >> http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> >> 04:16:51.493937 2712 process.cpp:3136] Handling HTTP event for process >> 'master' with path: '/master/api/v1/scheduler' >> I0315 04:16:51.494441 2714 http.cpp:312] HTTP POST for >> /master/api/v1/scheduler from 172.17.0.4:53182 >> I0315 04:16:51.495529 2714 master.cpp:3268] Processing ACCEPT call for >> offers: [ c326bc68-2581-48d4-9dc4-0d6f270bdda1-O0 ] on slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845 >> (maintenance-host) for framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> (default) >> I0315 04:16:51.495589 2714 master.cpp:2871] Authorizing framework >> principal 'test-principal' to launch task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 as user 'mesos' >> W0315 04:16:51.501534 2714 validation.cpp:404] Executor default for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 uses less CPUs (None) than the minimum >> required (0.01). Please update your executor, as this will be mandatory in >> future releases. >> W0315 04:16:51.501618 2714 validation.cpp:416] Executor default for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 uses less memory (None) than the >> minimum required (32MB). Please update your executor, as this will be >> mandatory in future releases. >> I0315 04:16:51.502182 2714 master.hpp:177] Adding task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 with resources cpus(*):2; mem(*):1024; >> disk(*):1024; ports(*):[31000-32000] on slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 (maintenance-host) >> I0315 04:16:51.502437 2714 master.cpp:3753] Launching task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) with resources >> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845 >> (maintenance-host) >> I0315 04:16:51.503787 2700 slave.cpp:1361] Got assigned task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 for framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.504485 2700 slave.cpp:1480] Launching task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 for framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.512953 2700 paths.cpp:528] Trying to chown >> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b' >> to user 'mesos' >> I0315 04:16:51.519822 2702 leveldb.cpp:341] Persisting action (16 bytes) >> to leveldb took 40.48414ms >> I0315 04:16:51.519923 2702 replica.cpp:712] Persisted action at 6 >> I0315 04:16:51.521419 2710 replica.cpp:691] Replica received learned >> notice for position 6 from @0.0.0.0:0 >> I0315 04:16:51.524533 2700 slave.cpp:5367] Launching executor default of >> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 with resources in work >> directory >> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b' >> I0315 04:16:51.527022 2700 exec.cpp:143] Version: 0.29.0 >> I0315 04:16:51.527752 2704 exec.cpp:193] Executor started at: >> executor(47)@172.17.0.4:39845 with pid 2681 >> I0315 04:16:51.527802 2700 slave.cpp:1698] Queuing task >> 'ce9b06cb-9896-4c2e-9fad-ea8538541cf4' for executor 'default' of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.527966 2700 slave.cpp:749] Successfully attached file >> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b' >> I0315 04:16:51.528192 2700 slave.cpp:2643] Got registration for executor >> 'default' of framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from >> executor(47)@172.17.0.4:39845 >> I0315 04:16:51.529881 2706 exec.cpp:217] Executor registered on slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 >> I0315 04:16:51.529955 2706 exec.cpp:229] Executor::registered took >> 36242ns >> I0315 04:16:51.530278 2700 slave.cpp:1863] Sending queued task >> 'ce9b06cb-9896-4c2e-9fad-ea8538541cf4' to executor 'default' of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 at executor(47)@ >> 172.17.0.4:39845 >> I0315 04:16:51.530894 2708 exec.cpp:304] Executor asked to run task >> 'ce9b06cb-9896-4c2e-9fad-ea8538541cf4' >> I0315 04:16:51.530988 2708 exec.cpp:313] Executor::launchTask took >> 67937ns >> I0315 04:16:51.531083 2708 exec.cpp:526] Executor sending status update >> TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.531365 2708 slave.cpp:3002] Handling status update >> TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from executor(47)@ >> 172.17.0.4:39845 >> I0315 04:16:51.532158 2708 status_update_manager.cpp:320] Received >> status update TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for >> task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.532274 2708 status_update_manager.cpp:497] Creating >> StatusUpdate stream for task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of >> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.532951 2708 status_update_manager.cpp:374] Forwarding >> update TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 to the slave >> I0315 04:16:51.533524 2708 slave.cpp:3400] Forwarding the update >> TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 to master@172.17.0.4:39845 >> I0315 04:16:51.533817 2708 slave.cpp:3294] Status update manager >> successfully handled status update TASK_RUNNING (UUID: >> 5c63475c-af40-417d-9368-b7e3ede4a30e) for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.533936 2708 slave.cpp:3310] Sending acknowledgement for >> status update TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for >> task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 to executor(47)@ >> 172.17.0.4:39845 >> I0315 04:16:51.534340 2708 master.cpp:4927] Status update TASK_RUNNING >> (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845 >> (maintenance-host) >> I0315 04:16:51.534457 2708 master.cpp:4975] Forwarding status update >> TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.534803 2701 exec.cpp:350] Executor received status update >> acknowledgement 5c63475c-af40-417d-9368-b7e3ede4a30e for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.535385 2708 master.cpp:6585] Updating the state of task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (latest state: TASK_RUNNING, >> status update state: TASK_RUNNING) >> I0315 04:16:51.537346 2704 scheduler.cpp:612] Enqueuing event UPDATE >> received from http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> >> 04:16:51.541487 2708 scheduler.cpp:230] Sending ACKNOWLEDGE call to >> http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> >> 04:16:51.542043 2708 scheduler.cpp:230] Sending DECLINE call to >> http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> >> 04:16:51.543292 2708 process.cpp:3136] Handling HTTP event for process >> 'master' with path: '/master/api/v1/scheduler' >> I0315 04:16:51.543979 2708 http.cpp:312] HTTP POST for >> /master/api/v1/scheduler from 172.17.0.4:53182 >> I0315 04:16:51.544251 2708 master.cpp:4082] Processing ACKNOWLEDGE call >> 5c63475c-af40-417d-9368-b7e3ede4a30e for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) on slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 >> I0315 04:16:51.544818 2708 status_update_manager.cpp:392] Received >> status update acknowledgement (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) >> for task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.545315 2708 slave.cpp:2412] Status update manager >> successfully handled status update acknowledgement (UUID: >> 5c63475c-af40-417d-9368-b7e3ede4a30e) for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.546144 2702 process.cpp:3136] Handling HTTP event for >> process 'master' with path: '/master/api/v1/scheduler' >> I0315 04:16:51.546668 2702 http.cpp:312] HTTP POST for >> /master/api/v1/scheduler from 172.17.0.4:53182 >> I0315 04:16:51.547322 2702 master.cpp:3805] Processing DECLINE call for >> offers: [ c326bc68-2581-48d4-9dc4-0d6f270bdda1-O1 ] for framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) >> I0315 04:16:51.565781 2710 leveldb.cpp:341] Persisting action (18 bytes) >> to leveldb took 44.297436ms >> I0315 04:16:51.565945 2710 leveldb.cpp:399] Deleting ~2 keys from >> leveldb took 76582ns >> I0315 04:16:51.565978 2710 replica.cpp:712] Persisted action at 6 >> I0315 04:16:51.566015 2710 replica.cpp:697] Replica learned TRUNCATE >> action at position 6 >> I0315 04:16:51.570482 2707 hierarchical.cpp:1453] No resources available >> to allocate! >> I0315 04:16:51.570847 2707 hierarchical.cpp:1130] Performed allocation >> for 1 slaves in 640118ns >> I0315 04:16:51.571091 2707 master.cpp:5578] Sending 1 inverse offers to >> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) >> I0315 04:16:51.573333 2712 scheduler.cpp:612] Enqueuing event OFFERS >> received from http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> >> 04:16:51.581941 2713 process.cpp:3136] Handling HTTP event for process >> 'master' with path: '/master/maintenance/status' >> I0315 04:16:51.582535 2706 http.cpp:312] HTTP GET for >> /master/maintenance/status from 172.17.0.4:53183 >> I0315 04:16:51.587846 2715 scheduler.cpp:230] Sending ACCEPT call to >> http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> >> 04:16:51.589800 2715 process.cpp:3136] Handling HTTP event for process >> 'master' with path: '/master/api/v1/scheduler' >> I0315 04:16:51.590328 2715 http.cpp:312] HTTP POST for >> /master/api/v1/scheduler from 172.17.0.4:53182 >> W0315 04:16:51.590833 2715 master.cpp:3231] ACCEPT call used invalid >> offers '[ c326bc68-2581-48d4-9dc4-0d6f270bdda1-O2 ]': Offer >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-O2 is no longer valid >> I0315 04:16:51.603070 2706 hierarchical.cpp:1453] No resources available >> to allocate! >> I0315 04:16:51.603425 2706 hierarchical.cpp:1130] Performed allocation >> for 1 slaves in 570929ns >> I0315 04:16:51.603674 2706 master.cpp:5578] Sending 1 inverse offers to >> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) >> I0315 04:16:51.605583 2711 scheduler.cpp:612] Enqueuing event OFFERS >> received from http://172.17.0.4:39845/master/api/v1/scheduler >> I0315 <http://172.17.0.4:39845/master/api/v1/schedulerI0315> >> 04:16:51.614972 2709 process.cpp:3136] Handling HTTP event for process >> 'master' with path: '/master/maintenance/status' >> I0315 04:16:51.616044 2713 http.cpp:312] HTTP GET for >> /master/maintenance/status from 172.17.0.4:53184 >> I0315 04:16:51.620043 2681 master.cpp:1065] Master terminating >> W0315 04:16:51.620407 2681 master.cpp:6637] Removing task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 with resources cpus(*):2; mem(*):1024; >> disk(*):1024; ports(*):[31000-32000] of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 on slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845 >> (maintenance-host) in non-terminal state TASK_RUNNING >> I0315 04:16:51.621245 2712 hierarchical.cpp:505] Removed slave >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 >> I0315 04:16:51.621573 2681 master.cpp:6680] Removing executor 'default' >> with resources of framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 on >> slave c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@ >> 172.17.0.4:39845 (maintenance-host) >> I0315 04:16:51.622886 2704 hierarchical.cpp:326] Removed framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> E0315 04:16:51.624392 2705 scheduler.cpp:585] End-Of-File received from >> master. The master closed the event stream >> I0315 04:16:51.628783 2703 slave.cpp:3528] master@172.17.0.4:39845 >> exited >> W0315 04:16:51.628839 2703 slave.cpp:3531] Master disconnected! Waiting >> for a new master to be elected >> I0315 04:16:51.632709 2704 slave.cpp:3528] executor(47)@172.17.0.4:39845 >> exited >> I0315 04:16:51.633152 2704 slave.cpp:3886] Executor 'default' of >> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 exited with status 0 >> I0315 04:16:51.633311 2704 slave.cpp:3002] Handling status update >> TASK_FAILED (UUID: f793d2cc-720c-4d89-91d5-3f45e73ad6ea) for task >> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from @0.0.0.0:0 >> I0315 04:16:51.641787 2704 slave.cpp:668] Slave terminating >> I0315 04:16:51.641914 2704 slave.cpp:2079] Asked to shut down framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 by @0.0.0.0:0 >> I0315 04:16:51.641957 2704 slave.cpp:2104] Shutting down framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.642027 2704 slave.cpp:3990] Cleaning up executor >> 'default' of framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 at >> executor(47)@172.17.0.4:39845 >> I0315 04:16:51.642453 2704 slave.cpp:4078] Cleaning up framework >> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.642616 2707 gc.cpp:55] Scheduling >> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b' >> for gc 6.99999256701333days in the future >> I0315 04:16:51.642633 2710 status_update_manager.cpp:282] Closing status >> update streams for framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.642719 2710 status_update_manager.cpp:528] Cleaning up >> status update stream for task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of >> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 >> I0315 04:16:51.643265 2707 gc.cpp:55] Scheduling >> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default' >> for gc 6.99999256488296days in the future >> I0315 04:16:51.643373 2707 gc.cpp:55] Scheduling >> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000' >> for gc 6.99999256301037days in the future >> I0315 04:16:51.646150 2705 scheduler.cpp:419] Re-detecting master >> I0315 04:16:51.646462 2705 scheduler.cpp:370] Ignoring disconnection >> attempt from stale connection >> I0315 04:16:51.646507 2705 scheduler.cpp:370] Ignoring disconnection >> attempt from stale connection >> [ OK ] MasterMaintenanceTest.InverseOffers (992 ms) >> [ RUN ] MasterMaintenanceTest.InverseOffersFilters >> *** Aborted at 1458015411 (unix time) try "date -d @1458015411" if you >> are using GNU date *** >> PC: @ 0x172ca21 >> testing::internal::UntypedFunctionMockerBase::UntypedInvokeWith() >> *** SIGSEGV (@0x0) received by PID 2681 (TID 0x2afe25c47700) from PID 0; >> stack trace: *** >> @ 0x2afe689dfff7 (unknown) >> @ 0x2afe689e4159 (unknown) >> @ 0x2afe1b57d340 (unknown) >> @ 0x172ca21 >> testing::internal::UntypedFunctionMockerBase::UntypedInvokeWith() >> @ 0xf494ff >> testing::internal::FunctionMockerBase<>::InvokeWith() >> @ 0xf43663 testing::internal::FunctionMocker<>::Invoke() >> @ 0xf42920 >> mesos::internal::tests::MasterMaintenanceTest::Callbacks::disconnected() >> @ 0xf5ab55 >> _ZNKSt7_Mem_fnIMN5mesos8internal5tests21MasterMaintenanceTest9CallbacksEFvvEEclIJEvEEvRS4_DpOT_ >> @ 0xf57120 >> _ZNSt5_BindIFSt7_Mem_fnIMN5mesos8internal5tests21MasterMaintenanceTest9CallbacksEFvvEESt17reference_wrapperIS5_EEE6__callIvJEJLm0EEEET_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE >> @ 0xf52d84 std::_Bind<>::operator()<>() >> @ 0xf4e099 std::_Function_handler<>::_M_invoke() >> @ 0x99f3ac std::function<>::operator()() >> I0315 04:16:51.810700 2681 leveldb.cpp:174] Opened db in 153.621998ms >> @ 0x2afe188c14e9 process::AsyncExecutorProcess::execute<>() >> @ 0x2afe188c8d09 >> _ZZN7process8dispatchI7NothingNS_20AsyncExecutorProcessERKSt8functionIFvvEEPvS5_S8_EENS_6FutureIT_EERKNS_3PIDIT0_EEMSD_FSA_T1_T2_ET3_T4_ENKUlPNS_11ProcessBaseEE_clESO_ >> @ 0x2afe188d48b1 >> _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEEZNS0_8dispatchI7NothingNS0_20AsyncExecutorProcessERKSt8functionIFvvEEPvS9_SC_EENS0_6FutureIT_EERKNS0_3PIDIT0_EEMSH_FSE_T1_T2_ET3_T4_EUlS2_E_E9_M_invokeERKSt9_Any_dataS2_ >> @ 0x2afe197a8c61 std::function<>::operator()() >> I0315 04:16:51.855080 2681 leveldb.cpp:181] Compacted db in 44.189206ms >> I0315 04:16:51.855180 2681 leveldb.cpp:196] Created db iterator in >> 27246ns >> I0315 04:16:51.855200 2681 leveldb.cpp:202] Seeked to beginning of db in >> 3314ns >> I0315 04:16:51.855211 2681 leveldb.cpp:271] Iterated through 0 keys in >> the db in 364ns >> I0315 04:16:51.855265 2681 replica.cpp:779] Replica recovered with log >> positions 0 -> 0 with 1 holes and 0 unlearned >> I0315 04:16:51.856449 2681 cluster.cpp:183] Creating default 'local' >> authorizer >> I0315 04:16:51.859966 2709 master.cpp:376] Master >> d429b4cf-027e-46a9-97af-226792924cc4 (01fcd642f65f) started on >> 172.17.0.4:39845 >> @ 0x2afe1978ee7f process::ProcessBase::visit() >> I0315 04:16:51.860005 2709 master.cpp:378] Flags at startup: --acls="" >> --allocation_interval="1secs" --allocator="HierarchicalDRF" >> --authenticate="false" --authenticate_http="true" >> --authenticate_slaves="true" --authenticators="crammd5" >> --authorizers="local" --credentials="/tmp/rHaIvb/credentials" >> --framework_sorter="drf" --help="false" --hostname_lookup="true" >> --http_authenticators="basic" --initialize_driver_logging="true" >> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" >> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" >> --max_slave_ping_timeouts="5" --quiet="false" >> --recovery_slave_removal_limit="100%" --registry="replicated_log" >> --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" >> --registry_strict="true" --root_submissions="true" >> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" >> --user_sorter="drf" --version="false" >> --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui" >> --work_dir="/tmp/rHaIvb/master" --zk_session_timeout="10secs" >> I0315 04:16:51.860431 2709 master.cpp:425] Master allowing >> unauthenticated frameworks to register >> I0315 04:16:51.860445 2709 master.cpp:428] Master only allowing >> authenticated slaves to register >> I0315 04:16:51.860453 2709 credentials.hpp:35] Loading credentials for >> authentication from '/tmp/rHaIvb/credentials' >> I0315 04:16:51.861218 2709 master.cpp:468] Using default 'crammd5' >> authenticator >> I0315 04:16:51.861392 2709 master.cpp:537] Using default 'basic' HTTP >> authenticator >> I0315 04:16:51.861528 2709 master.cpp:571] Authorization enabled >> I0315 04:16:51.861888 2706 hierarchical.cpp:144] Initialized >> hierarchical allocator process >> I0315 04:16:51.861968 2706 whitelist_watcher.cpp:77] No whitelist given >> I0315 04:16:51.862046 2714 recover.cpp:447] Starting replica recovery >> I0315 04:16:51.862376 2714 recover.cpp:473] Replica is in EMPTY status >> I0315 04:16:51.867487 2705 replica.cpp:673] Replica in EMPTY status >> received a broadcasted recover request from (4813)@172.17.0.4:39845 >> I0315 04:16:51.868098 2713 recover.cpp:193] Received a recover response >> from a replica in EMPTY status >> @ 0x2afe19794e0c process::DispatchEvent::visit() >> I0315 04:16:51.868788 2715 recover.cpp:564] Updating replica status to >> STARTING >> I0315 04:16:51.871018 2701 master.cpp:1806] The newly elected leader is >> master@172.17.0.4:39845 with id d429b4cf-027e-46a9-97af-226792924cc4 >> I0315 04:16:51.871063 2701 master.cpp:1819] Elected as the leading >> master! >> I0315 04:16:51.871083 2701 master.cpp:1508] Recovering from registrar >> I0315 04:16:51.871234 2707 registrar.cpp:307] Recovering registrar >> @ 0x99d90c process::ProcessBase::serve() >> @ 0x2afe1978b078 process::ProcessManager::resume() >> @ 0x2afe19788112 >> _ZZN7process14ProcessManager12init_threadsEvENKUlRKSt11atomic_boolE_clES3_ >> @ 0x2afe197945ce >> _ZNSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS3_EEE6__callIvIEILm0EEEET_OSt5tupleIIDpT0_EESt12_Index_tupleIIXspT1_EEE >> @ 0x2afe1979457e >> _ZNSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS3_EEEclIIEvEET0_DpOT_ >> @ 0x2afe19794510 >> _ZNSt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS4_EEEvEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE >> @ 0x2afe19794467 >> _ZNSt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS4_EEEvEEclEv >> @ 0x2afe19794400 >> _ZNSt6thread5_ImplISt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS6_EEEvEEE6_M_runEv >> @ 0x2afe1adfea60 (unknown) >> @ 0x2afe1b575182 start_thread >> @ 0x2afe1b88547d (unknown) >> make[4]: *** [check-local] Segmentation fault >> make[4]: Leaving directory `/mesos/mesos-0.29.0/_build/src' >> make[3]: *** [check-am] Error 2 >> make[3]: Leaving directory `/mesos/mesos-0.29.0/_build/src' >> make[2]: *** [check] Error 2 >> make[2]: Leaving directory `/mesos/mesos-0.29.0/_build/src' >> make[1]: *** [check-recursive] Error 1 >> make[1]: Leaving directory `/mesos/mesos-0.29.0/_build' >> make: *** [distcheck] Error 1 >> + docker rmi mesos-1458012352-18905 >> Untagged: mesos-1458012352-18905:latest >> Deleted: 136cfc69a211fc726228e37ee0b50f9d79ef349a6c5e2ac33c569c68057ab614 >> Deleted: fc91397a445e569ffadf2e537efdd1207bfad4d82534049de6d641ba98daa368 >> Deleted: b69b88c1e1cd00181d5c9154f3e9619ec8fb3afe892aeb0490f0765aebf780d8 >> Deleted: 17e1610f1e27666a13f8ca079e9ebb11c24494b8a5ed4ed5df877691ba470435 >> Deleted: d5fa89bf05553adfc6f954ce4ba7d916e71341915211c817d05975f52f4bc12e >> Deleted: 144027a85962f820f57caaf7d2104455214a428b1d0af893c9a8de74edd97e45 >> Deleted: 848daccb153b7aa6ff4a229278d24d945b6ea23e2ad8b06ecdc0f389c641da1a >> Deleted: 38957fcac7db8839ad02f28f40499a2207cc5950800d749ca6039073ffcca741 >> Deleted: d4c338b5a13fffa3aa27b7883e0eaf819948aa7c44ba88d294f32343fd62eec0 >> Deleted: 7477643b2cce0c37f0ca58fff6d9faeed377218cd81c26395557c08ca6913c9f >> Deleted: f6e006f6d02695a98bec8e3962e21cff0cda0293bc07880a8943cd1c0ec9cb2e >> Deleted: 65dc81e742400834c56b316b9ebaa09d8c3812ff8864ba1ccbae2f99badaa425 >> Deleted: 735b32b15c2d6bf3b1b0796ae49fda0cdc5e85106273bf943d1cf1ad1aa9f204 >> Deleted: f8c3ca62f0644c95f1499f0cac5da0680dc3d6533ed9bd5050429a27d0a497d3 >> Deleted: 87d93f820d589b1eb5a106762f6ae63ba67d2e7623783d07df14dd3599b9d3a0 >> Deleted: 7d6b1a49cb8025d36f0a6b29bfcdec395d23c88a00bad57fb0f4eca8667b9f53 >> Build step 'Execute shell' marked build as failure >> {code} >> >> >> >> -- >> This message was sent by Atlassian JIRA >> (v6.3.4#6332) >> > >
