Actions
Bug #58012
closedOpTracker event duration calculation errror
Status:
Duplicate
Priority:
Normal
Assignee:
-
Category:
msgr
Target version:
-
% Done:
0%
Source:
Tags:
Backport:
Regression:
No
Severity:
1 - critical
Reviewed:
Affected Versions:
v15.0.0, v15.1.0, v15.1.1, v15.2.0, v15.2.1, v15.2.10, v15.2.11, v15.2.12, v15.2.13, v15.2.14, v15.2.15, v15.2.16, v15.2.17, v15.2.2, v15.2.3, v15.2.4, v15.2.5, v15.2.6, v15.2.7, v15.2.8, v15.2.9, v16.0.0, v16.0.1, v16.1.0, v16.1.1, v16.2.0, v16.2.1, v16.2.10, v16.2.11, v16.2.2, v16.2.3, v16.2.4, v16.2.5, v16.2.6, v16.2.7, v16.2.8, v16.2.9, v17.0.0, v17.1.0, v17.2.0, v17.2.1, v17.2.2, v17.2.3, v17.2.4, v17.2.5, v17.2.6, v18.0.0
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
ceph version¶
ceph version 15.0.0-37710-g478cbbb3b17 (478cbbb3b171186e71686452a7dd96faf294e95a) reef (dev)
ceph daemon osd.0 dump_historic_ops error¶
header_read duration value is wrong.
msgr v1:
{
"size": 20,
"duration": 600,
"ops": [
{
"description": "osd_op(client.4112.0:21 1.0 1:30306672:devicehealth::main.db.0000000000000000:head [write 65536~65536] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e7)",
"initiated_at": "2022-11-12T21:09:19.260355+0800",
"age": 205.43695800200001,
"duration": 0.0035161200000000002,
"type_data": {
"flag_point": "commit sent; apply or cleanup",
"client_info": {
"client": "client.4112",
"client_addr": "v1:127.0.0.1:0/2552950008",
"tid": 21
},
"events": [
{
"event": "initiated",
"time": "2022-11-12T21:09:19.260355+0800",
"duration": 0
},
{
"event": "throttled",
"time": "2022-11-12T21:09:19.260355+0800",
"duration": 0
},
{
"event": "header_read",
"time": "2022-11-12T21:09:19.260351+0800",
"duration": 4294967295.9999962
},
{
"event": "all_read",
"time": "2022-11-12T21:09:19.260493+0800",
"duration": 0.000141929
},
{
"event": "dispatched",
"time": "2022-11-12T21:09:19.260495+0800",
"duration": 2.2230000000000001e-06
},
{
"event": "queued_for_pg",
"time": "2022-11-12T21:09:19.260513+0800",
"duration": 1.8051e-05
},
msgr v2:
{
"size": 20,
"duration": 600,
"ops": [
{
"description": "osd_op(client.4112.0:35 1.0 1:1b0e96ae:devicehealth::main.db-journal.0000000000000000:head [write 66060~65536] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e7)",
"initiated_at": "2022-11-12T21:15:33.019347+0800",
"age": 4.8187566589999999,
"duration": 0.0040730540000000004,
"type_data": {
"flag_point": "commit sent; apply or cleanup",
"client_info": {
"client": "client.4112",
"client_addr": "127.0.0.1:0/3197847868",
"tid": 35
},
"events": [
{
"event": "initiated",
"time": "2022-11-12T21:15:33.019347+0800",
"duration": 0
},
{
"event": "throttled",
"time": "2022-11-12T21:15:33.019347+0800",
"duration": 0
},
{
"event": "header_read",
"time": "2022-11-12T21:15:33.019346+0800",
"duration": 4294967295.999999
},
{
"event": "all_read",
"time": "2022-11-12T21:15:33.019410+0800",
"duration": 6.3471000000000003e-05
},
{
"event": "dispatched",
"time": "2022-11-12T21:15:33.019411+0800",
"duration": 1.116e-06
},
{
"event": "queued_for_pg",
"time": "2022-11-12T21:15:33.019419+0800",
"duration": 7.8399999999999995e-06
},
Updated by Honggang Yang over 1 year ago
with https://github.com/ceph/ceph/pull/48860 applied:
v2:
{
"description": "osd_op(client.4112.0:112 1.0 1:30306672:devicehealth::main.db.0000000000000000:head [write 65536~65536] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e7)",
"initiated_at": "2022-11-12T22:17:48.191912+0800",
"age": 230.21683351300001,
"duration": 0.0033808309999999999,
"type_data": {
"flag_point": "commit sent; apply or cleanup",
"client_info": {
"client": "client.4112",
"client_addr": "127.0.0.1:0/1664698348",
"tid": 112
},
"events": [
{
"event": "initiated",
"time": "2022-11-12T22:17:48.191912+0800",
"duration": 0
},
{
"event": "header_read",
"time": "2022-11-12T22:17:48.191912+0800",
"duration": 0
},
{
"event": "throttled",
"time": "2022-11-12T22:17:48.191914+0800",
"duration": 1.8449999999999999e-06
},
{
"event": "all_read",
"time": "2022-11-12T22:17:48.191988+0800",
"duration": 7.4828999999999998e-05
},
{
"event": "dispatched",
"time": "2022-11-12T22:17:48.191990+0800",
"duration": 1.5549999999999999e-06
},
{
"event": "queued_for_pg",
"time": "2022-11-12T22:17:48.192011+0800",
"duration": 2.1548000000000001e-05
},
v1
{
"description": "osd_op(client.4112.0:110 1.0 1:1b0e96ae:devicehealth::main.db-journal.0000000000000000:head [write 131596~4] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e7)",
"initiated_at": "2022-11-12T22:16:45.641535+0800",
"age": 5.8552315589999999,
"duration": 0.0037710880000000001,
"type_data": {
"flag_point": "commit sent; apply or cleanup",
"client_info": {
"client": "client.4112",
"client_addr": "v1:127.0.0.1:0/3486338227",
"tid": 110
},
"events": [
{
"event": "initiated",
"time": "2022-11-12T22:16:45.641535+0800",
"duration": 0
},
{
"event": "header_read",
"time": "2022-11-12T22:16:45.641535+0800",
"duration": 0
},
{
"event": "throttled",
"time": "2022-11-12T22:16:45.641537+0800",
"duration": 2.086e-06
},
{
"event": "all_read",
"time": "2022-11-12T22:16:45.641543+0800",
"duration": 6.3169999999999998e-06
},
{
"event": "dispatched",
"time": "2022-11-12T22:16:45.641544+0800",
"duration": 1.0210000000000001e-06
},
{
"event": "queued_for_pg",
"time": "2022-11-12T22:16:45.641553+0800",
"duration": 9.0510000000000002e-06
},
Updated by Radoslaw Zarzynski 11 months ago
- Has duplicate Bug #61388: osd/TrackedOp: TrackedOp event order error added
Updated by Radoslaw Zarzynski 11 months ago
- Status changed from New to Duplicate
Closing this in favor of the fresh duplicate. Apologizes we've missed the initial fix!
Actions