User: Password:
|
|
Subscribe / Log in / New account

ip_queue_xmit(): Re: [Bug #11308] tbench regression on each kernel release from 2.6.22 -> 2.6.28

From:  Ingo Molnar <mingo-X9Un+BFzKDI-AT-public.gmane.org>
To:  Linus Torvalds <torvalds-de/tnXTf+JLsfHDXvbKv3WD2FQJk+8+b-AT-public.gmane.org>
Subject:  ip_queue_xmit(): Re: [Bug #11308] tbench regression on each kernel release from 2.6.22 -&gt; 2.6.28
Date:  Mon, 17 Nov 2008 21:32:19 +0100
Cc:  Eric Dumazet <dada1-fPLkHRcR87vqlBn2x/YWAg-AT-public.gmane.org>, David Miller <davem-fT/PcQaiUtIeIZ0/mPfg9Q-AT-public.gmane.org>, rjw-KKrjLPT3xs0-AT-public.gmane.org, linux-kernel-u79uwXL29TY76Z2rM5mHXA-AT-public.gmane.org, kernel-testers-u79uwXL29TY76Z2rM5mHXA-AT-public.gmane.org, cl-de/tnXTf+JLsfHDXvbKv3WD2FQJk+8+b-AT-public.gmane.org, efault-Mmb7MZpHnFY-AT-public.gmane.org, a.p.zijlstra-/NLkJaSkS4VmR6Xm/wNWPw-AT-public.gmane.org, Stephen Hemminger <shemminger-ZtmgI6mnKB3QT0dZR+AlfA-AT-public.gmane.org>


* Ingo Molnar <mingo-X9Un+BFzKDI@public.gmane.org> wrote:

> 100.000000 total
> ................
>   3.356152 ip_queue_xmit

                      hits (335615 total)
                 .........
ffffffff804b7045:     1001 <ip_queue_xmit>:
ffffffff804b7045:     1001 	41 57                	push   %r15
ffffffff804b7047:    36698 	41 56                	push   %r14
ffffffff804b7049:        0 	49 89 fe             	mov    %rdi,%r14
ffffffff804b704c:        0 	41 55                	push   %r13
ffffffff804b704e:      447 	41 54                	push   %r12
ffffffff804b7050:        0 	55                   	push   %rbp
ffffffff804b7051:        4 	53                   	push   %rbx
ffffffff804b7052:      465 	48 83 ec 68          	sub    $0x68,%rsp
ffffffff804b7056:        1 	89 74 24 08          	mov    %esi,0x8(%rsp)
ffffffff804b705a:      486 	48 8b 47 28          	mov    0x28(%rdi),%rax
ffffffff804b705e:        0 	48 8b 6f 10          	mov    0x10(%rdi),%rbp
ffffffff804b7062:        7 	48 85 c0             	test   %rax,%rax
ffffffff804b7065:      480 	48 89 44 24 58       	mov    %rax,0x58(%rsp)
ffffffff804b706a:        0 	4c 8b bd 48 02 00 00 	mov    0x248(%rbp),%r15
ffffffff804b7071:        7 	0f 85 0d 01 00 00    	jne    ffffffff804b7184 <ip_queue_xmit+0x13f>
ffffffff804b7077:      452 	31 f6                	xor    %esi,%esi
ffffffff804b7079:        0 	48 89 ef             	mov    %rbp,%rdi
ffffffff804b707c:        5 	e8 c1 eb fc ff       	callq  ffffffff80485c42 <__sk_dst_check>
ffffffff804b7081:      434 	48 85 c0             	test   %rax,%rax
ffffffff804b7084:       54 	48 89 44 24 58       	mov    %rax,0x58(%rsp)
ffffffff804b7089:        0 	0f 85 e0 00 00 00    	jne    ffffffff804b716f <ip_queue_xmit+0x12a>
ffffffff804b708f:        0 	4d 85 ff             	test   %r15,%r15
ffffffff804b7092:        0 	44 8b ad 30 02 00 00 	mov    0x230(%rbp),%r13d
ffffffff804b7099:        0 	74 0a                	je     ffffffff804b70a5 <ip_queue_xmit+0x60>
ffffffff804b709b:        0 	41 80 7f 05 00       	cmpb   $0x0,0x5(%r15)
ffffffff804b70a0:        0 	74 03                	je     ffffffff804b70a5 <ip_queue_xmit+0x60>
ffffffff804b70a2:        0 	45 8b 2f             	mov    (%r15),%r13d
ffffffff804b70a5:        0 	8b 85 3c 02 00 00    	mov    0x23c(%rbp),%eax
ffffffff804b70ab:        0 	48 8d b5 10 01 00 00 	lea    0x110(%rbp),%rsi
ffffffff804b70b2:        0 	44 8b 65 04          	mov    0x4(%rbp),%r12d
ffffffff804b70b6:        0 	bf 0d 00 00 00       	mov    $0xd,%edi
ffffffff804b70bb:        0 	89 44 24 0c          	mov    %eax,0xc(%rsp)
ffffffff804b70bf:        0 	8a 9d 54 02 00 00    	mov    0x254(%rbp),%bl
ffffffff804b70c5:        0 	e8 9a df ff ff       	callq  ffffffff804b5064 <constant_test_bit>
ffffffff804b70ca:        0 	31 d2                	xor    %edx,%edx
ffffffff804b70cc:        0 	48 8d 7c 24 10       	lea    0x10(%rsp),%rdi
ffffffff804b70d1:        0 	41 89 c3             	mov    %eax,%r11d
ffffffff804b70d4:        0 	fc                   	cld    
ffffffff804b70d5:        0 	89 d0                	mov    %edx,%eax
ffffffff804b70d7:        0 	b9 10 00 00 00       	mov    $0x10,%ecx
ffffffff804b70dc:        0 	44 8a 45 39          	mov    0x39(%rbp),%r8b
ffffffff804b70e0:        0 	40 8a b5 57 02 00 00 	mov    0x257(%rbp),%sil
ffffffff804b70e7:        0 	44 8b 8d 50 02 00 00 	mov    0x250(%rbp),%r9d
ffffffff804b70ee:        0 	83 e3 1e             	and    $0x1e,%ebx
ffffffff804b70f1:        0 	44 8b 95 38 02 00 00 	mov    0x238(%rbp),%r10d
ffffffff804b70f8:        0 	44 09 db             	or     %r11d,%ebx
ffffffff804b70fb:        0 	f3 ab                	rep stos %eax,%es:(%rdi)
ffffffff804b70fd:        0 	40 c0 ee 05          	shr    $0x5,%sil
ffffffff804b7101:        0 	88 5c 24 24          	mov    %bl,0x24(%rsp)
ffffffff804b7105:        0 	48 8d 5c 24 10       	lea    0x10(%rsp),%rbx
ffffffff804b710a:        0 	83 e6 01             	and    $0x1,%esi
ffffffff804b710d:        0 	48 89 ef             	mov    %rbp,%rdi
ffffffff804b7110:        0 	44 88 44 24 40       	mov    %r8b,0x40(%rsp)
ffffffff804b7115:        0 	8b 44 24 0c          	mov    0xc(%rsp),%eax
ffffffff804b7119:        0 	40 88 74 24 41       	mov    %sil,0x41(%rsp)
ffffffff804b711e:        0 	48 89 de             	mov    %rbx,%rsi
ffffffff804b7121:        0 	66 44 89 4c 24 44    	mov    %r9w,0x44(%rsp)
ffffffff804b7127:        0 	66 44 89 54 24 46    	mov    %r10w,0x46(%rsp)
ffffffff804b712d:        0 	44 89 64 24 10       	mov    %r12d,0x10(%rsp)
ffffffff804b7132:        0 	44 89 6c 24 1c       	mov    %r13d,0x1c(%rsp)
ffffffff804b7137:        0 	89 44 24 20          	mov    %eax,0x20(%rsp)
ffffffff804b713b:        0 	e8 2d 9f e5 ff       	callq  ffffffff8031106d
<security_sk_classify_flow>
ffffffff804b7140:        0 	48 8d 74 24 58       	lea    0x58(%rsp),%rsi
ffffffff804b7145:        0 	45 31 c0             	xor    %r8d,%r8d
ffffffff804b7148:        0 	48 89 e9             	mov    %rbp,%rcx
ffffffff804b714b:        0 	48 89 da             	mov    %rbx,%rdx
ffffffff804b714e:        0 	48 c7 c7 d0 15 ab 80 	mov    $0xffffffff80ab15d0,%rdi
ffffffff804b7155:        0 	e8 1a 91 ff ff       	callq  ffffffff804b0274 <ip_route_output_flow>
ffffffff804b715a:        0 	85 c0                	test   %eax,%eax
ffffffff804b715c:        0 	0f 85 9f 01 00 00    	jne    ffffffff804b7301 <ip_queue_xmit+0x2bc>
ffffffff804b7162:        0 	48 8b 74 24 58       	mov    0x58(%rsp),%rsi
ffffffff804b7167:        0 	48 89 ef             	mov    %rbp,%rdi
ffffffff804b716a:        0 	e8 a8 eb fc ff       	callq  ffffffff80485d17 <sk_setup_caps>
ffffffff804b716f:      441 	48 8b 44 24 58       	mov    0x58(%rsp),%rax
ffffffff804b7174:     1388 	48 85 c0             	test   %rax,%rax
ffffffff804b7177:        0 	74 07                	je     ffffffff804b7180 <ip_queue_xmit+0x13b>
ffffffff804b7179:        0 	f0 ff 80 b0 00 00 00 	lock incl 0xb0(%rax)
ffffffff804b7180:      556 	49 89 46 28          	mov    %rax,0x28(%r14)
ffffffff804b7184:     8351 	4d 85 ff             	test   %r15,%r15
ffffffff804b7187:        0 	be 14 00 00 00       	mov    $0x14,%esi
ffffffff804b718c:      461 	74 26                	je     ffffffff804b71b4 <ip_queue_xmit+0x16f>
ffffffff804b718e:        0 	41 f6 47 08 01       	testb  $0x1,0x8(%r15)
ffffffff804b7193:        0 	74 17                	je     ffffffff804b71ac <ip_queue_xmit+0x167>
ffffffff804b7195:        0 	48 8b 54 24 58       	mov    0x58(%rsp),%rdx
ffffffff804b719a:        0 	8b 82 28 01 00 00    	mov    0x128(%rdx),%eax
ffffffff804b71a0:        0 	39 82 1c 01 00 00    	cmp    %eax,0x11c(%rdx)
ffffffff804b71a6:        0 	0f 85 55 01 00 00    	jne    ffffffff804b7301 <ip_queue_xmit+0x2bc>
ffffffff804b71ac:        0 	41 0f b6 47 04       	movzbl 0x4(%r15),%eax
ffffffff804b71b1:        0 	8d 70 14             	lea    0x14(%rax),%esi
ffffffff804b71b4:       39 	4c 89 f7             	mov    %r14,%rdi
ffffffff804b71b7:      493 	e8 f8 18 fd ff       	callq  ffffffff80488ab4 <skb_push>
ffffffff804b71bc:        0 	4c 89 f7             	mov    %r14,%rdi
ffffffff804b71bf:     1701 	e8 99 df ff ff       	callq  ffffffff804b515d
<skb_reset_network_header>
ffffffff804b71c4:      481 	0f b6 85 54 02 00 00 	movzbl 0x254(%rbp),%eax
ffffffff804b71cb:     4202 	41 8b 9e bc 00 00 00 	mov    0xbc(%r14),%ebx
ffffffff804b71d2:        3 	48 89 ef             	mov    %rbp,%rdi
ffffffff804b71d5:        0 	49 03 9e d0 00 00 00 	add    0xd0(%r14),%rbx
ffffffff804b71dc:      466 	80 cc 45             	or     $0x45,%ah
ffffffff804b71df:        7 	66 c1 c0 08          	rol    $0x8,%ax
ffffffff804b71e3:        0 	66 89 03             	mov    %ax,(%rbx)
ffffffff804b71e6:      492 	48 8b 74 24 58       	mov    0x58(%rsp),%rsi
ffffffff804b71eb:        3 	e8 a0 df ff ff       	callq  ffffffff804b5190 <ip_dont_fragment>
ffffffff804b71f0:     1405 	85 c0                	test   %eax,%eax
ffffffff804b71f2:     4391 	74 0f                	je     ffffffff804b7203 <ip_queue_xmit+0x1be>
ffffffff804b71f4:        0 	83 7c 24 08 00       	cmpl   $0x0,0x8(%rsp)
ffffffff804b71f9:      417 	75 08                	jne    ffffffff804b7203 <ip_queue_xmit+0x1be>
ffffffff804b71fb:      503 	66 c7 43 06 40 00    	movw   $0x40,0x6(%rbx)
ffffffff804b7201:     6743 	eb 06                	jmp    ffffffff804b7209 <ip_queue_xmit+0x1c4>
ffffffff804b7203:        0 	66 c7 43 06 00 00    	movw   $0x0,0x6(%rbx)
ffffffff804b7209:      118 	0f bf 85 40 02 00 00 	movswl 0x240(%rbp),%eax
ffffffff804b7210:    10867 	48 8b 54 24 58       	mov    0x58(%rsp),%rdx
ffffffff804b7215:      340 	85 c0                	test   %eax,%eax
ffffffff804b7217:        0 	79 06                	jns    ffffffff804b721f <ip_queue_xmit+0x1da>
ffffffff804b7219:   107464 	8b 82 9c 00 00 00    	mov    0x9c(%rdx),%eax
ffffffff804b721f:     4963 	88 43 08             	mov    %al,0x8(%rbx)
ffffffff804b7222:    26297 	8a 45 39             	mov    0x39(%rbp),%al
ffffffff804b7225:    76658 	4d 85 ff             	test   %r15,%r15
ffffffff804b7228:     1712 	88 43 09             	mov    %al,0x9(%rbx)
ffffffff804b722b:      148 	48 8b 44 24 58       	mov    0x58(%rsp),%rax
ffffffff804b7230:     2971 	8b 80 20 01 00 00    	mov    0x120(%rax),%eax
ffffffff804b7236:    14849 	89 43 0c             	mov    %eax,0xc(%rbx)
ffffffff804b7239:       84 	48 8b 44 24 58       	mov    0x58(%rsp),%rax
ffffffff804b723e:      360 	8b 80 1c 01 00 00    	mov    0x11c(%rax),%eax
ffffffff804b7244:      174 	89 43 10             	mov    %eax,0x10(%rbx)
ffffffff804b7247:       96 	74 32                	je     ffffffff804b727b <ip_queue_xmit+0x236>
ffffffff804b7249:        0 	41 8a 57 04          	mov    0x4(%r15),%dl
ffffffff804b724d:        0 	84 d2                	test   %dl,%dl
ffffffff804b724f:        0 	74 2a                	je     ffffffff804b727b <ip_queue_xmit+0x236>
ffffffff804b7251:        0 	c0 ea 02             	shr    $0x2,%dl
ffffffff804b7254:        0 	03 13                	add    (%rbx),%edx
ffffffff804b7256:        0 	8a 03                	mov    (%rbx),%al
ffffffff804b7258:        0 	45 31 c0             	xor    %r8d,%r8d
ffffffff804b725b:        0 	4c 89 fe             	mov    %r15,%rsi
ffffffff804b725e:        0 	4c 89 f7             	mov    %r14,%rdi
ffffffff804b7261:        0 	83 e0 f0             	and    $0xfffffffffffffff0,%eax
ffffffff804b7264:        0 	83 e2 0f             	and    $0xf,%edx
ffffffff804b7267:        0 	09 d0                	or     %edx,%eax
ffffffff804b7269:        0 	88 03                	mov    %al,(%rbx)
ffffffff804b726b:        0 	48 8b 4c 24 58       	mov    0x58(%rsp),%rcx
ffffffff804b7270:        0 	8b 95 30 02 00 00    	mov    0x230(%rbp),%edx
ffffffff804b7276:        0 	e8 e4 d8 ff ff       	callq  ffffffff804b4b5f <ip_options_build>
ffffffff804b727b:      541 	41 8b 86 c8 00 00 00 	mov    0xc8(%r14),%eax
ffffffff804b7282:      570 	31 d2                	xor    %edx,%edx
ffffffff804b7284:        0 	49 03 86 d0 00 00 00 	add    0xd0(%r14),%rax
ffffffff804b728b:       34 	8b 40 08             	mov    0x8(%rax),%eax
ffffffff804b728e:      496 	66 85 c0             	test   %ax,%ax
ffffffff804b7291:       11 	74 06                	je     ffffffff804b7299 <ip_queue_xmit+0x254>
ffffffff804b7293:        9 	0f b7 c0             	movzwl %ax,%eax
ffffffff804b7296:      495 	8d 50 ff             	lea    -0x1(%rax),%edx
ffffffff804b7299:        2 	f6 43 06 40          	testb  $0x40,0x6(%rbx)
ffffffff804b729d:        9 	48 8b 74 24 58       	mov    0x58(%rsp),%rsi
ffffffff804b72a2:      497 	74 34                	je     ffffffff804b72d8 <ip_queue_xmit+0x293>
ffffffff804b72a4:        8 	83 bd 30 02 00 00 00 	cmpl   $0x0,0x230(%rbp)
ffffffff804b72ab:       10 	74 23                	je     ffffffff804b72d0 <ip_queue_xmit+0x28b>
ffffffff804b72ad:     1044 	66 8b 85 52 02 00 00 	mov    0x252(%rbp),%ax
ffffffff804b72b4:        7 	66 c1 c0 08          	rol    $0x8,%ax
ffffffff804b72b8:        8 	66 89 43 04          	mov    %ax,0x4(%rbx)
ffffffff804b72bc:      432 	66 8b 85 52 02 00 00 	mov    0x252(%rbp),%ax
ffffffff804b72c3:        9 	ff c0                	inc    %eax
ffffffff804b72c5:       14 	01 d0                	add    %edx,%eax
ffffffff804b72c7:     1141 	66 89 85 52 02 00 00 	mov    %ax,0x252(%rbp)
ffffffff804b72ce:        7 	eb 10                	jmp    ffffffff804b72e0 <ip_queue_xmit+0x29b>
ffffffff804b72d0:        0 	66 c7 43 04 00 00    	movw   $0x0,0x4(%rbx)
ffffffff804b72d6:        0 	eb 08                	jmp    ffffffff804b72e0 <ip_queue_xmit+0x29b>
ffffffff804b72d8:        0 	48 89 df             	mov    %rbx,%rdi
ffffffff804b72db:        0 	e8 b7 9d ff ff       	callq  ffffffff804b1097 <__ip_select_ident>
ffffffff804b72e0:        6 	8b 85 54 01 00 00    	mov    0x154(%rbp),%eax
ffffffff804b72e6:      458 	4c 89 f7             	mov    %r14,%rdi
ffffffff804b72e9:        2 	41 89 46 78          	mov    %eax,0x78(%r14)
ffffffff804b72ed:        4 	8b 85 f0 01 00 00    	mov    0x1f0(%rbp),%eax
ffffffff804b72f3:      841 	41 89 86 b0 00 00 00 	mov    %eax,0xb0(%r14)
ffffffff804b72fa:       11 	e8 30 f2 ff ff       	callq  ffffffff804b652f <ip_local_out>
ffffffff804b72ff:        0 	eb 44                	jmp    ffffffff804b7345 <ip_queue_xmit+0x300>
ffffffff804b7301:        0 	65 48 8b 04 25 10 00 	mov    %gs:0x10,%rax
ffffffff804b7308:        0 	00 00 
ffffffff804b730a:        0 	8b 80 48 e0 ff ff    	mov    -0x1fb8(%rax),%eax
ffffffff804b7310:        0 	4c 89 f7             	mov    %r14,%rdi
ffffffff804b7313:        0 	30 c0                	xor    %al,%al
ffffffff804b7315:        0 	66 83 f8 01          	cmp    $0x1,%ax
ffffffff804b7319:        0 	48 19 c0             	sbb    %rax,%rax
ffffffff804b731c:        0 	83 e0 08             	and    $0x8,%eax
ffffffff804b731f:        0 	48 8b 90 a8 16 ab 80 	mov    -0x7f54e958(%rax),%rdx
ffffffff804b7326:        0 	65 8b 04 25 24 00 00 	mov    %gs:0x24,%eax
ffffffff804b732d:        0 	00 
ffffffff804b732e:        0 	89 c0                	mov    %eax,%eax
ffffffff804b7330:        0 	48 f7 d2             	not    %rdx
ffffffff804b7333:        0 	48 8b 04 c2          	mov    (%rdx,%rax,8),%rax
ffffffff804b7337:        0 	48 ff 40 68          	incq   0x68(%rax)
ffffffff804b733b:        0 	e8 b1 18 fd ff       	callq  ffffffff80488bf1 <kfree_skb>
ffffffff804b7340:        0 	b8 8f ff ff ff       	mov    $0xffffff8f,%eax
ffffffff804b7345:     9196 	48 83 c4 68          	add    $0x68,%rsp
ffffffff804b7349:      892 	5b                   	pop    %rbx
ffffffff804b734a:        0 	5d                   	pop    %rbp
ffffffff804b734b:      488 	41 5c                	pop    %r12
ffffffff804b734d:        0 	41 5d                	pop    %r13
ffffffff804b734f:        0 	41 5e                	pop    %r14
ffffffff804b7351:      513 	41 5f                	pop    %r15
ffffffff804b7353:        0 	c3                   	retq   

about 10% of this function's cost is artificial:

ffffffff804b7045:     1001 <ip_queue_xmit>:
ffffffff804b7045:     1001 	41 57                	push   %r15
ffffffff804b7047:    36698 	41 56                	push   %r14

there are profiler hits that leaked in via out-of-order execution from 
the callsites. The callsites are hard to map unfortunately, as this 
function is called via function pointers.

the most likely callsite is tcp_transmit_skb().

30% of the overhead of this function comes from:

ffffffff804b7203:        0 	66 c7 43 06 00 00    	movw   $0x0,0x6(%rbx)
ffffffff804b7209:      118 	0f bf 85 40 02 00 00 	movswl 0x240(%rbp),%eax
ffffffff804b7210:    10867 	48 8b 54 24 58       	mov    0x58(%rsp),%rdx
ffffffff804b7215:      340 	85 c0                	test   %eax,%eax
ffffffff804b7217:        0 	79 06                	jns    ffffffff804b721f <ip_queue_xmit+0x1da>
ffffffff804b7219:   107464 	8b 82 9c 00 00 00    	mov    0x9c(%rdx),%eax
ffffffff804b721f:     4963 	88 43 08             	mov    %al,0x8(%rbx)

the 16-bit movw looks a bit weird. It comes from line 372:

 0xffffffff804b7203 is in ip_queue_xmit (net/ipv4/ip_output.c:372).
 367		iph = ip_hdr(skb);
 368		*((__be16 *)iph) = htons((4 << 12) | (5 << 8) | (inet->tos & 0xff));
 369		if (ip_dont_fragment(sk, &rt->u.dst) && !ipfragok)
 370			iph->frag_off = htons(IP_DF);
 371		else
 372			iph->frag_off = 0;
 373		iph->ttl      = ip_select_ttl(inet, &rt->u.dst);
 374		iph->protocol = sk->sk_protocol;
 375		iph->saddr    = rt->rt_src;
 376		iph->daddr    = rt->rt_dst;

the ip-header fragment flag setting to zero.

16-bit ops are an on-off love/hate affair on x86 CPUs. The trend is 
towards eliminating them as much as possible.

_But_, the real overhead probably comes from:

 ffffffff804b7210:    10867 	48 8b 54 24 58       	mov    0x58(%rsp),%rdx

which is the next line, the ttl field:

 373             iph->ttl      = ip_select_ttl(inet, &rt->u.dst);

this shows that we are doing a hard cachemiss on the net-localhost 
route dst structure cacheline. We do a plain load instruction from it 
here and get a hefty cachemiss. (because 16 CPUs are banging on that 
single route)

And let make sure we see this in perspective as well: that single 
cachemiss is _1.0 percent_ of the total tbench cost. (!) We could make 
the scheduler 10% slower straight away and it would have less of a 
real-life effect than this single iph->ttl field setting.

	Ingo


(Log in to post comments)


Copyright © 2008, Eklektix, Inc.
Comments and public postings are copyrighted by their creators.
Linux is a registered trademark of Linus Torvalds