[prev in list] [next in list] [prev in thread] [next in thread]
List: mesos-issues
Subject: [jira] [Created] (MESOS-10102) MasterAPITest.ReservationUpdate is flaky
From: "Andrei Sekretenko (Jira)" <jira () apache ! org>
Date: 2020-03-06 18:21:00
Message-ID: JIRA.13290155.1583518813000.20324.1583518860343 () Atlassian ! JIRA
[Download RAW message or body]
Andrei Sekretenko created MESOS-10102:
-----------------------------------------
Summary: MasterAPITest.ReservationUpdate is flaky
Key: MESOS-10102
URL: https://issues.apache.org/jira/browse/MESOS-10102
Project: Mesos
Issue Type: Bug
Affects Versions: 1.10.0
Reporter: Andrei Sekretenko
There seems to be two kinds of flakes:
{code}
[ RUN ] ContentType/MasterAPITest.ReservationUpdate/0
I0306 13:09:52.496989 3096 cluster.cpp:186] Creating default 'local' authorizer
I0306 13:09:52.498562 3112 master.cpp:443] Master \
6ca18692-2b4b-4219-8e2f-78bdf56dc5d8 (core1.hw.ca1.mesosphere.com) started on \
66.70.182.167:35079 I0306 13:09:52.498643 3112 master.cpp:446] Flags at startup: \
--acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" \
--allocation_interval="1000secs" --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/VOU6Oj/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_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="/usr/local/share/mesos/webui" \
--work_dir="/tmp/VOU6Oj/master" --zk_session_timeout="10secs" I0306 13:09:52.498890 \
3112 master.cpp:495] Master only allowing authenticated frameworks to register I0306 \
13:09:52.498986 3112 master.cpp:501] Master only allowing authenticated agents to \
register I0306 13:09:52.499089 3112 master.cpp:507] Master only allowing \
authenticated HTTP frameworks to register I0306 13:09:52.499109 3112 \
credentials.hpp:37] Loading credentials for authentication from \
'/tmp/VOU6Oj/credentials' I0306 13:09:52.499182 3112 master.cpp:551] Using default \
'crammd5' authenticator I0306 13:09:52.499311 3112 http.cpp:1265] Creating default \
'basic' HTTP authenticator for realm 'mesos-master-readonly' I0306 13:09:52.499446 \
3112 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm \
'mesos-master-readwrite' I0306 13:09:52.499575 3112 http.cpp:1265] Creating default \
'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0306 13:09:52.499667 \
3112 master.cpp:632] Authorization enabled I0306 13:09:52.500351 3112 \
hierarchical.cpp:567] Initialized hierarchical allocator process I0306 \
13:09:52.500371 3153 whitelist_watcher.cpp:77] No whitelist given I0306 \
13:09:52.500718 3149 master.cpp:2165] Elected as the leading master! I0306 \
13:09:52.500874 3149 master.cpp:1661] Recovering from registrar I0306 \
13:09:52.500926 3149 registrar.cpp:339] Recovering registrar I0306 13:09:52.501082 \
3149 registrar.cpp:383] Successfully fetched the registry (0B) in 117248ns I0306 \
13:09:52.501142 3149 registrar.cpp:487] Applied 1 operations in 14299ns; attempting \
to update the registry I0306 13:09:52.501288 3142 registrar.cpp:544] Successfully \
updated the registry in 127744ns I0306 13:09:52.501333 3142 registrar.cpp:416] \
Successfully recovered registrar I0306 13:09:52.501436 3142 master.cpp:1814] \
Recovered 0 agents from the registry (181B); allowing 10mins for agents to reregister \
I0306 13:09:52.501466 3148 hierarchical.cpp:606] Skipping recovery of hierarchical \
allocator: nothing to recover W0306 13:09:52.503216 3096 process.cpp:2877] Attempted \
to spawn already running process files@66.70.182.167:35079 I0306 13:09:52.503903 \
3096 containerizer.cpp:317] Using isolation { environment_secret, filesystem/posix, \
network/cni, posix/cpu, posix/mem } I0306 13:09:52.508648 3096 \
linux_launcher.cpp:144] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the \
Linux launcher I0306 13:09:52.509362 3096 provisioner.cpp:277] Provisioner backend \
'overlay' is not supported on \
'/tmp/ContentType_MasterAPITest_ReservationUpdate_0_gt8tzQ/provisioner': Backend \
'overlay' is not supported due to missing d_type support on the underlying filesystem \
I0306 13:09:52.509479 3096 provisioner.cpp:294] Using default backend 'copy' I0306 \
13:09:52.510510 3096 cluster.cpp:533] Creating default 'local' authorizer I0306 \
13:09:52.511289 3151 slave.cpp:274] Mesos agent started on \
(3249)@66.70.182.167:35079 I0306 13:09:52.511371 3151 slave.cpp:275] Flags at \
startup: --acls="" --appc_simple_discovery_uri_prefix="http://" \
--appc_store_dir="/tmp/VOU6Oj/qxKg4T/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/VOU6Oj/qxKg4T/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/VOU6Oj/qxKg4T/store/docker" \
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" \
--docker_volume_chown="false" --enforce_container_disk_quota="false" \
--executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" \
--executor_shutdown_grace_period="5secs" \
--fetcher_cache_dir="/tmp/VOU6Oj/qxKg4T/fetch" --fetcher_cache_size="2GB" \
--fetcher_stall_timeout="1mins" --frameworks_home="/tmp/VOU6Oj/qxKg4T/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/VOU6Oj/qxKg4T/http_credentials" \
--http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" \
--initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" \
--launcher="linux" --launcher_dir="/home/asekretenko/b/mesos_cmake/src" \
--logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" \
--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/ContentType_MasterAPITest_ReservationUpdate_0_Q9aSjn" \
--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/ContentType_MasterAPITest_ReservationUpdate_0_gt8tzQ" \
--zk_session_timeout="10secs" I0306 13:09:52.511754 3151 credentials.hpp:86] Loading \
credential for authentication from '/tmp/VOU6Oj/qxKg4T/credential' I0306 \
13:09:52.511914 3151 slave.cpp:307] Agent using credential for: test-principal I0306 \
13:09:52.512038 3151 credentials.hpp:37] Loading credentials for authentication from \
'/tmp/VOU6Oj/qxKg4T/http_credentials' I0306 13:09:52.512202 3151 http.cpp:1265] \
Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0306 \
13:09:52.512348 3151 disk_profile_adaptor.cpp:78] Creating default disk profile \
adaptor module I0306 13:09:52.512687 3151 slave.cpp:622] 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"}] \
I0306 13:09:52.512864 3151 slave.cpp:630] Agent attributes: [ ] I0306 \
13:09:52.512979 3151 slave.cpp:639] Agent hostname: core1.hw.ca1.mesosphere.com \
I0306 13:09:52.513382 3151 task_status_update_manager.cpp:181] Pausing sending task \
status updates I0306 13:09:52.513412 3104 status_update_manager_process.hpp:379] \
Pausing operation status update manager I0306 13:09:52.513572 3150 state.cpp:68] \
Recovering state from \
'/tmp/ContentType_MasterAPITest_ReservationUpdate_0_gt8tzQ/meta' I0306 \
13:09:52.513773 3150 slave.cpp:7606] Finished recovering checkpointed state from \
'/tmp/ContentType_MasterAPITest_ReservationUpdate_0_gt8tzQ/meta', beginning agent \
recovery I0306 13:09:52.513873 3150 task_status_update_manager.cpp:207] Recovering \
task status update manager I0306 13:09:52.513978 3150 containerizer.cpp:820] \
Recovering Mesos containers I0306 13:09:52.514060 3150 linux_launcher.cpp:286] \
Recovering Linux launcher I0306 13:09:52.514261 3150 containerizer.cpp:1160] \
Recovering isolators I0306 13:09:52.514606 3165 containerizer.cpp:1199] Recovering \
provisioner I0306 13:09:52.514755 3165 provisioner.cpp:518] Provisioner recovery \
complete I0306 13:09:52.514951 3165 composing.cpp:339] Finished recovering all \
containerizers I0306 13:09:52.515048 3165 slave.cpp:8088] Recovering executors
I0306 13:09:52.515100 3165 slave.cpp:8241] Finished recovery
I0306 13:09:52.515558 3165 slave.cpp:1454] New master detected at \
master@66.70.182.167:35079 I0306 13:09:52.515693 3165 slave.cpp:1519] Detecting new \
master I0306 13:09:52.515602 3128 status_update_manager_process.hpp:379] Pausing \
operation status update manager I0306 13:09:52.515588 3129 \
task_status_update_manager.cpp:181] Pausing sending task status updates I0306 \
13:09:52.537189 3132 slave.cpp:1546] Authenticating with master \
master@66.70.182.167:35079 I0306 13:09:52.537283 3132 slave.cpp:1555] Using default \
CRAM-MD5 authenticatee I0306 13:09:52.537426 3132 authenticatee.cpp:121] Creating \
new client SASL connection I0306 13:09:52.537626 3132 master.cpp:9676] \
Authenticating slave(3249)@66.70.182.167:35079 I0306 13:09:52.537786 3132 \
authenticator.cpp:414] Starting authentication session for \
crammd5-authenticatee(3249)@66.70.182.167:35079 I0306 13:09:52.537964 3132 \
authenticator.cpp:98] Creating new server SASL connection I0306 13:09:52.538143 3132 \
authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0306 \
13:09:52.538264 3132 authenticatee.cpp:239] Attempting to authenticate with \
mechanism 'CRAM-MD5' I0306 13:09:52.538404 3132 authenticator.cpp:204] Received SASL \
authentication start I0306 13:09:52.538553 3132 authenticator.cpp:326] \
Authentication requires more steps I0306 13:09:52.538658 3132 authenticatee.cpp:259] \
Received SASL authentication step I0306 13:09:52.538777 3132 authenticator.cpp:232] \
Received SASL authentication step I0306 13:09:52.538908 3132 auxprop.cpp:109] \
Request to lookup properties for user: 'test-principal' realm: \
'core1.hw.ca1.mesosphere.com' server FQDN: 'core1.hw.ca1.mesosphere.com' \
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false \
SASL_AUXPROP_AUTHZID: false I0306 13:09:52.538987 3132 auxprop.cpp:181] Looking up \
auxiliary property '*userPassword' I0306 13:09:52.539018 3132 auxprop.cpp:181] \
Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0306 13:09:52.539093 3132 \
auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: \
'core1.hw.ca1.mesosphere.com' server FQDN: 'core1.hw.ca1.mesosphere.com' \
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false \
SASL_AUXPROP_AUTHZID: true I0306 13:09:52.539166 3132 auxprop.cpp:131] Skipping \
auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0306 \
13:09:52.539186 3132 auxprop.cpp:131] Skipping auxiliary property \
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0306 13:09:52.539206 \
3132 authenticator.cpp:318] Authentication success I0306 13:09:52.539314 3132 \
authenticatee.cpp:299] Authentication success I0306 13:09:52.539345 3103 \
master.cpp:9708] Successfully authenticated principal 'test-principal' at \
slave(3249)@66.70.182.167:35079 I0306 13:09:52.539366 3131 authenticator.cpp:432] \
Authentication session cleanup for crammd5-authenticatee(3249)@66.70.182.167:35079 \
I0306 13:09:52.539508 3125 slave.cpp:1646] Successfully authenticated with master \
master@66.70.182.167:35079 I0306 13:09:52.539616 3125 slave.cpp:2096] Will retry \
registration in 6.629717ms if necessary I0306 13:09:52.539661 3159 master.cpp:6174] \
Received register agent message from slave(3249)@66.70.182.167:35079 \
(core1.hw.ca1.mesosphere.com) I0306 13:09:52.539732 3159 master.cpp:3705] \
Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object \
I0306 13:09:52.539860 3159 master.cpp:6241] Authorized registration of agent at \
slave(3249)@66.70.182.167:35079 (core1.hw.ca1.mesosphere.com) I0306 13:09:52.539891 \
3159 master.cpp:6353] Registering agent at slave(3249)@66.70.182.167:35079 \
(core1.hw.ca1.mesosphere.com) with id 6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0 I0306 \
13:09:52.540021 3159 registrar.cpp:487] Applied 1 operations in 51485ns; attempting \
to update the registry I0306 13:09:52.540145 3159 registrar.cpp:544] Successfully \
updated the registry in 106240ns I0306 13:09:52.540196 3159 master.cpp:6401] \
Admitted agent 6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0 at \
slave(3249)@66.70.182.167:35079 (core1.hw.ca1.mesosphere.com) I0306 13:09:52.540336 \
3159 master.cpp:6446] Registered agent 6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0 at \
slave(3249)@66.70.182.167:35079 (core1.hw.ca1.mesosphere.com) with cpus:2; mem:1024; \
disk:1024; ports:[31000-32000] I0306 13:09:52.540423 3159 hierarchical.cpp:959] \
Added agent 6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0 (core1.hw.ca1.mesosphere.com) \
with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {}) \
I0306 13:09:52.540477 3159 hierarchical.cpp:1853] Performed allocation for 1 agents \
in 17277ns I0306 13:09:52.540519 3159 slave.cpp:1679] Registered with master \
master@66.70.182.167:35079; given agent ID 6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0 \
I0306 13:09:52.540838 3159 slave.cpp:1714] Checkpointing SlaveInfo to \
'/tmp/ContentType_MasterAPITest_ReservationUpdate_0_gt8tzQ/meta/slaves/6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0/slave.info'
I0306 13:09:52.541118 3140 task_status_update_manager.cpp:188] Resuming sending \
task status updates I0306 13:09:52.541126 3159 slave.cpp:1766] Forwarding agent \
update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"wu2u \
Rb4sS++ThCnAQ5fKUg=="},"slave_id":{"value":"6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0"},"update_oversubscribed_resources":false}
I0306 13:09:52.541409 3159 master.cpp:7584] Ignoring update on agent \
6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0 at slave(3249)@66.70.182.167:35079 \
(core1.hw.ca1.mesosphere.com) as it reports no changes I0306 13:09:52.541151 3150 \
status_update_manager_process.hpp:385] Resuming operation status update manager I0306 \
13:09:52.542691 3163 process.cpp:3671] Handling HTTP event for process 'master' with \
path: '/master/api/v1' I0306 13:09:52.542994 3163 http.cpp:1405] HTTP POST for \
/master/api/v1 from 66.70.182.167:37076 I0306 13:09:52.543073 3163 http.cpp:277] \
Processing call RESERVE_RESOURCES I0306 13:09:52.543253 3163 master.cpp:3705] \
Authorizing principal 'test-principal' to perform action UNRESERVE_RESOURCES on \
object {"value":"test-principal","resource":{"name":"cpus","type":"SCALAR","scalar":{" \
value":1.0},"reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/bar","principal":"test-principal"}]}}
I0306 13:09:52.543299 3163 master.cpp:3705] Authorizing principal 'test-principal' \
to perform action UNRESERVE_RESOURCES on object \
{"value":"test-principal","resource":{"name":"mem","type":"SCALAR","scalar":{"value":1 \
0.0},"reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/bar","principal":"test-principal"}]}}
I0306 13:09:52.543326 3163 master.cpp:3705] Authorizing principal 'test-principal' \
to perform action RESERVE_RESOURCES on object \
{"value":"role/foo","resource":{"name":"cpus","type":"SCALAR","scalar":{"value":1.0}," \
reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/foo","principal":"test-principal"}]}}
I0306 13:09:52.543602 3163 hierarchical.cpp:1346] Failed to update available \
resources on agent 6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0: cpus:2; mem:1024; \
disk:1024; ports:[31000-32000] does not contain cpus(reservations: \
[(DYNAMIC,role,test-principal),(DYNAMIC,role/bar,test-principal)]):1; \
mem(reservations: [(DYNAMIC,role,test-principal),(DYNAMIC,role/bar,test-principal)]):10
I0306 13:09:52.545033 3145 process.cpp:3671] Handling HTTP event for process \
'master' with path: '/master/api/v1' I0306 13:09:52.545262 3145 http.cpp:1405] HTTP \
POST for /master/api/v1 from 66.70.182.167:37078 I0306 13:09:52.545316 3145 \
http.cpp:277] Processing call RESERVE_RESOURCES I0306 13:09:52.545456 3145 \
master.cpp:3705] Authorizing principal 'test-principal' to perform action \
RESERVE_RESOURCES on object \
{"value":"role","resource":{"name":"cpus","type":"SCALAR","scalar":{"value":1.0},"reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"}]}}
I0306 13:09:52.545492 3145 master.cpp:3705] Authorizing principal 'test-principal' \
to perform action RESERVE_RESOURCES on object \
{"value":"role/foo","resource":{"name":"cpus","type":"SCALAR","scalar":{"value":1.0}," \
reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/foo","principal":"test-principal"}]}}
I0306 13:09:52.546684 3105 process.cpp:3671] Handling HTTP event for process \
'slave(3249)' with path: '/slave(3249)/state' I0306 13:09:52.546962 3138 \
http.cpp:1405] HTTP GET for /slave(3249)/state from 66.70.182.167:37080 I0306 \
13:09:52.547515 3138 http.cpp:1422] HTTP GET for /slave(3249)/state from \
66.70.182.167:37080: '200 OK' after 0.907776ms
/home/asekretenko/lsyncd/mesos/src/tests/api_tests.cpp:1541: Failure
Expected: reservations->values.size()
Which is: 0
To be equal to: 1u
Which is: 1
*** Aborted at 1583518192 (unix time) try "date -d @1583518192" if you are using GNU \
date ***
PC: @ 0x0 (unknown)
*** SIGSEGV (@0x0) received by PID 3096 (TID 0x7f8bae146140) from PID 0; stack trace: \
*** @ 0x7f8ba9a83fb0 (unknown)
I0306 13:09:52.555222 3108 master.cpp:11649] Sending operation '' (uuid: \
3a67d7b4-512a-40b3-aded-79676aa2ec76) to agent \
6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0 at slave(3249)@66.70.182.167:35079 \
(core1.hw.ca1.mesosphere.com) I0306 13:09:52.555321 3108 slave.cpp:4466] Ignoring \
new checkpointed resources and operations identical to the current version I0306 \
13:09:52.555375 3108 slave.cpp:9050] Updating the state of operation with no ID \
(uuid: 3a67d7b4-512a-40b3-aded-79676aa2ec76) for an operation API call (latest state: \
OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0306 13:09:52.555825 \
3108 slave.cpp:4554] Updated checkpointed resources from {} to cpus(reservations: \
[(DYNAMIC,role,test-principal),(DYNAMIC,role/foo,test-principal)]):1; \
mem(reservations: [(DYNAMIC,role,test-principal),(DYNAMIC,role/foo,test-principal)]):10
I0306 13:09:52.555869 3108 slave.cpp:4578] Updated checkpointed operations from [ \
] to [ 3a67d7b4-512a-40b3-aded-79676aa2ec76 (RESERVE, latest state: \
OPERATION_FINISHED) ] I0306 13:09:52.555932 3109 \
status_update_manager_process.hpp:152] Received operation status update \
OPERATION_FINISHED (Status UUID: 240cbed9-0d41-4193-a0b0-b564ab9d4e55) for operation \
UUID 3a67d7b4-512a-40b3-aded-79676aa2ec76 on agent \
6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0 I0306 13:09:52.555951 3109 \
status_update_manager_process.hpp:414] Creating operation status update stream \
3a67d7b4-512a-40b3-aded-79676aa2ec76 checkpoint=true I0306 13:09:52.556180 3109 \
status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status \
update OPERATION_FINISHED (Status UUID: 240cbed9-0d41-4193-a0b0-b564ab9d4e55) for \
operation UUID 3a67d7b4-512a-40b3-aded-79676aa2ec76 on agent \
6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0 @ 0x32eb210 \
testing::UnitTest::AddTestPartResult() @ 0x32eae5d \
testing::internal::AssertHelper::operator=() @ 0xb1f98e \
mesos::internal::tests::MasterAPITest_ReservationUpdate_Test::TestBody()::$_1::operator()()
I0306 13:09:52.572075 3109 status_update_manager_process.hpp:528] Forwarding \
operation status update OPERATION_FINISHED (Status UUID: \
240cbed9-0d41-4193-a0b0-b564ab9d4e55) for operation UUID \
3a67d7b4-512a-40b3-aded-79676aa2ec76 on agent 6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0 \
I0306 13:09:52.572214 3116 slave.cpp:9050] Updating the state of operation with no \
ID (uuid: 3a67d7b4-512a-40b3-aded-79676aa2ec76) for an operation API call (latest \
state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0306 \
13:09:52.572235 3116 slave.cpp:6441] Forwarding status update of operation with no \
ID (operation_uuid: 3a67d7b4-512a-40b3-aded-79676aa2ec76) for an operator API call \
I0306 13:09:52.572284 3116 master.cpp:11301] Updating the state of operation '' \
(uuid: 3a67d7b4-512a-40b3-aded-79676aa2ec76) for an operator API call (latest state: \
OPERATION_PENDING, status update state: OPERATION_FINISHED) I0306 13:09:52.572373 \
3116 status_update_manager_process.hpp:252] Received operation status update \
acknowledgement (UUID: 240cbed9-0d41-4193-a0b0-b564ab9d4e55) for stream \
3a67d7b4-512a-40b3-aded-79676aa2ec76 I0306 13:09:52.572397 3116 \
status_update_manager_process.hpp:929] Checkpointing ACK for operation status update \
OPERATION_FINISHED (Status UUID: 240cbed9-0d41-4193-a0b0-b564ab9d4e55) for operation \
UUID 3a67d7b4-512a-40b3-aded-79676aa2ec76 on agent \
6ca18692-2b4b-4219-8e2f-78bdf56dc5d8-S0 I0306 13:09:52.572896 3116 \
status_update_manager_process.hpp:490] Cleaning up operation status update stream \
3a67d7b4-512a-40b3-aded-79676aa2ec76 I0306 13:09:52.573267 3116 slave.cpp:4578] \
Updated checkpointed operations from [ 3a67d7b4-512a-40b3-aded-79676aa2ec76 (RESERVE, \
latest state: OPERATION_FINISHED) ] to [ ] @ 0xb1c242 \
mesos::internal::tests::MasterAPITest_ReservationUpdate_Test::TestBody() @ \
0x330e494 testing::internal::HandleExceptionsInMethodIfSupported<>() @ \
0x32f4ff1 testing::Test::Run() @ 0x32f5f90 testing::TestInfo::Run()
@ 0x32f6707 testing::TestCase::Run()
@ 0x32fea87 testing::internal::UnitTestImpl::RunAllTests()
@ 0x330ef54 testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x32fe65a testing::UnitTest::Run()
@ 0x7f7224 main
@ 0x7f8ba56d411b __libc_start_main
@ 0x70465a _start
@ 0x0 (unknown)
{noformat}
{noformat}
[ RUN ] ContentType/MasterAPITest.ReservationUpdate/0
I0306 13:14:00.626860 18861 cluster.cpp:186] Creating default 'local' authorizer
I0306 13:14:00.628518 18906 master.cpp:443] Master \
13016c18-4e40-461e-b9b5-43006bae2bf8 (core1.hw.ca1.mesosphere.com) started on \
66.70.182.167:44211 I0306 13:14:00.628603 18906 master.cpp:446] Flags at startup: \
--acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" \
--allocation_interval="1000secs" --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/hL920v/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_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="/usr/local/share/mesos/webui" \
--work_dir="/tmp/hL920v/master" --zk_session_timeout="10secs" I0306 13:14:00.628851 \
18906 master.cpp:495] Master only allowing authenticated frameworks to register I0306 \
13:14:00.628949 18906 master.cpp:501] Master only allowing authenticated agents to \
register I0306 13:14:00.629029 18906 master.cpp:507] Master only allowing \
authenticated HTTP frameworks to register I0306 13:14:00.629091 18906 \
credentials.hpp:37] Loading credentials for authentication from \
'/tmp/hL920v/credentials' I0306 13:14:00.629184 18906 master.cpp:551] Using default \
'crammd5' authenticator I0306 13:14:00.629318 18906 http.cpp:1265] Creating default \
'basic' HTTP authenticator for realm 'mesos-master-readonly' I0306 13:14:00.629472 \
18906 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm \
'mesos-master-readwrite' I0306 13:14:00.629639 18906 http.cpp:1265] Creating default \
'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0306 13:14:00.629781 \
18906 master.cpp:632] Authorization enabled I0306 13:14:00.629961 18887 \
hierarchical.cpp:567] Initialized hierarchical allocator process I0306 \
13:14:00.629983 18930 whitelist_watcher.cpp:77] No whitelist given I0306 \
13:14:00.630923 18906 master.cpp:2165] Elected as the leading master! I0306 \
13:14:00.631055 18906 master.cpp:1661] Recovering from registrar I0306 \
13:14:00.631192 18908 registrar.cpp:339] Recovering registrar I0306 13:14:00.631314 \
18908 registrar.cpp:383] Successfully fetched the registry (0B) in 99072ns I0306 \
13:14:00.631363 18908 registrar.cpp:487] Applied 1 operations in 21429ns; attempting \
to update the registry I0306 13:14:00.631484 18910 registrar.cpp:544] Successfully \
updated the registry in 100096ns I0306 13:14:00.631520 18910 registrar.cpp:416] \
Successfully recovered registrar I0306 13:14:00.631659 18907 hierarchical.cpp:606] \
Skipping recovery of hierarchical allocator: nothing to recover I0306 13:14:00.631660 \
18910 master.cpp:1814] Recovered 0 agents from the registry (181B); allowing 10mins \
for agents to reregister W0306 13:14:00.633738 18861 process.cpp:2877] Attempted to \
spawn already running process files@66.70.182.167:44211 I0306 13:14:00.634596 18861 \
containerizer.cpp:317] Using isolation { environment_secret, filesystem/posix, \
network/cni, posix/cpu, posix/mem } I0306 13:14:00.640466 18861 \
linux_launcher.cpp:144] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the \
Linux launcher I0306 13:14:00.641263 18861 provisioner.cpp:277] Provisioner backend \
'overlay' is not supported on \
'/tmp/ContentType_MasterAPITest_ReservationUpdate_0_nvt6G5/provisioner': Backend \
'overlay' is not supported due to missing d_type support on the underlying filesystem \
I0306 13:14:00.641384 18861 provisioner.cpp:294] Using default backend 'copy' I0306 \
13:14:00.642643 18861 cluster.cpp:533] Creating default 'local' authorizer I0306 \
13:14:00.643729 18902 slave.cpp:274] Mesos agent started on (725)@66.70.182.167:44211 \
I0306 13:14:00.643817 18902 slave.cpp:275] Flags at startup: --acls="" \
--appc_simple_discovery_uri_prefix="http://" \
--appc_store_dir="/tmp/hL920v/Kuof3e/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/hL920v/Kuof3e/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/hL920v/Kuof3e/store/docker" \
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" \
--docker_volume_chown="false" --enforce_container_disk_quota="false" \
--executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" \
--executor_shutdown_grace_period="5secs" \
--fetcher_cache_dir="/tmp/hL920v/Kuof3e/fetch" --fetcher_cache_size="2GB" \
--fetcher_stall_timeout="1mins" --frameworks_home="/tmp/hL920v/Kuof3e/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/hL920v/Kuof3e/http_credentials" \
--http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" \
--initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" \
--launcher="linux" --launcher_dir="/home/asekretenko/b/mesos_cmake/src" \
--logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" \
--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/ContentType_MasterAPITest_ReservationUpdate_0_1DzanF" \
--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/ContentType_MasterAPITest_ReservationUpdate_0_nvt6G5" \
--zk_session_timeout="10secs" I0306 13:14:00.644186 18902 credentials.hpp:86] Loading \
credential for authentication from '/tmp/hL920v/Kuof3e/credential' I0306 \
13:14:00.644345 18902 slave.cpp:307] Agent using credential for: test-principal I0306 \
13:14:00.644450 18902 credentials.hpp:37] Loading credentials for authentication from \
'/tmp/hL920v/Kuof3e/http_credentials' I0306 13:14:00.644613 18902 http.cpp:1265] \
Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0306 \
13:14:00.644784 18902 disk_profile_adaptor.cpp:78] Creating default disk profile \
adaptor module I0306 13:14:00.645176 18902 slave.cpp:622] 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"}] \
I0306 13:14:00.645345 18902 slave.cpp:630] Agent attributes: [ ] I0306 \
13:14:00.645447 18902 slave.cpp:639] Agent hostname: core1.hw.ca1.mesosphere.com \
I0306 13:14:00.645829 18902 task_status_update_manager.cpp:181] Pausing sending task \
status updates I0306 13:14:00.645859 18904 status_update_manager_process.hpp:379] \
Pausing operation status update manager I0306 13:14:00.646015 18883 state.cpp:68] \
Recovering state from \
'/tmp/ContentType_MasterAPITest_ReservationUpdate_0_nvt6G5/meta' I0306 \
13:14:00.646224 18908 slave.cpp:7606] Finished recovering checkpointed state from \
'/tmp/ContentType_MasterAPITest_ReservationUpdate_0_nvt6G5/meta', beginning agent \
recovery I0306 13:14:00.646306 18908 task_status_update_manager.cpp:207] Recovering \
task status update manager I0306 13:14:00.646412 18917 containerizer.cpp:820] \
Recovering Mesos containers I0306 13:14:00.646478 18917 linux_launcher.cpp:286] \
Recovering Linux launcher I0306 13:14:00.646674 18876 containerizer.cpp:1160] \
Recovering isolators I0306 13:14:00.646968 18914 containerizer.cpp:1199] Recovering \
provisioner I0306 13:14:00.647114 18914 provisioner.cpp:518] Provisioner recovery \
complete I0306 13:14:00.647282 18914 composing.cpp:339] Finished recovering all \
containerizers I0306 13:14:00.647363 18914 slave.cpp:8088] Recovering executors
I0306 13:14:00.647413 18914 slave.cpp:8241] Finished recovery
I0306 13:14:00.648025 18914 slave.cpp:1454] New master detected at \
master@66.70.182.167:44211 I0306 13:14:00.648125 18914 slave.cpp:1519] Detecting new \
master I0306 13:14:00.648073 18881 status_update_manager_process.hpp:379] Pausing \
operation status update manager I0306 13:14:00.648057 18928 \
task_status_update_manager.cpp:181] Pausing sending task status updates I0306 \
13:14:00.656507 18920 slave.cpp:1546] Authenticating with master \
master@66.70.182.167:44211 I0306 13:14:00.656548 18920 slave.cpp:1555] Using default \
CRAM-MD5 authenticatee I0306 13:14:00.656635 18920 authenticatee.cpp:121] Creating \
new client SASL connection I0306 13:14:00.656757 18920 master.cpp:9676] \
Authenticating slave(725)@66.70.182.167:44211 I0306 13:14:00.656816 18920 \
authenticator.cpp:414] Starting authentication session for \
crammd5-authenticatee(725)@66.70.182.167:44211 I0306 13:14:00.656884 18920 \
authenticator.cpp:98] Creating new server SASL connection I0306 13:14:00.656949 18920 \
authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0306 \
13:14:00.656972 18920 authenticatee.cpp:239] Attempting to authenticate with \
mechanism 'CRAM-MD5' I0306 13:14:00.657023 18920 authenticator.cpp:204] Received SASL \
authentication start I0306 13:14:00.657076 18920 authenticator.cpp:326] \
Authentication requires more steps I0306 13:14:00.657109 18920 authenticatee.cpp:259] \
Received SASL authentication step I0306 13:14:00.657150 18920 authenticator.cpp:232] \
Received SASL authentication step I0306 13:14:00.657174 18920 auxprop.cpp:109] \
Request to lookup properties for user: 'test-principal' realm: \
'core1.hw.ca1.mesosphere.com' server FQDN: 'core1.hw.ca1.mesosphere.com' \
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false \
SASL_AUXPROP_AUTHZID: false I0306 13:14:00.657189 18920 auxprop.cpp:181] Looking up \
auxiliary property '*userPassword' I0306 13:14:00.657207 18920 auxprop.cpp:181] \
Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0306 13:14:00.657219 18920 \
auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: \
'core1.hw.ca1.mesosphere.com' server FQDN: 'core1.hw.ca1.mesosphere.com' \
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false \
SASL_AUXPROP_AUTHZID: true I0306 13:14:00.657232 18920 auxprop.cpp:131] Skipping \
auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0306 \
13:14:00.657243 18920 auxprop.cpp:131] Skipping auxiliary property \
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0306 13:14:00.657259 \
18920 authenticator.cpp:318] Authentication success I0306 13:14:00.657313 18926 \
authenticatee.cpp:299] Authentication success I0306 13:14:00.657349 18920 \
master.cpp:9708] Successfully authenticated principal 'test-principal' at \
slave(725)@66.70.182.167:44211 I0306 13:14:00.657415 18926 slave.cpp:1646] \
Successfully authenticated with master master@66.70.182.167:44211 I0306 \
13:14:00.657687 18926 slave.cpp:2096] Will retry registration in 4.732327ms if \
necessary I0306 13:14:00.657754 18891 master.cpp:6174] Received register agent \
message from slave(725)@66.70.182.167:44211 (core1.hw.ca1.mesosphere.com) I0306 \
13:14:00.657842 18891 master.cpp:3705] Authorizing principal 'test-principal' to \
perform action REGISTER_AGENT on ANY object I0306 13:14:00.657974 18891 \
master.cpp:6241] Authorized registration of agent at slave(725)@66.70.182.167:44211 \
(core1.hw.ca1.mesosphere.com) I0306 13:14:00.658053 18891 master.cpp:6353] \
Registering agent at slave(725)@66.70.182.167:44211 (core1.hw.ca1.mesosphere.com) \
with id 13016c18-4e40-461e-b9b5-43006bae2bf8-S0 I0306 13:14:00.658183 18891 \
registrar.cpp:487] Applied 1 operations in 45486ns; attempting to update the registry \
I0306 13:14:00.658290 18891 registrar.cpp:544] Successfully updated the registry in \
76032ns I0306 13:14:00.658349 18891 master.cpp:6401] Admitted agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0 at slave(725)@66.70.182.167:44211 \
(core1.hw.ca1.mesosphere.com) I0306 13:14:00.658491 18891 master.cpp:6446] Registered \
agent 13016c18-4e40-461e-b9b5-43006bae2bf8-S0 at slave(725)@66.70.182.167:44211 \
(core1.hw.ca1.mesosphere.com) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] \
I0306 13:14:00.658558 18917 hierarchical.cpp:959] Added agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0 (core1.hw.ca1.mesosphere.com) with cpus:2; \
mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {}) I0306 \
13:14:00.658672 18917 hierarchical.cpp:1853] Performed allocation for 1 agents in \
19027ns I0306 13:14:00.657557 18882 authenticator.cpp:432] Authentication session \
cleanup for crammd5-authenticatee(725)@66.70.182.167:44211 I0306 13:14:00.658584 \
18901 slave.cpp:1679] Registered with master master@66.70.182.167:44211; given agent \
ID 13016c18-4e40-461e-b9b5-43006bae2bf8-S0 I0306 13:14:00.658953 18922 \
task_status_update_manager.cpp:188] Resuming sending task status updates I0306 \
13:14:00.659323 18901 slave.cpp:1714] Checkpointing SlaveInfo to \
'/tmp/ContentType_MasterAPITest_ReservationUpdate_0_nvt6G5/meta/slaves/13016c18-4e40-461e-b9b5-43006bae2bf8-S0/slave.info'
I0306 13:14:00.659822 18901 slave.cpp:1766] Forwarding agent update \
{"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"9xMrJiRbTpG \
0XhVd1l1SeQ=="},"slave_id":{"value":"13016c18-4e40-461e-b9b5-43006bae2bf8-S0"},"update_oversubscribed_resources":false}
I0306 13:14:00.659508 18909 process.cpp:3671] Handling HTTP event for process \
'master' with path: '/master/api/v1' I0306 13:14:00.659359 18876 \
status_update_manager_process.hpp:385] Resuming operation status update manager I0306 \
13:14:00.660755 18909 master.cpp:7584] Ignoring update on agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0 at slave(725)@66.70.182.167:44211 \
(core1.hw.ca1.mesosphere.com) as it reports no changes I0306 13:14:00.660984 18905 \
http.cpp:1405] HTTP POST for /master/api/v1 from 66.70.182.167:54982 I0306 \
13:14:00.661098 18905 http.cpp:277] Processing call RESERVE_RESOURCES I0306 \
13:14:00.661291 18905 master.cpp:3705] Authorizing principal 'test-principal' to \
perform action UNRESERVE_RESOURCES on object \
{"value":"test-principal","resource":{"name":"cpus","type":"SCALAR","scalar":{"value": \
1.0},"reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/bar","principal":"test-principal"}]}}
I0306 13:14:00.661343 18905 master.cpp:3705] Authorizing principal 'test-principal' \
to perform action UNRESERVE_RESOURCES on object \
{"value":"test-principal","resource":{"name":"mem","type":"SCALAR","scalar":{"value":1 \
0.0},"reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/bar","principal":"test-principal"}]}}
I0306 13:14:00.661366 18905 master.cpp:3705] Authorizing principal 'test-principal' \
to perform action RESERVE_RESOURCES on object \
{"value":"role/foo","resource":{"name":"cpus","type":"SCALAR","scalar":{"value":1.0}," \
reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/foo","principal":"test-principal"}]}}
I0306 13:14:00.661682 18933 hierarchical.cpp:1346] Failed to update available \
resources on agent 13016c18-4e40-461e-b9b5-43006bae2bf8-S0: cpus:2; mem:1024; \
disk:1024; ports:[31000-32000] does not contain cpus(reservations: \
[(DYNAMIC,role,test-principal),(DYNAMIC,role/bar,test-principal)]):1; \
mem(reservations: [(DYNAMIC,role,test-principal),(DYNAMIC,role/bar,test-principal)]):10
I0306 13:14:00.671203 18866 process.cpp:3671] Handling HTTP event for process \
'master' with path: '/master/api/v1' I0306 13:14:00.671648 18866 http.cpp:1405] HTTP \
POST for /master/api/v1 from 66.70.182.167:54984 I0306 13:14:00.671725 18866 \
http.cpp:277] Processing call RESERVE_RESOURCES I0306 13:14:00.671916 18866 \
master.cpp:3705] Authorizing principal 'test-principal' to perform action \
RESERVE_RESOURCES on object \
{"value":"role","resource":{"name":"cpus","type":"SCALAR","scalar":{"value":1.0},"reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"}]}}
I0306 13:14:00.671968 18866 master.cpp:3705] Authorizing principal 'test-principal' \
to perform action RESERVE_RESOURCES on object \
{"value":"role/foo","resource":{"name":"cpus","type":"SCALAR","scalar":{"value":1.0}," \
reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/foo","principal":"test-principal"}]}}
I0306 13:14:00.672778 18893 master.cpp:11649] Sending operation '' (uuid: \
ff59e995-b3c8-4ac4-8abb-a9cebe651801) to agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0 at slave(725)@66.70.182.167:44211 \
(core1.hw.ca1.mesosphere.com) I0306 13:14:00.673084 18893 slave.cpp:4466] Ignoring \
new checkpointed resources and operations identical to the current version I0306 \
13:14:00.673434 18893 slave.cpp:9050] Updating the state of operation with no ID \
(uuid: ff59e995-b3c8-4ac4-8abb-a9cebe651801) for an operation API call (latest state: \
OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0306 13:14:00.673995 \
18893 slave.cpp:4554] Updated checkpointed resources from {} to cpus(reservations: \
[(DYNAMIC,role,test-principal),(DYNAMIC,role/foo,test-principal)]):1; \
mem(reservations: [(DYNAMIC,role,test-principal),(DYNAMIC,role/foo,test-principal)]):10
I0306 13:14:00.674307 18893 slave.cpp:4578] Updated checkpointed operations from [ \
] to [ ff59e995-b3c8-4ac4-8abb-a9cebe651801 (RESERVE, latest state: \
OPERATION_FINISHED) ] I0306 13:14:00.674473 18893 \
status_update_manager_process.hpp:152] Received operation status update \
OPERATION_FINISHED (Status UUID: a420030d-7468-43c4-9c3b-d57326fb8d07) for operation \
UUID ff59e995-b3c8-4ac4-8abb-a9cebe651801 on agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0 I0306 13:14:00.674605 18893 \
status_update_manager_process.hpp:414] Creating operation status update stream \
ff59e995-b3c8-4ac4-8abb-a9cebe651801 checkpoint=true I0306 13:14:00.674919 18893 \
status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status \
update OPERATION_FINISHED (Status UUID: a420030d-7468-43c4-9c3b-d57326fb8d07) for \
operation UUID ff59e995-b3c8-4ac4-8abb-a9cebe651801 on agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0 I0306 13:14:00.674983 18913 process.cpp:3671] \
Handling HTTP event for process 'slave(725)' with path: '/slave(725)/state' I0306 \
13:14:00.675457 18910 http.cpp:1405] HTTP GET for /slave(725)/state from \
66.70.182.167:54986 I0306 13:14:00.676162 18911 http.cpp:1422] HTTP GET for \
/slave(725)/state from 66.70.182.167:54986: '200 OK' after 1.2672ms I0306 \
13:14:00.676312 18893 status_update_manager_process.hpp:528] Forwarding operation \
status update OPERATION_FINISHED (Status UUID: a420030d-7468-43c4-9c3b-d57326fb8d07) \
for operation UUID ff59e995-b3c8-4ac4-8abb-a9cebe651801 on agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0 I0306 13:14:00.676508 18893 slave.cpp:9050] \
Updating the state of operation with no ID (uuid: \
ff59e995-b3c8-4ac4-8abb-a9cebe651801) for an operation API call (latest state: \
OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0306 13:14:00.676625 \
18893 slave.cpp:6441] Forwarding status update of operation with no ID \
(operation_uuid: ff59e995-b3c8-4ac4-8abb-a9cebe651801) for an operator API call I0306 \
13:14:00.676798 18893 master.cpp:11301] Updating the state of operation '' (uuid: \
ff59e995-b3c8-4ac4-8abb-a9cebe651801) for an operator API call (latest state: \
OPERATION_PENDING, status update state: OPERATION_FINISHED) I0306 13:14:00.677024 \
18893 status_update_manager_process.hpp:252] Received operation status update \
acknowledgement (UUID: a420030d-7468-43c4-9c3b-d57326fb8d07) for stream \
ff59e995-b3c8-4ac4-8abb-a9cebe651801 I0306 13:14:00.677151 18893 \
status_update_manager_process.hpp:929] Checkpointing ACK for operation status update \
OPERATION_FINISHED (Status UUID: a420030d-7468-43c4-9c3b-d57326fb8d07) for operation \
UUID ff59e995-b3c8-4ac4-8abb-a9cebe651801 on agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0 I0306 13:14:00.677781 18889 process.cpp:3671] \
Handling HTTP event for process 'master' with path: '/master/api/v1' I0306 \
13:14:00.677976 18893 status_update_manager_process.hpp:490] Cleaning up operation \
status update stream ff59e995-b3c8-4ac4-8abb-a9cebe651801 I0306 13:14:00.678164 18889 \
http.cpp:1405] HTTP POST for /master/api/v1 from 66.70.182.167:54988 I0306 \
13:14:00.678257 18889 http.cpp:277] Processing call RESERVE_RESOURCES I0306 \
13:14:00.678463 18893 slave.cpp:4578] Updated checkpointed operations from [ \
ff59e995-b3c8-4ac4-8abb-a9cebe651801 (RESERVE, latest state: OPERATION_FINISHED) ] to \
[ ] I0306 13:14:00.678462 18889 master.cpp:3705] Authorizing principal \
'test-principal' to perform action UNRESERVE_RESOURCES on object \
{"value":"test-principal","resource":{"name":"cpus","type":"SCALAR","scalar":{"value": \
1.0},"reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/bar","principal":"test-principal"}]}}
I0306 13:14:00.678541 18889 master.cpp:3705] Authorizing principal 'test-principal' \
to perform action UNRESERVE_RESOURCES on object \
{"value":"test-principal","resource":{"name":"mem","type":"SCALAR","scalar":{"value":1 \
0.0},"reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/bar","principal":"test-principal"}]}}
I0306 13:14:00.678623 18889 master.cpp:3705] Authorizing principal 'test-principal' \
to perform action RESERVE_RESOURCES on object \
{"value":"role/foo","resource":{"name":"cpus","type":"SCALAR","scalar":{"value":1.0}," \
reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/foo","principal":"test-principal"}]}}
I0306 13:14:00.679316 18889 hierarchical.cpp:1346] Failed to update available \
resources on agent 13016c18-4e40-461e-b9b5-43006bae2bf8-S0: cpus:1; mem:1014; \
disk:1024; ports:[31000-32000]; cpus(reservations: \
[(DYNAMIC,role,test-principal),(DYNAMIC,role/foo,test-principal)]):1; \
mem(reservations: [(DYNAMIC,role,test-principal),(DYNAMIC,role/foo,test-principal)]):10 \
does not contain cpus(reservations: \
[(DYNAMIC,role,test-principal),(DYNAMIC,role/bar,test-principal)]):1; \
mem(reservations: [(DYNAMIC,role,test-principal),(DYNAMIC,role/bar,test-principal)]):10
I0306 13:14:00.680538 18906 process.cpp:3671] Handling HTTP event for process \
'master' with path: '/master/api/v1' I0306 13:14:00.680794 18908 http.cpp:1405] HTTP \
POST for /master/api/v1 from 66.70.182.167:54990 I0306 13:14:00.680856 18908 \
http.cpp:277] Processing call RESERVE_RESOURCES I0306 13:14:00.681062 18908 \
master.cpp:3705] Authorizing principal 'test-principal' to perform action \
UNRESERVE_RESOURCES on object \
{"value":"test-principal","resource":{"name":"cpus","type":"SCALAR","scalar":{"value": \
1.0},"reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/foo","principal":"test-principal"}]}}
I0306 13:14:00.681102 18908 master.cpp:3705] Authorizing principal 'test-principal' \
to perform action UNRESERVE_RESOURCES on object \
{"value":"test-principal","resource":{"name":"mem","type":"SCALAR","scalar":{"value":1 \
0.0},"reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/foo","principal":"test-principal"}]}}
I0306 13:14:00.681121 18908 master.cpp:3705] Authorizing principal 'test-principal' \
to perform action RESERVE_RESOURCES on object \
{"value":"role/bar","resource":{"name":"cpus","type":"SCALAR","scalar":{"value":1.0}," \
reservations":[{"type":"DYNAMIC","role":"role","principal":"test-principal"},{"type":"DYNAMIC","role":"role/bar","principal":"test-principal"}]}}
I0306 13:14:00.682327 18872 process.cpp:3671] Handling HTTP event for process \
'slave(725)' with path: '/slave(725)/state' I0306 13:14:00.682566 18911 \
http.cpp:1405] HTTP GET for /slave(725)/state from 66.70.182.167:54992 I0306 \
13:14:00.682682 18869 master.cpp:11649] Sending operation '' (uuid: \
ee788636-a6cc-4b79-8a89-6e466a0aa4ca) to agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0 at slave(725)@66.70.182.167:44211 \
(core1.hw.ca1.mesosphere.com) I0306 13:14:00.683116 18905 http.cpp:1422] HTTP GET for \
/slave(725)/state from 66.70.182.167:54992: '200 OK' after 0.876288ms I0306 \
I0306 13:14:00.683300 18905 slave.cpp:9050] Updating the state of operation with no \
ID (uuid: ee788636-a6cc-4b79-8a89-6e466a0aa4ca) for an operation API call (latest \
state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
/home/asekretenko/lsyncd/mesos/src/tests/api_tests.cpp:1547: Failure
Expected: role
Which is: "role/foo"
To be equal to: intendedRole
Which is: "role/bar"
*** Aborted at 1583518440 (unix time) try "date -d @1583518440" if you are using GNU \
date *** I0306 13:14:00.684623 18905 slave.cpp:4554] Updated checkpointed resources \
from cpus(reservations: \
[(DYNAMIC,role,test-principal),(DYNAMIC,role/foo,test-principal)]):1; \
mem(reservations: [(DYNAMIC,role,test-principal),(DYNAMIC,role/foo,test-principal)]):10 \
to cpus(reservations: \
[(DYNAMIC,role,test-principal),(DYNAMIC,role/bar,test-principal)]):1; \
mem(reservations: [(DYNAMIC,role,test-principal),(DYNAMIC,role/bar,test-principal)]):10
I0306 13:14:00.684702 18905 slave.cpp:4578] Updated checkpointed operations from [ \
] to [ ee788636-a6cc-4b79-8a89-6e466a0aa4ca (RESERVE, latest state: \
OPERATION_FINISHED) ] I0306 13:14:00.684764 18905 \
status_update_manager_process.hpp:152] Received operation status update \
OPERATION_FINISHED (Status UUID: fa7b9b59-94b5-401b-bf74-1fe4f0872d40) for operation \
UUID ee788636-a6cc-4b79-8a89-6e466a0aa4ca on agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0 I0306 13:14:00.684780 18905 \
status_update_manager_process.hpp:414] Creating operation status update stream \
ee788636-a6cc-4b79-8a89-6e466a0aa4ca checkpoint=true I0306 13:14:00.684937 18905 \
status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status \
update OPERATION_FINISHED (Status UUID: fa7b9b59-94b5-401b-bf74-1fe4f0872d40) for \
operation UUID ee788636-a6cc-4b79-8a89-6e466a0aa4ca on agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0 I0306 13:14:00.685716 18905 \
status_update_manager_process.hpp:528] Forwarding operation status update \
OPERATION_FINISHED (Status UUID: fa7b9b59-94b5-401b-bf74-1fe4f0872d40) for operation \
UUID ee788636-a6cc-4b79-8a89-6e466a0aa4ca on agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0 I0306 13:14:00.685777 18905 slave.cpp:9050] \
Updating the state of operation with no ID (uuid: \
ee788636-a6cc-4b79-8a89-6e466a0aa4ca) for an operation API call (latest state: \
OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0306 13:14:00.685789 \
18905 slave.cpp:6441] Forwarding status update of operation with no ID \
(operation_uuid: ee788636-a6cc-4b79-8a89-6e466a0aa4ca) for an operator API call I0306 \
13:14:00.685825 18905 master.cpp:11301] Updating the state of operation '' (uuid: \
ee788636-a6cc-4b79-8a89-6e466a0aa4ca) for an operator API call (latest state: \
OPERATION_PENDING, status update state: OPERATION_FINISHED) I0306 13:14:00.685895 \
18905 status_update_manager_process.hpp:252] Received operation status update \
acknowledgement (UUID: fa7b9b59-94b5-401b-bf74-1fe4f0872d40) for stream \
ee788636-a6cc-4b79-8a89-6e466a0aa4ca I0306 13:14:00.685914 18905 \
status_update_manager_process.hpp:929] Checkpointing ACK for operation status update \
OPERATION_FINISHED (Status UUID: fa7b9b59-94b5-401b-bf74-1fe4f0872d40) for operation \
UUID ee788636-a6cc-4b79-8a89-6e466a0aa4ca on agent \
13016c18-4e40-461e-b9b5-43006bae2bf8-S0
PC: @ 0x0 (unknown)
*** SIGSEGV (@0x0) received by PID 18861 (TID 0x7fcb66479140) from PID 0; stack \
trace: *** I0306 13:14:00.686733 18905 status_update_manager_process.hpp:490] \
Cleaning up operation status update stream ee788636-a6cc-4b79-8a89-6e466a0aa4ca I0306 \
13:14:00.687050 18905 slave.cpp:4578] Updated checkpointed operations from [ \
ee788636-a6cc-4b79-8a89-6e466a0aa4ca (RESERVE, latest state: OPERATION_FINISHED) ] to \
[ ] @ 0x7fcb61db6fb0 (unknown)
@ 0x32eb210 testing::UnitTest::AddTestPartResult()
@ 0x32eae5d testing::internal::AssertHelper::operator=()
@ 0xb1fad2 \
mesos::internal::tests::MasterAPITest_ReservationUpdate_Test::TestBody()::$_1::operator()()
@ 0xb1c2c4 \
mesos::internal::tests::MasterAPITest_ReservationUpdate_Test::TestBody() @ \
0x330e494 testing::internal::HandleExceptionsInMethodIfSupported<>() @ \
0x32f4ff1 testing::Test::Run() @ 0x32f5f90 testing::TestInfo::Run()
@ 0x32f6707 testing::TestCase::Run()
@ 0x32fea87 testing::internal::UnitTestImpl::RunAllTests()
@ 0x330ef54 testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x32fe65a testing::UnitTest::Run()
@ 0x7f7224 main
@ 0x7fcb5da0711b __libc_start_main
@ 0x70465a _start
@ 0x0 (unknown)
Segmentation fault
{noformat}
The most likely cause of these flakes is the fact that the test calls Agent API to \
validate the result of reservation update, but actually never waits for the agent to \
apply the operation.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
[prev in list] [next in list] [prev in thread] [next in thread]
Configure |
About |
News |
Add a list |
Sponsored by KoreLogic