Bug 2276034 - [Usability][logs] Set log_level lower than INFO for frequent get_subsystems calls unless it is user called
Summary: [Usability][logs] Set log_level lower than INFO for frequent get_subsystems c...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Ceph Storage
Classification: Red Hat Storage
Component: NVMeOF
Version: 7.1
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ---
: 7.1
Assignee: Gil Bregman
QA Contact: Rahul Lepakshi
ceph-doc-bot
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2024-04-19 07:14 UTC by Rahul Lepakshi
Modified: 2024-06-13 14:31 UTC (History)
4 users (show)

Fixed In Version: ceph-nvmeof-container-1.2.7-1
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2024-06-13 14:31:55 UTC
Embargoed:


Attachments (Terms of Use)
BZ_2276034 (1.07 MB, text/plain)
2024-05-08 04:31 UTC, Rahul Lepakshi
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker RHCEPH-8845 0 None None None 2024-04-19 07:25:32 UTC
Red Hat Product Errata RHSA-2024:3925 0 None None None 2024-06-13 14:31:58 UTC

Description Rahul Lepakshi 2024-04-19 07:14:15 UTC
Description of problem:
Currently, though use does not query for get_subsystems, events are logged at info level and this is filling up majority of log file(s). This unneccessarily fills log files and makes difficult to debug for user. This has to be recitifed.



Version-Release number of selected component (if applicable):
# ceph version
ceph version 18.2.1-149.el9cp (6944266a2186e8940baeefc45140e9c798b90141) reef (stable)

  cp.stg.icr.io/cp/ibm-ceph/nvmeof-cli-rhel9:1.2.4-1
  cp.stg.icr.io/cp/ibm-ceph/nvmeof-rhel9:1.2.4-1

How reproducible: always


Steps to Reproduce:
1. Observe nvmeof logs at /var/log/ceph/<fsid>/nvmeof location
2. We see lot of frequnt entries of "Received request to get subsystems, context: <grpc._server._Context object at 0x7f7550317b20>, client address: IPv4 10.0.205.20:36372"
3.

Actual results: 


Expected results: We expect to not to see these entries for reasons in problem description


Additional info:

Comment 1 Aviv Caro 2024-04-21 16:51:42 UTC
This is fixed in downstream, and will be provided as a part of next downstream build that will be numbered 1.2.5.

Comment 6 Rahul Lepakshi 2024-05-08 04:31:42 UTC
Created attachment 2032067 [details]
BZ_2276034

Comment 7 Rahul Lepakshi 2024-05-08 04:34:36 UTC
Reopened the BZ as issue still exists, refer above logs, though user does not query we log it as info

[08-May-2024 04:26:02] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:26:02] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:26:12] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:26:12] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:26:12] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:26:22] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:26:22] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:26:22] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:26:32] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:26:32] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:26:32] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:26:52] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:26:52] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:26:52] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:27:02] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:27:02] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:27:02] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:27:22] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:27:22] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:27:22] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:27:32] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:27:32] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:27:32] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:27:52] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:27:52] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:27:52] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:28:12] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:28:12] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:28:12] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:28:32] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:28:32] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:28:32] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:28:52] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:28:52] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:28:52] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:29:02] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:29:02] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:29:02] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:29:22] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:29:22] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:29:22] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:29:42] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:29:42] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:29:42] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None
[08-May-2024 04:29:52] INFO grpc.py:2362: Received request to list the subsystem, context: None
[08-May-2024 04:29:52] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode1, context: None
[08-May-2024 04:29:52] INFO grpc.py:1918: Received request to list connections for nqn.2016-06.io.spdk:cnode2, context: None

Comment 8 Rahul Lepakshi 2024-05-08 07:17:36 UTC
There was an issue while moving status to assigned(failed QA) earlier. Doing it properly now. We still see this issue with latest builds

Comment 9 Aviv Caro 2024-05-08 12:03:57 UTC
Rahul. I changed to high. I don't think this is urgent. It is not the same bug. The reason we see this print in the logs is related to Prometheus collecting data. We can change also this log to debug in this case.

Comment 10 Aviv Caro 2024-05-13 11:24:02 UTC
Fixed by https://gitlab.cee.redhat.com/ceph/ceph-nvmeof/-/commit/f3cb335e9a5aede5d1f8b444d62ca520a5bb6aae 
Please verify with 1.2.7 once published.

Comment 12 Rahul Lepakshi 2024-05-16 03:45:34 UTC
Verified. Now the logs do not have such non-user called entries unless we set log level to debug 

[ceph: root@tala014 /]# ceph version
ceph version 18.2.1-173.el9cp (6820b327efd7c9026508bce15c960bb8c75297d3) reef (stable)

nvmeof image - mgr/cephadm/container_image_nvmeof         icr.io/ibm-ceph-beta/nvmeof-rhel9:1.2.7-1 - 7.1 Beta build

Comment 13 errata-xmlrpc 2024-06-13 14:31:55 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Critical: Red Hat Ceph Storage 7.1 security, enhancements, and bug fix update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2024:3925


Note You need to log in before you can comment on or make changes to this bug.