----------------------------------------------------------- This is an automatically generated e-mail. To reply, visit: https://reviews.apache.org/r/71080/#review216638 -----------------------------------------------------------
Bad patch! Reviews applied: [71080] Failed command: ['bash', '-c', "set -o pipefail; export OS='ubuntu:14.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/docker-build.sh 2>&1 | tee build_71080"] Error: ...<truncated>... ve.cpp:7429] Finished recovering checkpointed state from '/tmp/MasterTest_DuplicatedSlaveIdWhenSlaveReregister_4R0TkX/meta', beginning agent recovery I0716 04:07:54.062824 18261 task_status_update_manager.cpp:207] Recovering task status update manager I0716 04:07:54.063207 18279 containerizer.cpp:796] Recovering Mesos containers I0716 04:07:54.063537 18279 containerizer.cpp:1122] Recovering isolators I0716 04:07:54.064132 18270 containerizer.cpp:1161] Recovering provisioner I0716 04:07:54.064779 18267 provisioner.cpp:498] Provisioner recovery complete I0716 04:07:54.065493 18275 composing.cpp:339] Finished recovering all containerizers I0716 04:07:54.065721 18276 slave.cpp:7893] Recovering executors I0716 04:07:54.065821 18276 slave.cpp:8046] Finished recovery I0716 04:07:54.066653 18281 task_status_update_manager.cpp:181] Pausing sending task status updates I0716 04:07:54.066674 18278 status_update_manager_process.hpp:379] Pausing operation status update manager I0716 04:07:54.066691 18276 slave.cpp:1340] New master detected at master@172.17.0.2:39944 I0716 04:07:54.066845 18276 slave.cpp:1405] Detecting new master I0716 04:07:54.069154 18280 slave.cpp:1432] Authenticating with master master@172.17.0.2:39944 I0716 04:07:54.069236 18280 slave.cpp:1441] Using default CRAM-MD5 authenticatee I0716 04:07:54.069547 18269 authenticatee.cpp:121] Creating new client SASL connection I0716 04:07:54.069874 18264 master.cpp:10481] Authenticating slave(299)@172.17.0.2:39944 I0716 04:07:54.070010 18271 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(609)@172.17.0.2:39944 I0716 04:07:54.070243 18270 authenticator.cpp:98] Creating new server SASL connection I0716 04:07:54.070472 18260 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0716 04:07:54.070502 18260 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0716 04:07:54.070619 18263 authenticator.cpp:204] Received SASL authentication start I0716 04:07:54.070681 18263 authenticator.cpp:326] Authentication requires more steps I0716 04:07:54.070816 18267 authenticatee.cpp:259] Received SASL authentication step I0716 04:07:54.070953 18267 authenticator.cpp:232] Received SASL authentication step I0716 04:07:54.070991 18267 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0716 04:07:54.071012 18267 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0716 04:07:54.071056 18267 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0716 04:07:54.071084 18267 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0716 04:07:54.071097 18267 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.071107 18267 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.071122 18267 authenticator.cpp:318] Authentication success I0716 04:07:54.071317 18266 authenticatee.cpp:299] Authentication success I0716 04:07:54.071386 18265 master.cpp:10513] Successfully authenticated principal 'test-principal' at slave(299)@172.17.0.2:39944 I0716 04:07:54.071390 18272 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(609)@172.17.0.2:39944 I0716 04:07:54.071679 18277 slave.cpp:1532] Successfully authenticated with master master@172.17.0.2:39944 I0716 04:07:54.072032 18277 slave.cpp:1982] Will retry registration in 9.614834ms if necessary I0716 04:07:54.072201 18282 master.cpp:7001] Received register agent message from slave(299)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.072585 18282 master.cpp:4200] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal' I0716 04:07:54.073243 18278 master.cpp:7068] Authorized registration of agent at slave(299)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.073344 18278 master.cpp:7183] Registering agent at slave(299)@172.17.0.2:39944 (653753ac5284) with id e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0 I0716 04:07:54.073949 18268 registrar.cpp:487] Applied 1 operations in 173797ns; attempting to update the registry I0716 04:07:54.074618 18268 registrar.cpp:544] Successfully updated the registry in 594944ns I0716 04:07:54.074792 18271 master.cpp:7231] Admitted agent e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0 at slave(299)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.075455 18271 master.cpp:7276] Registered agent e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0 at slave(299)@172.17.0.2:39944 (653753ac5284) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0716 04:07:54.075644 18263 hierarchical.cpp:617] Added agent e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0 (653753ac5284) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) I0716 04:07:54.075661 18260 slave.cpp:1565] Registered with master master@172.17.0.2:39944; given agent ID e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0 I0716 04:07:54.075788 18283 task_status_update_manager.cpp:188] Resuming sending task status updates I0716 04:07:54.076086 18260 slave.cpp:1600] Checkpointing SlaveInfo to '/tmp/MasterTest_DuplicatedSlaveIdWhenSlaveReregister_4R0TkX/meta/slaves/e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0/slave.info' I0716 04:07:54.076141 18272 status_update_manager_process.hpp:385] Resuming operation status update manager I0716 04:07:54.076436 18282 task_status_update_manager.cpp:181] Pausing sending task status updates I0716 04:07:54.076450 18281 status_update_manager_process.hpp:379] Pausing operation status update manager I0716 04:07:54.076454 18274 slave.cpp:1340] New master detected at master@172.17.0.2:39944 I0716 04:07:54.076566 18274 slave.cpp:1405] Detecting new master I0716 04:07:54.076726 18263 hierarchical.cpp:1508] Performed allocation for 1 agents in 860834ns I0716 04:07:54.077106 18260 slave.cpp:1652] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"C6sQIScFRqW6muwk6pfIUA=="},"slave_id":{"value":"e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0"},"update_oversubscribed_resources":false} I0716 04:07:54.077643 18268 master.cpp:8362] Ignoring update on agent e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0 at slave(299)@172.17.0.2:39944 (653753ac5284) as it reports no changes I0716 04:07:54.080879 18270 slave.cpp:1432] Authenticating with master master@172.17.0.2:39944 I0716 04:07:54.080945 18270 slave.cpp:1441] Using default CRAM-MD5 authenticatee I0716 04:07:54.081168 18271 authenticatee.cpp:121] Creating new client SASL connection I0716 04:07:54.081418 18261 master.cpp:10481] Authenticating slave(298)@172.17.0.2:39944 I0716 04:07:54.081532 18273 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(610)@172.17.0.2:39944 I0716 04:07:54.081764 18283 authenticator.cpp:98] Creating new server SASL connection I0716 04:07:54.081980 18265 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0716 04:07:54.082005 18265 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0716 04:07:54.082118 18275 authenticator.cpp:204] Received SASL authentication start I0716 04:07:54.082171 18275 authenticator.cpp:326] Authentication requires more steps I0716 04:07:54.082268 18272 authenticatee.cpp:259] Received SASL authentication step I0716 04:07:54.082396 18262 authenticator.cpp:232] Received SASL authentication step I0716 04:07:54.082432 18262 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0716 04:07:54.082448 18262 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0716 04:07:54.082484 18262 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0716 04:07:54.082506 18262 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0716 04:07:54.082518 18262 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.082527 18262 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.082541 18262 authenticator.cpp:318] Authentication success I0716 04:07:54.082638 18266 authenticatee.cpp:299] Authentication success I0716 04:07:54.082703 18277 master.cpp:10513] Successfully authenticated principal 'test-principal' at slave(298)@172.17.0.2:39944 I0716 04:07:54.082726 18282 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(610)@172.17.0.2:39944 I0716 04:07:54.082959 18281 slave.cpp:1532] Successfully authenticated with master master@172.17.0.2:39944 I0716 04:07:54.083349 18281 slave.cpp:1982] Will retry registration in 13.707355ms if necessary I0716 04:07:54.083528 18279 master.cpp:7355] Received reregister agent message from agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 at slave(298)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.083859 18279 master.cpp:4200] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal' I0716 04:07:54.084352 18280 master.cpp:7447] Authorized re-registration of agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 at slave(298)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.084452 18280 master.cpp:7619] Consulting registry about agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 at slave(298)@172.17.0.2:39944(653753ac5284) W0716 04:07:54.084820 18268 registry_operations.cpp:182] Allowing UNKNOWN agent to reregister: hostname: "653753ac5284" resources { name: "cpus" type: SCALAR scalar { value: 2 } } resources { name: "mem" type: SCALAR scalar { value: 1024 } } resources { name: "disk" type: SCALAR scalar { value: 1024 } } resources { name: "ports" type: RANGES ranges { range { begin: 31000 end: 32000 } } } id { value: "472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0" } checkpoint: true port: 39944 I0716 04:07:54.085177 18268 registrar.cpp:487] Applied 1 operations in 411988ns; attempting to update the registry I0716 04:07:54.085675 18268 registrar.cpp:544] Successfully updated the registry in 448us I0716 04:07:54.085832 18273 master.cpp:7675] Re-admitted agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 at slave(298)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.086412 18273 master.cpp:7872] Re-registered agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 at slave(298)@172.17.0.2:39944 (653753ac5284) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0716 04:07:54.086513 18275 hierarchical.cpp:617] Added agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 (653753ac5284) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) I0716 04:07:54.086607 18265 slave.cpp:1689] Re-registered with master master@172.17.0.2:39944 I0716 04:07:54.086716 18262 task_status_update_manager.cpp:188] Resuming sending task status updates I0716 04:07:54.086779 18263 status_update_manager_process.hpp:385] Resuming operation status update manager I0716 04:07:54.086813 18275 hierarchical.cpp:1508] Performed allocation for 1 agents in 137781ns I0716 04:07:54.086894 18265 slave.cpp:1735] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"/JgPoTqgRxaPZKulMZNEMw=="},"slave_id":{"value":"472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0"},"update_oversubscribed_resources":false} I0716 04:07:54.087144 18270 slave.cpp:914] Agent terminating I0716 04:07:54.087388 18264 master.cpp:8362] Ignoring update on agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 at slave(298)@172.17.0.2:39944 (653753ac5284) as it reports no changes I0716 04:07:54.265447 18263 master.cpp:1296] Agent e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0 at slave(299)@172.17.0.2:39944 (653753ac5284) disconnected I0716 04:07:54.265491 18263 master.cpp:3380] Disconnecting agent e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0 at slave(299)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.265555 18263 master.cpp:3399] Deactivating agent e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0 at slave(299)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.265759 18275 hierarchical.cpp:799] Agent e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0 deactivated I0716 04:07:54.274397 18259 slave.cpp:914] Agent terminating I0716 04:07:54.275082 18283 master.cpp:1296] Agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 at slave(298)@172.17.0.2:39944 (653753ac5284) disconnected I0716 04:07:54.275113 18283 master.cpp:3380] Disconnecting agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 at slave(298)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.275171 18283 master.cpp:3399] Deactivating agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 at slave(298)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.275310 18261 hierarchical.cpp:799] Agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 deactivated I0716 04:07:54.280932 18272 master.cpp:1136] Master terminating I0716 04:07:54.281486 18279 hierarchical.cpp:775] Removed all filters for agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 I0716 04:07:54.281519 18279 hierarchical.cpp:650] Removed agent 472c5ac9-7c1a-46f0-b2fa-3bef38517bda-S0 I0716 04:07:54.281842 18279 hierarchical.cpp:775] Removed all filters for agent e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0 I0716 04:07:54.281867 18279 hierarchical.cpp:650] Removed agent e80ea612-fbd6-4cf6-99e7-0bbebc45d7c3-S0 [ OK ] MasterTest.DuplicatedSlaveIdWhenSlaveReregister (507 ms) [ RUN ] MasterTest.FrameworkInfoLabels I0716 04:07:54.291272 18259 cluster.cpp:176] Creating default 'local' authorizer I0716 04:07:54.294896 18266 master.cpp:440] Master de15068b-5d66-4edb-b622-869d19e07a29 (653753ac5284) started on 172.17.0.2:39944 I0716 04:07:54.294925 18266 master.cpp:443] 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_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/MCL3Ed/credentials" --filter_gpu_resources="true" --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_framework_ids="50" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --m emory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="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="true" --version="false" --webui_dir="/mesos/mesos-1.9.0/_inst/share/mesos/webui" --work_dir="/tmp/MCL3Ed/master" --zk_session_timeout="10secs" I0716 04:07:54.295316 18266 master.cpp:492] Master only allowing authenticated frameworks to register I0716 04:07:54.295331 18266 master.cpp:498] Master only allowing authenticated agents to register I0716 04:07:54.295337 18266 master.cpp:504] Master only allowing authenticated HTTP frameworks to register I0716 04:07:54.295344 18266 credentials.hpp:37] Loading credentials for authentication from '/tmp/MCL3Ed/credentials' I0716 04:07:54.295594 18266 master.cpp:548] Using default 'crammd5' authenticator I0716 04:07:54.295749 18266 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0716 04:07:54.295925 18266 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0716 04:07:54.296046 18266 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0716 04:07:54.296161 18266 master.cpp:629] Authorization enabled I0716 04:07:54.296469 18263 whitelist_watcher.cpp:77] No whitelist given I0716 04:07:54.296507 18264 hierarchical.cpp:241] Initialized hierarchical allocator process I0716 04:07:54.298987 18269 master.cpp:2151] Elected as the leading master! I0716 04:07:54.299021 18269 master.cpp:1665] Recovering from registrar I0716 04:07:54.299190 18265 registrar.cpp:339] Recovering registrar I0716 04:07:54.299939 18265 registrar.cpp:383] Successfully fetched the registry (0B) in 700160ns I0716 04:07:54.300068 18265 registrar.cpp:487] Applied 1 operations in 40201ns; attempting to update the registry I0716 04:07:54.300710 18265 registrar.cpp:544] Successfully updated the registry in 577024ns I0716 04:07:54.300842 18265 registrar.cpp:416] Successfully recovered registrar I0716 04:07:54.301285 18282 master.cpp:1800] Recovered 0 agents from the registry (143B); allowing 10mins for agents to reregister I0716 04:07:54.301307 18270 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover W0716 04:07:54.302055 18259 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:39944 I0716 04:07:54.303009 18259 sched.cpp:239] Version: 1.9.0 I0716 04:07:54.303642 18279 sched.cpp:343] New master detected at master@172.17.0.2:39944 I0716 04:07:54.303752 18279 sched.cpp:408] Authenticating with master master@172.17.0.2:39944 I0716 04:07:54.303782 18279 sched.cpp:415] Using default CRAM-MD5 authenticatee I0716 04:07:54.304107 18281 authenticatee.cpp:121] Creating new client SASL connection I0716 04:07:54.304417 18283 master.cpp:10481] Authenticating scheduler-45f7d79b-5a46-4765-91a6-0feb018d7cfd@172.17.0.2:39944 I0716 04:07:54.304564 18276 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(611)@172.17.0.2:39944 I0716 04:07:54.304824 18272 authenticator.cpp:98] Creating new server SASL connection I0716 04:07:54.305038 18262 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0716 04:07:54.305066 18262 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0716 04:07:54.305188 18273 authenticator.cpp:204] Received SASL authentication start I0716 04:07:54.305248 18273 authenticator.cpp:326] Authentication requires more steps I0716 04:07:54.305353 18261 authenticatee.cpp:259] Received SASL authentication step I0716 04:07:54.305474 18265 authenticator.cpp:232] Received SASL authentication step I0716 04:07:54.305505 18265 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0716 04:07:54.305519 18265 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0716 04:07:54.305562 18265 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0716 04:07:54.305583 18265 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0716 04:07:54.305593 18265 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.305604 18265 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.305619 18265 authenticator.cpp:318] Authentication success I0716 04:07:54.305698 18280 authenticatee.cpp:299] Authentication success I0716 04:07:54.305814 18275 master.cpp:10513] Successfully authenticated principal 'test-principal' at scheduler-45f7d79b-5a46-4765-91a6-0feb018d7cfd@172.17.0.2:39944 I0716 04:07:54.305841 18260 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(611)@172.17.0.2:39944 I0716 04:07:54.306083 18268 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:39944 I0716 04:07:54.306126 18268 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:39944 I0716 04:07:54.306303 18268 sched.cpp:870] Will retry registration in 1.260129456secs if necessary I0716 04:07:54.306485 18264 master.cpp:2891] Received SUBSCRIBE call for framework 'default' at scheduler-45f7d79b-5a46-4765-91a6-0feb018d7cfd@172.17.0.2:39944 I0716 04:07:54.306529 18264 master.cpp:2223] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' I0716 04:07:54.307134 18267 master.cpp:2978] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] I0716 04:07:54.309110 18267 master.cpp:10711] Adding framework de15068b-5d66-4edb-b622-869d19e07a29-0000 (default) at scheduler-45f7d79b-5a46-4765-91a6-0feb018d7cfd@172.17.0.2:39944 with roles { } suppressed I0716 04:07:54.309617 18277 sched.cpp:751] Framework registered with de15068b-5d66-4edb-b622-869d19e07a29-0000 I0716 04:07:54.309764 18277 sched.cpp:770] Scheduler::registered took 110009ns I0716 04:07:54.309828 18269 hierarchical.cpp:368] Added framework de15068b-5d66-4edb-b622-869d19e07a29-0000 I0716 04:07:54.310221 18269 hierarchical.cpp:1508] Performed allocation for 0 agents in 115639ns I0716 04:07:54.312765 18261 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/state' I0716 04:07:54.314549 18263 http.cpp:1115] HTTP GET for /master/state from 172.17.0.2:39384 I0716 04:07:54.317001 18274 http.cpp:1132] HTTP GET for /master/state from 172.17.0.2:39384: '200 OK' after 4.54605ms I0716 04:07:54.318892 18259 sched.cpp:2166] Asked to stop the driver I0716 04:07:54.318994 18268 sched.cpp:1204] Stopping framework de15068b-5d66-4edb-b622-869d19e07a29-0000 I0716 04:07:54.319275 18260 master.cpp:11068] Processing TEARDOWN call for framework de15068b-5d66-4edb-b622-869d19e07a29-0000 (default) at scheduler-45f7d79b-5a46-4765-91a6-0feb018d7cfd@172.17.0.2:39944 I0716 04:07:54.319308 18260 master.cpp:11080] Removing framework de15068b-5d66-4edb-b622-869d19e07a29-0000 (default) at scheduler-45f7d79b-5a46-4765-91a6-0feb018d7cfd@172.17.0.2:39944 I0716 04:07:54.319322 18260 master.cpp:3343] Deactivating framework de15068b-5d66-4edb-b622-869d19e07a29-0000 (default) at scheduler-45f7d79b-5a46-4765-91a6-0feb018d7cfd@172.17.0.2:39944 I0716 04:07:54.319470 18267 hierarchical.cpp:475] Deactivated framework de15068b-5d66-4edb-b622-869d19e07a29-0000 I0716 04:07:54.319705 18274 hierarchical.cpp:1432] Allocation paused I0716 04:07:54.320015 18274 hierarchical.cpp:417] Removed framework de15068b-5d66-4edb-b622-869d19e07a29-0000 I0716 04:07:54.320016 18259 master.cpp:1136] Master terminating I0716 04:07:54.320065 18274 hierarchical.cpp:1442] Allocation resumed [ OK ] MasterTest.FrameworkInfoLabels (36 ms) [ RUN ] MasterTest.RejectFrameworkWithInvalidRole I0716 04:07:54.327844 18259 cluster.cpp:176] Creating default 'local' authorizer I0716 04:07:54.331383 18282 master.cpp:440] Master 5a7d444d-9507-402b-8812-2bd2c3646bed (653753ac5284) started on 172.17.0.2:39944 I0716 04:07:54.331405 18282 master.cpp:443] 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_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/DDYHqh/credentials" --filter_gpu_resources="true" --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_framework_ids="50" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --m emory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="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="true" --version="false" --webui_dir="/mesos/mesos-1.9.0/_inst/share/mesos/webui" --work_dir="/tmp/DDYHqh/master" --zk_session_timeout="10secs" I0716 04:07:54.331698 18282 master.cpp:492] Master only allowing authenticated frameworks to register I0716 04:07:54.331712 18282 master.cpp:498] Master only allowing authenticated agents to register I0716 04:07:54.331724 18282 master.cpp:504] Master only allowing authenticated HTTP frameworks to register I0716 04:07:54.331734 18282 credentials.hpp:37] Loading credentials for authentication from '/tmp/DDYHqh/credentials' I0716 04:07:54.331990 18282 master.cpp:548] Using default 'crammd5' authenticator I0716 04:07:54.332154 18282 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0716 04:07:54.332329 18282 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0716 04:07:54.332480 18282 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0716 04:07:54.332612 18282 master.cpp:629] Authorization enabled I0716 04:07:54.332931 18274 hierarchical.cpp:241] Initialized hierarchical allocator process I0716 04:07:54.332937 18283 whitelist_watcher.cpp:77] No whitelist given I0716 04:07:54.335392 18265 master.cpp:2151] Elected as the leading master! I0716 04:07:54.335422 18265 master.cpp:1665] Recovering from registrar I0716 04:07:54.335572 18261 registrar.cpp:339] Recovering registrar I0716 04:07:54.336259 18261 registrar.cpp:383] Successfully fetched the registry (0B) in 645888ns I0716 04:07:54.336390 18261 registrar.cpp:487] Applied 1 operations in 43817ns; attempting to update the registry I0716 04:07:54.336989 18261 registrar.cpp:544] Successfully updated the registry in 537088ns I0716 04:07:54.337116 18261 registrar.cpp:416] Successfully recovered registrar I0716 04:07:54.337549 18264 master.cpp:1800] Recovered 0 agents from the registry (143B); allowing 10mins for agents to reregister I0716 04:07:54.337574 18269 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover W0716 04:07:54.338243 18259 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:39944 I0716 04:07:54.339140 18259 sched.cpp:239] Version: 1.9.0 I0716 04:07:54.339720 18276 sched.cpp:343] New master detected at master@172.17.0.2:39944 I0716 04:07:54.339812 18276 sched.cpp:408] Authenticating with master master@172.17.0.2:39944 I0716 04:07:54.339838 18276 sched.cpp:415] Using default CRAM-MD5 authenticatee I0716 04:07:54.340162 18278 authenticatee.cpp:121] Creating new client SASL connection I0716 04:07:54.340466 18280 master.cpp:10481] Authenticating scheduler-f7727309-155a-4f2b-a38e-4bc53fbb7eba@172.17.0.2:39944 I0716 04:07:54.340611 18262 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(612)@172.17.0.2:39944 I0716 04:07:54.340881 18268 authenticator.cpp:98] Creating new server SASL connection I0716 04:07:54.341112 18263 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0716 04:07:54.341140 18263 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0716 04:07:54.341246 18277 authenticator.cpp:204] Received SASL authentication start I0716 04:07:54.341308 18277 authenticator.cpp:326] Authentication requires more steps I0716 04:07:54.341454 18267 authenticatee.cpp:259] Received SASL authentication step I0716 04:07:54.341590 18281 authenticator.cpp:232] Received SASL authentication step I0716 04:07:54.341624 18281 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0716 04:07:54.341647 18281 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0716 04:07:54.341698 18281 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0716 04:07:54.341724 18281 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0716 04:07:54.341737 18281 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.341744 18281 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.341759 18281 authenticator.cpp:318] Authentication success I0716 04:07:54.341848 18260 authenticatee.cpp:299] Authentication success I0716 04:07:54.341953 18261 master.cpp:10513] Successfully authenticated principal 'test-principal' at scheduler-f7727309-155a-4f2b-a38e-4bc53fbb7eba@172.17.0.2:39944 I0716 04:07:54.342007 18264 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(612)@172.17.0.2:39944 I0716 04:07:54.342169 18271 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:39944 I0716 04:07:54.342193 18271 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:39944 I0716 04:07:54.342310 18271 sched.cpp:870] Will retry registration in 1.387980512secs if necessary I0716 04:07:54.342465 18275 master.cpp:2881] Refusing subscription of framework 'default' at scheduler-f7727309-155a-4f2b-a38e-4bc53fbb7eba@172.17.0.2:39944: 'FrameworkInfo.roles' contains invalid role: Role '/test/test1' cannot start with a slash I0716 04:07:54.342595 18282 sched.cpp:1188] Got error ''FrameworkInfo.roles' contains invalid role: Role '/test/test1' cannot start with a slash' I0716 04:07:54.342614 18282 sched.cpp:2200] Asked to abort the driver I0716 04:07:54.342685 18282 sched.cpp:1199] Scheduler::error took 43771ns I0716 04:07:54.342728 18282 sched.cpp:1234] Aborting framework I0716 04:07:54.342749 18282 sched.cpp:1239] Not sending a deactivate message as master is disconnected I0716 04:07:54.343485 18259 master.cpp:1136] Master terminating [ OK ] MasterTest.RejectFrameworkWithInvalidRole (22 ms) [ RUN ] MasterTest.FrameworkSubscribeEmptyId I0716 04:07:54.349164 18259 cluster.cpp:176] Creating default 'local' authorizer I0716 04:07:54.352668 18283 master.cpp:440] Master cab9c628-62a1-452a-ae2d-7783cd1ba93c (653753ac5284) started on 172.17.0.2:39944 I0716 04:07:54.352695 18283 master.cpp:443] 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_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/G3tqfl/credentials" --filter_gpu_resources="true" --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_framework_ids="50" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --m emory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="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="true" --version="false" --webui_dir="/mesos/mesos-1.9.0/_inst/share/mesos/webui" --work_dir="/tmp/G3tqfl/master" --zk_session_timeout="10secs" I0716 04:07:54.353001 18283 master.cpp:492] Master only allowing authenticated frameworks to register I0716 04:07:54.353019 18283 master.cpp:498] Master only allowing authenticated agents to register I0716 04:07:54.353031 18283 master.cpp:504] Master only allowing authenticated HTTP frameworks to register I0716 04:07:54.353047 18283 credentials.hpp:37] Loading credentials for authentication from '/tmp/G3tqfl/credentials' I0716 04:07:54.353301 18283 master.cpp:548] Using default 'crammd5' authenticator I0716 04:07:54.353451 18283 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0716 04:07:54.353622 18283 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0716 04:07:54.353768 18283 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0716 04:07:54.353912 18283 master.cpp:629] Authorization enabled I0716 04:07:54.354198 18276 hierarchical.cpp:241] Initialized hierarchical allocator process I0716 04:07:54.354204 18280 whitelist_watcher.cpp:77] No whitelist given I0716 04:07:54.356461 18267 master.cpp:2151] Elected as the leading master! I0716 04:07:54.356488 18267 master.cpp:1665] Recovering from registrar I0716 04:07:54.356640 18272 registrar.cpp:339] Recovering registrar I0716 04:07:54.357291 18272 registrar.cpp:383] Successfully fetched the registry (0B) in 612096ns I0716 04:07:54.357414 18272 registrar.cpp:487] Applied 1 operations in 40456ns; attempting to update the registry I0716 04:07:54.357982 18272 registrar.cpp:544] Successfully updated the registry in 511232ns I0716 04:07:54.358116 18272 registrar.cpp:416] Successfully recovered registrar I0716 04:07:54.358525 18274 master.cpp:1800] Recovered 0 agents from the registry (143B); allowing 10mins for agents to reregister I0716 04:07:54.358558 18278 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover W0716 04:07:54.359246 18259 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:39944 I0716 04:07:54.360114 18259 sched.cpp:239] Version: 1.9.0 I0716 04:07:54.360630 18267 sched.cpp:343] New master detected at master@172.17.0.2:39944 I0716 04:07:54.360729 18267 sched.cpp:408] Authenticating with master master@172.17.0.2:39944 I0716 04:07:54.360754 18267 sched.cpp:415] Using default CRAM-MD5 authenticatee I0716 04:07:54.361034 18281 authenticatee.cpp:121] Creating new client SASL connection I0716 04:07:54.361323 18260 master.cpp:10481] Authenticating scheduler-01ab48be-168b-40fb-9d1a-633a8d74982a@172.17.0.2:39944 I0716 04:07:54.361765 18263 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(613)@172.17.0.2:39944 I0716 04:07:54.361999 18271 authenticator.cpp:98] Creating new server SASL connection I0716 04:07:54.362197 18264 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0716 04:07:54.362226 18264 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0716 04:07:54.362339 18275 authenticator.cpp:204] Received SASL authentication start I0716 04:07:54.362396 18275 authenticator.cpp:326] Authentication requires more steps I0716 04:07:54.362532 18282 authenticatee.cpp:259] Received SASL authentication step I0716 04:07:54.362656 18272 authenticator.cpp:232] Received SASL authentication step I0716 04:07:54.362685 18272 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0716 04:07:54.362699 18272 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0716 04:07:54.362733 18272 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0716 04:07:54.362753 18272 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0716 04:07:54.362776 18272 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.362790 18272 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.362805 18272 authenticator.cpp:318] Authentication success I0716 04:07:54.362891 18270 authenticatee.cpp:299] Authentication success I0716 04:07:54.362977 18273 master.cpp:10513] Successfully authenticated principal 'test-principal' at scheduler-01ab48be-168b-40fb-9d1a-633a8d74982a@172.17.0.2:39944 I0716 04:07:54.363013 18265 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(613)@172.17.0.2:39944 I0716 04:07:54.363292 18272 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:39944 I0716 04:07:54.363319 18272 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:39944 I0716 04:07:54.363447 18272 sched.cpp:870] Will retry registration in 9.107763ms if necessary I0716 04:07:54.363673 18280 master.cpp:2891] Received SUBSCRIBE call for framework 'default' at scheduler-01ab48be-168b-40fb-9d1a-633a8d74982a@172.17.0.2:39944 I0716 04:07:54.363713 18280 master.cpp:2223] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' I0716 04:07:54.364274 18283 master.cpp:2978] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] I0716 04:07:54.366245 18283 master.cpp:10711] Adding framework cab9c628-62a1-452a-ae2d-7783cd1ba93c-0000 (default) at scheduler-01ab48be-168b-40fb-9d1a-633a8d74982a@172.17.0.2:39944 with roles { } suppressed I0716 04:07:54.366668 18261 sched.cpp:751] Framework registered with cab9c628-62a1-452a-ae2d-7783cd1ba93c-0000 I0716 04:07:54.366760 18261 sched.cpp:770] Scheduler::registered took 64742ns I0716 04:07:54.367053 18279 hierarchical.cpp:368] Added framework cab9c628-62a1-452a-ae2d-7783cd1ba93c-0000 I0716 04:07:54.367332 18279 hierarchical.cpp:1508] Performed allocation for 0 agents in 122027ns I0716 04:07:54.367334 18264 master.cpp:1411] Framework cab9c628-62a1-452a-ae2d-7783cd1ba93c-0000 (default) at scheduler-01ab48be-168b-40fb-9d1a-633a8d74982a@172.17.0.2:39944 disconnected I0716 04:07:54.367373 18264 master.cpp:3343] Deactivating framework cab9c628-62a1-452a-ae2d-7783cd1ba93c-0000 (default) at scheduler-01ab48be-168b-40fb-9d1a-633a8d74982a@172.17.0.2:39944 I0716 04:07:54.367451 18264 master.cpp:3320] Disconnecting framework cab9c628-62a1-452a-ae2d-7783cd1ba93c-0000 (default) at scheduler-01ab48be-168b-40fb-9d1a-633a8d74982a@172.17.0.2:39944 I0716 04:07:54.367504 18278 hierarchical.cpp:475] Deactivated framework cab9c628-62a1-452a-ae2d-7783cd1ba93c-0000 I0716 04:07:54.367509 18264 master.cpp:1426] Giving framework cab9c628-62a1-452a-ae2d-7783cd1ba93c-0000 (default) at scheduler-01ab48be-168b-40fb-9d1a-633a8d74982a@172.17.0.2:39944 0ns to failover I0716 04:07:54.367668 18264 master.cpp:1136] Master terminating I0716 04:07:54.368049 18270 hierarchical.cpp:417] Removed framework cab9c628-62a1-452a-ae2d-7783cd1ba93c-0000 [ OK ] MasterTest.FrameworkSubscribeEmptyId (25 ms) [ RUN ] MasterTest.FrameworksEndpointWithoutFrameworks I0716 04:07:54.374814 18259 cluster.cpp:176] Creating default 'local' authorizer I0716 04:07:54.378914 18268 master.cpp:440] Master d4b27238-bb07-4b16-9203-d61fa01eda29 (localhost) started on 172.17.0.2:39944 I0716 04:07:54.378947 18268 master.cpp:443] 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_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --cluster="test-cluster" --credentials="/tmp/B0vI7o/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname="localhost" --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_framework_ids="50" --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_metrics="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="true" --version="false" --webui_dir="/mesos/mesos-1.9.0/_inst/share/mesos/webui" --work_dir="/tmp/B0vI7o/master" --zk_session_timeout="10secs" I0716 04:07:54.379397 18268 master.cpp:492] Master only allowing authenticated frameworks to register I0716 04:07:54.379411 18268 master.cpp:498] Master only allowing authenticated agents to register I0716 04:07:54.379417 18268 master.cpp:504] Master only allowing authenticated HTTP frameworks to register I0716 04:07:54.379427 18268 credentials.hpp:37] Loading credentials for authentication from '/tmp/B0vI7o/credentials' I0716 04:07:54.379695 18268 master.cpp:548] Using default 'crammd5' authenticator I0716 04:07:54.379858 18268 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0716 04:07:54.380054 18268 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0716 04:07:54.380205 18268 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0716 04:07:54.380357 18268 master.cpp:629] Authorization enabled I0716 04:07:54.380657 18278 hierarchical.cpp:241] Initialized hierarchical allocator process I0716 04:07:54.380684 18274 whitelist_watcher.cpp:77] No whitelist given I0716 04:07:54.383214 18276 master.cpp:2151] Elected as the leading master! I0716 04:07:54.383245 18276 master.cpp:1665] Recovering from registrar I0716 04:07:54.383491 18283 registrar.cpp:339] Recovering registrar I0716 04:07:54.384222 18283 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns I0716 04:07:54.384341 18283 registrar.cpp:487] Applied 1 operations in 36443ns; attempting to update the registry I0716 04:07:54.384974 18283 registrar.cpp:544] Successfully updated the registry in 0ns I0716 04:07:54.385116 18283 registrar.cpp:416] Successfully recovered registrar I0716 04:07:54.385535 18271 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover I0716 04:07:54.385526 18266 master.cpp:1800] Recovered 0 agents from the registry (137B); allowing 10mins for agents to reregister I0716 04:07:54.388540 18279 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/frameworks' I0716 04:07:54.390275 18272 http.cpp:1115] HTTP GET for /master/frameworks from 172.17.0.2:39388 I0716 04:07:54.391489 18277 http.cpp:1132] HTTP GET for /master/frameworks from 172.17.0.2:39388: '200 OK' after 0ms I0716 04:07:54.396718 18259 master.cpp:1136] Master terminating [ OK ] MasterTest.FrameworksEndpointWithoutFrameworks (29 ms) [ RUN ] MasterTest.FrameworksEndpointMultipleFrameworks I0716 04:07:54.403949 18259 cluster.cpp:176] Creating default 'local' authorizer I0716 04:07:54.407516 18267 master.cpp:440] Master 58332627-3707-4585-8462-fd714d32fe04 (653753ac5284) started on 172.17.0.2:39944 I0716 04:07:54.407544 18267 master.cpp:443] 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_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ZfZa4s/credentials" --filter_gpu_resources="true" --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_framework_ids="50" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --m emory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="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="true" --version="false" --webui_dir="/mesos/mesos-1.9.0/_inst/share/mesos/webui" --work_dir="/tmp/ZfZa4s/master" --zk_session_timeout="10secs" I0716 04:07:54.407908 18267 master.cpp:492] Master only allowing authenticated frameworks to register I0716 04:07:54.407927 18267 master.cpp:498] Master only allowing authenticated agents to register I0716 04:07:54.407938 18267 master.cpp:504] Master only allowing authenticated HTTP frameworks to register I0716 04:07:54.407953 18267 credentials.hpp:37] Loading credentials for authentication from '/tmp/ZfZa4s/credentials' I0716 04:07:54.408217 18267 master.cpp:548] Using default 'crammd5' authenticator I0716 04:07:54.408381 18267 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0716 04:07:54.408561 18267 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0716 04:07:54.408705 18267 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0716 04:07:54.408844 18267 master.cpp:629] Authorization enabled I0716 04:07:54.409168 18275 whitelist_watcher.cpp:77] No whitelist given I0716 04:07:54.409185 18263 hierarchical.cpp:241] Initialized hierarchical allocator process I0716 04:07:54.411661 18278 master.cpp:2151] Elected as the leading master! I0716 04:07:54.411692 18278 master.cpp:1665] Recovering from registrar I0716 04:07:54.411875 18269 registrar.cpp:339] Recovering registrar I0716 04:07:54.412556 18269 registrar.cpp:383] Successfully fetched the registry (0B) in 636928ns I0716 04:07:54.412703 18269 registrar.cpp:487] Applied 1 operations in 38054ns; attempting to update the registry I0716 04:07:54.413298 18269 registrar.cpp:544] Successfully updated the registry in 537856ns I0716 04:07:54.413425 18269 registrar.cpp:416] Successfully recovered registrar I0716 04:07:54.413834 18261 master.cpp:1800] Recovered 0 agents from the registry (143B); allowing 10mins for agents to reregister I0716 04:07:54.413878 18273 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover W0716 04:07:54.418841 18259 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:39944 I0716 04:07:54.419970 18259 containerizer.cpp:314] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } W0716 04:07:54.420526 18259 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges W0716 04:07:54.420552 18259 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges W0716 04:07:54.420677 18259 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges I0716 04:07:54.420722 18259 provisioner.cpp:298] Using default backend 'copy' I0716 04:07:54.422863 18259 cluster.cpp:510] Creating default 'local' authorizer I0716 04:07:54.424875 18261 slave.cpp:265] Mesos agent started on (300)@172.17.0.2:39944 I0716 04:07:54.424898 18261 slave.cpp:266] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ZfZa4s/B6wRZE/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --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/ZfZa4s/B6wRZE/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --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/ZfZa4s/B6wRZE/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ZfZa4s/B6wRZE/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/ZfZa4s/B6wRZE/frameworks" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/ZfZa4s/B6wRZE/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.9.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="15 0" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --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="/tmp/MasterTest_FrameworksEndpointMultipleFrameworks_3SDh1A" --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/MasterTest_FrameworksEndpointMultipleFrameworks_hzxI2w" --zk_session_timeout="10secs" I0716 04:07:54.425312 18261 credentials.hpp:86] Loading credential for authentication from '/tmp/ZfZa4s/B6wRZE/credential' I0716 04:07:54.425523 18261 slave.cpp:298] Agent using credential for: test-principal I0716 04:07:54.425549 18261 credentials.hpp:37] Loading credentials for authentication from '/tmp/ZfZa4s/B6wRZE/http_credentials' I0716 04:07:54.425776 18261 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0716 04:07:54.426102 18261 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module I0716 04:07:54.427417 18261 slave.cpp:613] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] I0716 04:07:54.427613 18261 slave.cpp:621] Agent attributes: [ ] I0716 04:07:54.427626 18261 slave.cpp:630] Agent hostname: 653753ac5284 I0716 04:07:54.427776 18265 status_update_manager_process.hpp:379] Pausing operation status update manager I0716 04:07:54.427780 18278 task_status_update_manager.cpp:181] Pausing sending task status updates I0716 04:07:54.429198 18270 state.cpp:67] Recovering state from '/tmp/MasterTest_FrameworksEndpointMultipleFrameworks_hzxI2w/meta' I0716 04:07:54.429426 18283 slave.cpp:7429] Finished recovering checkpointed state from '/tmp/MasterTest_FrameworksEndpointMultipleFrameworks_hzxI2w/meta', beginning agent recovery I0716 04:07:54.430002 18277 task_status_update_manager.cpp:207] Recovering task status update manager I0716 04:07:54.430361 18271 containerizer.cpp:796] Recovering Mesos containers I0716 04:07:54.430676 18271 containerizer.cpp:1122] Recovering isolators I0716 04:07:54.431311 18267 containerizer.cpp:1161] Recovering provisioner I0716 04:07:54.432027 18265 provisioner.cpp:498] Provisioner recovery complete I0716 04:07:54.432641 18283 composing.cpp:339] Finished recovering all containerizers I0716 04:07:54.432863 18260 slave.cpp:7893] Recovering executors I0716 04:07:54.432960 18260 slave.cpp:8046] Finished recovery I0716 04:07:54.433756 18266 task_status_update_manager.cpp:181] Pausing sending task status updates I0716 04:07:54.433763 18263 status_update_manager_process.hpp:379] Pausing operation status update manager I0716 04:07:54.433790 18273 slave.cpp:1340] New master detected at master@172.17.0.2:39944 I0716 04:07:54.433975 18273 slave.cpp:1405] Detecting new master I0716 04:07:54.442320 18262 slave.cpp:1432] Authenticating with master master@172.17.0.2:39944 I0716 04:07:54.442411 18262 slave.cpp:1441] Using default CRAM-MD5 authenticatee I0716 04:07:54.442740 18271 authenticatee.cpp:121] Creating new client SASL connection I0716 04:07:54.443099 18279 master.cpp:10481] Authenticating slave(300)@172.17.0.2:39944 I0716 04:07:54.443235 18267 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(614)@172.17.0.2:39944 I0716 04:07:54.443486 18274 authenticator.cpp:98] Creating new server SASL connection I0716 04:07:54.443707 18272 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0716 04:07:54.443734 18272 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0716 04:07:54.443838 18265 authenticator.cpp:204] Received SASL authentication start I0716 04:07:54.443898 18265 authenticator.cpp:326] Authentication requires more steps I0716 04:07:54.443995 18265 authenticatee.cpp:259] Received SASL authentication step I0716 04:07:54.444124 18282 authenticator.cpp:232] Received SASL authentication step I0716 04:07:54.444157 18282 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0716 04:07:54.444177 18282 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0716 04:07:54.444226 18282 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0716 04:07:54.444248 18282 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0716 04:07:54.444268 18282 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.444280 18282 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.444295 18282 authenticator.cpp:318] Authentication success I0716 04:07:54.444382 18261 authenticatee.cpp:299] Authentication success I0716 04:07:54.444530 18268 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(614)@172.17.0.2:39944 I0716 04:07:54.444591 18280 master.cpp:10513] Successfully authenticated principal 'test-principal' at slave(300)@172.17.0.2:39944 I0716 04:07:54.444784 18270 slave.cpp:1532] Successfully authenticated with master master@172.17.0.2:39944 I0716 04:07:54.445150 18270 slave.cpp:1982] Will retry registration in 8.337502ms if necessary I0716 04:07:54.445521 18281 master.cpp:7001] Received register agent message from slave(300)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.445804 18281 master.cpp:4200] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal' W0716 04:07:54.446166 18259 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:39944 I0716 04:07:54.446435 18279 master.cpp:7068] Authorized registration of agent at slave(300)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.446521 18279 master.cpp:7183] Registering agent at slave(300)@172.17.0.2:39944 (653753ac5284) with id 58332627-3707-4585-8462-fd714d32fe04-S0 I0716 04:07:54.447137 18274 registrar.cpp:487] Applied 1 operations in 170916ns; attempting to update the registry I0716 04:07:54.447271 18259 sched.cpp:239] Version: 1.9.0 W0716 04:07:54.447811 18259 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:39944 I0716 04:07:54.447842 18274 registrar.cpp:544] Successfully updated the registry in 630784ns I0716 04:07:54.447965 18269 sched.cpp:343] New master detected at master@172.17.0.2:39944 I0716 04:07:54.448011 18268 master.cpp:7231] Admitted agent 58332627-3707-4585-8462-fd714d32fe04-S0 at slave(300)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.448057 18269 sched.cpp:408] Authenticating with master master@172.17.0.2:39944 I0716 04:07:54.448076 18269 sched.cpp:415] Using default CRAM-MD5 authenticatee I0716 04:07:54.448323 18270 authenticatee.cpp:121] Creating new client SASL connection I0716 04:07:54.448487 18259 sched.cpp:239] Version: 1.9.0 I0716 04:07:54.448856 18268 master.cpp:7276] Registered agent 58332627-3707-4585-8462-fd714d32fe04-S0 at slave(300)@172.17.0.2:39944 (653753ac5284) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0716 04:07:54.448922 18262 slave.cpp:1565] Registered with master master@172.17.0.2:39944; given agent ID 58332627-3707-4585-8462-fd714d32fe04-S0 I0716 04:07:54.448954 18265 sched.cpp:343] New master detected at master@172.17.0.2:39944 I0716 04:07:54.449036 18283 task_status_update_manager.cpp:188] Resuming sending task status updates I0716 04:07:54.449051 18265 sched.cpp:408] Authenticating with master master@172.17.0.2:39944 I0716 04:07:54.449018 18281 hierarchical.cpp:617] Added agent 58332627-3707-4585-8462-fd714d32fe04-S0 (653753ac5284) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) I0716 04:07:54.449043 18268 master.cpp:10481] Authenticating scheduler-2541669e-25ed-4b76-991f-a040251479cb@172.17.0.2:39944 I0716 04:07:54.449072 18265 sched.cpp:415] Using default CRAM-MD5 authenticatee I0716 04:07:54.449168 18282 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(615)@172.17.0.2:39944 I0716 04:07:54.449285 18280 authenticatee.cpp:121] Creating new client SASL connection I0716 04:07:54.449434 18281 hierarchical.cpp:1508] Performed allocation for 1 agents in 191772ns I0716 04:07:54.449455 18262 slave.cpp:1600] Checkpointing SlaveInfo to '/tmp/MasterTest_FrameworksEndpointMultipleFrameworks_hzxI2w/meta/slaves/58332627-3707-4585-8462-fd714d32fe04-S0/slave.info' I0716 04:07:54.449599 18278 authenticator.cpp:98] Creating new server SASL connection I0716 04:07:54.449609 18274 master.cpp:10481] Authenticating scheduler-2345e9d2-ae26-49c4-a612-c648ca415821@172.17.0.2:39944 I0716 04:07:54.449633 18265 status_update_manager_process.hpp:385] Resuming operation status update manager I0716 04:07:54.449714 18266 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(616)@172.17.0.2:39944 I0716 04:07:54.449805 18269 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0716 04:07:54.449828 18269 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0716 04:07:54.449950 18264 authenticator.cpp:204] Received SASL authentication start I0716 04:07:54.449950 18278 authenticator.cpp:98] Creating new server SASL connection I0716 04:07:54.450016 18264 authenticator.cpp:326] Authentication requires more steps I0716 04:07:54.450166 18263 authenticatee.cpp:259] Received SASL authentication step I0716 04:07:54.450203 18276 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0716 04:07:54.450227 18276 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0716 04:07:54.450292 18279 authenticator.cpp:232] Received SASL authentication step I0716 04:07:54.450332 18279 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0716 04:07:54.450343 18276 authenticator.cpp:204] Received SASL authentication start I0716 04:07:54.450352 18279 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0716 04:07:54.450407 18276 authenticator.cpp:326] Authentication requires more steps I0716 04:07:54.450409 18279 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0716 04:07:54.450460 18279 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0716 04:07:54.450479 18279 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.450493 18279 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.450516 18279 authenticator.cpp:318] Authentication success I0716 04:07:54.450548 18275 authenticatee.cpp:259] Received SASL authentication step I0716 04:07:54.450693 18260 authenticator.cpp:232] Received SASL authentication step I0716 04:07:54.450714 18276 master.cpp:10513] Successfully authenticated principal 'test-principal' at scheduler-2541669e-25ed-4b76-991f-a040251479cb@172.17.0.2:39944 I0716 04:07:54.450729 18260 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0716 04:07:54.450728 18271 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(615)@172.17.0.2:39944 I0716 04:07:54.450775 18262 slave.cpp:1652] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"hc7uu2VCR4ibo6sCLvh+pw=="},"slave_id":{"value":"58332627-3707-4585-8462-fd714d32fe04-S0"},"update_oversubscribed_resources":false} I0716 04:07:54.450886 18282 authenticatee.cpp:299] Authentication success I0716 04:07:54.450927 18260 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0716 04:07:54.450970 18260 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0716 04:07:54.451011 18260 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0716 04:07:54.451035 18260 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.451050 18260 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.451088 18260 authenticator.cpp:318] Authentication success I0716 04:07:54.451212 18264 authenticatee.cpp:299] Authentication success I0716 04:07:54.451261 18272 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(616)@172.17.0.2:39944 I0716 04:07:54.451390 18270 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:39944 I0716 04:07:54.451421 18270 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:39944 I0716 04:07:54.451548 18266 master.cpp:8362] Ignoring update on agent 58332627-3707-4585-8462-fd714d32fe04-S0 at slave(300)@172.17.0.2:39944 (653753ac5284) as it reports no changes I0716 04:07:54.451567 18267 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:39944 I0716 04:07:54.451596 18267 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:39944 I0716 04:07:54.451592 18270 sched.cpp:870] Will retry registration in 1.205162525secs if necessary I0716 04:07:54.451642 18266 master.cpp:10513] Successfully authenticated principal 'test-principal' at scheduler-2345e9d2-ae26-49c4-a612-c648ca415821@172.17.0.2:39944 I0716 04:07:54.451728 18267 sched.cpp:870] Will retry registration in 1.209878805secs if necessary I0716 04:07:54.451845 18266 master.cpp:2891] Received SUBSCRIBE call for framework 'default' at scheduler-2541669e-25ed-4b76-991f-a040251479cb@172.17.0.2:39944 I0716 04:07:54.451876 18266 master.cpp:2223] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' I0716 04:07:54.452149 18266 master.cpp:2891] Received SUBSCRIBE call for framework 'default' at scheduler-2345e9d2-ae26-49c4-a612-c648ca415821@172.17.0.2:39944 I0716 04:07:54.452179 18266 master.cpp:2223] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' I0716 04:07:54.452426 18275 master.cpp:2978] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] I0716 04:07:54.454399 18275 master.cpp:10711] Adding framework 58332627-3707-4585-8462-fd714d32fe04-0000 (default) at scheduler-2541669e-25ed-4b76-991f-a040251479cb@172.17.0.2:39944 with roles { } suppressed I0716 04:07:54.454823 18275 master.cpp:2978] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] I0716 04:07:54.454859 18268 sched.cpp:751] Framework registered with 58332627-3707-4585-8462-fd714d32fe04-0000 I0716 04:07:54.454953 18268 sched.cpp:770] Scheduler::registered took 64337ns I0716 04:07:54.455261 18276 hierarchical.cpp:368] Added framework 58332627-3707-4585-8462-fd714d32fe04-0000 I0716 04:07:54.456310 18276 hierarchical.cpp:1508] Performed allocation for 1 agents in 872186ns I0716 04:07:54.456717 18275 master.cpp:10711] Adding framework 58332627-3707-4585-8462-fd714d32fe04-0001 (default) at scheduler-2345e9d2-ae26-49c4-a612-c648ca415821@172.17.0.2:39944 with roles { } suppressed I0716 04:07:54.457062 18281 hierarchical.cpp:368] Added framework 58332627-3707-4585-8462-fd714d32fe04-0001 I0716 04:07:54.457068 18261 sched.cpp:751] Framework registered with 58332627-3707-4585-8462-fd714d32fe04-0001 I0716 04:07:54.457165 18261 sched.cpp:770] Scheduler::registered took 61249ns I0716 04:07:54.457352 18281 hierarchical.cpp:1508] Performed allocation for 1 agents in 157542ns I0716 04:07:54.457512 18275 master.cpp:10296] Sending offers [ 58332627-3707-4585-8462-fd714d32fe04-O0 ] to framework 58332627-3707-4585-8462-fd714d32fe04-0000 (default) at scheduler-2541669e-25ed-4b76-991f-a040251479cb@172.17.0.2:39944 I0716 04:07:54.457908 18264 sched.cpp:934] Scheduler::resourceOffers took 18548ns I0716 04:07:54.460045 18283 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/frameworks' I0716 04:07:54.461678 18282 http.cpp:1115] HTTP GET for /master/frameworks from 172.17.0.2:39390 I0716 04:07:54.463431 18281 http.cpp:1132] HTTP GET for /master/frameworks from 172.17.0.2:39390: '200 OK' after 3.70816ms I0716 04:07:54.466812 18280 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/frameworks' I0716 04:07:54.467999 18264 http.cpp:1115] HTTP GET for /master/frameworks?framework_id=58332627-3707-4585-8462-fd714d32fe04-0000 from 172.17.0.2:39392 I0716 04:07:54.469270 18275 http.cpp:1132] HTTP GET for /master/frameworks?framework_id=58332627-3707-4585-8462-fd714d32fe04-0000 from 172.17.0.2:39392: '200 OK' after 2.74995ms I0716 04:07:54.471031 18259 sched.cpp:2166] Asked to stop the driver I0716 04:07:54.471161 18267 sched.cpp:1204] Stopping framework 58332627-3707-4585-8462-fd714d32fe04-0000 I0716 04:07:54.471532 18274 master.cpp:11068] Processing TEARDOWN call for framework 58332627-3707-4585-8462-fd714d32fe04-0000 (default) at scheduler-2541669e-25ed-4b76-991f-a040251479cb@172.17.0.2:39944 I0716 04:07:54.471565 18274 master.cpp:11080] Removing framework 58332627-3707-4585-8462-fd714d32fe04-0000 (default) at scheduler-2541669e-25ed-4b76-991f-a040251479cb@172.17.0.2:39944 I0716 04:07:54.471581 18274 master.cpp:3343] Deactivating framework 58332627-3707-4585-8462-fd714d32fe04-0000 (default) at scheduler-2541669e-25ed-4b76-991f-a040251479cb@172.17.0.2:39944 I0716 04:07:54.471740 18268 hierarchical.cpp:475] Deactivated framework 58332627-3707-4585-8462-fd714d32fe04-0000 I0716 04:07:54.472141 18274 master.cpp:12573] Removing offer 58332627-3707-4585-8462-fd714d32fe04-O0 I0716 04:07:54.472440 18277 slave.cpp:4045] Asked to shut down framework 58332627-3707-4585-8462-fd714d32fe04-0000 by master@172.17.0.2:39944 I0716 04:07:54.472474 18277 slave.cpp:4060] Cannot shut down unknown framework 58332627-3707-4585-8462-fd714d32fe04-0000 I0716 04:07:54.472633 18266 hierarchical.cpp:1218] Recovered cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 58332627-3707-4585-8462-fd714d32fe04-S0 from framework 58332627-3707-4585-8462-fd714d32fe04-0000 I0716 04:07:54.472719 18266 hierarchical.cpp:1432] Allocation paused I0716 04:07:54.472862 18266 hierarchical.cpp:417] Removed framework 58332627-3707-4585-8462-fd714d32fe04-0000 I0716 04:07:54.472903 18266 hierarchical.cpp:1442] Allocation resumed I0716 04:07:54.474325 18281 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/frameworks' I0716 04:07:54.475517 18265 http.cpp:1115] HTTP GET for /master/frameworks?framework_id=58332627-3707-4585-8462-fd714d32fe04-0000 from 172.17.0.2:39394 I0716 04:07:54.476622 18277 http.cpp:1132] HTTP GET for /master/frameworks?framework_id=58332627-3707-4585-8462-fd714d32fe04-0000 from 172.17.0.2:39394: '200 OK' after 2.56ms I0716 04:07:54.477928 18259 sched.cpp:2166] Asked to stop the driver I0716 04:07:54.478013 18264 sched.cpp:1204] Stopping framework 58332627-3707-4585-8462-fd714d32fe04-0001 I0716 04:07:54.478217 18268 master.cpp:11068] Processing TEARDOWN call for framework 58332627-3707-4585-8462-fd714d32fe04-0001 (default) at scheduler-2345e9d2-ae26-49c4-a612-c648ca415821@172.17.0.2:39944 I0716 04:07:54.478247 18268 master.cpp:11080] Removing framework 58332627-3707-4585-8462-fd714d32fe04-0001 (default) at scheduler-2345e9d2-ae26-49c4-a612-c648ca415821@172.17.0.2:39944 I0716 04:07:54.478261 18268 master.cpp:3343] Deactivating framework 58332627-3707-4585-8462-fd714d32fe04-0001 (default) at scheduler-2345e9d2-ae26-49c4-a612-c648ca415821@172.17.0.2:39944 I0716 04:07:54.478379 18262 hierarchical.cpp:475] Deactivated framework 58332627-3707-4585-8462-fd714d32fe04-0001 I0716 04:07:54.478400 18269 slave.cpp:4045] Asked to shut down framework 58332627-3707-4585-8462-fd714d32fe04-0001 by master@172.17.0.2:39944 I0716 04:07:54.478430 18269 slave.cpp:4060] Cannot shut down unknown framework 58332627-3707-4585-8462-fd714d32fe04-0001 I0716 04:07:54.478545 18274 hierarchical.cpp:1432] Allocation paused I0716 04:07:54.478806 18274 hierarchical.cpp:417] Removed framework 58332627-3707-4585-8462-fd714d32fe04-0001 I0716 04:07:54.478852 18274 hierarchical.cpp:1442] Allocation resumed I0716 04:07:54.479372 18282 slave.cpp:914] Agent terminating I0716 04:07:54.622506 18275 master.cpp:1296] Agent 58332627-3707-4585-8462-fd714d32fe04-S0 at slave(300)@172.17.0.2:39944 (653753ac5284) disconnected I0716 04:07:54.622545 18275 master.cpp:3380] Disconnecting agent 58332627-3707-4585-8462-fd714d32fe04-S0 at slave(300)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.622599 18275 master.cpp:3399] Deactivating agent 58332627-3707-4585-8462-fd714d32fe04-S0 at slave(300)@172.17.0.2:39944 (653753ac5284) I0716 04:07:54.622759 18268 hierarchical.cpp:799] Agent 58332627-3707-4585-8462-fd714d32fe04-S0 deactivated I0716 04:07:54.629801 18259 master.cpp:1136] Master terminating I0716 04:07:54.630250 18260 hierarchical.cpp:775] Removed all filters for agent 58332627-3707-4585-8462-fd714d32fe04-S0 I0716 04:07:54.630273 18260 hierarchical.cpp:650] Removed agent 58332627-3707-4585-8462-fd714d32fe04-S0 [ OK ] MasterTest.FrameworksEndpointMultipleFrameworks (235 ms) [ RUN ] MasterTest.MaxCompletedFrameworksFlag I0716 04:07:54.639806 18259 cluster.cpp:176] Creating default 'local' authorizer I0716 04:07:54.643447 18276 master.cpp:440] Master 402e1a8a-949b-478b-930a-bdd318de7458 (653753ac5284) started on 172.17.0.2:39944 I0716 04:07:54.643476 18276 master.cpp:443] 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_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/rX5QxR/credentials" --filter_gpu_resources="true" --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_framework_ids="50" --max_completed_frameworks="0" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --me mory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="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="true" --version="false" --webui_dir="/mesos/mesos-1.9.0/_inst/share/mesos/webui" --work_dir="/tmp/rX5QxR/master" --zk_session_timeout="10secs" I0716 04:07:54.643824 18276 master.cpp:492] Master only allowing authenticated frameworks to register I0716 04:07:54.643839 18276 master.cpp:498] Master only allowing authenticated agents to register I0716 04:07:54.643846 18276 master.cpp:504] Master only allowing authenticated HTTP frameworks to register I0716 04:07:54.643854 18276 credentials.hpp:37] Loading credentials for authentication from '/tmp/rX5QxR/credentials' I0716 04:07:54.644122 18276 master.cpp:548] Using default 'crammd5' authenticator I0716 04:07:54.644277 18276 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0716 04:07:54.644474 18276 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0716 04:07:54.644613 18276 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0716 04:07:54.644744 18276 master.cpp:629] Authorization enabled I0716 04:07:54.645069 18268 hierarchical.cpp:241] Initialized hierarchical allocator process I0716 04:07:54.645117 18275 whitelist_watcher.cpp:77] No whitelist given I0716 04:07:54.647668 18272 master.cpp:2151] Elected as the leading master! I0716 04:07:54.647708 18272 master.cpp:1665] Recovering from registrar I0716 04:07:54.647877 18260 registrar.cpp:339] Recovering registrar I0716 04:07:54.648588 18260 registrar.cpp:383] Successfully fetched the registry (0B) in 667136ns I0716 04:07:54.648722 18260 registrar.cpp:487] Applied 1 operations in 47668ns; attempting to update the registry I0716 04:07:54.649335 18260 registrar.cpp:544] Successfully updated the registry in 550144ns I0716 04:07:54.649456 18260 registrar.cpp:416] Successfully recovered registrar I0716 04:07:54.649857 18270 master.cpp:1800] Recovered 0 agents from the registry (143B); allowing 10mins for agents to reregister I0716 04:07:54.649888 18282 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover W0716 04:07:54.654981 18259 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:39944 I0716 04:07:54.656158 18259 containerizer.cpp:314] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } W0716 04:07:54.656704 18259 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges W0716 04:07:54.656731 18259 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges W0716 04:07:54.656862 18259 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges I0716 04:07:54.656900 18259 provisioner.cpp:298] Using default backend 'copy' I0716 04:07:54.659060 18259 cluster.cpp:510] Creating default 'local' authorizer I0716 04:07:54.661006 18275 slave.cpp:265] Mesos agent started on (301)@172.17.0.2:39944 I0716 04:07:54.661031 18275 slave.cpp:266] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/rX5QxR/2DI054/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --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/rX5QxR/2DI054/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --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/rX5QxR/2DI054/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/rX5QxR/2DI054/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/rX5QxR/2DI054/frameworks" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/rX5QxR/2DI054/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.9.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="15 0" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --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="/tmp/MasterTest_MaxCompletedFrameworksFlag_ifHWz0" --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/MasterTest_MaxCompletedFrameworksFlag_iHsT3V" --zk_session_timeout="10secs" I0716 04:07:54.661434 18275 credentials.hpp:86] Loading credential for authentication from '/tmp/rX5QxR/2DI054/credential' W0716 04:07:54.661448 18259 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:39944 I0716 04:07:54.661624 18275 slave.cpp:298] Agent using credential for: test-principal I0716 04:07:54.661650 18275 credentials.hpp:37] Loading credentials for authentication from '/tmp/rX5QxR/2DI054/http_credentials' I0716 04:07:54.661851 18275 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0716 04:07:54.662169 18275 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module I0716 04:07:54.662501 18259 sched.cpp:239] Version: 1.9.0 I0716 04:07:54.663209 18266 sched.cpp:343] New master detected at master@172.17.0.2:39944 I0716 04:07:54.663307 18266 sched.cpp:408] Authenticating with master master@172.17.0.2:39944 I0716 04:07:54.663326 18266 sched.cpp:415] Using default CRAM-MD5 authenticatee I0716 04:07:54.663470 18275 slave.cpp:613] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] I0716 04:07:54.663661 18263 authenticatee.cpp:121] Creating new client SASL connection I0716 04:07:54.663666 18275 slave.cpp:621] Agent attributes: [ ] I0716 04:07:54.663702 18275 slave.cpp:630] Agent hostname: 653753ac5284 I0716 04:07:54.663897 18261 task_status_update_manager.cpp:181] Pausing sending task status updates I0716 04:07:54.664001 18273 status_update_manager_process.hpp:379] Pausing operation status update manager I0716 04:07:54.664160 18265 master.cpp:10481] Authenticating scheduler-7b6810ec-81fc-40d7-9a50-6f1d28ef9e96@172.17.0.2:39944 I0716 04:07:54.664319 18262 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(617)@172.17.0.2:39944 I0716 04:07:54.664582 18282 authenticator.cpp:98] Creating new server SASL connection I0716 04:07:54.664817 18276 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0716 04:07:54.664849 18276 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0716 04:07:54.665014 18279 authenticator.cpp:204] Received SASL authentication start I0716 04:07:54.665086 18279 authenticator.cpp:326] Authentication requires more steps I0716 04:07:54.665251 18264 authenticatee.cpp:259] Received SASL authentication step I0716 04:07:54.665282 18268 state.cpp:67] Recovering state from '/tmp/MasterTest_MaxCompletedFrameworksFlag_iHsT3V/meta' I0716 04:07:54.665381 18272 authenticator.cpp:232] Received SASL authentication step I0716 04:07:54.665413 18272 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0716 04:07:54.665429 18272 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0716 04:07:54.665472 18272 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0716 04:07:54.665491 18272 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0716 04:07:54.665503 18272 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.665513 18272 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.665526 18272 authenticator.cpp:318] Authentication success I0716 04:07:54.665572 18277 slave.cpp:7429] Finished recovering checkpointed state from '/tmp/MasterTest_MaxCompletedFrameworksFlag_iHsT3V/meta', beginning agent recovery I0716 04:07:54.665640 18280 authenticatee.cpp:299] Authentication success I0716 04:07:54.665737 18281 master.cpp:10513] Successfully authenticated principal 'test-principal' at scheduler-7b6810ec-81fc-40d7-9a50-6f1d28ef9e96@172.17.0.2:39944 I0716 04:07:54.665799 18271 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(617)@172.17.0.2:39944 I0716 04:07:54.666047 18283 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:39944 I0716 04:07:54.666074 18283 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:39944 I0716 04:07:54.666160 18271 task_status_update_manager.cpp:207] Recovering task status update manager I0716 04:07:54.666241 18283 sched.cpp:870] Will retry registration in 1.826342039secs if necessary I0716 04:07:54.666416 18277 master.cpp:2891] Received SUBSCRIBE call for framework 'default' at scheduler-7b6810ec-81fc-40d7-9a50-6f1d28ef9e96@172.17.0.2:39944 I0716 04:07:54.666450 18277 master.cpp:2223] Authorizing framework principal 'test-principal' to receive offers for roles '{ foo }' I0716 04:07:54.666537 18269 containerizer.cpp:796] Recovering Mesos containers I0716 04:07:54.666889 18269 containerizer.cpp:1122] Recovering isolators I0716 04:07:54.667068 18279 master.cpp:2978] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] I0716 04:07:54.667471 18280 containerizer.cpp:1161] Recovering provisioner I0716 04:07:54.668196 18261 provisioner.cpp:498] Provisioner recovery complete I0716 04:07:54.668885 18262 composing.cpp:339] Finished recovering all containerizers I0716 04:07:54.669129 18279 master.cpp:10711] Adding framework 402e1a8a-949b-478b-930a-bdd318de7458-0000 (default) at scheduler-7b6810ec-81fc-40d7-9a50-6f1d28ef9e96@172.17.0.2:39944 with roles { } suppressed I0716 04:07:54.669173 18276 slave.cpp:7893] Recovering executors I0716 04:07:54.669289 18276 slave.cpp:8046] Finished recovery I0716 04:07:54.669587 18268 sched.cpp:751] Framework registered with 402e1a8a-949b-478b-930a-bdd318de7458-0000 I0716 04:07:54.669675 18268 sched.cpp:770] Scheduler::registered took 61950ns I0716 04:07:54.669915 18270 hierarchical.cpp:368] Added framework 402e1a8a-949b-478b-930a-bdd318de7458-0000 I0716 04:07:54.670172 18263 task_status_update_manager.cpp:181] Pausing sending task status updates I0716 04:07:54.670198 18276 slave.cpp:1340] New master detected at master@172.17.0.2:39944 I0716 04:07:54.670207 18278 status_update_manager_process.hpp:379] Pausing operation status update manager I0716 04:07:54.670226 18270 hierarchical.cpp:1508] Performed allocation for 0 agents in 123540ns I0716 04:07:54.670372 18276 slave.cpp:1405] Detecting new master I0716 04:07:54.670567 18259 sched.cpp:2166] Asked to stop the driver I0716 04:07:54.670676 18261 sched.cpp:1204] Stopping framework 402e1a8a-949b-478b-930a-bdd318de7458-0000 I0716 04:07:54.670895 18273 master.cpp:11068] Processing TEARDOWN call for framework 402e1a8a-949b-478b-930a-bdd318de7458-0000 (default) at scheduler-7b6810ec-81fc-40d7-9a50-6f1d28ef9e96@172.17.0.2:39944 I0716 04:07:54.670925 18273 master.cpp:11080] Removing framework 402e1a8a-949b-478b-930a-bdd318de7458-0000 (default) at scheduler-7b6810ec-81fc-40d7-9a50-6f1d28ef9e96@172.17.0.2:39944 I0716 04:07:54.670940 18273 master.cpp:3343] Deactivating framework 402e1a8a-949b-478b-930a-bdd318de7458-0000 (default) at scheduler-7b6810ec-81fc-40d7-9a50-6f1d28ef9e96@172.17.0.2:39944 I0716 04:07:54.671061 18283 hierarchical.cpp:475] Deactivated framework 402e1a8a-949b-478b-930a-bdd318de7458-0000 I0716 04:07:54.671283 18274 hierarchical.cpp:1432] Allocation paused I0716 04:07:54.671737 18274 hierarchical.cpp:417] Removed framework 402e1a8a-949b-478b-930a-bdd318de7458-0000 I0716 04:07:54.671800 18274 hierarchical.cpp:1442] Allocation resumed W0716 04:07:54.671921 18259 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:39944 I0716 04:07:54.672850 18259 sched.cpp:239] Version: 1.9.0 I0716 04:07:54.673385 18267 sched.cpp:343] New master detected at master@172.17.0.2:39944 I0716 04:07:54.673478 18267 sched.cpp:408] Authenticating with master master@172.17.0.2:39944 I0716 04:07:54.673496 18267 sched.cpp:415] Using default CRAM-MD5 authenticatee I0716 04:07:54.673740 18269 authenticatee.cpp:121] Creating new client SASL connection I0716 04:07:54.674003 18270 master.cpp:10481] Authenticating scheduler-cd72adcf-12da-44ad-a0cb-b96d22e72900@172.17.0.2:39944 I0716 04:07:54.674119 18276 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(618)@172.17.0.2:39944 I0716 04:07:54.674342 18266 authenticator.cpp:98] Creating new server SASL connection I0716 04:07:54.674558 18281 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0716 04:07:54.674589 18281 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0716 04:07:54.674688 18260 authenticator.cpp:204] Received SASL authentication start I0716 04:07:54.674743 18260 authenticator.cpp:326] Authentication requires more steps I0716 04:07:54.674861 18261 authenticatee.cpp:259] Received SASL authentication step I0716 04:07:54.674995 18271 authenticator.cpp:232] Received SASL authentication step I0716 04:07:54.675034 18271 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0716 04:07:54.675052 18271 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0716 04:07:54.675096 18271 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0716 04:07:54.675119 18271 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '653753ac5284' server FQDN: '653753ac5284' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0716 04:07:54.675137 18271 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.675146 18271 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0716 04:07:54.675163 18271 authenticator.cpp:318] Authentication success I0716 04:07:54.675242 18282 authenticatee.cpp:299] Authentication success I0716 04:07:54.675336 18283 master.cpp:10513] Successfully authenticated principal 'test-principal' at scheduler-cd72adcf-12da-44ad-a0cb-b96d22e72900@172.17.0.2:39944 I0716 04:07:54.675361 18277 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(618)@172.17.0.2:39944 I0716 04:07:54.675597 18262 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:39944 I0716 04:07:54.675621 18262 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:39944 I0716 04:07:54.675745 18262 sched.cpp:870] Will retry registration in 1.313337177secs if necessary I0716 04:07:54.675887 18268 master.cpp:2891] Received SUBSCRIBE call for framework 'default' at scheduler-cd72adcf-12da-44ad-a0cb-b96d22e72900@172.17.0.2:39944 I0716 04:07:54.675920 18268 master.cpp:2223] Authorizing framework principal 'test-principal' to receive offers for roles '{ foo }' I0716 04:07:54.676367 18264 master.cpp:2978] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] I0716 04:07:54.678186 18264 master.cpp:10711] Adding framework 402e1a8a-949b-478b-930a-bdd318de7458-0001 (default) at scheduler-cd72adcf-12da-44ad-a0cb-b96d22e72900@172.17.0.2:39944 with roles { } suppressed I0716 04:07:54.678575 18263 sched.cpp:751] Framework registered with 402e1a8a-949b-478b-930a-bdd318de7458-0001 I0716 04:07:54.678648 18263 sched.cpp:770] Scheduler::registered took 49031ns I0716 04:07:54.678746 18280 hierarchical.cpp:368] Added framework 402e1a8a-949b-478b-930a-bdd318de7458-0001 I0716 04:07:54.678953 18259 sched.cpp:2166] Asked to stop the driver I0716 04:07:54.678989 18280 hierarchical.cpp:1508] Performed allocation for 0 agents in 83596ns I0716 04:07:54.679049 18270 sched.cpp:1204] Stopping framework 402e1a8a-949b-478b-930a-bdd318de7458-0001 I0716 04:07:54.679273 18276 master.cpp:11068] Processing TEARDOWN call for framework 402e1a8a-949b-478b-930a-bdd318de7458-0001 (default) at scheduler-cd72adcf-12da-44ad-a0cb-b96d22e72900@172.17.0.2:39944 I0716 04:07:54.679311 18276 master.cpp:11080] Removing framework 402e1a8a-949b-478b-930a-bdd318de7458-0001 (default) at scheduler-cd72adcf-12da-44ad-a0cb-b96d22e72900@172.17.0.2:39944 I0716 04:07:54.679339 18276 master.cpp:3343] Deactivating framework 402e1a8a-949b-478b-930a-bdd318de7458-0001 (default) at scheduler-cd72adcf-12da-44ad-a0cb-b96d22e72900@172.17.0.2:39944 I0716 04:07:54.679450 18260 hierarchical.cpp:475] Deactivated framework 402e1a8a-949b-478b-930a-bdd318de7458-0001 I0716 04:07:54.679746 18273 hierarchical.cpp:1432] Allocation paused I0716 04:07:54.679986 18273 hierarchical.cpp:417] Removed framework 402e1a8a-949b-478b-930a-bdd318de7458-0001 I0716 04:07:54.680052 18273 hierarchical.cpp:1442] Allocation resumed I0716 04:07:54.680135 18271 slave.cpp:1432] Authenticating with master master@172.17.0.2:39944 I0716 04:07:54.680213 18271 slave.cpp:1441] Using default CRAM-MD5 authenticatee I0716 04:07:54.680588 18283 authenticatee.cpp:121] Creating new client SASL connection *** Aborted at 1563250074 (unix time) try "date -d @1563250074" if you are using GNU date *** PC: @ 0x560b2974683a boost::hash_combine<>() *** SIGSEGV (@0x2b71e8092000) received by PID 18259 (TID 0x2b71d28c3700) from PID 18446744073307496448; stack trace: *** @ 0x2b7235d808f7 (unknown) @ 0x2b7235d85249 JVM_handle_linux_signal @ 0x2b71c79c6330 (unknown) @ 0x560b2974683a boost::hash_combine<>() @ 0x560b29710f2a boost::hash_range<>() @ 0x560b296e8f66 boost::hash_value<>() @ 0x560b296c930a boost::hash<>::operator()() @ 0x560b296e92af boost::hash_combine<>() @ 0x560b2a00045e std::hash<>::operator()() @ 0x2b71c16bbc57 std::__detail::_Hash_code_base<>::_M_hash_code() @ 0x2b71c16bbac9 std::_Hashtable<>::count() @ 0x2b71c169269b std::unordered_map<>::count() @ 0x2b71c165f15f hashmap<>::contains() @ 0x2b71c162d272 BoundedHashMap<>::set() @ 0x2b71c15dae26 mesos::internal::master::Master::removeFramework() @ 0x2b71c15d8ed9 mesos::internal::master::Master::teardown() @ 0x2b71c159629a mesos::internal::master::Master::receive() @ 0x2b71c1637e7a ProtobufProcess<>::handlerMutM<>() @ 0x2b71c16d93d7 _ZNSt5_BindIFPFvPN5mesos8internal6master6MasterEMS3_FvRKN7process4UPIDEONS0_9scheduler4CallEES8_RKSsES4_SD_St12_PlaceholderILi1EESI_ILi2EEEE6__callIvIS8_SF_EILm0ELm1ELm2ELm3EEEET_OSt5tupleIIDpT0_EESt12_Index_tupleIIXspT1_EEE @ 0x2b71c16c343c std::_Bind<>::operator()<>() @ 0x2b71c169cb17 std::_Function_handler<>::_M_invoke() @ 0x560b2a208f79 std::function<>::operator()() @ 0x2b71c1619937 ProtobufProcess<>::consume() I0716 04:07:55.646657 18270 hierarchical.cpp:1508] Performed allocation for 0 agents in 140876ns @ 0x2b71c158ff5f mesos::internal::master::Master::_consume() @ 0x2b71c158f639 mesos::internal::master::Master::consume() @ 0x2b71c1602502 _ZNO7process12MessageEvent7consumeEPNS_13EventConsumerE @ 0x560b29499e18 process::ProcessBase::serve() @ 0x2b71c3ba919d process::ProcessManager::resume() @ 0x2b71c3ba54ea _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv @ 0x2b71c3bcccea _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE @ 0x2b71c3bcbf5b _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv @ 0x2b71c3bcb05e _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv make[4]: *** [check-local] Segmentation fault (core dumped) make[4]: Leaving directory `/mesos/mesos-1.9.0/_build/src' make[3]: *** [check-am] Error 2 make[3]: Leaving directory `/mesos/mesos-1.9.0/_build/src' make[2]: *** [check] Error 2 make[2]: Leaving directory `/mesos/mesos-1.9.0/_build/src' make[1]: *** [check-recursive] Error 1 make[1]: Leaving directory `/mesos/mesos-1.9.0/_build' make: *** [distcheck] Error 1 + docker rmi --force mesos-1563245121-20265 Untagged: mesos-1563245121-20265:latest Deleted: sha256:8011e89e4fd403467c74518822814e78ecaee69e41013ae264e2923e7bf8ef2b Deleted: sha256:8d00265870aea1077d224faf7f8e631fc485c888ed591e0412dd88aa8b8f1456 Deleted: sha256:d25de26a84c8c48593338cbc27e1b381db64d9439ee15b97ee24bef001868bb9 Deleted: sha256:15a5c8a4702ae452957451f917b5cf33ea86637c0055fb6264a78d9d998e7acb Deleted: sha256:a3a097e7ada0026f07ca1c723aab292a6caad0929d5e2aaaf478ec4a429f3c77 Deleted: sha256:c0a8b81c5827b107f12531f8376f05d180c86ac162531032bd6fff6a265760c2 Deleted: sha256:92c9b0836e0507b716f889a6b98c0405c5a4cffdaae4905089d0ffc87ef17ce8 Deleted: sha256:06e7cecf9393f093973b608db40460f1d4040db67563438e0751f206b017088c Deleted: sha256:878ecd9100dc79e32754cfdc887653ad860b1cfe194162cbf9e1bcc33d1d2a19 Deleted: sha256:f5f3567454d83040140e0677f1523d2afd09488c69663e9629c2a30a52ef57c2 Deleted: sha256:4e3fd224ba1cda847eb47d95d244310449ea71565fd4fc34e00774064f9d4076 Deleted: sha256:92d859da75c64c53c4d0392db066301c2b8f4c171533e146d73642d5741d3e14 Deleted: sha256:4a7c05de5dcd6cf36ce0cea02c5bbb0b71c293ae7fab1d1977abf5568260b642 Deleted: sha256:4e302345e14af11f57c13a34f08c1b4c90096f981fb9ad75340e0b6ebd516fbe Deleted: sha256:48e0755132c80da363cd9132675ddf53879e3ee3822a5f42ab6845622a76a8b9 Deleted: sha256:a523a7dd86e5a6bd8c7d1a10e15039fe8f34159efb4d4bed38528c2990b4bca6 Deleted: sha256:35ae7b390f49f69a04a253732aea5a5268f15d970e24660bf72a515ae090b146 Deleted: sha256:5799d7990618cb68abd5befaea7a181dd5eaa29dc34a4d7dcb0cdfe20ebc6f82 Deleted: sha256:bef62635b6ae4f1fc3b4477dc0415f08cb99c6162aa4c33394b0afb8ff1cf465 Deleted: sha256:6fea5d5370f2f8cbbf815a67d8dba9c757f76ca05ec10d7c51f47c477aff3134 Deleted: sha256:64a34a50f3c853e7fe8292484b3f492825ecc07f1463aa09c769064cc4f62986 Deleted: sha256:03a1e78f320af243c16831ee88de9672f48926d67d373e6f5d1f235165716b77 Deleted: sha256:4bed3177fab934c044386e4378c5ff5ab03d4b0c58479d5066283bb0017e687c Deleted: sha256:5bbcfb15d40ad532033121e054cd5819d9ec354b326c3cf4a53a2c9f06fa4912 Deleted: sha256:17e4b9c6d24a95a5b2136fb89a997eaa29ddf4a09e0f38a68bdf2988b84d1487 Deleted: sha256:245f0f5c60836061d666993d6ec60a7d5c10e7ea6ed08e6c693dbdcdef0674d8 Deleted: sha256:77227c47d164d9158884f80e6b077d7b02e4fa3ba85871ddae78aff99caf3f40 Deleted: sha256:5bf91a73ba79e0d000dd148dcd675ae7f983382cb1a33e7c37e7e1f08d0af80e Deleted: sha256:9292c1551669b6e0b3c8fce3d75559261b9f786c97d2795a9ed37a57e7a307e7 Deleted: sha256:afe87c18faf989026ec4a8e24f2c35dd5a11dc1e9660f50760bf5ad56e40b4cd Full log: https://builds.apache.org/job/Mesos-Reviewbot-Linux/2579/console - Mesos Reviewbot On July 15, 2019, 11:46 p.m., Xudong Ni wrote: > > ----------------------------------------------------------- > This is an automatically generated e-mail. To reply, visit: > https://reviews.apache.org/r/71080/ > ----------------------------------------------------------- > > (Updated July 15, 2019, 11:46 p.m.) > > > Review request for mesos, James Peach and Jiang Yan Xu. > > > Bugs: MESOS-8636 > https://issues.apache.org/jira/browse/MESOS-8636 > > > Repository: mesos > > > Description > ------- > > It should be separately from that for webUI and endpoints. > Currently the master stores the history of completed frameworks in > a map with the full historical data of the framework, it is > prohibitively expensive to keep a long history; In order to reject > frameworks from reregistering if they have previously marked as > completed, we only need to persist the framework ids and are able > to keep long history. > > > Diffs > ----- > > docs/configuration/master.md c56ac8510ea968f9587e23e81ed310caa968ee9e > docs/operator-http-api.md 2d4a9b66e20cf19eceec718b7de3d812ab285772 > include/mesos/allocator/allocator.hpp > 2bab53ab5fb25931a724c20a039e1301983ba574 > src/master/flags.hpp 78623d68bf428cd3f52684303d98a525d42eb878 > src/master/flags.cpp 74f4daadd48e8e691be43759b88dc8b3c2df489a > src/master/http.cpp cd0f40cb7b966d6620e3fb49d4c08807185c9101 > src/master/master.hpp e8def83fe9bcee19772df9a9764852bc694c5247 > src/master/master.cpp 5247377c2e7e92b9843dd4c9d28f92ba679ad742 > > > Diff: https://reviews.apache.org/r/71080/diff/1/ > > > Testing > ------- > > make check > > > Thanks, > > Xudong Ni > >