You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@mesos.apache.org by "Benjamin Bannier (JIRA)" <ji...@apache.org> on 2016/12/20 09:35:58 UTC
[jira] [Created] (MESOS-6820)
FaultToleranceTest.FrameworkReregister is flaky
Benjamin Bannier created MESOS-6820:
---------------------------------------
Summary: FaultToleranceTest.FrameworkReregister is flaky
Key: MESOS-6820
URL: https://issues.apache.org/jira/browse/MESOS-6820
Project: Mesos
Issue Type: Bug
Components: test
Environment: Debian 8, OS X
Reporter: Benjamin Bannier
I just saw {{FaultToleranceTest.FrameworkReregister}} fail in internal CI on a Debian 8 system. Running the test in repetition on my OS X machine I was able to reproduce the issue on OS X as well.
{noformat}
[ RUN ] FaultToleranceTest.FrameworkReregister
I1219 23:04:12.914769 23530 cluster.cpp:160] Creating default 'local' authorizer
I1219 23:04:12.915388 23545 master.cpp:380] Master 4daa3046-9990-49c7-b601-958964306799 (ip-172-16-10-223.mesosphere.io) started on 172.16.10.223:52614
I1219 23:04:12.915400 23545 master.cpp:382] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/mnt/teamcity/temp/buildTmp/4KpUDy/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/mnt/teamcity/temp/buildTmp/4KpUDy/master" --zk_session_timeout="10secs"
I1219 23:04:12.915504 23545 master.cpp:432] Master only allowing authenticated frameworks to register
I1219 23:04:12.915509 23545 master.cpp:446] Master only allowing authenticated agents to register
I1219 23:04:12.915511 23545 master.cpp:459] Master only allowing authenticated HTTP frameworks to register
I1219 23:04:12.915514 23545 credentials.hpp:37] Loading credentials for authentication from '/mnt/teamcity/temp/buildTmp/4KpUDy/credentials'
I1219 23:04:12.915570 23545 master.cpp:504] Using default 'crammd5' authenticator
I1219 23:04:12.915597 23545 http.cpp:922] Using default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I1219 23:04:12.915617 23545 http.cpp:922] Using default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I1219 23:04:12.915658 23545 http.cpp:922] Using default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I1219 23:04:12.915688 23545 master.cpp:584] Authorization enabled
I1219 23:04:12.915725 23546 whitelist_watcher.cpp:77] No whitelist given
I1219 23:04:12.915737 23547 hierarchical.cpp:149] Initialized hierarchical allocator process
I1219 23:04:12.916110 23545 master.cpp:2046] Elected as the leading master!
I1219 23:04:12.916118 23545 master.cpp:1568] Recovering from registrar
I1219 23:04:12.916179 23548 registrar.cpp:329] Recovering registrar
I1219 23:04:12.916311 23545 registrar.cpp:362] Successfully fetched the registry (0B) in 115968ns
I1219 23:04:12.916334 23545 registrar.cpp:461] Applied 1 operations in 1982ns; attempting to update the registry
I1219 23:04:12.916554 23547 registrar.cpp:506] Successfully updated the registry in 208896ns
I1219 23:04:12.916770 23547 registrar.cpp:392] Successfully recovered registrar
I1219 23:04:12.916853 23547 master.cpp:1684] Recovered 0 agents from the registry (174B); allowing 10mins for agents to re-register
I1219 23:04:12.916956 23544 hierarchical.cpp:176] Skipping recovery of hierarchical allocator: nothing to recover
I1219 23:04:12.918097 23530 containerizer.cpp:220] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni
I1219 23:04:12.920801 23530 linux_launcher.cpp:150] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
I1219 23:04:12.921478 23530 cluster.cpp:446] Creating default 'local' authorizer
I1219 23:04:12.921813 23546 slave.cpp:209] Mesos agent started on (36)@172.16.10.223:52614
I1219 23:04:12.921823 23546 slave.cpp:210] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/mnt/teamcity/temp/buildTmp/mesos/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --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="/mnt/teamcity/temp/buildTmp/FaultToleranceTest_FrameworkReregister_PIW1QY/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="/mnt/teamcity/temp/buildTmp/mesos/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/mnt/teamcity/temp/buildTmp/FaultToleranceTest_FrameworkReregister_PIW1QY/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_command_executor="false" --http_credentials="/mnt/teamcity/temp/buildTmp/FaultToleranceTest_FrameworkReregister_PIW1QY/http_credentials" --http_heartbeat_interval="30secs" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="linux" --launcher_dir="/mnt/teamcity/work/4240ba9ddd0997c3/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --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;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/mnt/teamcity/temp/buildTmp/FaultToleranceTest_FrameworkReregister_PIW1QY" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/mnt/teamcity/temp/buildTmp/FaultToleranceTest_FrameworkReregister_ytYsKg"
I1219 23:04:12.922118 23546 credentials.hpp:86] Loading credential for authentication from '/mnt/teamcity/temp/buildTmp/FaultToleranceTest_FrameworkReregister_PIW1QY/credential'
I1219 23:04:12.922175 23546 slave.cpp:352] Agent using credential for: test-principal
I1219 23:04:12.922183 23546 credentials.hpp:37] Loading credentials for authentication from '/mnt/teamcity/temp/buildTmp/FaultToleranceTest_FrameworkReregister_PIW1QY/http_credentials'
I1219 23:04:12.922237 23546 http.cpp:922] Using default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1219 23:04:12.922269 23546 http.cpp:922] Using default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I1219 23:04:12.922341 23530 sched.cpp:232] Version: 1.2.0
I1219 23:04:12.922451 23551 sched.cpp:336] New master detected at master@172.16.10.223:52614
I1219 23:04:12.922477 23551 sched.cpp:402] Authenticating with master master@172.16.10.223:52614
I1219 23:04:12.922487 23551 sched.cpp:409] Using default CRAM-MD5 authenticatee
I1219 23:04:12.922564 23545 authenticatee.cpp:121] Creating new client SASL connection
I1219 23:04:12.922552 23546 slave.cpp:539] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1219 23:04:12.922590 23546 slave.cpp:547] Agent attributes: [ ]
I1219 23:04:12.922596 23546 slave.cpp:552] Agent hostname: ip-172-16-10-223.mesosphere.io
I1219 23:04:12.922739 23545 master.cpp:6751] Authenticating scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614
I1219 23:04:12.922794 23547 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(100)@172.16.10.223:52614
I1219 23:04:12.922869 23545 authenticator.cpp:98] Creating new server SASL connection
I1219 23:04:12.922893 23546 state.cpp:57] Recovering state from '/mnt/teamcity/temp/buildTmp/FaultToleranceTest_FrameworkReregister_ytYsKg/meta'
I1219 23:04:12.923012 23546 status_update_manager.cpp:203] Recovering status update manager
I1219 23:04:12.923072 23545 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1219 23:04:12.923086 23545 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1219 23:04:12.923137 23545 authenticator.cpp:204] Received SASL authentication start
I1219 23:04:12.923156 23548 containerizer.cpp:599] Recovering containerizer
I1219 23:04:12.923158 23545 authenticator.cpp:326] Authentication requires more steps
I1219 23:04:12.923212 23545 authenticatee.cpp:259] Received SASL authentication step
I1219 23:04:12.923260 23545 authenticator.cpp:232] Received SASL authentication step
I1219 23:04:12.923276 23545 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-223.mesosphere.io' server FQDN: 'ip-172-16-10-223.mesosphere.io' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1219 23:04:12.923283 23545 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1219 23:04:12.923292 23545 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1219 23:04:12.923300 23545 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-223.mesosphere.io' server FQDN: 'ip-172-16-10-223.mesosphere.io' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1219 23:04:12.923306 23545 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1219 23:04:12.923312 23545 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1219 23:04:12.923322 23545 authenticator.cpp:318] Authentication success
I1219 23:04:12.923377 23548 authenticatee.cpp:299] Authentication success
I1219 23:04:12.923403 23550 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(100)@172.16.10.223:52614
I1219 23:04:12.923434 23545 master.cpp:6781] Successfully authenticated principal 'test-principal' at scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614
I1219 23:04:12.923477 23548 sched.cpp:508] Successfully authenticated with master master@172.16.10.223:52614
I1219 23:04:12.923485 23548 sched.cpp:826] Sending SUBSCRIBE call to master@172.16.10.223:52614
I1219 23:04:12.923519 23548 sched.cpp:859] Will retry registration in 1.760040858secs if necessary
I1219 23:04:12.923565 23551 master.cpp:2634] Received SUBSCRIBE call for framework 'default' at scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614
I1219 23:04:12.923579 23551 master.cpp:2082] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1219 23:04:12.923686 23551 master.cpp:2710] Subscribing framework default with checkpointing disabled and capabilities [ ]
I1219 23:04:12.923876 23551 sched.cpp:749] Framework registered with 4daa3046-9990-49c7-b601-958964306799-0000
I1219 23:04:12.923877 23547 hierarchical.cpp:277] Added framework 4daa3046-9990-49c7-b601-958964306799-0000
I1219 23:04:12.923913 23547 hierarchical.cpp:1690] No allocations performed
I1219 23:04:12.923918 23551 sched.cpp:763] Scheduler::registered took 21516ns
I1219 23:04:12.923923 23547 hierarchical.cpp:1785] No inverse offers to send out!
I1219 23:04:12.923933 23547 hierarchical.cpp:1292] Performed allocation for 0 agents in 27585ns
I1219 23:04:12.924137 23548 provisioner.cpp:253] Provisioner recovery complete
I1219 23:04:12.924263 23545 slave.cpp:5407] Finished recovery
I1219 23:04:12.924439 23545 slave.cpp:5581] Querying resource estimator for oversubscribable resources
I1219 23:04:12.924515 23545 slave.cpp:924] New master detected at master@172.16.10.223:52614
I1219 23:04:12.924522 23547 status_update_manager.cpp:177] Pausing sending status updates
I1219 23:04:12.924528 23545 slave.cpp:983] Authenticating with master master@172.16.10.223:52614
I1219 23:04:12.924545 23545 slave.cpp:994] Using default CRAM-MD5 authenticatee
I1219 23:04:12.924588 23545 slave.cpp:956] Detecting new master
I1219 23:04:12.924609 23551 authenticatee.cpp:121] Creating new client SASL connection
I1219 23:04:12.924648 23545 slave.cpp:5595] Received oversubscribable resources {} from the resource estimator
I1219 23:04:12.924757 23551 master.cpp:6751] Authenticating slave(36)@172.16.10.223:52614
I1219 23:04:12.924804 23551 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(101)@172.16.10.223:52614
I1219 23:04:12.924855 23551 authenticator.cpp:98] Creating new server SASL connection
I1219 23:04:12.924983 23551 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1219 23:04:12.924993 23551 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1219 23:04:12.925047 23547 authenticator.cpp:204] Received SASL authentication start
I1219 23:04:12.925068 23547 authenticator.cpp:326] Authentication requires more steps
I1219 23:04:12.925098 23547 authenticatee.cpp:259] Received SASL authentication step
I1219 23:04:12.925143 23547 authenticator.cpp:232] Received SASL authentication step
I1219 23:04:12.925158 23547 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-223.mesosphere.io' server FQDN: 'ip-172-16-10-223.mesosphere.io' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1219 23:04:12.925165 23547 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1219 23:04:12.925171 23547 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1219 23:04:12.925176 23547 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-223.mesosphere.io' server FQDN: 'ip-172-16-10-223.mesosphere.io' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1219 23:04:12.925180 23547 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1219 23:04:12.925184 23547 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1219 23:04:12.925189 23547 authenticator.cpp:318] Authentication success
I1219 23:04:12.925221 23547 authenticatee.cpp:299] Authentication success
I1219 23:04:12.925243 23545 master.cpp:6781] Successfully authenticated principal 'test-principal' at slave(36)@172.16.10.223:52614
I1219 23:04:12.925264 23546 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(101)@172.16.10.223:52614
I1219 23:04:12.925400 23547 slave.cpp:1078] Successfully authenticated with master master@172.16.10.223:52614
I1219 23:04:12.925447 23547 slave.cpp:1493] Will retry registration in 8.623943ms if necessary
I1219 23:04:12.925516 23545 master.cpp:5162] Registering agent at slave(36)@172.16.10.223:52614 (ip-172-16-10-223.mesosphere.io) with id 4daa3046-9990-49c7-b601-958964306799-S0
I1219 23:04:12.925616 23547 registrar.cpp:461] Applied 1 operations in 8538ns; attempting to update the registry
I1219 23:04:12.925874 23548 registrar.cpp:506] Successfully updated the registry in 0ns
I1219 23:04:12.926054 23548 slave.cpp:4263] Received ping from slave-observer(30)@172.16.10.223:52614
I1219 23:04:12.926064 23547 master.cpp:5233] Registered agent 4daa3046-9990-49c7-b601-958964306799-S0 at slave(36)@172.16.10.223:52614 (ip-172-16-10-223.mesosphere.io) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1219 23:04:12.926103 23548 slave.cpp:1124] Registered with master master@172.16.10.223:52614; given agent ID 4daa3046-9990-49c7-b601-958964306799-S0
I1219 23:04:12.926118 23548 fetcher.cpp:90] Clearing fetcher cache
I1219 23:04:12.926123 23550 hierarchical.cpp:491] Added agent 4daa3046-9990-49c7-b601-958964306799-S0 (ip-172-16-10-223.mesosphere.io) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I1219 23:04:12.926188 23547 status_update_manager.cpp:184] Resuming sending status updates
I1219 23:04:12.926255 23548 slave.cpp:1147] Checkpointing SlaveInfo to '/mnt/teamcity/temp/buildTmp/FaultToleranceTest_FrameworkReregister_ytYsKg/meta/slaves/4daa3046-9990-49c7-b601-958964306799-S0/slave.info'
I1219 23:04:12.926273 23550 hierarchical.cpp:1785] No inverse offers to send out!
I1219 23:04:12.926287 23550 hierarchical.cpp:1315] Performed allocation for agent 4daa3046-9990-49c7-b601-958964306799-S0 in 148466ns
I1219 23:04:12.926336 23548 slave.cpp:1184] Forwarding total oversubscribed resources {}
I1219 23:04:12.926396 23549 master.cpp:6580] Sending 1 offers to framework 4daa3046-9990-49c7-b601-958964306799-0000 (default) at scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614
I1219 23:04:12.926475 23549 master.cpp:5636] Received update of agent 4daa3046-9990-49c7-b601-958964306799-S0 at slave(36)@172.16.10.223:52614 (ip-172-16-10-223.mesosphere.io) with total oversubscribed resources {}
I1219 23:04:12.926549 23550 sched.cpp:923] Scheduler::resourceOffers took 13898ns
I1219 23:04:12.926579 23548 hierarchical.cpp:561] Agent 4daa3046-9990-49c7-b601-958964306799-S0 (ip-172-16-10-223.mesosphere.io) updated with oversubscribed resources {} (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000])
I1219 23:04:12.926609 23548 hierarchical.cpp:1690] No allocations performed
I1219 23:04:12.926614 23548 hierarchical.cpp:1785] No inverse offers to send out!
I1219 23:04:12.926620 23548 hierarchical.cpp:1315] Performed allocation for agent 4daa3046-9990-49c7-b601-958964306799-S0 in 22643ns
I1219 23:04:12.926808 23547 sched.cpp:330] Scheduler::disconnected took 5874ns
I1219 23:04:12.926820 23547 sched.cpp:336] New master detected at master@172.16.10.223:52614
I1219 23:04:12.926839 23547 sched.cpp:402] Authenticating with master master@172.16.10.223:52614
I1219 23:04:12.926846 23547 sched.cpp:409] Using default CRAM-MD5 authenticatee
I1219 23:04:12.926908 23547 authenticatee.cpp:121] Creating new client SASL connection
I1219 23:04:12.927048 23547 master.cpp:6751] Authenticating scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614
I1219 23:04:12.927093 23547 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(102)@172.16.10.223:52614
I1219 23:04:12.927150 23550 authenticator.cpp:98] Creating new server SASL connection
I1219 23:04:12.927280 23550 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1219 23:04:12.927294 23550 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1219 23:04:12.927328 23550 authenticator.cpp:204] Received SASL authentication start
I1219 23:04:12.927351 23550 authenticator.cpp:326] Authentication requires more steps
I1219 23:04:12.927383 23550 authenticatee.cpp:259] Received SASL authentication step
I1219 23:04:12.927435 23547 authenticator.cpp:232] Received SASL authentication step
I1219 23:04:12.927450 23547 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-223.mesosphere.io' server FQDN: 'ip-172-16-10-223.mesosphere.io' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1219 23:04:12.927456 23547 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1219 23:04:12.927461 23547 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1219 23:04:12.927466 23547 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-223.mesosphere.io' server FQDN: 'ip-172-16-10-223.mesosphere.io' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1219 23:04:12.927471 23547 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1219 23:04:12.927474 23547 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1219 23:04:12.927482 23547 authenticator.cpp:318] Authentication success
I1219 23:04:12.927520 23547 master.cpp:6781] Successfully authenticated principal 'test-principal' at scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614
I1219 23:04:12.927542 23544 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(102)@172.16.10.223:52614
I1219 23:04:12.927557 23550 authenticatee.cpp:299] Authentication success
I1219 23:04:12.927649 23549 sched.cpp:508] Successfully authenticated with master master@172.16.10.223:52614
I1219 23:04:12.927662 23549 sched.cpp:826] Sending SUBSCRIBE call to master@172.16.10.223:52614
I1219 23:04:12.927709 23549 sched.cpp:859] Will retry registration in 880.434321ms if necessary
I1219 23:04:12.927744 23548 master.cpp:2634] Received SUBSCRIBE call for framework 'default' at scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614
I1219 23:04:12.927759 23548 master.cpp:2082] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1219 23:04:12.927870 23545 master.cpp:2710] Subscribing framework default with checkpointing disabled and capabilities [ ]
I1219 23:04:12.927881 23545 master.cpp:2788] Updating info for framework 4daa3046-9990-49c7-b601-958964306799-0000
I1219 23:04:12.927911 23545 master.cpp:2804] Allowing framework 4daa3046-9990-49c7-b601-958964306799-0000 (default) at scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614 to subscribe with an already used id
I1219 23:04:12.928001 23549 sched.cpp:826] Sending SUBSCRIBE call to master@172.16.10.223:52614
I1219 23:04:12.928040 23549 sched.cpp:859] Will retry registration in 1.080834119secs if necessary
I1219 23:04:12.928081 23548 hierarchical.cpp:1024] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent 4daa3046-9990-49c7-b601-958964306799-S0 from framework 4daa3046-9990-49c7-b601-958964306799-0000
I1219 23:04:12.928102 23549 sched.cpp:935] Ignoring rescind offer message because the driver is disconnected!
I1219 23:04:12.928150 23549 sched.cpp:791] Framework re-registered with 4daa3046-9990-49c7-b601-958964306799-0000
I1219 23:04:12.928181 23549 sched.cpp:805] Scheduler::reregistered took 18438ns
I1219 23:04:12.928247 23548 hierarchical.cpp:1785] No inverse offers to send out!
I1219 23:04:12.928254 23545 master.cpp:2634] Received SUBSCRIBE call for framework 'default' at scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614
I1219 23:04:12.928261 23548 hierarchical.cpp:1292] Performed allocation for 1 agents in 109229ns
I1219 23:04:12.928268 23545 master.cpp:2082] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1219 23:04:12.928400 23545 master.cpp:6580] Sending 1 offers to framework 4daa3046-9990-49c7-b601-958964306799-0000 (default) at scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614
I1219 23:04:12.928444 23545 master.cpp:2710] Subscribing framework default with checkpointing disabled and capabilities [ ]
I1219 23:04:12.928453 23545 master.cpp:2788] Updating info for framework 4daa3046-9990-49c7-b601-958964306799-0000
I1219 23:04:12.928472 23545 master.cpp:2804] Allowing framework 4daa3046-9990-49c7-b601-958964306799-0000 (default) at scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614 to subscribe with an already used id
I1219 23:04:12.928524 23546 sched.cpp:923] Scheduler::resourceOffers took 26359ns
I1219 23:04:12.928570 23546 sched.cpp:949] Rescinded offer 4daa3046-9990-49c7-b601-958964306799-O1
I1219 23:04:12.928592 23546 sched.cpp:960] Scheduler::offerRescinded took 9442ns
I1219 23:04:12.928618 23546 sched.cpp:778] Ignoring framework re-registered message because the driver is already connected!
I1219 23:04:12.928642 23547 hierarchical.cpp:1024] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent 4daa3046-9990-49c7-b601-958964306799-S0 from framework 4daa3046-9990-49c7-b601-958964306799-0000
I1219 23:04:12.929006 23548 hierarchical.cpp:1785] No inverse offers to send out!
I1219 23:04:12.929029 23548 hierarchical.cpp:1292] Performed allocation for 1 agents in 150224ns
I1219 23:04:12.929085 23545 master.cpp:6580] Sending 1 offers to framework 4daa3046-9990-49c7-b601-958964306799-0000 (default) at scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614
../../src/tests/fault_tolerance_tests.cpp:833: Failure
Mock function called more times than expected - returning directly.
Function call: resourceOffers(0x7ffc5fce0260, @0x7f7e348a4ba0 { 152-byte object <90-E5 85-3F 7E-7F 00-00 00-00 00-00 00-00 00-00 1F-00 00-00 00-00 00-00 10-0A 01-24 7E-7F 00-00 40-0A 01-24 7E-7F 00-00 C0-24 00-24 7E-7F 00-00 A0-65 00-24 7E-7F 00-00 B0-93 00-24 7E-7F 00-00 ... 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00> })
Expected: to be called once
Actual: called twice - over-saturated and active
I1219 23:04:12.929224 23545 sched.cpp:923] Scheduler::resourceOffers took 69622ns
I1219 23:04:12.929244 23544 process.cpp:3679] Handling HTTP event for process 'master' with path: '/master/state'
I1219 23:04:12.929577 23551 http.cpp:402] HTTP GET for /master/state from 172.16.10.223:49741
I1219 23:04:12.930861 23530 sched.cpp:2008] Asked to stop the driver
I1219 23:04:12.930907 23550 sched.cpp:1193] Stopping framework 4daa3046-9990-49c7-b601-958964306799-0000
I1219 23:04:12.930974 23551 master.cpp:7291] Processing TEARDOWN call for framework 4daa3046-9990-49c7-b601-958964306799-0000 (default) at scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614
I1219 23:04:12.930989 23551 master.cpp:7303] Removing framework 4daa3046-9990-49c7-b601-958964306799-0000 (default) at scheduler-09a58709-8c77-40d4-a431-5faba5cbbe7d@172.16.10.223:52614
I1219 23:04:12.931046 23548 slave.cpp:2581] Asked to shut down framework 4daa3046-9990-49c7-b601-958964306799-0000 by master@172.16.10.223:52614
I1219 23:04:12.931061 23548 slave.cpp:2596] Cannot shut down unknown framework 4daa3046-9990-49c7-b601-958964306799-0000
I1219 23:04:12.931068 23550 hierarchical.cpp:392] Deactivated framework 4daa3046-9990-49c7-b601-958964306799-0000
I1219 23:04:12.931175 23550 hierarchical.cpp:1024] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent 4daa3046-9990-49c7-b601-958964306799-S0 from framework 4daa3046-9990-49c7-b601-958964306799-0000
I1219 23:04:12.931290 23550 hierarchical.cpp:343] Removed framework 4daa3046-9990-49c7-b601-958964306799-0000
I1219 23:04:12.931711 23547 slave.cpp:796] Agent terminating
I1219 23:04:12.931782 23544 master.cpp:1258] Agent 4daa3046-9990-49c7-b601-958964306799-S0 at slave(36)@172.16.10.223:52614 (ip-172-16-10-223.mesosphere.io) disconnected
I1219 23:04:12.931797 23544 master.cpp:2978] Disconnecting agent 4daa3046-9990-49c7-b601-958964306799-S0 at slave(36)@172.16.10.223:52614 (ip-172-16-10-223.mesosphere.io)
I1219 23:04:12.931813 23544 master.cpp:2997] Deactivating agent 4daa3046-9990-49c7-b601-958964306799-S0 at slave(36)@172.16.10.223:52614 (ip-172-16-10-223.mesosphere.io)
I1219 23:04:12.931854 23548 hierarchical.cpp:590] Agent 4daa3046-9990-49c7-b601-958964306799-S0 deactivated
I1219 23:04:12.933393 23530 master.cpp:1097] Master terminating
I1219 23:04:12.933498 23544 hierarchical.cpp:523] Removed agent 4daa3046-9990-49c7-b601-958964306799-S0
[ FAILED ] FaultToleranceTest.FrameworkReregister (20 ms)
{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)