Debian: Delete datanetwork request shows Auditlogging exception in sysinv-api.log

[João Victor Portal]

Brief Description
-----------------
Debian: Delete datanetwork request shows Auditlogging exception in "sysinv-api.log".

Severity
--------
Minor.

Steps to Reproduce
------------------
1)login to horizon ui and create a data network

2)verify that a POST request is logged to /var/log/sysinv-api.log

sysinv 2022-05-25 16:04:22.766 78038 INFO sysinv.api.hooks.auditor [req-c67e75a1-07ea-4e4e-b5ae-e1e142d56c59 3a0075cc40d74fdebbdd5450279343f4 06f73d3965384b0e892d80ab1777a0a5] 192.168.204.2 "POST /v1/datanetworks HTTP/1.0" status: 200 len: 273 time: 0.009198904037475586 POST: {'name': 'test', 'network_type': 'vlan', 'description': 'test', 'mtu': 1500} host:192.168.204.1:6385 agent:Python-httplib2/0.18.1 (gzip) user: admin tenant: admin domain: Default

3)now modify the datanetwork and verify that patch request is logged to /var/log/sysinv-api.log

sysinv 2022-05-25 16:04:30.901 78038 INFO sysinv.api.hooks.auditor [req-fe838649-f2e9-49eb-91c4-db481b5034e8 8cd261ac74a04e66a2b09d9e38d08b6e 4775c34a564e4430bcf43d1f78f6ed2c] 192.168.204.2 "PATCH /v1/ihosts/3336f38e-63a9-44fc-8fe0-90953c10c97f HTTP/1.0" status: 200 len: 6330 time: 0.1088571548461914 POST: [{'path': '/uptime', 'value': '67135', 'op': 'replace'}] host:192.168.204.1 agent:mtce/1.0 user: mtce tenant: services domain: Default
sysinv 2022-05-25 16:04:39.479 78038 INFO sysinv.api.hooks.auditor [req-b50bb9e8-8f06-411b-8afb-4bd21885e7d8 3a0075cc40d74fdebbdd5450279343f4 06f73d3965384b0e892d80ab1777a0a5] 192.168.204.2 "PATCH /v1/datanetworks/5 HTTP/1.0" status: 200 len: 274 time: 0.014768123626708984 POST: [{'path': '/description', 'value': 'test3', 'op': 'replace'}, {'path': '/mtu', 'value': 1500, 'op': 'replace'}] host:192.168.204.1:6385 agent:Python-httplib2/0.18.1 (gzip) user: admin tenant: admin domain: Default

4)Now try deleting the datanetwork and an exception is shown in the /var/log/sysinv-api.log

sysinv 2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor [-] Exception in AuditLogging on event 'after': simplejson.errors.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor Traceback (most recent call last):
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor File "/usr/lib/python3/dist-packages/sysinv/api/hooks.py", line 333, in after
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor self.__after(state)
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor File "/usr/lib/python3/dist-packages/sysinv/api/hooks.py", line 288, in __after
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor json_post_data(state))
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor File "/usr/lib/python3/dist-packages/sysinv/api/hooks.py", line 281, in json_post_data
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor if not hasattr(rest_state.request, 'json'):
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor File "/usr/lib/python3/dist-packages/pecan/core.py", line 52, in __getattribute__
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor return WebObRequest.__getattribute__(self, name)
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor File "/usr/lib/python3/dist-packages/webob/request.py", line 715, in _json_body__get
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor return json.loads(self.body.decode(self.charset))
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor File "/usr/lib/python3/dist-packages/simplejson/__init__.py", line 525, in loads
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor return _default_decoder.decode(s)
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor File "/usr/lib/python3/dist-packages/simplejson/decoder.py", line 370, in decode
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor obj, end = self.raw_decode(s)
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor File "/usr/lib/python3/dist-packages/simplejson/decoder.py", line 400, in raw_decode
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor return self.scan_once(s, idx=_w(s, idx).end())
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor simplejson.errors.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
2022-05-25 16:04:54.242 78038 ERROR sysinv.api.hooks.auditor

Expected Behavior
------------------
POST,PATCH,DELETE request should be logged without any errors

Actual Behavior
----------------
DELETE request throws exception in the /var/log/sysinv-api.log

Reproducibility
---------------
100% reproducible.

System Configuration
--------------------
AIO-SX.

Branch/Pull Time/Commit
-----------------------
N/A.

Last Pass
---------
N/A.

Timestamp/Logs
--------------
See section "Steps to Reproduce".

Test Activity
-------------
Feature Testing.

Workaround
----------
N/A.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/starlingx/config/+/848781
Committed: https://opendev.org/starlingx/config/commit/8033aae4478712bc37bfdd0848e8e60df104f720
Submitter: "Zuul (22348)"
Branch: master

commit 8033aae4478712bc37bfdd0848e8e60df104f720
Author: Joao Victor Portal <email address hidden>
Date: Tue Jul 5 17:34:00 2022 -0300

    Ignore JSON decode error in request log.

    For DELETE requests with no request body or "Content-Length" field, the
    expected return value for "hasattr(rest_state.request, 'json')" would be
    False and for "rest_state.request.json" would be an empty string.
    Instead, what occurs is that both "hasattr(rest_state.request, 'json')"
    and "rest_state.request.json" are throwing JSON decode exceptions in
    this case. This change adds tolerance for this exception. This is done
    because it is not know all the possible request conditions that may
    cause this exception to be thrown.

    Test Plan:

    PASS: Successfully deploy an AIO-SX using a Debian image with this
    commit present and, using horizon interface, create and delete a data
    network, checking that in log file "/var/log/sysinv-api.log" no
    exception was thrown in the delete request.

    Closes-Bug: 1980842
    Signed-off-by: Joao Victor Portal <email address hidden>
    Change-Id: Ib9f72f3b2d4d60790fa8011674a013bcd141a61e