• Stewart Smith's avatar
    Add --trace support (in blktrace format) · e50e654b
    Stewart Smith authored
    In an effort understand what PNOR requests come from the host, it'd be
    good to be able to trace what requests come in and visualise them.
    blktrace is some Linux infrastructure for tracing block device activity
    all the way through the linux block layer, for which there is a variety
    of existing tooling. These tools process the (typically) kernel produced
    blktrace output. We can produce this same output programatically from
    mboxd though.
    
    This patch gives us the (option) to start mboxd in a mode where it will
    write a blktrace file out, which can be fed into tools like blkparse(1)
    or tools like iowatcher[1] to generate charts (and video).
    
    A quirk of the blktrace format is that it's very geared towards a full
    IO subsystem, so we can't directly map window operations (what we know
    in mboxd) to specific IO ops (i.e. we don't get "firmware read one page
    out of this window before closing it"). So, for each Window opening (or
    reusing a cached one), we write THREE blktrace events: a Queue,
    Dispatch, and Complete.
    
    We can usk tools like blkparse to do everything from get a detailed list
    of what windows were opened and for how long:
    
      0,0    0        1     0.000000000     0  Q   R 0 + 8 [(null)]
      0,0    0        2     0.000000000     0  D   R 0 + 8 [(null)]
      0,0    0        3     0.000182022     0  C   R 0 + 8 [0]
      0,0    0        4     0.042416351     0  Q   R 4144 + 2040 [(null)]
      0,0    0        5     0.042416351     0  D   R 4144 + 2040 [(null)]
      0,0    0        6     0.060802662     0  C   R 4144 + 2040 [0]
      0,0    0        7     0.084775813     0  Q   R 64 + 288 [(null)]
      0,0    0        8     0.084775813     0  D   R 64 + 288 [(null)]
      0,0    0        9     0.087835720     0  C   R 64 + 288 [0]
      0,0    0       10     1.429234244     0  Q   R 8488 + 2048 [(null)]
    
    to getting a simple summary at the end of how many windows were opened
    read and read/write:
    
    CPU0 (0,0):
     Reads Queued:          90,   74,040KiB	 Writes Queued:           6,    2,664KiB
     Read Dispatches:       90,   74,040KiB	 Write Dispatches:        6,    2,664KiB
     Reads Requeued:         0		 Writes Requeued:         0
     Reads Completed:       90,   74,040KiB	 Writes Completed:        6,    2,664KiB
     Read Merges:            0,        0KiB	 Write Merges:            0,        0KiB
     Read depth:             1        	 Write depth:             1
     IO unplugs:             0        	 Timer unplugs:           0
    
    If you change the window size to something tiny, like 4096 bytes, you
    can get detailed paging information for hostboot at the expense of IPL
    time.
    
    Pretty graphs and animations:
    https://www.flamingspork.com/blog/?p=4419
    
    [1] iowatcher: http://masoncoding.com/iowatcher/
    
    Change-Id: I5dd02b6bc616c441abf54d87a5d67c972cbaf228
    Signed-off-by: default avatarStewart Smith <stewart@linux.ibm.com>
    [AJ: Resolve merge conflicts, some tidy ups]
    Signed-off-by: Andrew Jeffery's avatarAndrew Jeffery <andrew@aj.id.au>
    e50e654b
protocol.c 20.1 KB