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

[Guenter Roeck]

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