Page MenuHomeFreeBSD

usr.sbin/gstat: add microsecond precision for disk latency
ClosedPublic

Authored by mizhka on Sep 27 2023, 12:57 PM.
Tags
None
Referenced Files
Unknown Object (File)
Wed, Nov 6, 8:02 AM
Unknown Object (File)
Sat, Oct 19, 3:21 PM
Unknown Object (File)
Oct 2 2024, 1:40 PM
Unknown Object (File)
Sep 30 2024, 12:11 PM
Unknown Object (File)
Sep 30 2024, 10:01 AM
Unknown Object (File)
Sep 30 2024, 9:34 AM
Unknown Object (File)
Sep 27 2024, 9:13 AM
Unknown Object (File)
Sep 25 2024, 6:06 AM
Subscribers
None

Details

Summary

In short, gstat shows the disk latency in 0.1 milliseconds, although modern NVMe drives have even lower latency on the order of tens of microseconds. For instance, actual timing of disks is 140us for read and 50us for write, so gstat shows it like "0.1ms" and "0.1ms".

This patch makes gstat to show latency in microseconds if actual latency is less than 1ms.

Test Plan

Use NVMe / SSD disk with good latency and run gstat with flags:

  1. -C
  2. -Cd
  3. without any flags
  4. -d
  5. -Co
  6. -o
  7. -Cdo

Diff Detail

Repository
rG FreeBSD src repository
Lint
Lint Not Applicable
Unit
Tests Not Applicable

Event Timeline

mizhka created this revision.

gstat -C (CSV mode)

Before patch

timestamp,name,q-depth,total_ops/s,read/s,read-KiB/s,ms/read,write/s,write-KiB/s,ms/write,%busy
2023-09-27 13:16:10.917166035,nda4,0,275,2,19,0.1,273,13071,0.0,1.1
2023-09-27 13:16:10.917166035,nda5,0,276,3,19,0.1,273,13071,0.0,1.1
2023-09-27 13:16:10.917166035,nda6,0,440,4,23,0.1,436,23979,0.0,1.9
2023-09-27 13:16:10.917166035,nda7,0,437,1,4,0.1,436,23979,0.1,2.1
2023-09-27 13:16:10.917166035,nda8,0,259,2,11,0.1,257,15038,0.0,1.2
2023-09-27 13:16:10.917166035,nda9,0,258,1,8,0.1,257,15038,0.0,1.1
2023-09-27 13:16:10.917166035,nda10,0,393,3,30,0.1,390,28558,0.1,1.9
2023-09-27 13:16:10.917166035,nda11,0,393,3,19,0.1,390,28558,0.1,1.9

after patch

timestamp,name,q-depth,total_ops/s,read/s,read-KiB/s,ms/read,write/s,write-KiB/s,ms/write,%busy
2023-09-27 17:03:23.056176622,nda4,0,506,163,4986,0.148,344,14788,0.040,2.3
2023-09-27 17:03:23.056176622,nda5,0,503,159,4946,0.157,345,14788,0.040,2.4
2023-09-27 17:03:23.056176622,nda6,0,595,130,3971,0.148,465,22909,0.045,3.0
2023-09-27 17:03:23.056176622,nda7,0,640,160,4839,0.121,481,22909,0.042,3.0
2023-09-27 17:03:23.056176622,nda8,0,528,150,4649,0.155,379,15434,0.039,2.5
2023-09-27 17:03:23.056176622,nda9,0,573,184,5703,0.122,388,15434,0.039,2.6
2023-09-27 17:03:23.056176622,nda10,0,570,133,4094,0.159,437,17816,0.039,2.8
2023-09-27 17:03:23.056176622,nda11,0,575,140,4344,0.158,435,17816,0.038,2.7

Examples of changes (nda4 line):

  • read: 0.1 -> 0.148
  • write: 0.0 -> 0.040
mizhka retitled this revision from usr.sbin/gstat: add microsecond resolution to usr.sbin/gstat: add microsecond precision for disk latency .Sep 28 2023, 11:22 AM

I will appreciate any review.
If no objectives, I would like to commit this patch.

Seems interesting. No brainer yes(with the one tweak i have) for csv. How is the visual display affected?

usr.sbin/gstat/gstat.c
414

Why not do this all the time? Or at least make the cut off 10ms so you always get at least 3 significant digits?

In D41999#966679, @imp wrote:

Seems interesting. No brainer yes(with the one tweak i have) for csv. How is the visual display affected?

Before:

dT: 1.065s  w: 1.000s
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w   %busy Name
    0    922      0      0    0.0    922  35809    0.0    2.8| nda0
    0    928      2     34    0.1    926  35809    0.0    3.1| nda1
    0    695      2     60    0.2    693  29502    0.0    2.2| nda2
    0    676      2     60    0.2    674  29502    0.0    2.3| nda3
    0   1067      3     64    0.1   1064  40046    0.0    3.1| nda4
    0   1072      2     60    0.1   1071  40046    0.0    2.8| nda5
    0   1060      4    120    0.1   1056  45076    0.1    3.8| nda6
    0   1094      1     30    0.2   1093  45076    0.0    3.3| nda7

After:

dT: 1.016s  w: 1.000s
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w   %busy Name
    0    496      1     31  0.156    495  16020  0.040    1.5| nda0
    0    492      0      0  0.000    492  16020  0.042    1.5| nda1
    0    449      1     31  0.104    448  13895  0.039    1.3| nda2
    0    450      1     31  0.155    449  13895  0.043    1.4| nda3
    0    723      1     31  0.091    722  23056  0.039    2.0| nda4
    0    733      2      8  0.089    731  23056  0.033    1.8| nda5
    0    739      1     31  0.114    738  29785  0.052    2.6| nda6
    0    822      2     63  0.157    820  29785  0.040    2.4| nda7

Patch updated: removed "unexpected" comma

I'm not seeing anything wrong with this one.
I could make some suggestions for having a function to return the format... But it wouldn't save that much...

This revision is now accepted and ready to land.Aug 3 2024, 4:38 AM

Were you planning on committing this s
?

Thank you for review. Landed in -current & planned MFC