Project

General

Profile

Bug #58012

OpTracker event duration calculation errror

Added by Honggang Yang 3 months ago. Updated 3 months ago.

Status:
New
Priority:
Normal
Assignee:
-
Category:
msgr
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
1 - critical
Reviewed:

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
                    },

History

#1 Updated by Honggang Yang 3 months 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
                    },

Also available in: Atom PDF