On Tue, Jan 17, 2017 at 6:38 PM, Sagi Grimberg [off-list ref] wrote:

Hey, so I made some initial analysis of whats going on with
irq-poll.

First, I sampled how much time it takes before we
get the interrupt in nvme_irq and the initial visit
to nvme_irqpoll_handler. I ran a single threaded fio
with QD=32 of 4K reads. This is two displays of a
histogram of the latency (ns):
--
[1]
queue = b'nvme0q1'
     usecs               : count     distribution
         0 -> 1          : 7310 |****************************************|
         2 -> 3          : 11       |      |
         4 -> 7          : 10       |      |
         8 -> 15         : 20       |      |
        16 -> 31         : 0        |      |
        32 -> 63         : 0        |      |
        64 -> 127        : 1        |      |

[2]
queue = b'nvme0q1'
     usecs               : count     distribution
         0 -> 1          : 7309 |****************************************|
         2 -> 3          : 14       |      |
         4 -> 7          : 7        |      |
         8 -> 15         : 17       |      |

We can see that most of the time our latency is pretty good (<1ns) but with
huge tail latencies (some 8-15 ns and even one in 32-63 ns).
**NOTE, in order to reduce the tracing impact on performance I sampled
for every 100 interrupts.

I also sampled for a multiple threads/queues with QD=32 of 4K reads.
This is a collection of histograms for 5 queues (5 fio threads):
queue = b'nvme0q1'
     usecs               : count     distribution
         0 -> 1          : 701 |****************************************|
         2 -> 3          : 177      |**********      |
         4 -> 7          : 56       |***      |
         8 -> 15         : 24       |*      |
        16 -> 31         : 6        |      |
        32 -> 63         : 1        |      |

queue = b'nvme0q2'
     usecs               : count     distribution
         0 -> 1          : 412 |****************************************|
         2 -> 3          : 52       |*****      |
         4 -> 7          : 19       |*      |
         8 -> 15         : 13       |*      |
        16 -> 31         : 5        |      |

queue = b'nvme0q3'
     usecs               : count     distribution
         0 -> 1          : 381 |****************************************|
         2 -> 3          : 74       |*******      |
         4 -> 7          : 26       |**      |
         8 -> 15         : 12       |*      |
        16 -> 31         : 3        |      |
        32 -> 63         : 0        |      |
        64 -> 127        : 0        |      |
       128 -> 255        : 1        |      |

queue = b'nvme0q4'
     usecs               : count     distribution
         0 -> 1          : 386 |****************************************|
         2 -> 3          : 63       |******      |
         4 -> 7          : 30       |***      |
         8 -> 15         : 11       |*      |
        16 -> 31         : 7        |      |
        32 -> 63         : 1        |      |

queue = b'nvme0q5'
     usecs               : count     distribution
         0 -> 1          : 384 |****************************************|
         2 -> 3          : 69       |*******      |
         4 -> 7          : 25       |**      |
         8 -> 15         : 15       |*      |
        16 -> 31         : 3        |      |

Overall looks pretty much the same but some more samples with tails...

Next, I sampled how many completions we are able to consume per interrupt.
Two exaples of histograms of how many completions we take per interrupt.
--
queue = b'nvme0q1'
     completed     : count     distribution
        0          : 0        |                                        |
        1          : 11690    |****************************************|
        2          : 46       |                                        |
        3          : 1        |                                        |

queue = b'nvme0q1'
     completed     : count     distribution
        0          : 0        |                                        |
        1          : 944      |****************************************|
        2          : 8        |                                        |
--

So it looks like we are super not efficient because most of the times we
catch 1
completion per interrupt and the whole point is that we need to find more!
This fio
is single threaded with QD=32 so I'd expect that we be somewhere in 8-31
almost all
the time... I also tried QD=1024, histogram is still the same.

It looks like it takes you longer to submit an I/O than to service an
interrupt, so increasing queue depth in the singe-threaded case doesn't
make much difference. You might want to try multiple threads per core with
QD, say, 32 (but beware that Intel limits the aggregate queue depth to 256
and even 128 for some models).

Regards,
Andrey

**NOTE: Here I also sampled for every 100 interrupts.


I'll try to run the counter on the current nvme driver and see what I get.



I attached the bpf scripts I wrote (nvme-trace-irq, nvme-count-comps)
with hope that someone is interested enough to try and reproduce these
numbers on his/hers setup and maybe suggest some other useful tracing
we can do.

Prerequisites:
1. iovisor is needed for python bpf support.
  $ echo "deb [trusted=yes] https://repo.iovisor.org/apt/xenial
xenial-nightly main" | sudo tee /etc/apt/sources.list.d/iovisor.list
  $ sudo apt-get update -y
  $ sudo apt-get install bcc-tools -y
  # Nastty hack .. bcc only available in python2 but copliant with
python3..
  $ sudo cp -r /usr/lib/python2.7/dist-packages/bcc
/usr/lib/python3/dist-packages/

2. Because we don't have the nvme-pci symbols exported, The nvme.h file is
needed on the
   test machine (where the bpf code is running). I used nfs mount for the
linux source (this
   is why I include from /mnt/linux in the scripts).


_______________________________________________
Linux-nvme mailing list
Linux-nvme@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-nvme