Project

General

Profile

Actions

Bug #61590

open

add more context for log messages

Added by Patrick Donnelly 12 months ago. Updated 11 months ago.

Status:
Fix Under Review
Priority:
High
Assignee:
Category:
-
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Crash signature (v1):
Crash signature (v2):

Description

2023-05-28T19:57:05.527684+00:00 smithi062 kernel: libceph: mon0 (1)172.21.15.62:6789 session established
2023-05-28T19:57:05.527774+00:00 smithi062 kernel: libceph: client15495 fsid 7e93fa48-fd90-11ed-9b1d-001a4aab830c
2023-05-28T19:57:05.543697+00:00 smithi062 kernel: ceph: mds3 session blocklisted
2023-05-28T19:57:05.561687+00:00 smithi062 kernel: ceph: mds0 session blocklisted
2023-05-28T19:57:17.951686+00:00 smithi062 kernel: ceph: mds1 session blocklisted
2023-05-28T19:57:17.975685+00:00 smithi062 kernel: ceph: mds4 session blocklisted
2023-05-28T19:58:01.123723+00:00 smithi062 kernel: ceph: mds2 session blocklisted

From: /teuthology/yuriw-2023-05-28_14:46:14-fs-reef-release-distro-default-smithi/7288964/remote/smithi062/syslog/kern.log.gz

There's a few problems from this but the one this ticket is about: please add session context for related debug messages. Specifically, "client15495: ". Multiple cephfs mounts on a host is increasingly common so disambiguating messages like this is necessary.

Actions #1

Updated by Xiubo Li 12 months ago

  • Status changed from New to In Progress
Actions #2

Updated by Xiubo Li 12 months ago

  • Status changed from In Progress to Fix Under Review
Actions #3

Updated by Patrick Donnelly 11 months ago

Xiubo, I lost my subscription somehow to ceph-devel so I can't comment on the patch in the normal way. I think this ticket is more concerned with general dout messages across fs/ceph. I think any dout() message should include this context information.

Actions #4

Updated by Xiubo Li 11 months ago

Patrick Donnelly wrote:

Xiubo, I lost my subscription somehow to ceph-devel so I can't comment on the patch in the normal way. I think this ticket is more concerned with general dout messages across fs/ceph. I think any dout() message should include this context information.

Okay, yesterday I added this in many other places, but thought that may not much neccessary and removed them before sending out the patch.

But with that really could help much. Let me try how to improve that.

Actions #5

Updated by Xiubo Li 11 months ago

The v2 ceph patchwork link: https://patchwork.kernel.org/project/ceph-devel/list/?series=756269

And the output will be something like:

<7>[33404.475305] ceph:  [client.4236] caps reclaim work queued
<7>[33409.591736] ceph:  [client.4236] mdsc delayed_work
<7>[33409.591770] ceph:  [client.4236] ceph_check_delayed_caps
<7>[33409.591789] ceph:  [client.4236] caps reclaim work queued
<7>[33414.711970] ceph:  [client.4236] mdsc delayed_work
<7>[33414.711993] ceph:  [client.4236] send_renew_caps to mds0 (up:active)
<7>[33414.712122] ceph:  [client.4236] ceph_check_delayed_caps
<7>[33414.712151] ceph:  [client.4236] caps reclaim work queued
<7>[33414.715517] ceph:  [client.4236] handle_session mds0 renewcaps 000000005e065e1d state open seq 27
<7>[33414.715551] ceph:  [client.4236] renewed_caps mds0 ttl now 4328139360, was fresh, now stale
<7>[33420.344833] ceph:  [client.4236] mdsc delayed_work
<7>[33420.344870] ceph:  [client.4236] ceph_check_delayed_caps
<7>[33420.344889] ceph:  [client.4236] caps reclaim work queued
<7>[33425.463922] ceph:  [client.4236] mdsc delayed_work
<7>[33425.463976] ceph:  [client.4236] ceph_check_delayed_caps
<7>[33425.464008] ceph:  [client.4236] caps reclaim work queued
<7>[33430.585101] ceph:  [client.4236] mdsc delayed_work
<7>[33430.585127] ceph:  [client.4236] send_renew_caps to mds0 (up:active)
<7>[33430.585256] ceph:  [client.4236] ceph_check_delayed_caps
<7>[33430.585286] ceph:  [client.4236] caps reclaim work queued
<7>[33430.591074] ceph:  [client.4236] handle_session mds0 renewcaps 000000005e065e1d state open seq 28
<7>[33430.591104] ceph:  [client.4236] renewed_caps mds0 ttl now 4328155233, was fresh, now stale
<7>[33435.705243] ceph:  [client.4236] mdsc delayed_work
<7>[33435.705300] ceph:  [client.4236] ceph_check_delayed_caps
<7>[33435.705329] ceph:  [client.4236] caps reclaim work queued
<7>[33441.848145] ceph:  [client.4236] mdsc delayed_work
<7>[33441.848195] ceph:  [client.4236] ceph_check_delayed_caps
<7>[33441.848224] ceph:  [client.4236] caps reclaim work queued
<7>[33447.479776] ceph:  [client.4236] mdsc delayed_work
<7>[33447.479794] ceph:  [client.4236] send_renew_caps to mds0 (up:active)
<7>[33447.479872] ceph:  [client.4236] ceph_check_delayed_caps
<7>[33447.479890] ceph:  [client.4236] caps reclaim work queued
<7>[33447.480641] ceph:  [client.4236] handle_session mds0 renewcaps 000000005e065e1d state open seq 29
<7>[33447.480662] ceph:  [client.4236] renewed_caps mds0 ttl now 4328172128, was fresh, now stale
<7>[33452.605961] ceph:  [client.4236] mdsc delayed_work
<7>[33452.606012] ceph:  [client.4236] caps reclaim work queued
<7>[33458.751031] ceph:  [client.4236] mdsc delayed_work
<7>[33458.751096] ceph:  [client.4236] caps reclaim work queued
<7>[33464.375799] ceph:  [client.4236] mdsc delayed_work
<7>[33464.375817] ceph:  [client.4236] send_renew_caps to mds0 (up:active)
<7>[33464.375913] ceph:  [client.4236] caps reclaim work queued
Actions

Also available in: Atom PDF