* Does perf-annotate work correctly?
@ 2017-09-12 10:10 Du, Changbin
2017-09-12 14:33 ` Arnaldo Carvalho de Melo
0 siblings, 1 reply; 11+ messages in thread
From: Du, Changbin @ 2017-09-12 10:10 UTC (permalink / raw)
To: peterz, mingo, acme, alexander.shishkin, linux-kernel; +Cc: changbin.du
[-- Attachment #1: Type: text/plain, Size: 6207 bytes --]
When a annotate a symbol, I find the annotated C source code doesn't match assembly code.
So I cannot determine which line of C code has much overhead withou gdb's help.
Here is a example result of function apic_has_interrupt_for_ppr() in kvm module.
│580 __clear_bit(KVM_APIC_PV_EOI_PENDING, &vcpu->arch.apic_attention); ▒
│581 } ▒
│ ▒
│583 static int apic_has_interrupt_for_ppr(struct kvm_lapic *apic, u32 ppr) ▒
│584 { ▒
0.88 │30: cmpb $0x0,0x91(%rdi) ▒
2.54 │ ↓ je 63 ▒
0.20 │ mov 0xa0(%rdi),%rcx ▒
│581 int highest_irr; ▒
│582 if (kvm_x86_ops->sync_pir_to_irr && apic->vcpu->arch.apicv_active) ▒
4.91 │ mov $0xe0,%eax x ▒
1.46 │45: mov %eax,%edx x ▒
0.02 │ sar $0x5,%edx x ▒
3.57 │ shl $0x4,%edx x ▒
3.34 │ movslq %edx,%rdx x ▒
1.25 │ mov 0x200(%rcx,%rdx,1),%edx x ▒
42.44 │ test %edx,%edx x ▒
0.01 │ ┌──jne 88 x ▒
3.48 │ │ sub $0x20,%eax x ▒
2.24 │ │ cmp $0xffffffe0,%eax x ▒
│586│apic_find_highest_irr(): ▒
│ │ ▒
│407│ /* ▒
│408│ * Note that irr_pending is just a hint. It will be always ▒
│409│ * true with virtual interrupt delivery enabled. ▒
│410│ */ ▒
│411│ if (!apic->irr_pending) ▒
│ │↑ jne 45 ▒
0.62 │63:│ mov $0xffffffff,%eax ◆
0.83 │ │ leaveq ▒
13.52 │ │← retq ▒
│6a:│ mov %esi,-0x4(%rbp) ▒
│ │ mov %rdx,%rdi ▒
│418│find_highest_vector(): ▒
│340│static int find_highest_vector(void *bitmap) ▒
│341│{ ▒
│342│ int vec; ▒
│343│ u32 *reg; ▒
│ │ ▒
│345│ for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG; ▒
│ │→ callq *%rax ▒
│ │ mov -0x4(%rbp),%esi ▒
│343│ vec >= 0; vec -= APIC_VECTORS_PER_REG) { ▒
│344│ reg = bitmap + REG_POS(vec); ▒
│345│ if (*reg) ▒
0.05 │75:│ cmp $0xffffffff,%eax ▒
│ │↑ je 63 ▒
1.95 │ │ mov %eax,%edx ▒
1.45 │ │ and $0xf0,%edx
Look at the assembly code block where I have put a 'x' on the right. Apparently the
assembly code doesn't match the C source code arrounded. Let's look the correct disassemble
result from gdb:
340 for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG;
0x000000000003b4e0 <+64>: mov $0xe0,%eax
342 reg = bitmap + REG_POS(vec);
343 if (*reg)
0x000000000003b4e5 <+69>: mov %eax,%edx
0x000000000003b4e7 <+71>: sar $0x5,%edx
0x000000000003b4ea <+74>: shl $0x4,%edx
0x000000000003b4ed <+77>: movslq %edx,%rdx
0x000000000003b4f0 <+80>: mov 0x200(%rcx,%rdx,1),%edx
0x000000000003b4f7 <+87>: test %edx,%edx
0x000000000003b4f9 <+89>: jne 0x3b528 <apic_has_interrupt_for_ppr+136>
341 vec >= 0; vec -= APIC_VECTORS_PER_REG) {
0x000000000003b4fb <+91>: sub $0x20,%eax
340 for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG;
0x000000000003b4fe <+94>: cmp $0xffffffe0,%eax
0x000000000003b501 <+97>: jne 0x3b4e5 <apic_has_interrupt_for_ppr+69>
Compared to gdb, perf-annoate has messed up. is it a bug or just perf is not as perfect as gdb?
--
Thanks,
Changbin Du
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 473 bytes --]
^ permalink raw reply [flat|nested] 11+ messages in thread* Re: Does perf-annotate work correctly? 2017-09-12 10:10 Does perf-annotate work correctly? Du, Changbin @ 2017-09-12 14:33 ` Arnaldo Carvalho de Melo 2017-09-13 1:54 ` Du, Changbin 2017-09-13 9:14 ` Du, Changbin 0 siblings, 2 replies; 11+ messages in thread From: Arnaldo Carvalho de Melo @ 2017-09-12 14:33 UTC (permalink / raw) To: Du, Changbin; +Cc: peterz, mingo, alexander.shishkin, linux-kernel Em Tue, Sep 12, 2017 at 06:10:35PM +0800, Du, Changbin escreveu: > When a annotate a symbol, I find the annotated C source code doesn't match assembly code. > So I cannot determine which line of C code has much overhead withou gdb's help. > > Here is a example result of function apic_has_interrupt_for_ppr() in kvm module. Ok, was this using the module .ko file or /proc/kcore? You forgot to cut'n'paste the first line on the screen. Also, how did you use gdb? perf uses objdump to do the disassembly, and depending on how it is used (live system, post processing on a different machine, permissions) it may use different files to do the disassembly. Please provide more detailed information on the exact command line arguments and usage scenario. - Arnaldo > │580 __clear_bit(KVM_APIC_PV_EOI_PENDING, &vcpu->arch.apic_attention); ▒ > │581 } ▒ > │ ▒ > │583 static int apic_has_interrupt_for_ppr(struct kvm_lapic *apic, u32 ppr) ▒ > │584 { ▒ > 0.88 │30: cmpb $0x0,0x91(%rdi) ▒ > 2.54 │ ↓ je 63 ▒ > 0.20 │ mov 0xa0(%rdi),%rcx ▒ > │581 int highest_irr; ▒ > │582 if (kvm_x86_ops->sync_pir_to_irr && apic->vcpu->arch.apicv_active) ▒ > 4.91 │ mov $0xe0,%eax x ▒ > 1.46 │45: mov %eax,%edx x ▒ > 0.02 │ sar $0x5,%edx x ▒ > 3.57 │ shl $0x4,%edx x ▒ > 3.34 │ movslq %edx,%rdx x ▒ > 1.25 │ mov 0x200(%rcx,%rdx,1),%edx x ▒ > 42.44 │ test %edx,%edx x ▒ > 0.01 │ ┌──jne 88 x ▒ > 3.48 │ │ sub $0x20,%eax x ▒ > 2.24 │ │ cmp $0xffffffe0,%eax x ▒ > │586│apic_find_highest_irr(): ▒ > │ │ ▒ > │407│ /* ▒ > │408│ * Note that irr_pending is just a hint. It will be always ▒ > │409│ * true with virtual interrupt delivery enabled. ▒ > │410│ */ ▒ > │411│ if (!apic->irr_pending) ▒ > │ │↑ jne 45 ▒ > 0.62 │63:│ mov $0xffffffff,%eax ◆ > 0.83 │ │ leaveq ▒ > 13.52 │ │← retq ▒ > │6a:│ mov %esi,-0x4(%rbp) ▒ > │ │ mov %rdx,%rdi ▒ > │418│find_highest_vector(): ▒ > │340│static int find_highest_vector(void *bitmap) ▒ > │341│{ ▒ > │342│ int vec; ▒ > │343│ u32 *reg; ▒ > │ │ ▒ > │345│ for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG; ▒ > │ │→ callq *%rax ▒ > │ │ mov -0x4(%rbp),%esi ▒ > │343│ vec >= 0; vec -= APIC_VECTORS_PER_REG) { ▒ > │344│ reg = bitmap + REG_POS(vec); ▒ > │345│ if (*reg) ▒ > 0.05 │75:│ cmp $0xffffffff,%eax ▒ > │ │↑ je 63 ▒ > 1.95 │ │ mov %eax,%edx ▒ > 1.45 │ │ and $0xf0,%edx > > > Look at the assembly code block where I have put a 'x' on the right. Apparently the > assembly code doesn't match the C source code arrounded. Let's look the correct disassemble > result from gdb: > > 340 for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG; > 0x000000000003b4e0 <+64>: mov $0xe0,%eax > > 342 reg = bitmap + REG_POS(vec); > 343 if (*reg) > 0x000000000003b4e5 <+69>: mov %eax,%edx > 0x000000000003b4e7 <+71>: sar $0x5,%edx > 0x000000000003b4ea <+74>: shl $0x4,%edx > 0x000000000003b4ed <+77>: movslq %edx,%rdx > 0x000000000003b4f0 <+80>: mov 0x200(%rcx,%rdx,1),%edx > 0x000000000003b4f7 <+87>: test %edx,%edx > 0x000000000003b4f9 <+89>: jne 0x3b528 <apic_has_interrupt_for_ppr+136> > > 341 vec >= 0; vec -= APIC_VECTORS_PER_REG) { > 0x000000000003b4fb <+91>: sub $0x20,%eax > > 340 for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG; > 0x000000000003b4fe <+94>: cmp $0xffffffe0,%eax > 0x000000000003b501 <+97>: jne 0x3b4e5 <apic_has_interrupt_for_ppr+69> > > > Compared to gdb, perf-annoate has messed up. is it a bug or just perf is not as perfect as gdb? > > -- > Thanks, > Changbin Du ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Does perf-annotate work correctly? 2017-09-12 14:33 ` Arnaldo Carvalho de Melo @ 2017-09-13 1:54 ` Du, Changbin 2017-09-26 6:06 ` Du, Changbin 2017-09-13 9:14 ` Du, Changbin 1 sibling, 1 reply; 11+ messages in thread From: Du, Changbin @ 2017-09-13 1:54 UTC (permalink / raw) To: Arnaldo Carvalho de Melo Cc: Du, Changbin, peterz, mingo, alexander.shishkin, linux-kernel [-- Attachment #1: Type: text/plain, Size: 9333 bytes --] On Tue, Sep 12, 2017 at 11:33:50AM -0300, Arnaldo Carvalho de Melo wrote: > Em Tue, Sep 12, 2017 at 06:10:35PM +0800, Du, Changbin escreveu: > > When a annotate a symbol, I find the annotated C source code doesn't match assembly code. > > So I cannot determine which line of C code has much overhead withou gdb's help. > > > > Here is a example result of function apic_has_interrupt_for_ppr() in kvm module. > > Ok, was this using the module .ko file or /proc/kcore? You forgot to > cut'n'paste the first line on the screen. > It is arch/x86/kvm/kvm.ko. > Also, how did you use gdb? > $ gdb arch/x86/kvm/kvm.ko $ (gdb) disassemble /s apic_has_interrupt_for_ppr > perf uses objdump to do the disassembly, and depending on how it is used > (live system, post processing on a different machine, permissions) it > may use different files to do the disassembly. > But objdump has same out as gdb. (Always on same machine, and no binary changed.) $ objdump -d -S arch/x86/kvm/kvm.o ... static int apic_has_interrupt_for_ppr(struct kvm_lapic *apic, u32 ppr) { 3b4a0: e8 00 00 00 00 callq 3b4a5 <apic_has_interrupt_for_ppr+0x5> 3b4a5: 55 push %rbp 3b4a6: 48 89 e5 mov %rsp,%rbp 3b4a9: 48 83 ec 08 sub $0x8,%rsp int highest_irr; if (kvm_x86_ops->sync_pir_to_irr && apic->vcpu->arch.apicv_active) 3b4ad: 48 8b 05 00 00 00 00 mov 0x0(%rip),%rax # 3b4b4 <apic_has_interrupt_for_ppr+0x14> 3b4b4: 48 8b 80 38 02 00 00 mov 0x238(%rax),%rax 3b4bb: 48 85 c0 test %rax,%rax 3b4be: 74 10 je 3b4d0 <apic_has_interrupt_for_ppr+0x30> 3b4c0: 48 8b 97 88 00 00 00 mov 0x88(%rdi),%rdx 3b4c7: 80 ba 28 03 00 00 00 cmpb $0x0,0x328(%rdx) 3b4ce: 75 3a jne 3b50a <apic_has_interrupt_for_ppr+0x6a> /* * Note that irr_pending is just a hint. It will be always * true with virtual interrupt delivery enabled. */ if (!apic->irr_pending) 3b4d0: 80 bf 91 00 00 00 00 cmpb $0x0,0x91(%rdi) 3b4d7: 74 2a je 3b503 <apic_has_interrupt_for_ppr+0x63> 3b4d9: 48 8b 8f a0 00 00 00 mov 0xa0(%rdi),%rcx static int find_highest_vector(void *bitmap) { int vec; u32 *reg; for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG; 3b4e0: b8 e0 00 00 00 mov $0xe0,%eax vec >= 0; vec -= APIC_VECTORS_PER_REG) { reg = bitmap + REG_POS(vec); if (*reg) 3b4e5: 89 c2 mov %eax,%edx 3b4e7: c1 fa 05 sar $0x5,%edx 3b4ea: c1 e2 04 shl $0x4,%edx 3b4ed: 48 63 d2 movslq %edx,%rdx 3b4f0: 8b 94 11 00 02 00 00 mov 0x200(%rcx,%rdx,1),%edx 3b4f7: 85 d2 test %edx,%edx 3b4f9: 75 2d jne 3b528 <apic_has_interrupt_for_ppr+0x88> > Please provide more detailed information on the exact command line > arguments and usage scenario. > > - Arnaldo > > > │580 __clear_bit(KVM_APIC_PV_EOI_PENDING, &vcpu->arch.apic_attention); ▒ > > │581 } ▒ > > │ ▒ > > │583 static int apic_has_interrupt_for_ppr(struct kvm_lapic *apic, u32 ppr) ▒ > > │584 { ▒ > > 0.88 │30: cmpb $0x0,0x91(%rdi) ▒ > > 2.54 │ ↓ je 63 ▒ > > 0.20 │ mov 0xa0(%rdi),%rcx ▒ > > │581 int highest_irr; ▒ > > │582 if (kvm_x86_ops->sync_pir_to_irr && apic->vcpu->arch.apicv_active) ▒ > > 4.91 │ mov $0xe0,%eax x ▒ > > 1.46 │45: mov %eax,%edx x ▒ > > 0.02 │ sar $0x5,%edx x ▒ > > 3.57 │ shl $0x4,%edx x ▒ > > 3.34 │ movslq %edx,%rdx x ▒ > > 1.25 │ mov 0x200(%rcx,%rdx,1),%edx x ▒ > > 42.44 │ test %edx,%edx x ▒ > > 0.01 │ ┌──jne 88 x ▒ > > 3.48 │ │ sub $0x20,%eax x ▒ > > 2.24 │ │ cmp $0xffffffe0,%eax x ▒ > > │586│apic_find_highest_irr(): ▒ > > │ │ ▒ > > │407│ /* ▒ > > │408│ * Note that irr_pending is just a hint. It will be always ▒ > > │409│ * true with virtual interrupt delivery enabled. ▒ > > │410│ */ ▒ > > │411│ if (!apic->irr_pending) ▒ > > │ │↑ jne 45 ▒ > > 0.62 │63:│ mov $0xffffffff,%eax ◆ > > 0.83 │ │ leaveq ▒ > > 13.52 │ │← retq ▒ > > │6a:│ mov %esi,-0x4(%rbp) ▒ > > │ │ mov %rdx,%rdi ▒ > > │418│find_highest_vector(): ▒ > > │340│static int find_highest_vector(void *bitmap) ▒ > > │341│{ ▒ > > │342│ int vec; ▒ > > │343│ u32 *reg; ▒ > > │ │ ▒ > > │345│ for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG; ▒ > > │ │→ callq *%rax ▒ > > │ │ mov -0x4(%rbp),%esi ▒ > > │343│ vec >= 0; vec -= APIC_VECTORS_PER_REG) { ▒ > > │344│ reg = bitmap + REG_POS(vec); ▒ > > │345│ if (*reg) ▒ > > 0.05 │75:│ cmp $0xffffffff,%eax ▒ > > │ │↑ je 63 ▒ > > 1.95 │ │ mov %eax,%edx ▒ > > 1.45 │ │ and $0xf0,%edx > > > > > > Look at the assembly code block where I have put a 'x' on the right. Apparently the > > assembly code doesn't match the C source code arrounded. Let's look the correct disassemble > > result from gdb: > > > > 340 for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG; > > 0x000000000003b4e0 <+64>: mov $0xe0,%eax > > > > 342 reg = bitmap + REG_POS(vec); > > 343 if (*reg) > > 0x000000000003b4e5 <+69>: mov %eax,%edx > > 0x000000000003b4e7 <+71>: sar $0x5,%edx > > 0x000000000003b4ea <+74>: shl $0x4,%edx > > 0x000000000003b4ed <+77>: movslq %edx,%rdx > > 0x000000000003b4f0 <+80>: mov 0x200(%rcx,%rdx,1),%edx > > 0x000000000003b4f7 <+87>: test %edx,%edx > > 0x000000000003b4f9 <+89>: jne 0x3b528 <apic_has_interrupt_for_ppr+136> > > > > 341 vec >= 0; vec -= APIC_VECTORS_PER_REG) { > > 0x000000000003b4fb <+91>: sub $0x20,%eax > > > > 340 for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG; > > 0x000000000003b4fe <+94>: cmp $0xffffffe0,%eax > > 0x000000000003b501 <+97>: jne 0x3b4e5 <apic_has_interrupt_for_ppr+69> > > > > > > Compared to gdb, perf-annoate has messed up. is it a bug or just perf is not as perfect as gdb? > > > > -- > > Thanks, > > Changbin Du > > -- Thanks, Changbin Du [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 473 bytes --] ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Does perf-annotate work correctly? 2017-09-13 1:54 ` Du, Changbin @ 2017-09-26 6:06 ` Du, Changbin 0 siblings, 0 replies; 11+ messages in thread From: Du, Changbin @ 2017-09-26 6:06 UTC (permalink / raw) To: Du, Changbin Cc: Arnaldo Carvalho de Melo, peterz, mingo, alexander.shishkin, linux-kernel [-- Attachment #1: Type: text/plain, Size: 9914 bytes --] Hi Arnaldo and all, Is there someone looking at this issue? I can provide more info if you need. This issue makes it so inconvenient to use perf. Thanks. On Wed, Sep 13, 2017 at 09:54:25AM +0800, Du, Changbin wrote: > On Tue, Sep 12, 2017 at 11:33:50AM -0300, Arnaldo Carvalho de Melo wrote: > > Em Tue, Sep 12, 2017 at 06:10:35PM +0800, Du, Changbin escreveu: > > > When a annotate a symbol, I find the annotated C source code doesn't match assembly code. > > > So I cannot determine which line of C code has much overhead withou gdb's help. > > > > > > Here is a example result of function apic_has_interrupt_for_ppr() in kvm module. > > > > Ok, was this using the module .ko file or /proc/kcore? You forgot to > > cut'n'paste the first line on the screen. > > > It is arch/x86/kvm/kvm.ko. > > > Also, how did you use gdb? > > > $ gdb arch/x86/kvm/kvm.ko > $ (gdb) disassemble /s apic_has_interrupt_for_ppr > > > perf uses objdump to do the disassembly, and depending on how it is used > > (live system, post processing on a different machine, permissions) it > > may use different files to do the disassembly. > > > But objdump has same out as gdb. (Always on same machine, and no binary changed.) > > $ objdump -d -S arch/x86/kvm/kvm.o > ... > static int apic_has_interrupt_for_ppr(struct kvm_lapic *apic, u32 ppr) > { > 3b4a0: e8 00 00 00 00 callq 3b4a5 <apic_has_interrupt_for_ppr+0x5> > 3b4a5: 55 push %rbp > 3b4a6: 48 89 e5 mov %rsp,%rbp > 3b4a9: 48 83 ec 08 sub $0x8,%rsp > int highest_irr; > if (kvm_x86_ops->sync_pir_to_irr && apic->vcpu->arch.apicv_active) > 3b4ad: 48 8b 05 00 00 00 00 mov 0x0(%rip),%rax # 3b4b4 <apic_has_interrupt_for_ppr+0x14> > 3b4b4: 48 8b 80 38 02 00 00 mov 0x238(%rax),%rax > 3b4bb: 48 85 c0 test %rax,%rax > 3b4be: 74 10 je 3b4d0 <apic_has_interrupt_for_ppr+0x30> > 3b4c0: 48 8b 97 88 00 00 00 mov 0x88(%rdi),%rdx > 3b4c7: 80 ba 28 03 00 00 00 cmpb $0x0,0x328(%rdx) > 3b4ce: 75 3a jne 3b50a <apic_has_interrupt_for_ppr+0x6a> > > /* > * Note that irr_pending is just a hint. It will be always > * true with virtual interrupt delivery enabled. > */ > if (!apic->irr_pending) > 3b4d0: 80 bf 91 00 00 00 00 cmpb $0x0,0x91(%rdi) > 3b4d7: 74 2a je 3b503 <apic_has_interrupt_for_ppr+0x63> > 3b4d9: 48 8b 8f a0 00 00 00 mov 0xa0(%rdi),%rcx > static int find_highest_vector(void *bitmap) > { > int vec; > u32 *reg; > > for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG; > 3b4e0: b8 e0 00 00 00 mov $0xe0,%eax > vec >= 0; vec -= APIC_VECTORS_PER_REG) { > reg = bitmap + REG_POS(vec); > if (*reg) > 3b4e5: 89 c2 mov %eax,%edx > 3b4e7: c1 fa 05 sar $0x5,%edx > 3b4ea: c1 e2 04 shl $0x4,%edx > 3b4ed: 48 63 d2 movslq %edx,%rdx > 3b4f0: 8b 94 11 00 02 00 00 mov 0x200(%rcx,%rdx,1),%edx > 3b4f7: 85 d2 test %edx,%edx > 3b4f9: 75 2d jne 3b528 <apic_has_interrupt_for_ppr+0x88> > > > > > Please provide more detailed information on the exact command line > > arguments and usage scenario. > > > > - Arnaldo > > > > > > │580 __clear_bit(KVM_APIC_PV_EOI_PENDING, &vcpu->arch.apic_attention); ▒ > > > │581 } ▒ > > > │ ▒ > > > │583 static int apic_has_interrupt_for_ppr(struct kvm_lapic *apic, u32 ppr) ▒ > > > │584 { ▒ > > > 0.88 │30: cmpb $0x0,0x91(%rdi) ▒ > > > 2.54 │ ↓ je 63 ▒ > > > 0.20 │ mov 0xa0(%rdi),%rcx ▒ > > > │581 int highest_irr; ▒ > > > │582 if (kvm_x86_ops->sync_pir_to_irr && apic->vcpu->arch.apicv_active) ▒ > > > 4.91 │ mov $0xe0,%eax x ▒ > > > 1.46 │45: mov %eax,%edx x ▒ > > > 0.02 │ sar $0x5,%edx x ▒ > > > 3.57 │ shl $0x4,%edx x ▒ > > > 3.34 │ movslq %edx,%rdx x ▒ > > > 1.25 │ mov 0x200(%rcx,%rdx,1),%edx x ▒ > > > 42.44 │ test %edx,%edx x ▒ > > > 0.01 │ ┌──jne 88 x ▒ > > > 3.48 │ │ sub $0x20,%eax x ▒ > > > 2.24 │ │ cmp $0xffffffe0,%eax x ▒ > > > │586│apic_find_highest_irr(): ▒ > > > │ │ ▒ > > > │407│ /* ▒ > > > │408│ * Note that irr_pending is just a hint. It will be always ▒ > > > │409│ * true with virtual interrupt delivery enabled. ▒ > > > │410│ */ ▒ > > > │411│ if (!apic->irr_pending) ▒ > > > │ │↑ jne 45 ▒ > > > 0.62 │63:│ mov $0xffffffff,%eax ◆ > > > 0.83 │ │ leaveq ▒ > > > 13.52 │ │← retq ▒ > > > │6a:│ mov %esi,-0x4(%rbp) ▒ > > > │ │ mov %rdx,%rdi ▒ > > > │418│find_highest_vector(): ▒ > > > │340│static int find_highest_vector(void *bitmap) ▒ > > > │341│{ ▒ > > > │342│ int vec; ▒ > > > │343│ u32 *reg; ▒ > > > │ │ ▒ > > > │345│ for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG; ▒ > > > │ │→ callq *%rax ▒ > > > │ │ mov -0x4(%rbp),%esi ▒ > > > │343│ vec >= 0; vec -= APIC_VECTORS_PER_REG) { ▒ > > > │344│ reg = bitmap + REG_POS(vec); ▒ > > > │345│ if (*reg) ▒ > > > 0.05 │75:│ cmp $0xffffffff,%eax ▒ > > > │ │↑ je 63 ▒ > > > 1.95 │ │ mov %eax,%edx ▒ > > > 1.45 │ │ and $0xf0,%edx > > > > > > > > > Look at the assembly code block where I have put a 'x' on the right. Apparently the > > > assembly code doesn't match the C source code arrounded. Let's look the correct disassemble > > > result from gdb: > > > > > > 340 for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG; > > > 0x000000000003b4e0 <+64>: mov $0xe0,%eax > > > > > > 342 reg = bitmap + REG_POS(vec); > > > 343 if (*reg) > > > 0x000000000003b4e5 <+69>: mov %eax,%edx > > > 0x000000000003b4e7 <+71>: sar $0x5,%edx > > > 0x000000000003b4ea <+74>: shl $0x4,%edx > > > 0x000000000003b4ed <+77>: movslq %edx,%rdx > > > 0x000000000003b4f0 <+80>: mov 0x200(%rcx,%rdx,1),%edx > > > 0x000000000003b4f7 <+87>: test %edx,%edx > > > 0x000000000003b4f9 <+89>: jne 0x3b528 <apic_has_interrupt_for_ppr+136> > > > > > > 341 vec >= 0; vec -= APIC_VECTORS_PER_REG) { > > > 0x000000000003b4fb <+91>: sub $0x20,%eax > > > > > > 340 for (vec = MAX_APIC_VECTOR - APIC_VECTORS_PER_REG; > > > 0x000000000003b4fe <+94>: cmp $0xffffffe0,%eax > > > 0x000000000003b501 <+97>: jne 0x3b4e5 <apic_has_interrupt_for_ppr+69> > > > > > > > > > Compared to gdb, perf-annoate has messed up. is it a bug or just perf is not as perfect as gdb? > > > > > > -- > > > Thanks, > > > Changbin Du > > > > > > -- > Thanks, > Changbin Du -- Thanks, Changbin Du [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 473 bytes --] ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Does perf-annotate work correctly? 2017-09-12 14:33 ` Arnaldo Carvalho de Melo 2017-09-13 1:54 ` Du, Changbin @ 2017-09-13 9:14 ` Du, Changbin 2017-10-13 10:15 ` Du, Changbin 1 sibling, 1 reply; 11+ messages in thread From: Du, Changbin @ 2017-09-13 9:14 UTC (permalink / raw) To: Arnaldo Carvalho de Melo Cc: Du, Changbin, peterz, mingo, alexander.shishkin, linux-kernel [-- Attachment #1: Type: text/plain, Size: 6209 bytes --] Here is another example which may be easy to analyse. I beleve that something wrong in parsing objdump output. The 'test %esi,%esi' is not of 'if (unlikely(error))', but 'if (!idtv_info_valid)'. perf annotate of function vmx_complete_interrupts(): vmx_complete_interrupts /lib/modules/4.13.0+/kernel/arch/x86/kvm/kvm-intel.ko Percent│ mov 0x4590(%rdi),%esi ▒ │ vmx_cancel_injection(): ▒ │ vmcs_read32(VM_ENTRY_INTR_INFO_FIELD), ▒ │ VM_ENTRY_INSTRUCTION_LEN, ▒ │ VM_ENTRY_EXCEPTION_ERROR_CODE); ▒ │ ▒ │ vmcs_write32(VM_ENTRY_INTR_INFO_FIELD, 0); ▒ │ } ▒ │ movb $0x0,0x32c8(%rdi) ▒ │ __vmx_complete_interrupts(): ▒ │ movb $0x0,0x1a7c(%rdi) ▒ │ movb $0x0,0x1a88(%rdi) ▒ │ __vmcs_writel(): ▒ │ u8 error; ▒ │ ▒ │ asm volatile (__ex(ASM_VMX_VMWRITE_RAX_RDX) "; setna %0" ▒ │ : "=q"(error) : "a"(value), "d"(field) : "cc"); ▒ │ if (unlikely(error)) ▒ │ vmwrite_error(field, value); ▒ 0.02 │ test %esi,%esi ▒ │ ↓ js 25 ▒ 99.98 │ ← retq ▒ │25: push %rbp ▒ │ mov $0x440a,%ecx ▒ │ mov $0x440c,%edx ▒ │ vmx_complete_interrupts(): ◆ │ break; ▒ │ } ▒ │ } ▒ │ ▒ │ static void vmx_complete_interrupts(struct vcpu_vmx *vmx) ▒ │ { ▒ │ mov %rsp,%rbp ▒ │ → callq __vmx_complete_interrupts.part.64 ▒ │ __vmx_complete_interrupts(&vmx->vcpu, vmx->idt_vectoring_info, ▒ │ pop %rbp ▒ │ ← retq ▒ GDB disassable: (gdb) disassemble /s vmx_complete_interrupts Dump of assembler code for function vmx_complete_interrupts: arch/x86/kvm/vmx.c: 8917 { 0x0000000000007110 <+0>: callq 0x7115 <vmx_complete_interrupts+5> 8918 __vmx_complete_interrupts(&vmx->vcpu, vmx->idt_vectoring_info, 0x0000000000007115 <+5>: mov 0x4590(%rdi),%esi 8873 vcpu->arch.nmi_injected = false; 0x000000000000711b <+11>: movb $0x0,0x32c8(%rdi) arch/x86/kvm/x86.h: 14 vcpu->arch.exception.pending = false; 0x0000000000007122 <+18>: movb $0x0,0x1a7c(%rdi) 15 } 16 17 static inline void kvm_queue_interrupt(struct kvm_vcpu *vcpu, u8 vector, 18 bool soft) 19 { 20 vcpu->arch.interrupt.pending = true; 21 vcpu->arch.interrupt.soft = soft; 22 vcpu->arch.interrupt.nr = vector; 23 } 24 25 static inline void kvm_clear_interrupt_queue(struct kvm_vcpu *vcpu) 26 { 27 vcpu->arch.interrupt.pending = false; 0x0000000000007129 <+25>: movb $0x0,0x1a88(%rdi) arch/x86/kvm/vmx.c: 8877 if (!idtv_info_valid) 0x0000000000007130 <+32>: test %esi,%esi 0x0000000000007132 <+34>: js 0x7135 <vmx_complete_interrupts+37> 8919 VM_EXIT_INSTRUCTION_LEN, 8920 IDT_VECTORING_ERROR_CODE); 8921 } 0x0000000000007134 <+36>: retq 8917 { 0x0000000000007135 <+37>: push %rbp 0x0000000000007136 <+38>: mov $0x440a,%ecx 0x000000000000713b <+43>: mov $0x440c,%edx ---Type <return> to continue, or q <return> to quit--- 0x0000000000007140 <+48>: mov %rsp,%rbp 0x0000000000007143 <+51>: callq 0x7000 <__vmx_complete_interrupts> 8919 VM_EXIT_INSTRUCTION_LEN, 8920 IDT_VECTORING_ERROR_CODE); 8921 } [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 473 bytes --] ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Does perf-annotate work correctly? 2017-09-13 9:14 ` Du, Changbin @ 2017-10-13 10:15 ` Du, Changbin 2017-10-16 9:28 ` Jiri Olsa 2017-10-16 9:30 ` Jiri Olsa 0 siblings, 2 replies; 11+ messages in thread From: Du, Changbin @ 2017-10-13 10:15 UTC (permalink / raw) To: Du, Changbin Cc: Arnaldo Carvalho de Melo, peterz, mingo, alexander.shishkin, linux-kernel, jolsa [-- Attachment #1: Type: text/plain, Size: 6741 bytes --] Hi Jiri, Sorry, missed you (but get_maintainer.pl doesn't list you). Here is ealier email. https://lkml.org/lkml/2017/9/12/158 Do you think if this is a real issue? btw, is their a dedicated mailist for perf? Thanks. On Wed, Sep 13, 2017 at 05:14:09PM +0800, Du, Changbin wrote: > > Here is another example which may be easy to analyse. I beleve that something wrong > in parsing objdump output. > > The 'test %esi,%esi' is not of 'if (unlikely(error))', but 'if (!idtv_info_valid)'. > > > perf annotate of function vmx_complete_interrupts(): > vmx_complete_interrupts /lib/modules/4.13.0+/kernel/arch/x86/kvm/kvm-intel.ko > Percent│ mov 0x4590(%rdi),%esi ▒ > │ vmx_cancel_injection(): ▒ > │ vmcs_read32(VM_ENTRY_INTR_INFO_FIELD), ▒ > │ VM_ENTRY_INSTRUCTION_LEN, ▒ > │ VM_ENTRY_EXCEPTION_ERROR_CODE); ▒ > │ ▒ > │ vmcs_write32(VM_ENTRY_INTR_INFO_FIELD, 0); ▒ > │ } ▒ > │ movb $0x0,0x32c8(%rdi) ▒ > │ __vmx_complete_interrupts(): ▒ > │ movb $0x0,0x1a7c(%rdi) ▒ > │ movb $0x0,0x1a88(%rdi) ▒ > │ __vmcs_writel(): ▒ > │ u8 error; ▒ > │ ▒ > │ asm volatile (__ex(ASM_VMX_VMWRITE_RAX_RDX) "; setna %0" ▒ > │ : "=q"(error) : "a"(value), "d"(field) : "cc"); ▒ > │ if (unlikely(error)) ▒ > │ vmwrite_error(field, value); ▒ > 0.02 │ test %esi,%esi ▒ > │ ↓ js 25 ▒ > 99.98 │ ← retq ▒ > │25: push %rbp ▒ > │ mov $0x440a,%ecx ▒ > │ mov $0x440c,%edx ▒ > │ vmx_complete_interrupts(): ◆ > │ break; ▒ > │ } ▒ > │ } ▒ > │ ▒ > │ static void vmx_complete_interrupts(struct vcpu_vmx *vmx) ▒ > │ { ▒ > │ mov %rsp,%rbp ▒ > │ → callq __vmx_complete_interrupts.part.64 ▒ > │ __vmx_complete_interrupts(&vmx->vcpu, vmx->idt_vectoring_info, ▒ > │ pop %rbp ▒ > │ ← retq ▒ > > > > > GDB disassable: > (gdb) disassemble /s vmx_complete_interrupts > Dump of assembler code for function vmx_complete_interrupts: > arch/x86/kvm/vmx.c: > 8917 { > 0x0000000000007110 <+0>: callq 0x7115 <vmx_complete_interrupts+5> > > 8918 __vmx_complete_interrupts(&vmx->vcpu, vmx->idt_vectoring_info, > 0x0000000000007115 <+5>: mov 0x4590(%rdi),%esi > > 8873 vcpu->arch.nmi_injected = false; > 0x000000000000711b <+11>: movb $0x0,0x32c8(%rdi) > > arch/x86/kvm/x86.h: > 14 vcpu->arch.exception.pending = false; > 0x0000000000007122 <+18>: movb $0x0,0x1a7c(%rdi) > > 15 } > 16 > 17 static inline void kvm_queue_interrupt(struct kvm_vcpu *vcpu, u8 vector, > 18 bool soft) > 19 { > 20 vcpu->arch.interrupt.pending = true; > 21 vcpu->arch.interrupt.soft = soft; > 22 vcpu->arch.interrupt.nr = vector; > 23 } > 24 > 25 static inline void kvm_clear_interrupt_queue(struct kvm_vcpu *vcpu) > 26 { > 27 vcpu->arch.interrupt.pending = false; > 0x0000000000007129 <+25>: movb $0x0,0x1a88(%rdi) > > arch/x86/kvm/vmx.c: > 8877 if (!idtv_info_valid) > 0x0000000000007130 <+32>: test %esi,%esi > 0x0000000000007132 <+34>: js 0x7135 <vmx_complete_interrupts+37> > > 8919 VM_EXIT_INSTRUCTION_LEN, > 8920 IDT_VECTORING_ERROR_CODE); > 8921 } > 0x0000000000007134 <+36>: retq > > 8917 { > 0x0000000000007135 <+37>: push %rbp > 0x0000000000007136 <+38>: mov $0x440a,%ecx > 0x000000000000713b <+43>: mov $0x440c,%edx > ---Type <return> to continue, or q <return> to quit--- > 0x0000000000007140 <+48>: mov %rsp,%rbp > 0x0000000000007143 <+51>: callq 0x7000 <__vmx_complete_interrupts> > > 8919 VM_EXIT_INSTRUCTION_LEN, > 8920 IDT_VECTORING_ERROR_CODE); > 8921 } > -- Thanks, Changbin Du [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 473 bytes --] ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Does perf-annotate work correctly? 2017-10-13 10:15 ` Du, Changbin @ 2017-10-16 9:28 ` Jiri Olsa 2017-10-16 9:34 ` Du, Changbin 2017-10-16 9:30 ` Jiri Olsa 1 sibling, 1 reply; 11+ messages in thread From: Jiri Olsa @ 2017-10-16 9:28 UTC (permalink / raw) To: Du, Changbin Cc: Arnaldo Carvalho de Melo, peterz, mingo, alexander.shishkin, linux-kernel, jolsa On Fri, Oct 13, 2017 at 06:15:00PM +0800, Du, Changbin wrote: > Hi Jiri, > Sorry, missed you (but get_maintainer.pl doesn't list you). Here is ealier email. > https://lkml.org/lkml/2017/9/12/158 > > Do you think if this is a real issue? SNIP > > 0.02 │ test %esi,%esi ▒ > > │ ↓ js 25 ▒ > > 99.98 │ ← retq ▒ > > │25: push %rbp ▒ > > │ mov $0x440a,%ecx ▒ > > │ mov $0x440c,%edx ▒ > > │ vmx_complete_interrupts(): ◆ > > │ break; ▒ > > │ } ▒ > > │ } ▒ > > │ ▒ > > │ static void vmx_complete_interrupts(struct vcpu_vmx *vmx) ▒ > > │ { ▒ > > │ mov %rsp,%rbp ▒ > > │ → callq __vmx_complete_interrupts.part.64 ▒ > > │ __vmx_complete_interrupts(&vmx->vcpu, vmx->idt_vectoring_info, ▒ > > │ pop %rbp ▒ > > │ ← retq ▒ hi, there's 'o' key to togle the instruction address or you can use the perf annotate --stdio to get it.. should be easier to tell if that's the same instruction jirka ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Does perf-annotate work correctly? 2017-10-16 9:28 ` Jiri Olsa @ 2017-10-16 9:34 ` Du, Changbin 0 siblings, 0 replies; 11+ messages in thread From: Du, Changbin @ 2017-10-16 9:34 UTC (permalink / raw) To: Jiri Olsa Cc: Du, Changbin, Arnaldo Carvalho de Melo, peterz, mingo, alexander.shishkin, linux-kernel, jolsa [-- Attachment #1: Type: text/plain, Size: 2718 bytes --] On Mon, Oct 16, 2017 at 11:28:53AM +0200, Jiri Olsa wrote: > On Fri, Oct 13, 2017 at 06:15:00PM +0800, Du, Changbin wrote: > > Hi Jiri, > > Sorry, missed you (but get_maintainer.pl doesn't list you). Here is ealier email. > > https://lkml.org/lkml/2017/9/12/158 > > > > Do you think if this is a real issue? > > SNIP > > > > 0.02 │ test %esi,%esi ▒ > > > │ ↓ js 25 ▒ > > > 99.98 │ ← retq ▒ > > > │25: push %rbp ▒ > > > │ mov $0x440a,%ecx ▒ > > > │ mov $0x440c,%edx ▒ > > > │ vmx_complete_interrupts(): ◆ > > > │ break; ▒ > > > │ } ▒ > > > │ } ▒ > > > │ ▒ > > > │ static void vmx_complete_interrupts(struct vcpu_vmx *vmx) ▒ > > > │ { ▒ > > > │ mov %rsp,%rbp ▒ > > > │ → callq __vmx_complete_interrupts.part.64 ▒ > > > │ __vmx_complete_interrupts(&vmx->vcpu, vmx->idt_vectoring_info, ▒ > > > │ pop %rbp ▒ > > > │ ← retq ▒ > > hi, > there's 'o' key to togle the instruction address or you > can use the perf annotate --stdio to get it.. should be > easier to tell if that's the same instruction > Thanks for replying. I know the reason now, the instructions are shown in pc address order, and some C statments are split into chunks. It gives me a illusion. Thanks. > jirka > -- Thanks, Changbin Du [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 473 bytes --] ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Does perf-annotate work correctly? 2017-10-13 10:15 ` Du, Changbin 2017-10-16 9:28 ` Jiri Olsa @ 2017-10-16 9:30 ` Jiri Olsa 2017-10-16 9:35 ` Du, Changbin 1 sibling, 1 reply; 11+ messages in thread From: Jiri Olsa @ 2017-10-16 9:30 UTC (permalink / raw) To: Du, Changbin Cc: Arnaldo Carvalho de Melo, peterz, mingo, alexander.shishkin, linux-kernel, jolsa On Fri, Oct 13, 2017 at 06:15:00PM +0800, Du, Changbin wrote: > Hi Jiri, > Sorry, missed you (but get_maintainer.pl doesn't list you). Here is ealier email. > https://lkml.org/lkml/2017/9/12/158 > > Do you think if this is a real issue? > > btw, is their a dedicated mailist for perf? Thanks. there's linux-perf-users@vger.kernel.org for perf specific issues jirka ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Does perf-annotate work correctly? 2017-10-16 9:30 ` Jiri Olsa @ 2017-10-16 9:35 ` Du, Changbin 2017-10-16 10:45 ` Jiri Olsa 0 siblings, 1 reply; 11+ messages in thread From: Du, Changbin @ 2017-10-16 9:35 UTC (permalink / raw) To: Jiri Olsa Cc: Du, Changbin, Arnaldo Carvalho de Melo, peterz, mingo, alexander.shishkin, linux-kernel, jolsa [-- Attachment #1: Type: text/plain, Size: 546 bytes --] On Mon, Oct 16, 2017 at 11:30:51AM +0200, Jiri Olsa wrote: > On Fri, Oct 13, 2017 at 06:15:00PM +0800, Du, Changbin wrote: > > Hi Jiri, > > Sorry, missed you (but get_maintainer.pl doesn't list you). Here is ealier email. > > https://lkml.org/lkml/2017/9/12/158 > > > > Do you think if this is a real issue? > > > > btw, is their a dedicated mailist for perf? Thanks. > > there's linux-perf-users@vger.kernel.org for perf specific issues > Good to know it. Can we add it to MAINTAINERS? > jirka -- Thanks, Changbin Du [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 473 bytes --] ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Does perf-annotate work correctly? 2017-10-16 9:35 ` Du, Changbin @ 2017-10-16 10:45 ` Jiri Olsa 0 siblings, 0 replies; 11+ messages in thread From: Jiri Olsa @ 2017-10-16 10:45 UTC (permalink / raw) To: Du, Changbin Cc: Arnaldo Carvalho de Melo, peterz, mingo, alexander.shishkin, linux-kernel, jolsa On Mon, Oct 16, 2017 at 05:35:33PM +0800, Du, Changbin wrote: > On Mon, Oct 16, 2017 at 11:30:51AM +0200, Jiri Olsa wrote: > > On Fri, Oct 13, 2017 at 06:15:00PM +0800, Du, Changbin wrote: > > > Hi Jiri, > > > Sorry, missed you (but get_maintainer.pl doesn't list you). Here is ealier email. > > > https://lkml.org/lkml/2017/9/12/158 > > > > > > Do you think if this is a real issue? > > > > > > btw, is their a dedicated mailist for perf? Thanks. > > > > there's linux-perf-users@vger.kernel.org for perf specific issues > > > > Good to know it. Can we add it to MAINTAINERS? not sure, leaving this one to Arnaldo ;-) jirka ^ permalink raw reply [flat|nested] 11+ messages in thread
end of thread, other threads:[~2017-10-16 10:45 UTC | newest] Thread overview: 11+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2017-09-12 10:10 Does perf-annotate work correctly? Du, Changbin 2017-09-12 14:33 ` Arnaldo Carvalho de Melo 2017-09-13 1:54 ` Du, Changbin 2017-09-26 6:06 ` Du, Changbin 2017-09-13 9:14 ` Du, Changbin 2017-10-13 10:15 ` Du, Changbin 2017-10-16 9:28 ` Jiri Olsa 2017-10-16 9:34 ` Du, Changbin 2017-10-16 9:30 ` Jiri Olsa 2017-10-16 9:35 ` Du, Changbin 2017-10-16 10:45 ` Jiri Olsa
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).