[ https://issues.apache.org/jira/browse/MESOS-8266?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16761770#comment-16761770 ]
Vinod Kone commented on MESOS-8266: ----------------------------------- Observed this on internal CI. {code} [ RUN ] MasterMaintenanceTest.AcceptInvalidInverseOffer I0206 05:13:46.592031 27319 cluster.cpp:174] Creating default 'local' authorizer I0206 05:13:46.593217 27341 master.cpp:414] Master 9ee5ab9a-1898-4ba6-a7f3-0093d03b19f8 (ip-172-16-10-145.ec2.internal) started on 172.16.10.145:36957 I0206 05:13:46.593240 27341 master.cpp:417] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator ="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwri te="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/cBTYhp/credentials" --filter_gpu_resources="true" --framework_s orter="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" --max_operator_event_stream _subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_me trics="true" --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" --require_agent_domain="false" --role_sorter="drf" --root_submissions="t rue" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/cBTYhp/master" --zk_session_timeout="10secs" I0206 05:13:46.593377 27341 master.cpp:466] Master only allowing authenticated frameworks to register I0206 05:13:46.593385 27341 master.cpp:472] Master only allowing authenticated agents to register I0206 05:13:46.593391 27341 master.cpp:478] Master only allowing authenticated HTTP frameworks to register I0206 05:13:46.593397 27341 credentials.hpp:37] Loading credentials for authentication from '/tmp/cBTYhp/credentials' I0206 05:13:46.593485 27341 master.cpp:522] Using default 'crammd5' authenticator I0206 05:13:46.593521 27341 http.cpp:965] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0206 05:13:46.593560 27341 http.cpp:965] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0206 05:13:46.593582 27341 http.cpp:965] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0206 05:13:46.593605 27341 master.cpp:603] Authorization enabled I0206 05:13:46.594100 27340 hierarchical.cpp:176] Initialized hierarchical allocator process I0206 05:13:46.594298 27341 whitelist_watcher.cpp:77] No whitelist given I0206 05:13:46.594842 27344 master.cpp:2103] Elected as the leading master! I0206 05:13:46.594856 27344 master.cpp:1638] Recovering from registrar I0206 05:13:46.594935 27344 registrar.cpp:339] Recovering registrar I0206 05:13:46.595073 27344 registrar.cpp:383] Successfully fetched the registry (0B) in 115968ns I0206 05:13:46.595101 27344 registrar.cpp:487] Applied 1 operations in 6424ns; attempting to update the registry I0206 05:13:46.595223 27344 registrar.cpp:544] Successfully updated the registry in 105984ns I0206 05:13:46.595314 27344 registrar.cpp:416] Successfully recovered registrar I0206 05:13:46.595392 27344 master.cpp:1752] Recovered 0 agents from the registry (176B); allowing 10mins for agents to reregister I0206 05:13:46.595446 27344 hierarchical.cpp:216] Skipping recovery of hierarchical allocator: nothing to recover W0206 05:13:46.595887 27319 process.cpp:2829] Attempted to spawn already running process version@172.16.10.145:36957 I0206 05:13:46.597141 27319 sched.cpp:232] Version: 1.8.0 I0206 05:13:46.597421 27345 sched.cpp:336] New master detected at master@172.16.10.145:36957 I0206 05:13:46.597458 27345 sched.cpp:401] Authenticating with master master@172.16.10.145:36957 I0206 05:13:46.597509 27345 sched.cpp:408] Using default CRAM-MD5 authenticatee I0206 05:13:46.597611 27345 authenticatee.cpp:121] Creating new client SASL connection I0206 05:13:46.597707 27345 master.cpp:9902] Authenticating scheduler-6e5ae29d-e284-4d9b-bbc2-2df8747428fd@172.16.10.145:36957 I0206 05:13:46.597754 27345 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(459)@172.16.10.145:36957 I0206 05:13:46.597805 27345 authenticator.cpp:98] Creating new server SASL connection I0206 05:13:46.597946 27345 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0206 05:13:46.597962 27345 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0206 05:13:46.597993 27345 authenticator.cpp:204] Received SASL authentication start I0206 05:13:46.598042 27345 authenticator.cpp:326] Authentication requires more steps I0206 05:13:46.598074 27345 authenticatee.cpp:259] Received SASL authentication step I0206 05:13:46.598117 27345 authenticator.cpp:232] Received SASL authentication step I0206 05:13:46.598134 27345 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-145' server FQDN: 'ip-172-16-10-145' SASL_AUXPROP_OVERRID E: false SASL_AUXPROP_AUTHZID: false I0206 05:13:46.598141 27345 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0206 05:13:46.598153 27345 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0206 05:13:46.598162 27345 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-145' server FQDN: 'ip-172-16-10-145' SASL_AUXPROP_OVERRID E: false SASL_AUXPROP_AUTHZID: true I0206 05:13:46.598170 27345 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0206 05:13:46.598176 27345 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0206 05:13:46.598189 27345 authenticator.cpp:318] Authentication success I0206 05:13:46.598278 27346 authenticatee.cpp:299] Authentication success I0206 05:13:46.601868 27344 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(459)@172.16.10.145:36957 I0206 05:13:46.601971 27346 sched.cpp:513] Successfully authenticated with master master@172.16.10.145:36957 I0206 05:13:46.601984 27346 sched.cpp:817] Sending SUBSCRIBE call to master@172.16.10.145:36957 I0206 05:13:46.602026 27346 sched.cpp:850] Will retry registration in 407.644532ms if necessary I0206 05:13:46.602324 27342 master.cpp:9934] Successfully authenticated principal 'test-principal' at scheduler-6e5ae29d-e284-4d9b-bbc2-2df8747428fd@172.16.10.145:36957 I0206 05:13:46.602547 27342 master.cpp:2879] Received SUBSCRIBE call for framework 'default' at scheduler-6e5ae29d-e284-4d9b-bbc2-2df8747428fd@172.16.10.145:36957 I0206 05:13:46.602775 27342 master.cpp:2175] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' I0206 05:13:46.603092 27342 master.cpp:2960] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] I0206 05:13:46.603636 27342 master.cpp:10132] Adding framework 9ee5ab9a-1898-4ba6-a7f3-0093d03b19f8-0000 (default) at scheduler-6e5ae29d-e284-4d9b-bbc2-2df8747428fd@172.16.10.145:36957 with roles { } suppressed I0206 05:13:46.604151 27341 hierarchical.cpp:305] Added framework 9ee5ab9a-1898-4ba6-a7f3-0093d03b19f8-0000 I0206 05:13:46.604200 27341 hierarchical.cpp:1558] Performed allocation for 0 agents in 9359ns I0206 05:13:46.604594 27340 master.cpp:5894] Processing ACCEPT_INVERSE_OFFERS call for inverse offers: [ invalid-inverse-offer ] for framework 9ee5ab9a-1898-4ba6-a7f3-0093d03b19f8-0000 (default) at scheduler-6e5ae29d-e284-4d9b-bbc2-2df8747428fd@172.16.10.145:36957 W0206 05:13:46.604635 27340 master.cpp:5929] Ignoring accept of inverse offer invalid-inverse-offer since it is no longer valid W0206 05:13:46.604643 27340 master.cpp:5935] ACCEPT_INVERSE_OFFERS call used invalid offers '[ invalid-inverse-offer ]': Inverse offer invalid-inverse-offer is no longer valid I0206 05:13:46.604686 27319 sched.cpp:2008] Asked to stop the driver I0206 05:13:46.604753 27342 sched.cpp:725] Ignoring framework registered message because the driver is not running! I0206 05:13:46.604771 27342 sched.cpp:1184] Stopping framework I0206 05:13:46.604898 27340 master.cpp:1384] Framework 9ee5ab9a-1898-4ba6-a7f3-0093d03b19f8-0000 (default) at scheduler-6e5ae29d-e284-4d9b-bbc2-2df8747428fd@172.16.10.145:36957 disconnected I0206 05:13:46.604915 27340 master.cpp:3255] Deactivating framework 9ee5ab9a-1898-4ba6-a7f3-0093d03b19f8-0000 (default) at scheduler-6e5ae29d-e284-4d9b-bbc2-2df8747428fd@172.16.10.145:36957 I0206 05:13:46.604931 27340 master.cpp:3232] Disconnecting framework 9ee5ab9a-1898-4ba6-a7f3-0093d03b19f8-0000 (default) at scheduler-6e5ae29d-e284-4d9b-bbc2-2df8747428fd@172.16.10.145:36957 I0206 05:13:46.604943 27340 master.cpp:1399] Giving framework 9ee5ab9a-1898-4ba6-a7f3-0093d03b19f8-0000 (default) at scheduler-6e5ae29d-e284-4d9b-bbc2-2df8747428fd@172.16.10.145:36957 0ns to failover I0206 05:13:46.604982 27340 hierarchical.cpp:419] Deactivated framework 9ee5ab9a-1898-4ba6-a7f3-0093d03b19f8-0000 I0206 05:13:46.605463 27341 master.cpp:9509] Framework failover timeout, removing framework 9ee5ab9a-1898-4ba6-a7f3-0093d03b19f8-0000 (default) at scheduler-6e5ae29d-e284-4d9b-bbc2-2df8747428fd@172.16.10.145:36957 I0206 05:13:46.605481 27341 master.cpp:10449] Removing framework 9ee5ab9a-1898-4ba6-a7f3-0093d03b19f8-0000 (default) at scheduler-6e5ae29d-e284-4d9b-bbc2-2df8747428fd@172.16.10.145:36957 ../../src/tests/master_maintenance_tests.cpp:1920: Failure Actual function call count doesn't match EXPECT_CALL(sched, registered(&driver, _, _))... Expected: to be called once Actual: never called - unsatisfied and active I0206 05:13:46.607028 27319 master.cpp:1109] Master terminating I0206 05:13:46.610884 27344 hierarchical.cpp:358] Removed framework 9ee5ab9a-1898-4ba6-a7f3-0093d03b19f8-0000 [ FAILED ] MasterMaintenanceTest.AcceptInvalidInverseOffer (20 ms) {code} > MasterMaintenanceTest.AcceptInvalidInverseOffer is flaky. > --------------------------------------------------------- > > Key: MESOS-8266 > URL: https://issues.apache.org/jira/browse/MESOS-8266 > Project: Mesos > Issue Type: Bug > Components: test > Affects Versions: 1.5.0 > Environment: Ubuntu 17.04 > Reporter: Alexander Rukletsov > Priority: Minor > Labels: flaky-test > Attachments: AcceptInvalidInverseOffer-badrun.txt > > > {noformat} > /home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-ubuntu-17.04/mesos/src/tests/master_maintenance_tests.cpp:1923 > Actual function call count doesn't match EXPECT_CALL(sched, > registered(&driver, _, _))... > Expected: to be called once > Actual: never called - unsatisfied and active > {noformat} > Full log attached. -- This message was sent by Atlassian JIRA (v7.6.3#76005)