Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss

[BUG] perf tests: Test converting perf time to TSC

9 views
Skip to first unread message

Jiri Olsa

unread,
Oct 2, 2013, 9:30:03 AM10/2/13
to
hi,
got a segfault in the tsc test on latest acme's tree.

I'm dealing with some other issues right now, so just reporting ;-)

thanks,
jirka

(gdb) r test 20
Starting program: /home/jolsa/linux-perf/tools/perf/perf test 20
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
20: Test converting perf time to TSC :
Program received signal SIGFPE, Arithmetic exception.
0x00000000004cee73 in perf_time_to_tsc (ns=1460625577603, tc=0x7fffffffdf50) at arch/x86/util/tsc.c:16
16 quot = t / tc->time_mult;
Missing separate debuginfos, use: debuginfo-install audit-libs-2.2.1-1.fc16.x86_64 elfutils-libelf-0.154-2.fc16.x86_64 elfutils-libs-0.154-2.fc16.x86_64 glibc-2.14.90-24.fc16.9.x86_64 nss-softokn-freebl-3.14.1-3.fc16.x86_64 numactl-2.0.7-2.fc16.x86_64 perl-libs-5.14.3-205.fc16.x86_64 python-libs-2.7.3-4.fc16.x86_64 slang-2.2.4-1.fc16.x86_64 xz-libs-5.1.1-1alpha.fc16.x86_64 zlib-1.2.5-7.fc16.x86_64
(gdb) bt
#0 0x00000000004cee73 in perf_time_to_tsc (ns=1460625577603, tc=0x7fffffffdf50) at arch/x86/util/tsc.c:16
#1 0x00000000004cbdb8 in test__perf_time_to_tsc () at tests/perf-time-to-tsc.c:144
#2 0x00000000004491b7 in __cmd_test (argc=1, argv=0x7fffffffe400, skiplist=0x0) at tests/builtin-test.c:175
#3 0x0000000000449512 in cmd_test (argc=1, argv=0x7fffffffe400, prefix=0x0) at tests/builtin-test.c:240
#4 0x0000000000418dfd in run_builtin (p=0x802500, argc=2, argv=0x7fffffffe400) at perf.c:319
#5 0x0000000000419035 in handle_internal_command (argc=2, argv=0x7fffffffe400) at perf.c:376
#6 0x0000000000419181 in run_argv (argcp=0x7fffffffe2dc, argv=0x7fffffffe2d0) at perf.c:420
#7 0x0000000000419468 in main (argc=2, argv=0x7fffffffe400) at perf.c:529
(gdb) p tc->time_mult
$1 = 0
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majo...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Adrian Hunter

unread,
Oct 2, 2013, 9:50:03 AM10/2/13
to
On 02/10/13 16:23, Jiri Olsa wrote:
> hi,
> got a segfault in the tsc test on latest acme's tree.
>
> I'm dealing with some other issues right now, so just reporting ;-)

The capability bits have changed positions. You need to have:

commit fa7315871046b9a4c48627905691dbde57e51033
Author: Peter Zijlstra <pet...@infradead.org>
Date: Thu Sep 19 10:16:42 2013 +0200

perf: Fix capabilities bitfield compatibility in 'struct
perf_event_mmap_page'

in both (or neither) of your kernel and perf tools.

Arnaldo Carvalho de Melo

unread,
Oct 2, 2013, 12:20:02 PM10/2/13
to
Em Wed, Oct 02, 2013 at 04:46:59PM +0300, Adrian Hunter escreveu:
> On 02/10/13 16:23, Jiri Olsa wrote:
> > hi,
> > got a segfault in the tsc test on latest acme's tree.
> >
> > I'm dealing with some other issues right now, so just reporting ;-)
>
> The capability bits have changed positions. You need to have:
>
> commit fa7315871046b9a4c48627905691dbde57e51033
> Author: Peter Zijlstra <pet...@infradead.org>
> Date: Thu Sep 19 10:16:42 2013 +0200
>
> perf: Fix capabilities bitfield compatibility in 'struct
> perf_event_mmap_page'
>
> in both (or neither) of your kernel and perf tools.

Yeah, I'll merge perf/urgent into acme/perf/core soon.

- Arnaldo

Jiri Olsa

unread,
Oct 3, 2013, 4:20:01 AM10/3/13
to
On Wed, Oct 02, 2013 at 04:46:59PM +0300, Adrian Hunter wrote:
> On 02/10/13 16:23, Jiri Olsa wrote:
> > hi,
> > got a segfault in the tsc test on latest acme's tree.
> >
> > I'm dealing with some other issues right now, so just reporting ;-)
>
> The capability bits have changed positions. You need to have:
>
> commit fa7315871046b9a4c48627905691dbde57e51033
> Author: Peter Zijlstra <pet...@infradead.org>
> Date: Thu Sep 19 10:16:42 2013 +0200
>
> perf: Fix capabilities bitfield compatibility in 'struct
> perf_event_mmap_page'

ok, I'll try that.. but anyway, the test should
not crash in account of missing kernel change

jirka

Adrian Hunter

unread,
Oct 3, 2013, 4:40:02 AM10/3/13
to
On 03/10/13 11:17, Jiri Olsa wrote:
> On Wed, Oct 02, 2013 at 04:46:59PM +0300, Adrian Hunter wrote:
>> On 02/10/13 16:23, Jiri Olsa wrote:
>>> hi,
>>> got a segfault in the tsc test on latest acme's tree.
>>>
>>> I'm dealing with some other issues right now, so just reporting ;-)
>>
>> The capability bits have changed positions. You need to have:
>>
>> commit fa7315871046b9a4c48627905691dbde57e51033
>> Author: Peter Zijlstra <pet...@infradead.org>
>> Date: Thu Sep 19 10:16:42 2013 +0200
>>
>> perf: Fix capabilities bitfield compatibility in 'struct
>> perf_event_mmap_page'
>
> ok, I'll try that.. but anyway, the test should
> not crash in account of missing kernel change

No the ABI is broken in that case - better to crash.

Peter Zijlstra

unread,
Oct 3, 2013, 5:00:01 AM10/3/13
to
On Thu, Oct 03, 2013 at 11:42:46AM +0300, Adrian Hunter wrote:
> On 03/10/13 11:17, Jiri Olsa wrote:
> > On Wed, Oct 02, 2013 at 04:46:59PM +0300, Adrian Hunter wrote:
> >> On 02/10/13 16:23, Jiri Olsa wrote:
> >>> hi,
> >>> got a segfault in the tsc test on latest acme's tree.
> >>>
> >>> I'm dealing with some other issues right now, so just reporting ;-)
> >>
> >> The capability bits have changed positions. You need to have:
> >>
> >> commit fa7315871046b9a4c48627905691dbde57e51033
> >> Author: Peter Zijlstra <pet...@infradead.org>
> >> Date: Thu Sep 19 10:16:42 2013 +0200
> >>
> >> perf: Fix capabilities bitfield compatibility in 'struct
> >> perf_event_mmap_page'
> >
> > ok, I'll try that.. but anyway, the test should
> > not crash in account of missing kernel change
>
> No the ABI is broken in that case - better to crash.

No; neither case should crash.

Anyway; looking at this, why does time_zero have these different checks
from the other time bits?

@@ -1897,6 +1898,11 @@ void arch_perf_update_userpage(struct perf_event_mmap_page *userpg, u64 now)
userpg->time_mult = this_cpu_read(cyc2ns);
userpg->time_shift = CYC2NS_SCALE_FACTOR;
userpg->time_offset = this_cpu_read(cyc2ns_offset) - now;
+
+ if (sched_clock_stable && !check_tsc_disabled()) {
+ userpg->cap_usr_time_zero = 1;
+ userpg->time_zero = this_cpu_read(cyc2ns_offset);
+ }
}

That doesn't make any kind of sense.. why is cyc2ns_offset differently
tested from cyc2ns itself?

Peter Zijlstra

unread,
Oct 3, 2013, 5:00:01 AM10/3/13
to
On Thu, Oct 03, 2013 at 10:56:25AM +0200, Peter Zijlstra wrote:
> > No the ABI is broken in that case - better to crash.
>
> No; neither case should crash.

OK; previously we would report cap_usr_time = 1 even though we might not
have written stuff into the fields; which would indeed explain the
crash.

However; Jiri actually has the patch; as the code he posted had 'user' not
'usr'

Adrian Hunter

unread,
Oct 3, 2013, 5:50:01 AM10/3/13
to
On 03/10/13 11:58, Peter Zijlstra wrote:
> On Thu, Oct 03, 2013 at 10:56:25AM +0200, Peter Zijlstra wrote:
>>> No the ABI is broken in that case - better to crash.
>>
>> No; neither case should crash.
>
> OK; previously we would report cap_usr_time = 1 even though we might not
> have written stuff into the fields; which would indeed explain the
> crash.
>
> However; Jiri actually has the patch; as the code he posted had 'user' not
> 'usr'

Where do you see that?

Adrian Hunter

unread,
Oct 3, 2013, 6:10:03 AM10/3/13
to
I am afraid I don't understand the scaling calculations
so I don't know if they make any sense.

cap_usr_time_zero (now cap_user_time_zero) means you can convert
perf time to / from TSC. That only works if TSC is not disabled
and sched_clock is stable (and you have constant, non-stop TSC)

As far as I can tell, assuming the hardware is not broken,
sched_clock will be stable unless something (BIOS) or someone
(meddling user) has changed TSC manually.

Peter Zijlstra

unread,
Oct 3, 2013, 6:10:03 AM10/3/13
to
On Thu, Oct 03, 2013 at 12:54:32PM +0300, Adrian Hunter wrote:
> Where do you see that?

my minds eye.. I should go back to sleep or so :-( Its going to be one
of those days.

Peter Zijlstra

unread,
Oct 3, 2013, 7:10:02 AM10/3/13
to
On Thu, Oct 03, 2013 at 01:13:45PM +0300, Adrian Hunter wrote:
> > Anyway; looking at this, why does time_zero have these different checks
> > from the other time bits?
> >
> > @@ -1897,6 +1898,11 @@ void arch_perf_update_userpage(struct perf_event_mmap_page *userpg, u64 now)
> > userpg->time_mult = this_cpu_read(cyc2ns);
> > userpg->time_shift = CYC2NS_SCALE_FACTOR;
> > userpg->time_offset = this_cpu_read(cyc2ns_offset) - now;
> > +
> > + if (sched_clock_stable && !check_tsc_disabled()) {
> > + userpg->cap_usr_time_zero = 1;
> > + userpg->time_zero = this_cpu_read(cyc2ns_offset);
> > + }
> > }
> >
> > That doesn't make any kind of sense.. why is cyc2ns_offset differently
> > tested from cyc2ns itself?
>
> I am afraid I don't understand the scaling calculations
> so I don't know if they make any sense.
>
> cap_usr_time_zero (now cap_user_time_zero) means you can convert
> perf time to / from TSC. That only works if TSC is not disabled
> and sched_clock is stable (and you have constant, non-stop TSC)
>
> As far as I can tell, assuming the hardware is not broken,
> sched_clock will be stable unless something (BIOS) or someone
> (meddling user) has changed TSC manually.

Well all the scaling mess only applies to TSC.. furthermore note how
time_offset even uses cyc2ns_offset.

So I don't see any point in cap_user_time and cap_user_time_zero having
different conditions.

Also, I don't think that a cpu without cap_tsc will ever run perf code
so I don't see the point of testing tsc_disabled; if someone is mad
enough to boot with that he can bloody well keep the pieces.

Arguably the CONSTANT && NONSTOP test was to test the same thing as
sched_clock_stable, but I suppose we can use that.

Which reminds me; I should go and fix the transition for
sched_clock_stable: 1->0.

---
diff --git a/arch/x86/kernel/cpu/perf_event.c b/arch/x86/kernel/cpu/perf_event.c
index 897783b3302a..9db2b361a63d 100644
--- a/arch/x86/kernel/cpu/perf_event.c
+++ b/arch/x86/kernel/cpu/perf_event.c
@@ -1888,21 +1888,16 @@ void arch_perf_update_userpage(struct perf_event_mmap_page *userpg, u64 now)
userpg->cap_user_rdpmc = x86_pmu.attr_rdpmc;
userpg->pmc_width = x86_pmu.cntval_bits;

- if (!boot_cpu_has(X86_FEATURE_CONSTANT_TSC))
- return;
-
- if (!boot_cpu_has(X86_FEATURE_NONSTOP_TSC))
- return;
+ if (!sched_clock_stable)
+ return

userpg->cap_user_time = 1;
userpg->time_mult = this_cpu_read(cyc2ns);
userpg->time_shift = CYC2NS_SCALE_FACTOR;
userpg->time_offset = this_cpu_read(cyc2ns_offset) - now;

- if (sched_clock_stable && !check_tsc_disabled()) {
- userpg->cap_user_time_zero = 1;
- userpg->time_zero = this_cpu_read(cyc2ns_offset);
- }
+ userpg->cap_user_time_zero = 1;
+ userpg->time_zero = this_cpu_read(cyc2ns_offset);
}

/*

Adrian Hunter

unread,
Oct 3, 2013, 7:50:02 AM10/3/13
to
You can boot with notsc and perf still seems to work
e.g.

$ dmesg | grep -i tsc
[ 0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-3.11.0+ root=UUID=f1b4c71a-15aa-41a6-8898-cdde49966bce ro ignore_loglevel earlyprintk=ttyS0 console=ttyS0,115200n8 no_console_suspend notsc=1
[ 0.000000] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-3.11.0+ root=UUID=f1b4c71a-15aa-41a6-8898-cdde49966bce ro ignore_loglevel earlyprintk=ttyS0 console=ttyS0,115200n8 no_console_suspend notsc=1
[ 0.000000] tsc: Kernel compiled with CONFIG_X86_TSC, cannot disable TSC completely
[ 0.000000] tsc: Fast TSC calibration using PIT
[ 0.004000] tsc: Detected 2593.932 MHz processor
[ 0.224000] TSC deadline timer enabled


$ tools/perf/perf record -e instructions:u uname
Linux
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.032 MB perf.data (~1414 samples) ]

$ tools/perf/perf script
# ========
# captured on: Thu Oct 3 17:31:38 2013
# hostname : ivb01
# os release : 3.11.0+
# perf version : 3.11.rc4.gde8db8
# arch : x86_64
# nrcpus online : 8
# nrcpus avail : 8
# cpudesc : Intel(R) Core(TM) i7-3720QM CPU @ 2.60GHz
# cpuid : GenuineIntel,6,58,9
# total memory : 8074624 kB
# cmdline : /home/ahunter/git/linux-perf/tools/perf/perf record -e instructions:u uname
# event : name = instructions:u, type = 0, config = 0x1, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 1, excl_host = 0, e
# HEADER_CPU_TOPOLOGY info available, use -I to display
# HEADER_NUMA_TOPOLOGY info available, use -I to display
# pmu mappings: cpu = 4, software = 1, tracepoint = 2, uncore_cbox_0 = 6, uncore_cbox_1 = 7, uncore_cbox_2 = 8, uncore_cbox_3 = 9, b
# ========
#
uname 3914 451.484000: instructions:u: 7fe3f3315af3 [unknown] (/lib/x86_64-linux-gnu/ld-2.13.so)
uname 3914 451.484000: instructions:u: ffffffff813a1ad0 page_fault ([kernel.kallsyms])
uname 3914 451.484000: instructions:u: 7fe3f3316136 _dl_start (/lib/x86_64-linux-gnu/ld-2.13.so)
uname 3914 451.484000: instructions:u: ffffffff813a1ad0 page_fault ([kernel.kallsyms])
uname 3914 451.484000: instructions:u: ffffffff813a1ad0 page_fault ([kernel.kallsyms])
uname 3914 451.484000: instructions:u: ffffffff813a1ad0 page_fault ([kernel.kallsyms])
uname 3914 451.484000: instructions:u: 7fe3f33161b4 _dl_start (/lib/x86_64-linux-gnu/ld-2.13.so)
uname 3914 451.484000: instructions:u: 7fe3f33161af _dl_start (/lib/x86_64-linux-gnu/ld-2.13.so)
uname 3914 451.484000: instructions:u: 7fe3f33161af _dl_start (/lib/x86_64-linux-gnu/ld-2.13.so)
uname 3914 451.484000: instructions:u: 7fe3f33161af _dl_start (/lib/x86_64-linux-gnu/ld-2.13.so)
uname 3914 451.484000: instructions:u: 7fe3f33161bd _dl_start (/lib/x86_64-linux-gnu/ld-2.13.so)
uname 3914 451.484000: instructions:u: 7fe3f3316388 _dl_start (/lib/x86_64-linux-gnu/ld-2.13.so)
uname 3914 451.484000: instructions:u: 7fe3f3316590 _dl_start (/lib/x86_64-linux-gnu/ld-2.13.so)
uname 3914 451.484000: instructions:u: 7fe3f33165a0 _dl_start (/lib/x86_64-linux-gnu/ld-2.13.so)

Peter Zijlstra

unread,
Oct 3, 2013, 10:00:02 AM10/3/13
to
On Thu, Oct 03, 2013 at 02:49:09PM +0300, Adrian Hunter wrote:
> You can boot with notsc and perf still seems to work
> e.g.
>
> $ dmesg | grep -i tsc
> [ 0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-3.11.0+ root=UUID=f1b4c71a-15aa-41a6-8898-cdde49966bce ro ignore_loglevel earlyprintk=ttyS0 console=ttyS0,115200n8 no_console_suspend notsc=1
> [ 0.000000] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-3.11.0+ root=UUID=f1b4c71a-15aa-41a6-8898-cdde49966bce ro ignore_loglevel earlyprintk=ttyS0 console=ttyS0,115200n8 no_console_suspend notsc=1
> [ 0.000000] tsc: Kernel compiled with CONFIG_X86_TSC, cannot disable TSC completely
> [ 0.000000] tsc: Fast TSC calibration using PIT
> [ 0.004000] tsc: Detected 2593.932 MHz processor
> [ 0.224000] TSC deadline timer enabled

Yeah, and we still use the TSC deadline timer too.. I think we should
seriously consider removing the notsc option. I really don't know what
its good for.

Thomas, Ingo, hpa?
0 new messages