6

I run a SPECJbb benchmark in my KVM virtual machine. It shows a drastic drop on throughput between Warehouse 2 and Warehouse 3(The different between them is just addding on cocurrent task)

Then I use perf in my guest virtual machine. It shows that _spin_unlock_irqrestore has very high sampling rate.

Events: 31K cycles

  • 74.89% [kernel] [k] _spin_unlock_irqrestore

  • 7.36% perf-1968.map [.] 0x7f84b913e064

  • 6.82% [kernel] [k] __do_softirq

  • 6.39% [kernel] [k] handle_IRQ_event

...

It seems that only 7.36% cpu time running my Java program. Why _spin_unlock_irqrestore's sampling rate is so high? And what does it do?

Sili
  • 927
  • 1
  • 12
  • 17

1 Answers1

10

It's bad reporting by perf, not cycles consumed by _spin_unlock_irqrestore.

When IRQs are disabled, perf's interrupts are not processed. Instead, they're processed when interrupts are re-enabled. When perf's interrupt handler looks at the instruction pointer, to see what code was running, it finds the function that enabled interrupts - quite often it's _spin_unlock_irqrestore.

So all you know is that the cycles were consumed by code that had interrupts disabled, and enabled them using _spin_unlock_irqrestore.

If you can get perf to use NMI (non maskable interrupt), it could solve this problem.
I know that it can be done with oprofile (perf's predecessor) by changing the makefile, but don't know about perf.

ugoren
  • 16,023
  • 3
  • 35
  • 65
  • Thanks for your answer. Could you give me some more explain about why IRQ disabled time is so long? Is that because I run it in kvm? Thanks! – Sili Feb 07 '13 at 03:12