Re: [tip:x86/timers] sched/clock: Enable sched clock early

From: Guenter Roeck
Date: Tue Jul 24 2018 - 21:24:16 EST


On 07/24/2018 05:36 PM, Pavel Tatashin wrote:
On Tue, Jul 24, 2018 at 4:22 PM Pavel Tatashin
<pasha.tatashin@xxxxxxxxxx> wrote:

On Tue, Jul 24, 2018 at 3:54 PM Guenter Roeck <linux@xxxxxxxxxxxx> wrote:

Hi,

On Thu, Jul 19, 2018 at 03:33:21PM -0700, tip-bot for Pavel Tatashin wrote:
Commit-ID: 857baa87b6422bcfb84ed3631d6839920cb5b09d
Gitweb: https://git.kernel.org/tip/857baa87b6422bcfb84ed3631d6839920cb5b09d
Author: Pavel Tatashin <pasha.tatashin@xxxxxxxxxx>
AuthorDate: Thu, 19 Jul 2018 16:55:42 -0400
Committer: Thomas Gleixner <tglx@xxxxxxxxxxxxx>
CommitDate: Fri, 20 Jul 2018 00:02:43 +0200

sched/clock: Enable sched clock early

Allow sched_clock() to be used before schec_clock_init() is called. This
provides a way to get early boot timestamps on machines with unstable
clocks.


This patch causes a regression when running a qemu emulation with
arm:integratorcp.

Thank you for the report. I will study it.


...
Console: colour dummy device 80x30
------------[ cut here ]------------
WARNING: CPU: 0 PID: 0 at kernel/time/sched_clock.c:180
sched_clock_register+0x44/0x278
Modules linked in:
CPU: 0 PID: 0 Comm: swapper Not tainted 4.18.0-rc6-next-20180724 #1
Hardware name: ARM Integrator/CP (Device Tree)
[<c0010cb4>] (unwind_backtrace) from [<c000dc24>] (show_stack+0x10/0x18)
[<c000dc24>] (show_stack) from [<c03ffb94>] (dump_stack+0x18/0x24)
[<c03ffb94>] (dump_stack) from [<c001a000>] (__warn+0xc8/0xf0)
[<c001a000>] (__warn) from [<c001a13c>] (warn_slowpath_null+0x3c/0x4c)
[<c001a13c>] (warn_slowpath_null) from [<c052367c>] (sched_clock_register+0x44/0x278)
[<c052367c>] (sched_clock_register) from [<c05238d8>] (generic_sched_clock_init+0x28/0x88)
[<c05238d8>] (generic_sched_clock_init) from [<c0521a00>] (sched_clock_init+0x54/0x74)
[<c0521a00>] (sched_clock_init) from [<c0519c18>] (start_kernel+0x310/0x3e4)
[<c0519c18>] (start_kernel) from [<00000000>] ( (null))
---[ end trace 08080eb81afa002c ]---
sched_clock: 32 bits at 100 Hz, resolution 10000000ns, wraps every 21474836475000000ns
...

A complete boot log is available at
http://kerneltests.org/builders/qemu-arm-next/builds/979/steps/qemubuildcommand/logs/stdio

Unfortunately, reverting the patch results in conflicts, so I am unable
to confirm that it is the only culprit.

From the context and from looking into the patch, it appears that this
can happen in any system if CONFIG_HAVE_UNSTABLE_SCHED_CLOCK is not
enabled.

Do you have a complete config, and also qemu args that were used? I
have tried defconfig arm, and run in qemu, could not reproduce the
problem.


integrator_defconfig+CONFIG_DEVTMPFS=y+CONFIG_DEVTMPFS_MOUNT=y

Qemu command line is
qemu-system-arm -M integratorcp -m 128 \
-kernel arch/arm/boot/zImage -no-reboot \
-initrd busybox-armv4.cpio \
--append "rdinit=/sbin/init console=ttyAMA0,115200" \
-serial stdio -monitor null -nographic \
-dtb arch/arm/boot/dts/integratorcp.dtb

The scripts and files used are available from git@xxxxxxxxxx:groeck/linux-build-test.git.
qemu is version 2.12.

Guenter

Thank you,
Pavel


Bisect log is attached.

Guenter

---
# bad: [3946cd385042069ec57d3f04240def53b4eed7e5] Add linux-next specific files for 20180724
# good: [d72e90f33aa4709ebecc5005562f52335e106a60] Linux 4.18-rc6
git bisect start 'HEAD' 'v4.18-rc6'
# good: [f5fa891e325acf096c0f79e1d1b922002e251e5a] Merge remote-tracking branch 'crypto/master'
git bisect good f5fa891e325acf096c0f79e1d1b922002e251e5a
# good: [cb6471f6bcfdacbeef9c23ba9dac00e67bd3c3a4] Merge remote-tracking branch 'spi/for-next'
git bisect good cb6471f6bcfdacbeef9c23ba9dac00e67bd3c3a4
# bad: [6b5bfa57bf4553d051be65d85d021465041406d8] Merge remote-tracking branch 'char-misc/char-misc-next'
git bisect bad 6b5bfa57bf4553d051be65d85d021465041406d8
# bad: [675a67e9ef3c041999f412cb75418d2b0def3854] Merge remote-tracking branch 'rcu/rcu/next'
git bisect bad 675a67e9ef3c041999f412cb75418d2b0def3854
# good: [e78b01a51131f25fc2d881bc43001575c129069c] Merge branch 'perf/core'
git bisect good e78b01a51131f25fc2d881bc43001575c129069c
# good: [4e581bce514f4107ce84525f0f75f89c92b4140e] Merge branch 'x86/cpu'
git bisect good 4e581bce514f4107ce84525f0f75f89c92b4140e
# good: [20fa22e90e54e2d21cace7ba083598531670f7cf] Merge branch 'x86/pti'
git bisect good 20fa22e90e54e2d21cace7ba083598531670f7cf
# good: [4763f03d3d186ce8a1125844790152d76804ad60] x86/tsc: Use TSC as sched clock early
git bisect good 4763f03d3d186ce8a1125844790152d76804ad60
# good: [5f9ef44c7d1c59d0eda1d86e31d981bdffe2a725] tools/memory-model: Rename litmus tests to comply to norm7
git bisect good 5f9ef44c7d1c59d0eda1d86e31d981bdffe2a725
# bad: [fc3d25e1c8f6a9232530db02a1072033e22e0fe3] Merge branch 'x86/timers'
git bisect bad fc3d25e1c8f6a9232530db02a1072033e22e0fe3
# bad: [46457ea464f5341d1f9dad8dd213805d45f7f117] sched/clock: Use static key for sched_clock_running
git bisect bad 46457ea464f5341d1f9dad8dd213805d45f7f117
# bad: [857baa87b6422bcfb84ed3631d6839920cb5b09d] sched/clock: Enable sched clock early
git bisect bad 857baa87b6422bcfb84ed3631d6839920cb5b09d
# good: [5d2a4e91a541cb04d20d11602f0f9340291322ac] sched/clock: Move sched clock initialization and merge with generic clock
git bisect good 5d2a4e91a541cb04d20d11602f0f9340291322ac
# first bad commit: [857baa87b6422bcfb84ed3631d6839920cb5b09d] sched/clock: Enable sched clock early