search

F5Networks / f5-ansible

Imperative Ansible modules for F5 BIG-IP products
GNU General Public License v3.0
375 stars 229 forks source link

bigip_provision: infinite loop when changing provision.extramb value #2286

Closed PeepOks closed 1 year ago

PeepOks commented 1 year ago
COMPONENT NAME

bigip_provision

Environment

ANSIBLE VERSION
ansible [core 2.13.7]
  config file = /home/peepo/Scripts/nw-ansible/ansible.cfg
  configured module search path = ['/home/peepo/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /home/peepo/.local/lib/python3.8/site-packages/ansible
  ansible collection location = /home/peepo/Scripts/nw-ansible/collections
  executable location = /home/peepo/.local/bin/ansible
  python version = 3.8.10 (default, Nov 14 2022, 12:59:47) [GCC 9.4.0]
  jinja version = 3.1.2
  libyaml = True
BIGIP VERSION
Sys::Version
Main Package
  Product     BIG-IP
  Version     14.1.2.6
  Build       0.0.2
  Edition     Point Release 6
  Date        Fri Jun  5 11:36:46 PDT 2020
CONFIGURATION
[defaults]
collections_paths = collections
roles_path = roles
deprecation_warnings = False
display_skipped_hosts = False

inventory_plugins = ./scripts/inventory_plugins

lookup_plugins = ./scripts/lookup_plugins

log_path = logs/ansible.log
display_args_to_stdout = False
OS / ENVIRONMENT
“N/A”
SUMMARY

When changing provision.extramb value, TMM is restarted. K92565345. After that API authentication tokens are gone and no new token is requested. Module is in loop and using authentication token given before TMM restart.

STEPS TO REPRODUCE
- name: Provision MGMT with 500 amount of memory.
  bigip_provision:
    module: "mgmt"
    memory: "500"
    provider: "{{provider}}"
EXPECTED RESULTS

Module should either fail due to an expired authentication token or requests a new token and succeed. Module should consider status code "401" as error and new token would be requested.

ACTUAL RESULTS

The module is in infinite loop, the ansible task never finishes.

[I][1378][29 Dec 2022 10:46:49 UTC][ForwarderPassThroughWorker] {"user":"local/null","method":"POST","uri":"http://localhost:8100/mgmt/shared/authn/login","status":200,"from":"10.65.102.13"}
[I][1379][29 Dec 2022 10:46:49 UTC][ForwarderPassThroughWorker] {"user":"local/admin","method":"PATCH","uri":"http://localhost:8100/mgmt/shared/authz/tokens/5VITDUHYUNUBEZ2UNVNP2HAF2R","status":200,"from":"http://localhost:8100/shared/gossip"}
[I][1380][29 Dec 2022 10:46:49 UTC][ForwarderPassThroughWorker] {"user":"tmos/admin","method":"PATCH","uri":"http://localhost:8100/mgmt/shared/authz/tokens/GCMXFQ3KAUNQWB5SL4T2LRKEQP","status":200,"from":"10.65.102.13"}
[I][1381][29 Dec 2022 10:46:55 UTC][ForwarderPassThroughWorker] {"user":"tmos/admin","method":"PATCH","uri":"http://localhost:8100/mgmt/tm/sys/db/provision.extramb/","status":200,"from":"10.65.102.13"}
[I][1384][29 Dec 2022 10:47:01 UTC][ForwarderPassThroughWorker] {"user":"tmos/admin","method":"POST","uri":"http://localhost:8100/mgmt/tm/util/bash","status":200,"from":"10.65.102.13"}
[I][1387][29 Dec 2022 10:47:07 UTC][ForwarderPassThroughWorker] {"user":"tmos/admin","method":"POST","uri":"http://localhost:8100/mgmt/tm/util/bash","status":200,"from":"10.65.102.13"}
[I][1388][29 Dec 2022 10:47:13 UTC][ForwarderPassThroughWorker] {"user":"tmos/admin","method":"POST","uri":"http://localhost:8100/mgmt/tm/util/bash","status":200,"from":"10.65.102.13"}
[I][1389][29 Dec 2022 10:47:19 UTC][ForwarderPassThroughWorker] {"user":"tmos/admin","method":"POST","uri":"http://localhost:8100/mgmt/tm/util/bash","status":200,"from":"10.65.102.13"}
[I][1390][29 Dec 2022 10:47:25 UTC][ForwarderPassThroughWorker] {"user":"null","method":"POST","uri":"http://localhost:8100/mgmt/tm/util/bash","status":401,"from":"10.65.102.13"}
[I][1395][29 Dec 2022 10:47:35 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.13"}
[I][1396][29 Dec 2022 10:47:40 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.13"}
[I][1399][29 Dec 2022 10:47:46 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.13"}
[I][1400][29 Dec 2022 10:47:51 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.13"}
.
.
.
[I][455][29 Dec 2022 11:26:50 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.13"}
[I][456][29 Dec 2022 11:26:55 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.13"}
[I][457][29 Dec 2022 11:27:01 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.13"}
[I][458][29 Dec 2022 11:27:06 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.13"}
[I][459][29 Dec 2022 11:27:07 UTC][ForwarderPassThroughWorker] {"user":"null","method":"DELETE","uri":"http://localhost:8100/mgmt/shared/authz/tokens/GCMXFQ3KAUNQWB5SL4T2LRKEQP","status":401,"from":"10.65.102.13"}
PeepOks commented 1 year ago

This bug is kinda similar to problem https://github.com/F5Networks/f5-ansible/issues/2275

KrithikaChidambaram commented 1 year ago

Hi, could you test this with the new version and tell us if it solves this issue? Thanks!

PeepOks commented 1 year ago

Newer software or module version didn't resolve problem

Sys::Version
Main Package
  Product     BIG-IP
  Version     14.1.4.4
  Build       0.32.4
  Edition     Engineering Hotfix
  Date        Tue Aug 31 16:27:41 PDT 2021

F5 logs when it tried to change mgmt module memory size

/var/log/restjavad-audit.0.log

[I][792][14 Mar 2023 12:36:54 UTC][ForwarderPassThroughWorker] {"user":"local/null","method":"POST","uri":"http://localhost:8100/mgmt/shared/authn/login","status":200,"from":"10.65.102.12"}
[I][793][14 Mar 2023 12:36:54 UTC][ForwarderPassThroughWorker] {"user":"tmos/admin","method":"PATCH","uri":"http://localhost:8100/mgmt/shared/authz/tokens/SA4L37SHDOLGLUYIUBS7R3GGES","status":200,"from":"10.65.102.12"}
[I][794][14 Mar 2023 12:36:58 UTC][ForwarderPassThroughWorker] {"user":"tmos/admin","method":"PATCH","uri":"http://localhost:8100/mgmt/tm/sys/db/provision.extramb/","status":200,"from":"10.65.102.12"}
[I][795][14 Mar 2023 12:37:00 UTC][ForwarderPassThroughWorker] {"user":"local/admin","method":"POST","uri":"http://localhost:8100/mgmt/shared/authz/tokens","status":200,"from":"Unknown"}
[I][798][14 Mar 2023 12:37:04 UTC][ForwarderPassThroughWorker] {"user":"tmos/admin","method":"POST","uri":"http://localhost:8100/mgmt/tm/util/bash","status":200,"from":"10.65.102.12"}
[I][799][14 Mar 2023 12:37:10 UTC][ForwarderPassThroughWorker] {"user":"tmos/admin","method":"POST","uri":"http://localhost:8100/mgmt/tm/util/bash","status":200,"from":"10.65.102.12"}
[I][800][14 Mar 2023 12:37:15 UTC][ForwarderPassThroughWorker] {"user":"tmos/admin","method":"POST","uri":"http://localhost:8100/mgmt/tm/util/bash","status":200,"from":"10.65.102.12"}
[I][801][14 Mar 2023 12:37:21 UTC][ForwarderPassThroughWorker] {"user":"tmos/admin","method":"POST","uri":"http://localhost:8100/mgmt/tm/util/bash","status":200,"from":"10.65.102.12"}
[I][803][14 Mar 2023 12:37:27 UTC][ForwarderPassThroughWorker] {"user":"null","method":"POST","uri":"http://localhost:8100/mgmt/tm/util/bash","status":401,"from":"10.65.102.12"}
[I][804][14 Mar 2023 12:37:37 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.12"}
[I][805][14 Mar 2023 12:37:43 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.12"}
[I][806][14 Mar 2023 12:37:48 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.12"}
[I][807][14 Mar 2023 12:37:53 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.12"}
[I][808][14 Mar 2023 12:37:59 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.12"}
[I][809][14 Mar 2023 12:38:04 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.12"}
[I][810][14 Mar 2023 12:38:10 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.12"}
[I][811][14 Mar 2023 12:38:15 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.12"}
[I][812][14 Mar 2023 12:38:21 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.12"}
[I][813][14 Mar 2023 12:38:26 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.12"}
[I][814][14 Mar 2023 12:38:32 UTC][ForwarderPassThroughWorker] {"user":"null","method":"GET","uri":"http://localhost:8100/mgmt/tm/sys/available","status":401,"from":"10.65.102.12"}
[I][815][14 Mar 2023 12:38:32 UTC][ForwarderPassThroughWorker] {"user":"null","method":"DELETE","uri":"http://localhost:8100/mgmt/shared/authz/tokens/SA4L37SHDOLGLUYIUBS7R3GGES","status":401,"from":"10.65.102.12"}

/var/log/audit

Mar 14 12:36:56 mitspgb-sb-lb01.mitspshared.ptec notice mcpd[5256]: 01070417:5: AUDIT - client tmsh, tmsh-pid-11505, user admin - transaction #1492-2 - object 0 - modify { db_variable { db_variable_name "provision.extramb" db_variable_value "500" } } [Status=Command OK]
Mar 14 12:36:58 mitspgb-sb-lb01.mitspshared.ptec notice icrd_child[11505]: 01420002:5: AUDIT - pid=11505 user=admin folder=/Common module=(tmos)# status=[Command OK] cmd_data=modify sys db provision.extramb { value 500 }
Mar 14 12:37:04 mitspgb-sb-lb01.mitspshared.ptec notice icrd_child[11505]: 01420002:5: AUDIT - pid=11505 user=admin folder=/Common module=(tmos)# status=[Command OK] cmd_data=run util bash -c "ps aux | grep '[m]prov' | grep -v /usr/libexec/qemu-kvm"
Mar 14 12:37:10 mitspgb-sb-lb01.mitspshared.ptec notice icrd_child[11505]: 01420002:5: AUDIT - pid=11505 user=admin folder=/Common module=(tmos)# status=[Command OK] cmd_data=run util bash -c "ps aux | grep '[m]prov' | grep -v /usr/libexec/qemu-kvm"
Mar 14 12:37:14 mitspgb-sb-lb01.mitspshared.ptec notice tmsh[17425]: 01420002:5: AUDIT - pid=17425 user=root folder=/Common module=(tmos)# status=[Command OK] cmd_data=list sys crypto fips external-hsm vendor
Mar 14 12:37:15 mitspgb-sb-lb01.mitspshared.ptec notice icrd_child[11505]: 01420002:5: AUDIT - pid=11505 user=admin folder=/Common module=(tmos)# status=[Command OK] cmd_data=run util bash -c "ps aux | grep '[m]prov' | grep -v /usr/libexec/qemu-kvm"
Mar 14 12:37:21 mitspgb-sb-lb01.mitspshared.ptec notice icrd_child[11505]: 01420002:5: AUDIT - pid=11505 user=admin folder=/Common module=(tmos)# status=[Command OK] cmd_data=run util bash -c "ps aux | grep '[m]prov' | grep -v /usr/libexec/qemu-kvm"
pgouband commented 1 year ago

Hi, thanks for reporting this issue. Added to the backlog and internal tracking ID for this request is: INFRAANO-1167, thanks!