Bug #52484: cephadm: add thread ident to log messages - Orchestrator - Ceph

Actions

Copy link

Bug #52484

closed

cephadm: add thread ident to log messages

Added by Michael Fritch over 2 years ago. Updated over 2 years ago.

Status:

Resolved

Priority:

Normal

Assignee:

Michael Fritch

Category:

cephadm (binary)

Target version:

% Done:

Source:

Tags:

Backport:

Regression:

Severity:

3 - minor

Reviewed:

Affected Versions:

ceph-qa-suite:

Pull request ID:

43010

Crash signature (v1):

Crash signature (v2):

Description

log lines for multiple calls async calls to bin/cephadm are intermingled within the /var/lib/ceph/cephadm.log file

likewise, the context of which command (with args) that generated the log lines is also missing.

2021-08-25 08:21:53,983 DEBUG Running command: /usr/bin/podman version --format {{.Client.Version}}
2021-08-25 08:21:54,052 DEBUG /usr/bin/podman: 3.2.3
2021-08-25 08:21:54,178 DEBUG Running command: sysctl -a
2021-08-25 08:21:54,214 DEBUG Running command: sysctl -a
2021-08-25 08:22:54,644 DEBUG Running command: /usr/bin/podman version --format {{.Client.Version}}
2021-08-25 08:22:54,708 DEBUG /usr/bin/podman: 3.2.3
2021-08-25 08:22:54,831 DEBUG Running command: sysctl -a
2021-08-25 08:22:54,863 DEBUG Running command: sysctl -a
2021-08-25 08:23:55,304 DEBUG Running command: /usr/bin/podman version --format {{.Client.Version}}
2021-08-25 08:23:55,375 DEBUG /usr/bin/podman: 3.2.3
2021-08-25 08:23:55,467 DEBUG Running command: /usr/bin/podman stats --format {{.ID}},{{.MemUsage}} --no-stream
2021-08-25 08:23:55,541 DEBUG /usr/bin/podman: c111790c7b7f,46.96MB / 135.1GB
2021-08-25 08:23:55,541 DEBUG /usr/bin/podman: e368d9286f4a,61.28MB / 135.1GB
2021-08-25 08:23:55,542 DEBUG /usr/bin/podman: e6f89a86ff1f,60.31MB / 135.1GB
2021-08-25 08:23:55,630 DEBUG Running command: systemctl is-enabled ceph-beeb434c-9e41-42c7-b5dd-e2f2263dc540@crash.host3
2021-08-25 08:23:55,647 DEBUG systemctl: enabled
2021-08-25 08:23:55,649 DEBUG Running command: systemctl is-active ceph-beeb434c-9e41-42c7-b5dd-e2f2263dc540@crash.host3
2021-08-25 08:23:55,660 DEBUG systemctl: active
2021-08-25 08:23:55,662 DEBUG Running command: /usr/bin/podman inspect --format {{.Id}},{{.Config.Image}},{{.Image}},{{.Created}},{{index .Config.Labels "io.ceph.version"}} ceph-beeb434c-9e41-42c7-b5dd-e2f2263dc540-crash-host3
2021-08-25 08:23:55,745 DEBUG /usr/bin/podman: c111790c7b7fc1d24350d8c083b83be79b53388b92e3ebc3c8ec0b8eb7c3de39,docker.io/ceph/daemon-base@sha256:8aaf4224877028e18a8247de2d341f38cacb2cd6cb2b744dbde978a7c9d9b694,909bfb98792e0c3ba3c3cdbc016b2aac9e7e4f94f6ad5d62e19751e98b6c13ad,2021-08-19 14:25:29.61914488 -0600 MDT,
2021-08-25 08:23:55,832 DEBUG Running command: /usr/bin/podman image inspect 909bfb98792e0c3ba3c3cdbc016b2aac9e7e4f94f6ad5d62e19751e98b6c13ad --format {{.RepoDigests}}
2021-08-25 08:23:55,917 DEBUG /usr/bin/podman: [docker.io/ceph/daemon-base@sha256:8aaf4224877028e18a8247de2d341f38cacb2cd6cb2b744dbde978a7c9d9b694]
2021-08-25 08:23:55,993 DEBUG Running command: /usr/bin/podman exec c111790c7b7fc1d24350d8c083b83be79b53388b92e3ebc3c8ec0b8eb7c3de39 ceph -v
2021-08-25 08:23:56,661 DEBUG /usr/bin/podman: ceph version 17.0.0-7078-gfcdf7f37 (fcdf7f3791fd331c296d775aa6ea07fb1e5fdd4c) quincy (dev)

Actions

Copy link

Updated by Michael Fritch over 2 years ago

Status changed from In Progress to Fix Under Review
Pull request ID set to 43010

sample output of multiple async cephadm calls with thread ident:

2021-09-01 07:45:03,026 7fc53e5eb740 DEBUG --------------------------------------------------------------------------------
cephadm ['--image', 'docker.io/ceph/daemon-base@sha256:673ed6755ec01f8ba5ceb01598318bcd349375e136d16f7cde01b45e898822a5', 'ls']
2021-09-01 07:45:03,027 7fc53e5eb740 DEBUG Running command: /usr/bin/podman version --format {{.Client.Version}}
2021-09-01 07:45:03,054 7f3af56dc740 DEBUG /usr/bin/podman: 66ae558c37b5d987f777dc3c05e0629f5f2bd52292bf821efa729f22e5ae0f6f,docker.io/ceph/daemon-base@sha256:673ed6755ec01f8ba5ceb01598318bcd349375e136d16f7cde01b45e898822a5,75e3d7089cea6d20368af487d639b5c9028e0086b7bc7ccfe047b8ce6d6d14d0,2021-08-30 10:54:33.255623469 -0600 MDT,
2021-09-01 07:45:03,093 7fc53e5eb740 DEBUG /usr/bin/podman: 3.2.3
2021-09-01 07:45:03,133 7f3af56dc740 DEBUG Running command: systemctl is-enabled ceph-8b7093f5-f046-42a8-97eb-36b0be80a8f4@mds.a.host3.yenfjl
2021-09-01 07:45:03,149 7f3af56dc740 DEBUG systemctl: enabled
2021-09-01 07:45:03,150 7f3af56dc740 DEBUG Running command: systemctl is-active ceph-8b7093f5-f046-42a8-97eb-36b0be80a8f4@mds.a.host3.yenfjl
2021-09-01 07:45:03,161 7f3af56dc740 DEBUG systemctl: active
2021-09-01 07:45:03,163 7f3af56dc740 DEBUG Running command: /usr/bin/podman inspect --format {{.Id}},{{.Config.Image}},{{.Image}},{{.Created}},{{index .Config.Labels "io.ceph.version"}} ceph-8b7093f5-f046-42a8-97eb-36b0be80a8f4-mds-a-host3-yenfjl
2021-09-01 07:45:03,189 7fc53e5eb740 DEBUG Running command: /usr/bin/podman stats --format {{.ID}},{{.MemUsage}} --no-stream
2021-09-01 07:45:03,246 7f3af56dc740 DEBUG /usr/bin/podman: af060b7fa9fc6c921f74da9cb5d3b0744bc8721f7b4df903bee2c73f9276df24,docker.io/ceph/daemon-base@sha256:673ed6755ec01f8ba5ceb01598318bcd349375e136d16f7cde01b45e898822a5,75e3d7089cea6d20368af487d639b5c9028e0086b7bc7ccfe047b8ce6d6d14d0,2021-08-30 10:54:44.872087053 -0600 MDT,
2021-09-01 07:45:03,322 7fc53e5eb740 DEBUG /usr/bin/podman: 12ff8883d6f3,46.96MB / 135.1GB
2021-09-01 07:45:03,322 7fc53e5eb740 DEBUG /usr/bin/podman: 66ae558c37b5,60.83MB / 135.1GB
2021-09-01 07:45:03,322 7fc53e5eb740 DEBUG /usr/bin/podman: 9ac2c1562e47,42.56MB / 135.1GB
2021-09-01 07:45:03,322 7fc53e5eb740 DEBUG /usr/bin/podman: af060b7fa9fc,60.66MB / 135.1GB
2021-09-01 07:45:03,322 7fc53e5eb740 DEBUG /usr/bin/podman: eb40008f2bf4,5.857MB / 135.1GB
2021-09-01 07:45:03,405 7fc53e5eb740 DEBUG Running command: systemctl is-enabled ceph-8b7093f5-f046-42a8-97eb-36b0be80a8f4@crash.host3
2021-09-01 07:45:03,419 7fc53e5eb740 DEBUG systemctl: enabled
2021-09-01 07:45:03,420 7fc53e5eb740 DEBUG Running command: systemctl is-active ceph-8b7093f5-f046-42a8-97eb-36b0be80a8f4@crash.host3
2021-09-01 07:45:03,432 7fc53e5eb740 DEBUG systemctl: active
2021-09-01 07:45:03,434 7fc53e5eb740 DEBUG Running command: /usr/bin/podman inspect --format {{.Id}},{{.Config.Image}},{{.Image}},{{.Created}},{{index .Config.Labels "io.ceph.version"}} ceph-8b7093f5-f046-42a8-97eb-36b0be80a8f4-crash-host3
2021-09-01 07:45:03,518 7fc53e5eb740 DEBUG /usr/bin/podman: 12ff8883d6f36e88ab470327af439c304a31426834f15491781e7c29443bce17,docker.io/ceph/daemon-base@sha256:673ed6755ec01f8ba5ceb01598318bcd349375e136d16f7cde01b45e898822a5,75e3d7089cea6d20368af487d639b5c9028e0086b7bc7ccfe047b8ce6d6d14d0,2021-08-30 10:53:56.581450431 -0600 MDT,
2021-09-01 07:45:03,588 7f74d3c84740 DEBUG --------------------------------------------------------------------------------
cephadm ['ls']
2021-09-01 07:45:03,588 7f74d3c84740 DEBUG Running command: /usr/bin/podman version --format {{.Client.Version}}
2021-09-01 07:45:03,600 7fc53e5eb740 DEBUG Running command: /usr/bin/podman image inspect 75e3d7089cea6d20368af487d639b5c9028e0086b7bc7ccfe047b8ce6d6d14d0 --format {{.RepoDigests}}
2021-09-01 07:45:03,656 7f74d3c84740 DEBUG /usr/bin/podman: 3.2.3
2021-09-01 07:45:03,676 7fc53e5eb740 DEBUG /usr/bin/podman: [docker.io/ceph/daemon-base@sha256:673ed6755ec01f8ba5ceb01598318bcd349375e136d16f7cde01b45e898822a5]
2021-09-01 07:45:03,749 7f74d3c84740 DEBUG Running command: /usr/bin/podman stats --format {{.ID}},{{.MemUsage}} --no-stream
2021-09-01 07:45:03,757 7fc53e5eb740 DEBUG Running command: /usr/bin/podman exec 12ff8883d6f36e88ab470327af439c304a31426834f15491781e7c29443bce17 ceph -v
2021-09-01 07:45:03,822 7f74d3c84740 DEBUG /usr/bin/podman: 12ff8883d6f3,46.96MB / 135.1GB
2021-09-01 07:45:03,822 7f74d3c84740 DEBUG /usr/bin/podman: 66ae558c37b5,60.83MB / 135.1GB
2021-09-01 07:45:03,822 7f74d3c84740 DEBUG /usr/bin/podman: 9ac2c1562e47,42.56MB / 135.1GB
2021-09-01 07:45:03,823 7f74d3c84740 DEBUG /usr/bin/podman: af060b7fa9fc,60.66MB / 135.1GB
2021-09-01 07:45:03,823 7f74d3c84740 DEBUG /usr/bin/podman: eb40008f2bf4,5.857MB / 135.1GB
2021-09-01 07:45:03,912 7f74d3c84740 DEBUG Running command: systemctl is-enabled ceph-8b7093f5-f046-42a8-97eb-36b0be80a8f4@crash.host3
2021-09-01 07:45:03,926 7f74d3c84740 DEBUG systemctl: enabled
2021-09-01 07:45:03,928 7f74d3c84740 DEBUG Running command: systemctl is-active ceph-8b7093f5-f046-42a8-97eb-36b0be80a8f4@crash.host3
2021-09-01 07:45:03,939 7f74d3c84740 DEBUG systemctl: active
2021-09-01 07:45:03,940 7f74d3c84740 DEBUG Running command: /usr/bin/podman inspect --format {{.Id}},{{.Config.Image}},{{.Image}},{{.Created}},{{index .Config.Labels "io.ceph.version"}} ceph-8b7093f5-f046-42a8-97eb-36b0be80a8f4-crash-host3
2021-09-01 07:45:04,411 7fc53e5eb740 DEBUG /usr/bin/podman: ceph version 17.0.0-7183-g54142666 (54142666e5705ced88e3e2d91ddc0ff29867a362) quincy (dev)

Actions

Copy link