Looking at TLB flushes with systemtap

Looking at TLB flushes with systemtap

[William Cohen]

I was working on generating some more useful scripts for SystemTap. The 
following is something written up for looking into the TLB invalidations. Any 
Feedback on it would be appreciated.

-Will


Watching TLB flushes

The Translation Look-aside Buffer (TLB) speed the translation of
virtual memory addresses to physical memory addresses. When the memory
map is changed the entries in the TLB many need to be removed
(flushed).  TLB flushes can be expensive operations on computer
systems because it may trigger interprocessors interrupts to clear out
similar entries on other processors and additional accesses to memory
to recompute mappings that were previously in the TLB.

The simple script at the end of this prints out the number of
different TLB flushes observed every 5 seconds. Some computer
architectures do not implement all forms of the TLB flush
operations. In these cases the TLB flush operation call a TLB flush
operation that is a superset of the desired flush. This may be
observed on i686/x86_64 machine where the flush_tlb_kernel_range
uses the flush_tlb_all.

The script also prints out a sorted list of showing the number times that a
particular systemcall for an executable makes a TLB flush. If the tlb
flush was due to something other than a systemcall, the word "kernel"
will be printed rather than the syscall operation.

When starting up qemu-kvm see that there are a number ioctl calls that
are causing tlb flushes on an x86_64 machine running Fedora 9:

tlb flush types

flush_tlb_all                        1731
flush_tlb_kernel_range               1731
flush_tlb_mm                          202
flush_tlb_page                        440
flush_tlb_range                        88


tlb flush syscall

qemu-kvm                                 ioctl       3462
redhat-ddns-cli                         kernel        188
crond                                   kernel        177
crond                                 mprotect         66
crond                                   munmap         53
wget                                  mprotect         44
sh                                      kernel         39
unix_chkpwd                           mprotect         26
qemu-kvm                                munmap         14
wget                                    kernel         12


On a Dell Inspiron 1420 laptop running Fedora 9 the TLB flush script
highlighted that the Hardware Abstraction Layer was polling to find
out the status of the wireless card with dellWirelessCtl and this
continual execution of dellWirelessCtl causes a number of TLB flushes:

tlb flush types

flush_tlb_mm                           87
flush_tlb_page                        210
flush_tlb_range                        35


tlb flush syscall

hal-system-kill                         kernel        162
hald-runner                             kernel         35
hal-system-kill                       mprotect         32
dellWirelessCtl                       mprotect         18
hal-is-caller-p                       mprotect         14
dellWirelessCtl                         munmap         11
hal-system-kill                         munmap         10
hald                                    munmap          9
basename                              mprotect          6
dellWirelessCtl                         kernel          5


The tlb_flush script:



probe begin { printf("Starting probe ... hit control-c to exit\n") }

global flush_tlb_type, flush_tlb_sys, in_syscall

probe syscall.* { in_syscall[tid()]=name }
probe syscall.*.return { delete in_syscall[tid()] }

probe kernel.function("flush_tlb*")
{
	t=tid(); e=execname()
	sys=in_syscall[t]
	if (sys=="") sys="kernel"
	flush_tlb_type[probefunc()] <<< 1
	flush_tlb_sys[e, sys] <<< 1
}

probe end, timer.s(5)
{
	printf("\ntlb flush types\n\n")
	foreach(t+ in flush_tlb_type) {
		printf( "%-30s %10d\n", t,
			@sum(flush_tlb_type[t]))
	}
	printf("\n\ntlb flush syscall\n\n")
	foreach([t,s] in flush_tlb_sys- limit 10) {
		printf( "%-30s %15s %10d\n", t, s,
			@sum(flush_tlb_sys[t,s]))
	}
	delete flush_tlb_type
	delete flush_tlb_sys
}