Bug 2276034

Summary:

[Usability][logs] Set log_level lower than INFO for frequent get_subsystems calls unless it is user called

Product:

[Red Hat Storage] Red Hat Ceph Storage

Reporter:

Rahul Lepakshi <rlepaksh>

Component:

NVMeOF

Assignee:

Gil Bregman <gbregman>

Status:

CLOSED ERRATA

QA Contact:

Rahul Lepakshi <rlepaksh>

Severity:

high

Docs Contact:

ceph-doc-bot <ceph-doc-bugzilla>

Priority:

unspecified

Version:

7.1

CC:

acaro, cephqe-warriors, sunnagar, tserlin

Target Milestone:

---

Target Release:

7.1

Hardware:

Unspecified

OS:

Unspecified

Whiteboard:

Fixed In Version:

ceph-nvmeof-container-1.2.7-1

Doc Type:

If docs needed, set a value

Doc Text:

Story Points:

---

Clone Of:

Environment:

Last Closed:

2024-06-13 14:31:55 UTC

Type:

Bug

Regression:

---

Mount Type:

---

Documentation:

---

CRM:

Verified Versions:

Category:

---

oVirt Team:

---

RHEL 7.3 requirements from Atomic Host:

Cloudforms Team:

---

Target Upstream Version:

Embargoed:

Attachments:

Description	Flags
BZ_2276034	none

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 2 Aviv Caro 2024-04-30 13:56:47 UTC

Fixed in https://pkgs.devel.redhat.com/cgit/containers/ceph-nvmeof/commit/?h=ceph-7.1-rhel-9&id=3912329fbf36a7355510fe5786046e302139d66e 
Please verify with GW/CLI version >= 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