linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
       [not found] <87mvo8gd44.fsf@yhuang-dev.intel.com>
@ 2016-05-03  8:32 ` Peter Zijlstra
  2016-05-03  9:19   ` Wanpeng Li
                     ` (2 more replies)
  0 siblings, 3 replies; 23+ messages in thread
From: Peter Zijlstra @ 2016-05-03  8:32 UTC (permalink / raw)
  To: kernel test robot
  Cc: Steve Muckle, lkp, linux-kernel, Vincent Guittot,
	Thomas Gleixner, Rafael J. Wysocki, Patrick Bellasi,
	Morten Rasmussen, Mike Galbraith, Michael Turquette, Juri Lelli,
	Dietmar Eggemann, Steve Muckle, Ingo Molnar

On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
> FYI, we noticed the following commit:
> 
> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")


> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
> [   14.884474] random: systemd urandom read with 5 bits of entropy available
> [   14.903975] divide error: 0000 [#1] SMP 
> [   14.908375] Modules linked in:
> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
> [   15.018359] Stack:
> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
> [   15.045493] Call Trace:
> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77 
> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
> [   15.138875]  RSP <ffff88081ab23d70>
> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
> [   15.149323] Kernel panic - not syncing: Fatal exception
> 

That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
so.

Rafael?

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-03  8:32 ` [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP Peter Zijlstra
@ 2016-05-03  9:19   ` Wanpeng Li
  2016-05-03  9:25     ` Wanpeng Li
  2016-05-03 12:15   ` Rafael J. Wysocki
  2016-05-04 12:01   ` [PATCH] intel_pstate: Fix intel_pstate_get() Rafael J. Wysocki
  2 siblings, 1 reply; 23+ messages in thread
From: Wanpeng Li @ 2016-05-03  9:19 UTC (permalink / raw)
  To: Peter Zijlstra
  Cc: kernel test robot, Steve Muckle, lkp, linux-kernel,
	Vincent Guittot, Thomas Gleixner, Rafael J. Wysocki,
	Patrick Bellasi, Morten Rasmussen, Mike Galbraith,
	Michael Turquette, Juri Lelli, Dietmar Eggemann, Steve Muckle,
	Ingo Molnar

2016-05-03 16:32 GMT+08:00 Peter Zijlstra <peterz@infradead.org>:
> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>> FYI, we noticed the following commit:
>>
>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>
>
>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
>> [   14.903975] divide error: 0000 [#1] SMP
>> [   14.908375] Modules linked in:
>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
>> [   15.018359] Stack:
>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
>> [   15.045493] Call Trace:
>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>> [   15.138875]  RSP <ffff88081ab23d70>
>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
>> [   15.149323] Kernel panic - not syncing: Fatal exception
>>
>
> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
> so.

I think one sample should be called during intel_pstate driver
initialization, how about the below patch(untested)?

----snip----

diff --git a/drivers/cpufreq/intel_pstate.c b/drivers/cpufreq/intel_pstate.c
index 8b5a415..57b3843 100644
--- a/drivers/cpufreq/intel_pstate.c
+++ b/drivers/cpufreq/intel_pstate.c
@@ -1241,6 +1241,7 @@ static int intel_pstate_init_cpu(unsigned int cpunum)
        intel_pstate_get_cpu_pstates(cpu);

        intel_pstate_busy_pid_reset(cpu);
+       intel_pstate_sample(cpu);

        cpu->update_util.func = intel_pstate_update_util;

^ permalink raw reply related	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-03  9:19   ` Wanpeng Li
@ 2016-05-03  9:25     ` Wanpeng Li
  2016-05-03 13:33       ` Rafael J. Wysocki
  0 siblings, 1 reply; 23+ messages in thread
From: Wanpeng Li @ 2016-05-03  9:25 UTC (permalink / raw)
  To: Peter Zijlstra
  Cc: kernel test robot, Steve Muckle, lkp, linux-kernel,
	Vincent Guittot, Thomas Gleixner, Rafael J. Wysocki,
	Patrick Bellasi, Morten Rasmussen, Mike Galbraith,
	Michael Turquette, Juri Lelli, Dietmar Eggemann, Steve Muckle,
	Ingo Molnar

2016-05-03 17:19 GMT+08:00 Wanpeng Li <kernellwp@gmail.com>:
> 2016-05-03 16:32 GMT+08:00 Peter Zijlstra <peterz@infradead.org>:
>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>>> FYI, we noticed the following commit:
>>>
>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>>
>>
>>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
>>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
>>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
>>> [   14.903975] divide error: 0000 [#1] SMP
>>> [   14.908375] Modules linked in:
>>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
>>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
>>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
>>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
>>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
>>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
>>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
>>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
>>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
>>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
>>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
>>> [   15.018359] Stack:
>>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
>>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
>>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
>>> [   15.045493] Call Trace:
>>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
>>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
>>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
>>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
>>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
>>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
>>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
>>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
>>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
>>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
>>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
>>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>> [   15.138875]  RSP <ffff88081ab23d70>
>>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
>>> [   15.149323] Kernel panic - not syncing: Fatal exception
>>>
>>
>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>> so.
>
> I think one sample should be called during intel_pstate driver
> initialization, how about the below patch(untested)?
>
> ----snip----
>
> diff --git a/drivers/cpufreq/intel_pstate.c b/drivers/cpufreq/intel_pstate.c
> index 8b5a415..57b3843 100644
> --- a/drivers/cpufreq/intel_pstate.c
> +++ b/drivers/cpufreq/intel_pstate.c
> @@ -1241,6 +1241,7 @@ static int intel_pstate_init_cpu(unsigned int cpunum)
>         intel_pstate_get_cpu_pstates(cpu);
>
>         intel_pstate_busy_pid_reset(cpu);
> +       intel_pstate_sample(cpu);

intel_pstate_sample(cpu, 0);

>
>         cpu->update_util.func = intel_pstate_update_util;

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-03  8:32 ` [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP Peter Zijlstra
  2016-05-03  9:19   ` Wanpeng Li
@ 2016-05-03 12:15   ` Rafael J. Wysocki
  2016-05-03 12:54     ` Rafael J. Wysocki
  2016-05-04  0:58     ` Wanpeng Li
  2016-05-04 12:01   ` [PATCH] intel_pstate: Fix intel_pstate_get() Rafael J. Wysocki
  2 siblings, 2 replies; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-03 12:15 UTC (permalink / raw)
  To: Peter Zijlstra
  Cc: kernel test robot, Steve Muckle, lkp, Linux Kernel Mailing List,
	Vincent Guittot, Thomas Gleixner, Rafael J. Wysocki,
	Patrick Bellasi, Morten Rasmussen, Mike Galbraith,
	Michael Turquette, Juri Lelli, Dietmar Eggemann, Steve Muckle,
	Ingo Molnar

On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>> FYI, we noticed the following commit:
>>
>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>
>
>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
>> [   14.903975] divide error: 0000 [#1] SMP
>> [   14.908375] Modules linked in:
>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
>> [   15.018359] Stack:
>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
>> [   15.045493] Call Trace:
>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>> [   15.138875]  RSP <ffff88081ab23d70>
>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
>> [   15.149323] Kernel panic - not syncing: Fatal exception
>>
>
> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
> so.

Well, what's the tree based on?

The mainline does this:

bool sample_taken = intel_pstate_sample(cpu, time);

if (sample_taken && !hwp_active)
        intel_pstate_adjust_busy_pstate(cpu);

and (the mainline version of) intel_pstate_sample() returns false when
it is called for the first time after setting the update_util hook.

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-03 12:15   ` Rafael J. Wysocki
@ 2016-05-03 12:54     ` Rafael J. Wysocki
  2016-05-03 12:58       ` Rafael J. Wysocki
  2016-05-04  0:58     ` Wanpeng Li
  1 sibling, 1 reply; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-03 12:54 UTC (permalink / raw)
  To: Peter Zijlstra
  Cc: kernel test robot, Steve Muckle, lkp, Linux Kernel Mailing List,
	Vincent Guittot, Thomas Gleixner, Patrick Bellasi,
	Morten Rasmussen, Mike Galbraith, Michael Turquette, Juri Lelli,
	Dietmar Eggemann, Steve Muckle, Ingo Molnar

On Tue, May 3, 2016 at 2:15 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>>> FYI, we noticed the following commit:
>>>
>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>>
>>
>>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
>>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
>>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
>>> [   14.903975] divide error: 0000 [#1] SMP
>>> [   14.908375] Modules linked in:
>>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
>>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
>>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
>>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
>>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
>>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
>>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
>>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
>>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
>>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
>>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
>>> [   15.018359] Stack:
>>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
>>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
>>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
>>> [   15.045493] Call Trace:
>>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
>>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
>>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
>>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
>>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
>>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
>>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
>>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
>>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
>>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
>>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
>>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>> [   15.138875]  RSP <ffff88081ab23d70>
>>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
>>> [   15.149323] Kernel panic - not syncing: Fatal exception
>>>
>>
>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>> so.
>
> Well, what's the tree based on?
>
> The mainline does this:
>
> bool sample_taken = intel_pstate_sample(cpu, time);
>
> if (sample_taken && !hwp_active)
>         intel_pstate_adjust_busy_pstate(cpu);
>
> and (the mainline version of) intel_pstate_sample() returns false when
> it is called for the first time after setting the update_util hook.

If that helps, I can expose my pm-cpufreq-fixes branch to pull from.
It contains all cpufreq material that went into the Linus' tree to
date and is based on 4.5-rc3.

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-03 12:54     ` Rafael J. Wysocki
@ 2016-05-03 12:58       ` Rafael J. Wysocki
  2016-05-03 13:22         ` Rafael J. Wysocki
  0 siblings, 1 reply; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-03 12:58 UTC (permalink / raw)
  To: Peter Zijlstra
  Cc: kernel test robot, Steve Muckle, lkp, Linux Kernel Mailing List,
	Vincent Guittot, Thomas Gleixner, Patrick Bellasi,
	Morten Rasmussen, Mike Galbraith, Michael Turquette, Juri Lelli,
	Dietmar Eggemann, Steve Muckle, Ingo Molnar

On Tue, May 3, 2016 at 2:54 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
> On Tue, May 3, 2016 at 2:15 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
>> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>>>> FYI, we noticed the following commit:
>>>>
>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>>>
>>>
>>>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
>>>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
>>>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
>>>> [   14.903975] divide error: 0000 [#1] SMP
>>>> [   14.908375] Modules linked in:
>>>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
>>>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
>>>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
>>>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
>>>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
>>>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
>>>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
>>>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
>>>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
>>>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
>>>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
>>>> [   15.018359] Stack:
>>>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
>>>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
>>>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
>>>> [   15.045493] Call Trace:
>>>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
>>>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
>>>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
>>>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
>>>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
>>>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
>>>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
>>>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
>>>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
>>>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
>>>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
>>>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>>> [   15.138875]  RSP <ffff88081ab23d70>
>>>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
>>>> [   15.149323] Kernel panic - not syncing: Fatal exception
>>>>
>>>
>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>>> so.
>>
>> Well, what's the tree based on?
>>
>> The mainline does this:
>>
>> bool sample_taken = intel_pstate_sample(cpu, time);
>>
>> if (sample_taken && !hwp_active)
>>         intel_pstate_adjust_busy_pstate(cpu);
>>
>> and (the mainline version of) intel_pstate_sample() returns false when
>> it is called for the first time after setting the update_util hook.
>
> If that helps, I can expose my pm-cpufreq-fixes branch to pull from.
> It contains all cpufreq material that went into the Linus' tree to
> date and is based on 4.5-rc3.

In fact, it is exposed already:

git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm.git \
pm-cpufreq-fixes

and the top-most commit is 1becf03545a0859ceaaf9e8c2d9861882a71cb01
(cpufreq: intel_pstate: Fix processing for turbo activation ratio).

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-03 12:58       ` Rafael J. Wysocki
@ 2016-05-03 13:22         ` Rafael J. Wysocki
  2016-05-03 13:53           ` Rafael J. Wysocki
  0 siblings, 1 reply; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-03 13:22 UTC (permalink / raw)
  To: Rafael J. Wysocki
  Cc: Peter Zijlstra, kernel test robot, Steve Muckle, lkp,
	Linux Kernel Mailing List, Vincent Guittot, Thomas Gleixner,
	Patrick Bellasi, Morten Rasmussen, Mike Galbraith,
	Michael Turquette, Juri Lelli, Dietmar Eggemann, Steve Muckle,
	Ingo Molnar

On Tue, May 3, 2016 at 2:58 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
> On Tue, May 3, 2016 at 2:54 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
>> On Tue, May 3, 2016 at 2:15 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
>>> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
>>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>>>>> FYI, we noticed the following commit:
>>>>>
>>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>>>>
>>>>
>>>>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
>>>>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
>>>>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
>>>>> [   14.903975] divide error: 0000 [#1] SMP
>>>>> [   14.908375] Modules linked in:
>>>>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
>>>>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
>>>>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
>>>>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>>>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
>>>>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
>>>>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
>>>>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
>>>>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
>>>>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
>>>>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
>>>>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>>>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
>>>>> [   15.018359] Stack:
>>>>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
>>>>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
>>>>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
>>>>> [   15.045493] Call Trace:
>>>>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
>>>>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
>>>>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
>>>>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
>>>>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
>>>>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
>>>>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
>>>>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
>>>>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
>>>>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
>>>>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
>>>>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>>>> [   15.138875]  RSP <ffff88081ab23d70>
>>>>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
>>>>> [   15.149323] Kernel panic - not syncing: Fatal exception
>>>>>
>>>>
>>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>>>> so.
>>>
>>> Well, what's the tree based on?
>>>
>>> The mainline does this:
>>>
>>> bool sample_taken = intel_pstate_sample(cpu, time);
>>>
>>> if (sample_taken && !hwp_active)
>>>         intel_pstate_adjust_busy_pstate(cpu);
>>>
>>> and (the mainline version of) intel_pstate_sample() returns false when
>>> it is called for the first time after setting the update_util hook.
>>
>> If that helps, I can expose my pm-cpufreq-fixes branch to pull from.
>> It contains all cpufreq material that went into the Linus' tree to
>> date and is based on 4.5-rc3.
>
> In fact, it is exposed already:
>
> git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm.git \
> pm-cpufreq-fixes
>
> and the top-most commit is 1becf03545a0859ceaaf9e8c2d9861882a71cb01
> (cpufreq: intel_pstate: Fix processing for turbo activation ratio).

Ah, that will fail as well.

The problem is that intel_pstate_get() can be called before we take
the first sample.

I need to think about how to fix that.

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-03  9:25     ` Wanpeng Li
@ 2016-05-03 13:33       ` Rafael J. Wysocki
  2016-05-04  0:53         ` Wanpeng Li
  0 siblings, 1 reply; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-03 13:33 UTC (permalink / raw)
  To: Wanpeng Li
  Cc: Peter Zijlstra, kernel test robot, Steve Muckle, lkp,
	linux-kernel, Vincent Guittot, Thomas Gleixner,
	Rafael J. Wysocki, Patrick Bellasi, Morten Rasmussen,
	Mike Galbraith, Michael Turquette, Juri Lelli, Dietmar Eggemann,
	Steve Muckle, Ingo Molnar

On Tue, May 3, 2016 at 11:25 AM, Wanpeng Li <kernellwp@gmail.com> wrote:
> 2016-05-03 17:19 GMT+08:00 Wanpeng Li <kernellwp@gmail.com>:
>> 2016-05-03 16:32 GMT+08:00 Peter Zijlstra <peterz@infradead.org>:
>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>>>> FYI, we noticed the following commit:
>>>>
>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>>>
>>>
>>>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
>>>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
>>>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
>>>> [   14.903975] divide error: 0000 [#1] SMP
>>>> [   14.908375] Modules linked in:
>>>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
>>>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
>>>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
>>>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
>>>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
>>>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
>>>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
>>>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
>>>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
>>>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
>>>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
>>>> [   15.018359] Stack:
>>>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
>>>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
>>>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
>>>> [   15.045493] Call Trace:
>>>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
>>>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
>>>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
>>>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
>>>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
>>>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
>>>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
>>>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
>>>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
>>>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
>>>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
>>>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>>> [   15.138875]  RSP <ffff88081ab23d70>
>>>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
>>>> [   15.149323] Kernel panic - not syncing: Fatal exception
>>>>
>>>
>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>>> so.
>>
>> I think one sample should be called during intel_pstate driver
>> initialization, how about the below patch(untested)?
>>
>> ----snip----
>>
>> diff --git a/drivers/cpufreq/intel_pstate.c b/drivers/cpufreq/intel_pstate.c
>> index 8b5a415..57b3843 100644
>> --- a/drivers/cpufreq/intel_pstate.c
>> +++ b/drivers/cpufreq/intel_pstate.c
>> @@ -1241,6 +1241,7 @@ static int intel_pstate_init_cpu(unsigned int cpunum)
>>         intel_pstate_get_cpu_pstates(cpu);
>>
>>         intel_pstate_busy_pid_reset(cpu);
>> +       intel_pstate_sample(cpu);
>
> intel_pstate_sample(cpu, 0);
>
>>
>>         cpu->update_util.func = intel_pstate_update_util;

That would avoid the divide by 0, but the value returned by
intel_pstate_get() would still be bogus.

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-03 13:22         ` Rafael J. Wysocki
@ 2016-05-03 13:53           ` Rafael J. Wysocki
  2016-05-03 15:10             ` Rafael J. Wysocki
  0 siblings, 1 reply; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-03 13:53 UTC (permalink / raw)
  To: Peter Zijlstra, Wanpeng Li
  Cc: Rafael J. Wysocki, kernel test robot, Steve Muckle, lkp,
	Linux Kernel Mailing List, Vincent Guittot, Thomas Gleixner,
	Patrick Bellasi, Morten Rasmussen, Mike Galbraith,
	Michael Turquette, Juri Lelli, Dietmar Eggemann, Steve Muckle,
	Ingo Molnar, Linux PM list, Srinivas Pandruvada

On Tuesday, May 03, 2016 03:22:24 PM Rafael J. Wysocki wrote:
> On Tue, May 3, 2016 at 2:58 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
> > On Tue, May 3, 2016 at 2:54 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
> >> On Tue, May 3, 2016 at 2:15 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
> >>> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
> >>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
> >>>>> FYI, we noticed the following commit:
> >>>>>
> >>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
> >>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
> >>>>
> >>>>
> >>>>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
> >>>>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
> >>>>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
> >>>>> [   14.903975] divide error: 0000 [#1] SMP
> >>>>> [   14.908375] Modules linked in:
> >>>>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
> >>>>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
> >>>>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
> >>>>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
> >>>>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
> >>>>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
> >>>>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
> >>>>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
> >>>>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
> >>>>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
> >>>>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
> >>>>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> >>>>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
> >>>>> [   15.018359] Stack:
> >>>>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
> >>>>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
> >>>>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
> >>>>> [   15.045493] Call Trace:
> >>>>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
> >>>>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
> >>>>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
> >>>>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
> >>>>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
> >>>>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
> >>>>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
> >>>>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
> >>>>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
> >>>>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
> >>>>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
> >>>>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
> >>>>> [   15.138875]  RSP <ffff88081ab23d70>
> >>>>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
> >>>>> [   15.149323] Kernel panic - not syncing: Fatal exception
> >>>>>
> >>>>
> >>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
> >>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
> >>>> so.
> >>>
> >>> Well, what's the tree based on?
> >>>
> >>> The mainline does this:
> >>>
> >>> bool sample_taken = intel_pstate_sample(cpu, time);
> >>>
> >>> if (sample_taken && !hwp_active)
> >>>         intel_pstate_adjust_busy_pstate(cpu);
> >>>
> >>> and (the mainline version of) intel_pstate_sample() returns false when
> >>> it is called for the first time after setting the update_util hook.
> >>
> >> If that helps, I can expose my pm-cpufreq-fixes branch to pull from.
> >> It contains all cpufreq material that went into the Linus' tree to
> >> date and is based on 4.5-rc3.
> >
> > In fact, it is exposed already:
> >
> > git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm.git \
> > pm-cpufreq-fixes
> >
> > and the top-most commit is 1becf03545a0859ceaaf9e8c2d9861882a71cb01
> > (cpufreq: intel_pstate: Fix processing for turbo activation ratio).
> 
> Ah, that will fail as well.
> 
> The problem is that intel_pstate_get() can be called before we take
> the first sample.
> 
> I need to think about how to fix that.

Maybe something like the below (untested, but builds).

It will make intel_pstate_get() return 0 until avg_frequency gets populated
which is actually OK.

---
 drivers/cpufreq/intel_pstate.c |    6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

Index: linux-pm/drivers/cpufreq/intel_pstate.c
===================================================================
--- linux-pm.orig/drivers/cpufreq/intel_pstate.c
+++ linux-pm/drivers/cpufreq/intel_pstate.c
@@ -114,6 +114,7 @@ struct cpudata {
 	u64	prev_mperf;
 	u64	prev_tsc;
 	u64	prev_cummulative_iowait;
+	int	avg_frequency;
 	struct sample sample;
 };
 
@@ -1037,6 +1038,7 @@ static inline void intel_pstate_adjust_b
 	intel_pstate_update_pstate(cpu, target_pstate);
 
 	sample = &cpu->sample;
+	cpu->avg_frequency = get_avg_frequency(cpu);
 	trace_pstate_sample(fp_toint(sample->core_pct_busy),
 		fp_toint(sample->busy_scaled),
 		from,
@@ -1044,7 +1046,7 @@ static inline void intel_pstate_adjust_b
 		sample->mperf,
 		sample->aperf,
 		sample->tsc,
-		get_avg_frequency(cpu));
+		cpu->avg_frequency);
 }
 
 static void intel_pstate_update_util(struct update_util_data *data, u64 time,
@@ -1130,7 +1132,7 @@ static unsigned int intel_pstate_get(uns
 	if (!cpu)
 		return 0;
 	sample = &cpu->sample;
-	return get_avg_frequency(cpu);
+	return cpu->avg_frequency;
 }
 
 static void intel_pstate_set_update_util_hook(unsigned int cpu_num)

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-03 13:53           ` Rafael J. Wysocki
@ 2016-05-03 15:10             ` Rafael J. Wysocki
  2016-05-05  5:05               ` Wanpeng Li
  0 siblings, 1 reply; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-03 15:10 UTC (permalink / raw)
  To: Peter Zijlstra, Wanpeng Li
  Cc: Rafael J. Wysocki, kernel test robot, Steve Muckle, lkp,
	Linux Kernel Mailing List, Vincent Guittot, Thomas Gleixner,
	Patrick Bellasi, Morten Rasmussen, Mike Galbraith,
	Michael Turquette, Juri Lelli, Dietmar Eggemann, Steve Muckle,
	Ingo Molnar, Linux PM list, Srinivas Pandruvada

On Tuesday, May 03, 2016 03:53:12 PM Rafael J. Wysocki wrote:
> On Tuesday, May 03, 2016 03:22:24 PM Rafael J. Wysocki wrote:
> > On Tue, May 3, 2016 at 2:58 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
> > > On Tue, May 3, 2016 at 2:54 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
> > >> On Tue, May 3, 2016 at 2:15 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
> > >>> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
> > >>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
> > >>>>> FYI, we noticed the following commit:
> > >>>>>
> > >>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
> > >>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
> > >>>>
> > >>>>
> > >>>>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
> > >>>>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
> > >>>>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
> > >>>>> [   14.903975] divide error: 0000 [#1] SMP
> > >>>>> [   14.908375] Modules linked in:
> > >>>>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
> > >>>>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
> > >>>>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
> > >>>>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
> > >>>>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
> > >>>>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
> > >>>>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
> > >>>>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
> > >>>>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
> > >>>>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
> > >>>>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
> > >>>>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > >>>>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
> > >>>>> [   15.018359] Stack:
> > >>>>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
> > >>>>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
> > >>>>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
> > >>>>> [   15.045493] Call Trace:
> > >>>>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
> > >>>>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
> > >>>>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
> > >>>>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
> > >>>>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
> > >>>>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
> > >>>>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
> > >>>>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
> > >>>>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
> > >>>>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
> > >>>>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
> > >>>>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
> > >>>>> [   15.138875]  RSP <ffff88081ab23d70>
> > >>>>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
> > >>>>> [   15.149323] Kernel panic - not syncing: Fatal exception
> > >>>>>
> > >>>>
> > >>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
> > >>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
> > >>>> so.
> > >>>
> > >>> Well, what's the tree based on?
> > >>>
> > >>> The mainline does this:
> > >>>
> > >>> bool sample_taken = intel_pstate_sample(cpu, time);
> > >>>
> > >>> if (sample_taken && !hwp_active)
> > >>>         intel_pstate_adjust_busy_pstate(cpu);
> > >>>
> > >>> and (the mainline version of) intel_pstate_sample() returns false when
> > >>> it is called for the first time after setting the update_util hook.
> > >>
> > >> If that helps, I can expose my pm-cpufreq-fixes branch to pull from.
> > >> It contains all cpufreq material that went into the Linus' tree to
> > >> date and is based on 4.5-rc3.
> > >
> > > In fact, it is exposed already:
> > >
> > > git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm.git \
> > > pm-cpufreq-fixes
> > >
> > > and the top-most commit is 1becf03545a0859ceaaf9e8c2d9861882a71cb01
> > > (cpufreq: intel_pstate: Fix processing for turbo activation ratio).
> > 
> > Ah, that will fail as well.
> > 
> > The problem is that intel_pstate_get() can be called before we take
> > the first sample.
> > 
> > I need to think about how to fix that.
> 
> Maybe something like the below (untested, but builds).
> 
> It will make intel_pstate_get() return 0 until avg_frequency gets populated
> which is actually OK.

The previous one would break the HWP case, so below is a new one (still
untested).

---
 drivers/cpufreq/intel_pstate.c |   19 +++++++++----------
 1 file changed, 9 insertions(+), 10 deletions(-)

Index: linux-pm/drivers/cpufreq/intel_pstate.c
===================================================================
--- linux-pm.orig/drivers/cpufreq/intel_pstate.c
+++ linux-pm/drivers/cpufreq/intel_pstate.c
@@ -114,6 +114,7 @@ struct cpudata {
 	u64	prev_mperf;
 	u64	prev_tsc;
 	u64	prev_cummulative_iowait;
+	int	avg_frequency;
 	struct sample sample;
 };
 
@@ -1044,7 +1045,7 @@ static inline void intel_pstate_adjust_b
 		sample->mperf,
 		sample->aperf,
 		sample->tsc,
-		get_avg_frequency(cpu));
+		cpu->avg_frequency);
 }
 
 static void intel_pstate_update_util(struct update_util_data *data, u64 time,
@@ -1056,8 +1057,11 @@ static void intel_pstate_update_util(str
 	if ((s64)delta_ns >= pid_params.sample_rate_ns) {
 		bool sample_taken = intel_pstate_sample(cpu, time);
 
-		if (sample_taken && !hwp_active)
-			intel_pstate_adjust_busy_pstate(cpu);
+		if (sample_taken) {
+			cpu->avg_frequency = get_avg_frequency(cpu);
+			if (!hwp_active)
+				intel_pstate_adjust_busy_pstate(cpu);
+		}
 	}
 }
 
@@ -1123,14 +1127,9 @@ static int intel_pstate_init_cpu(unsigne
 
 static unsigned int intel_pstate_get(unsigned int cpu_num)
 {
-	struct sample *sample;
-	struct cpudata *cpu;
+	struct cpudata *cpu = all_cpu_data[cpu_num];
 
-	cpu = all_cpu_data[cpu_num];
-	if (!cpu)
-		return 0;
-	sample = &cpu->sample;
-	return get_avg_frequency(cpu);
+	return cpu ? cpu->avg_frequency : 0;
 }
 
 static void intel_pstate_set_update_util_hook(unsigned int cpu_num)

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-03 13:33       ` Rafael J. Wysocki
@ 2016-05-04  0:53         ` Wanpeng Li
  2016-05-04 11:41           ` Rafael J. Wysocki
  0 siblings, 1 reply; 23+ messages in thread
From: Wanpeng Li @ 2016-05-04  0:53 UTC (permalink / raw)
  To: Rafael J. Wysocki
  Cc: Peter Zijlstra, kernel test robot, Steve Muckle, lkp,
	linux-kernel, Vincent Guittot, Thomas Gleixner, Patrick Bellasi,
	Morten Rasmussen, Mike Galbraith, Michael Turquette, Juri Lelli,
	Dietmar Eggemann, Steve Muckle, Ingo Molnar

2016-05-03 21:33 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
> On Tue, May 3, 2016 at 11:25 AM, Wanpeng Li <kernellwp@gmail.com> wrote:
>> 2016-05-03 17:19 GMT+08:00 Wanpeng Li <kernellwp@gmail.com>:
>>> 2016-05-03 16:32 GMT+08:00 Peter Zijlstra <peterz@infradead.org>:
>>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>>>>> FYI, we noticed the following commit:
>>>>>
>>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>>>>
>>>>
>>>>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
>>>>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
>>>>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
>>>>> [   14.903975] divide error: 0000 [#1] SMP
>>>>> [   14.908375] Modules linked in:
>>>>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
>>>>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
>>>>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
>>>>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>>>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
>>>>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
>>>>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
>>>>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
>>>>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
>>>>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
>>>>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
>>>>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>>>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
>>>>> [   15.018359] Stack:
>>>>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
>>>>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
>>>>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
>>>>> [   15.045493] Call Trace:
>>>>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
>>>>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
>>>>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
>>>>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
>>>>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
>>>>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
>>>>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
>>>>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
>>>>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
>>>>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
>>>>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
>>>>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>>>> [   15.138875]  RSP <ffff88081ab23d70>
>>>>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
>>>>> [   15.149323] Kernel panic - not syncing: Fatal exception
>>>>>
>>>>
>>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>>>> so.
>>>
>>> I think one sample should be called during intel_pstate driver
>>> initialization, how about the below patch(untested)?
>>>
>>> ----snip----
>>>
>>> diff --git a/drivers/cpufreq/intel_pstate.c b/drivers/cpufreq/intel_pstate.c
>>> index 8b5a415..57b3843 100644
>>> --- a/drivers/cpufreq/intel_pstate.c
>>> +++ b/drivers/cpufreq/intel_pstate.c
>>> @@ -1241,6 +1241,7 @@ static int intel_pstate_init_cpu(unsigned int cpunum)
>>>         intel_pstate_get_cpu_pstates(cpu);
>>>
>>>         intel_pstate_busy_pid_reset(cpu);
>>> +       intel_pstate_sample(cpu);
>>
>> intel_pstate_sample(cpu, 0);
>>
>>>
>>>         cpu->update_util.func = intel_pstate_update_util;
>
> That would avoid the divide by 0, but the value returned by
> intel_pstate_get() would still be bogus.

If your bogus means that some data is stale and could you explain more?

Regards,
Wanpeng Li

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-03 12:15   ` Rafael J. Wysocki
  2016-05-03 12:54     ` Rafael J. Wysocki
@ 2016-05-04  0:58     ` Wanpeng Li
  2016-05-04 11:44       ` Rafael J. Wysocki
  1 sibling, 1 reply; 23+ messages in thread
From: Wanpeng Li @ 2016-05-04  0:58 UTC (permalink / raw)
  To: Rafael J. Wysocki
  Cc: Peter Zijlstra, kernel test robot, Steve Muckle, lkp,
	Linux Kernel Mailing List, Vincent Guittot, Thomas Gleixner,
	Patrick Bellasi, Morten Rasmussen, Mike Galbraith,
	Michael Turquette, Juri Lelli, Dietmar Eggemann, Steve Muckle,
	Ingo Molnar

2016-05-03 20:15 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>>> FYI, we noticed the following commit:
>>>
>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>>
>>
>>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
>>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
>>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
>>> [   14.903975] divide error: 0000 [#1] SMP
>>> [   14.908375] Modules linked in:
>>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
>>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
>>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
>>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
>>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
>>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
>>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
>>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
>>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
>>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
>>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
>>> [   15.018359] Stack:
>>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
>>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
>>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
>>> [   15.045493] Call Trace:
>>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
>>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
>>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
>>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
>>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
>>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
>>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
>>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
>>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
>>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
>>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
>>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>>> [   15.138875]  RSP <ffff88081ab23d70>
>>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
>>> [   15.149323] Kernel panic - not syncing: Fatal exception
>>>
>>
>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>> so.
>
> Well, what's the tree based on?
>
> The mainline does this:
>
> bool sample_taken = intel_pstate_sample(cpu, time);
>
> if (sample_taken && !hwp_active)
>         intel_pstate_adjust_busy_pstate(cpu);
>
> and (the mainline version of) intel_pstate_sample() returns false when
> it is called for the first time after setting the update_util hook.

The callsites in scheduler will set time to rq_clock(rq) when trigger
sample, so when time 0 will be used even if it is set just before
setting the update_util hook?

Regards,
Wanpeng Li

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-04  0:53         ` Wanpeng Li
@ 2016-05-04 11:41           ` Rafael J. Wysocki
  2016-05-04 11:46             ` Wanpeng Li
  0 siblings, 1 reply; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-04 11:41 UTC (permalink / raw)
  To: Wanpeng Li
  Cc: Rafael J. Wysocki, Peter Zijlstra, kernel test robot,
	Steve Muckle, lkp, linux-kernel, Vincent Guittot,
	Thomas Gleixner, Patrick Bellasi, Morten Rasmussen,
	Mike Galbraith, Michael Turquette, Juri Lelli, Dietmar Eggemann,
	Steve Muckle, Ingo Molnar

On Wed, May 4, 2016 at 2:53 AM, Wanpeng Li <kernellwp@gmail.com> wrote:
> 2016-05-03 21:33 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
>> On Tue, May 3, 2016 at 11:25 AM, Wanpeng Li <kernellwp@gmail.com> wrote:
>>> 2016-05-03 17:19 GMT+08:00 Wanpeng Li <kernellwp@gmail.com>:
>>>> 2016-05-03 16:32 GMT+08:00 Peter Zijlstra <peterz@infradead.org>:
>>>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:

[cut]

>>>> ----snip----
>>>>
>>>> diff --git a/drivers/cpufreq/intel_pstate.c b/drivers/cpufreq/intel_pstate.c
>>>> index 8b5a415..57b3843 100644
>>>> --- a/drivers/cpufreq/intel_pstate.c
>>>> +++ b/drivers/cpufreq/intel_pstate.c
>>>> @@ -1241,6 +1241,7 @@ static int intel_pstate_init_cpu(unsigned int cpunum)
>>>>         intel_pstate_get_cpu_pstates(cpu);
>>>>
>>>>         intel_pstate_busy_pid_reset(cpu);
>>>> +       intel_pstate_sample(cpu);
>>>
>>> intel_pstate_sample(cpu, 0);
>>>
>>>>
>>>>         cpu->update_util.func = intel_pstate_update_util;
>>
>> That would avoid the divide by 0, but the value returned by
>> intel_pstate_get() would still be bogus.
>
> If your bogus means that some data is stale and could you explain more?

get_avg_frequency() expects sample.aperf to be a delta between two
different values of the APERF register obtained at two different
instants of time, and analogously for sample.mperf, because that's
when the formula used by it is guaranteed to be valid.  This means
that it generally is not sufficient to read those registers just once
to get a meaningful result, they need to be read at least twice for
that (with some time between the reads to let the counters grow
sufficiently).

With your modification sample.aperf and sample.mperf would simply
contain the values of APERF and MPERF, respectively, at the the
intel_pstate_sample(cpu, 0) invocation time, so using them in the
computation would not be guaranteed to lead to a meaningful result.

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-04  0:58     ` Wanpeng Li
@ 2016-05-04 11:44       ` Rafael J. Wysocki
  2016-05-04 11:51         ` Wanpeng Li
  0 siblings, 1 reply; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-04 11:44 UTC (permalink / raw)
  To: Wanpeng Li
  Cc: Rafael J. Wysocki, Peter Zijlstra, kernel test robot,
	Steve Muckle, lkp, Linux Kernel Mailing List, Vincent Guittot,
	Thomas Gleixner, Patrick Bellasi, Morten Rasmussen,
	Mike Galbraith, Michael Turquette, Juri Lelli, Dietmar Eggemann,
	Steve Muckle, Ingo Molnar

On Wed, May 4, 2016 at 2:58 AM, Wanpeng Li <kernellwp@gmail.com> wrote:
> 2016-05-03 20:15 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
>> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>>>> FYI, we noticed the following commit:
>>>>
>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>>>

[cut]

>>>
>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>>> so.
>>
>> Well, what's the tree based on?
>>
>> The mainline does this:
>>
>> bool sample_taken = intel_pstate_sample(cpu, time);
>>
>> if (sample_taken && !hwp_active)
>>         intel_pstate_adjust_busy_pstate(cpu);
>>
>> and (the mainline version of) intel_pstate_sample() returns false when
>> it is called for the first time after setting the update_util hook.
>
> The callsites in scheduler will set time to rq_clock(rq) when trigger
> sample, so when time 0 will be used even if it is set just before
> setting the update_util hook?

I'm not sure what you mean.

time=0 is special as it will cause intel_pstate_sample() to return
false on the next invocation.

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-04 11:41           ` Rafael J. Wysocki
@ 2016-05-04 11:46             ` Wanpeng Li
  0 siblings, 0 replies; 23+ messages in thread
From: Wanpeng Li @ 2016-05-04 11:46 UTC (permalink / raw)
  To: Rafael J. Wysocki
  Cc: Peter Zijlstra, kernel test robot, Steve Muckle, lkp,
	linux-kernel, Vincent Guittot, Thomas Gleixner, Patrick Bellasi,
	Morten Rasmussen, Mike Galbraith, Michael Turquette, Juri Lelli,
	Dietmar Eggemann, Steve Muckle, Ingo Molnar

2016-05-04 19:41 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
> On Wed, May 4, 2016 at 2:53 AM, Wanpeng Li <kernellwp@gmail.com> wrote:
>> 2016-05-03 21:33 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
>>> On Tue, May 3, 2016 at 11:25 AM, Wanpeng Li <kernellwp@gmail.com> wrote:
>>>> 2016-05-03 17:19 GMT+08:00 Wanpeng Li <kernellwp@gmail.com>:
>>>>> 2016-05-03 16:32 GMT+08:00 Peter Zijlstra <peterz@infradead.org>:
>>>>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>
> [cut]
>
>>>>> ----snip----
>>>>>
>>>>> diff --git a/drivers/cpufreq/intel_pstate.c b/drivers/cpufreq/intel_pstate.c
>>>>> index 8b5a415..57b3843 100644
>>>>> --- a/drivers/cpufreq/intel_pstate.c
>>>>> +++ b/drivers/cpufreq/intel_pstate.c
>>>>> @@ -1241,6 +1241,7 @@ static int intel_pstate_init_cpu(unsigned int cpunum)
>>>>>         intel_pstate_get_cpu_pstates(cpu);
>>>>>
>>>>>         intel_pstate_busy_pid_reset(cpu);
>>>>> +       intel_pstate_sample(cpu);
>>>>
>>>> intel_pstate_sample(cpu, 0);
>>>>
>>>>>
>>>>>         cpu->update_util.func = intel_pstate_update_util;
>>>
>>> That would avoid the divide by 0, but the value returned by
>>> intel_pstate_get() would still be bogus.
>>
>> If your bogus means that some data is stale and could you explain more?
>
> get_avg_frequency() expects sample.aperf to be a delta between two
> different values of the APERF register obtained at two different
> instants of time, and analogously for sample.mperf, because that's
> when the formula used by it is guaranteed to be valid.  This means
> that it generally is not sufficient to read those registers just once
> to get a meaningful result, they need to be read at least twice for
> that (with some time between the reads to let the counters grow
> sufficiently).
>
> With your modification sample.aperf and sample.mperf would simply
> contain the values of APERF and MPERF, respectively, at the the
> intel_pstate_sample(cpu, 0) invocation time, so using them in the
> computation would not be guaranteed to lead to a meaningful result.

I see, thanks Rafael.

Regards,
Wanpeng Li

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-04 11:44       ` Rafael J. Wysocki
@ 2016-05-04 11:51         ` Wanpeng Li
  2016-05-04 11:56           ` Rafael J. Wysocki
  0 siblings, 1 reply; 23+ messages in thread
From: Wanpeng Li @ 2016-05-04 11:51 UTC (permalink / raw)
  To: Rafael J. Wysocki
  Cc: Peter Zijlstra, kernel test robot, Steve Muckle, lkp,
	Linux Kernel Mailing List, Vincent Guittot, Thomas Gleixner,
	Patrick Bellasi, Morten Rasmussen, Mike Galbraith,
	Michael Turquette, Juri Lelli, Dietmar Eggemann, Steve Muckle,
	Ingo Molnar

2016-05-04 19:44 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
> On Wed, May 4, 2016 at 2:58 AM, Wanpeng Li <kernellwp@gmail.com> wrote:
>> 2016-05-03 20:15 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
>>> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
>>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>>>>> FYI, we noticed the following commit:
>>>>>
>>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>>>>
>
> [cut]
>
>>>>
>>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>>>> so.
>>>
>>> Well, what's the tree based on?
>>>
>>> The mainline does this:
>>>
>>> bool sample_taken = intel_pstate_sample(cpu, time);
>>>
>>> if (sample_taken && !hwp_active)
>>>         intel_pstate_adjust_busy_pstate(cpu);
>>>
>>> and (the mainline version of) intel_pstate_sample() returns false when
>>> it is called for the first time after setting the update_util hook.
>>
>> The callsites in scheduler will set time to rq_clock(rq) when trigger
>> sample, so when time 0 will be used even if it is set just before
>> setting the update_util hook?
>
> I'm not sure what you mean.
>
> time=0 is special as it will cause intel_pstate_sample() to return
> false on the next invocation.

Sample is driven by cpufreq_update_util() which uses rq_clock(rq) as
time parameter, so there is no opportunity to pass time 0 to
intel_pstate_sample().

Regards,
Wanpeng Li

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-04 11:51         ` Wanpeng Li
@ 2016-05-04 11:56           ` Rafael J. Wysocki
  2016-05-04 12:04             ` Wanpeng Li
  0 siblings, 1 reply; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-04 11:56 UTC (permalink / raw)
  To: Wanpeng Li
  Cc: Rafael J. Wysocki, Peter Zijlstra, kernel test robot,
	Steve Muckle, lkp, Linux Kernel Mailing List, Vincent Guittot,
	Thomas Gleixner, Patrick Bellasi, Morten Rasmussen,
	Mike Galbraith, Michael Turquette, Juri Lelli, Dietmar Eggemann,
	Steve Muckle, Ingo Molnar

On Wed, May 4, 2016 at 1:51 PM, Wanpeng Li <kernellwp@gmail.com> wrote:
> 2016-05-04 19:44 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
>> On Wed, May 4, 2016 at 2:58 AM, Wanpeng Li <kernellwp@gmail.com> wrote:
>>> 2016-05-03 20:15 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
>>>> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
>>>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>>>>>> FYI, we noticed the following commit:
>>>>>>
>>>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>>>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>>>>>
>>
>> [cut]
>>
>>>>>
>>>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>>>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>>>>> so.
>>>>
>>>> Well, what's the tree based on?
>>>>
>>>> The mainline does this:
>>>>
>>>> bool sample_taken = intel_pstate_sample(cpu, time);
>>>>
>>>> if (sample_taken && !hwp_active)
>>>>         intel_pstate_adjust_busy_pstate(cpu);
>>>>
>>>> and (the mainline version of) intel_pstate_sample() returns false when
>>>> it is called for the first time after setting the update_util hook.
>>>
>>> The callsites in scheduler will set time to rq_clock(rq) when trigger
>>> sample, so when time 0 will be used even if it is set just before
>>> setting the update_util hook?
>>
>> I'm not sure what you mean.
>>
>> time=0 is special as it will cause intel_pstate_sample() to return
>> false on the next invocation.
>
> Sample is driven by cpufreq_update_util() which uses rq_clock(rq) as
> time parameter, so there is no opportunity to pass time 0 to
> intel_pstate_sample().

Right.

So I should have said that had time=0 been passed to
intel_pstate_sample(), it would have caused it to return false on the
next invocation. :-)

The way it works is that sample.time is 0 initially, so
intel_pstate_sample() returns false first time it is called and the
second invocation gets all of the deltas as needed.

^ permalink raw reply	[flat|nested] 23+ messages in thread

* [PATCH] intel_pstate: Fix intel_pstate_get()
  2016-05-03  8:32 ` [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP Peter Zijlstra
  2016-05-03  9:19   ` Wanpeng Li
  2016-05-03 12:15   ` Rafael J. Wysocki
@ 2016-05-04 12:01   ` Rafael J. Wysocki
  2 siblings, 0 replies; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-04 12:01 UTC (permalink / raw)
  To: Peter Zijlstra, Linux PM list
  Cc: kernel test robot, Steve Muckle, lkp, linux-kernel,
	Vincent Guittot, Thomas Gleixner, Rafael J. Wysocki,
	Patrick Bellasi, Morten Rasmussen, Mike Galbraith,
	Michael Turquette, Juri Lelli, Dietmar Eggemann, Steve Muckle,
	Ingo Molnar, Srinivas Pandruvada

From: Rafael J. Wysocki <rafael.j.wysocki@intel.com>

After commit 8fa520af5081 "intel_pstate: Remove freq calculation from
intel_pstate_calc_busy()" intel_pstate_get() calls get_avg_frequency()
to compute the average frequency, which is problematic for two reasons.

First, intel_pstate_get() may be invoked before the driver reads the
CPU feedback registers for the first time and if that happens,
get_avg_frequency() will attempt to divide by zero.

Second, the get_avg_frequency() call in intel_pstate_get() is racy
with respect to intel_pstate_sample() and it may end up returning
completely meaningless values for this reason.

Moreover, after commit 7349ec0470b6 "intel_pstate: Move
intel_pstate_calc_busy() into get_target_pstate_use_performance()"
sample.core_pct_busy is never computed on Atom, but it is used in
intel_pstate_adjust_busy_pstate() in that case too.

To address those problems notice that if sample.core_pct_busy
was used in the average frequency computation carried out by
get_avg_frequency(), both the divide by zero problem and the
race with respect to intel_pstate_sample() would be avoided.

Accordingly, move the invocation of intel_pstate_calc_busy() from
get_target_pstate_use_performance() to intel_pstate_update_util(),
which also will take care of the uninitialized sample.core_pct_busy
on Atom, and modify get_avg_frequency() to use sample.core_pct_busy
as per the above.

Reported-by: kernel test robot <ying.huang@linux.intel.com>
Link: http://marc.info/?l=linux-kernel&m=146226437623173&w=4
Fixes: 8fa520af5081 "intel_pstate: Remove freq calculation from intel_pstate_calc_busy()"
Fixes: 7349ec0470b6 "intel_pstate: Move intel_pstate_calc_busy() into get_target_pstate_use_performance()"
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
---
 drivers/cpufreq/intel_pstate.c |   14 ++++++++------
 1 file changed, 8 insertions(+), 6 deletions(-)

Index: linux-pm/drivers/cpufreq/intel_pstate.c
===================================================================
--- linux-pm.orig/drivers/cpufreq/intel_pstate.c
+++ linux-pm/drivers/cpufreq/intel_pstate.c
@@ -928,8 +928,9 @@ static inline bool intel_pstate_sample(s
 
 static inline int32_t get_avg_frequency(struct cpudata *cpu)
 {
-	return div64_u64(cpu->pstate.max_pstate_physical * cpu->sample.aperf *
-		cpu->pstate.scaling, cpu->sample.mperf);
+	return fp_toint(mul_fp(cpu->sample.core_pct_busy,
+			       int_tofp(cpu->pstate.max_pstate_physical *
+						cpu->pstate.scaling / 100)));
 }
 
 static inline int32_t get_target_pstate_use_cpu_load(struct cpudata *cpu)
@@ -972,8 +973,6 @@ static inline int32_t get_target_pstate_
 	int32_t core_busy, max_pstate, current_pstate, sample_ratio;
 	u64 duration_ns;
 
-	intel_pstate_calc_busy(cpu);
-
 	/*
 	 * core_busy is the ratio of actual performance to max
 	 * max_pstate is the max non turbo pstate available
@@ -1056,8 +1055,11 @@ static void intel_pstate_update_util(str
 	if ((s64)delta_ns >= pid_params.sample_rate_ns) {
 		bool sample_taken = intel_pstate_sample(cpu, time);
 
-		if (sample_taken && !hwp_active)
-			intel_pstate_adjust_busy_pstate(cpu);
+		if (sample_taken) {
+			intel_pstate_calc_busy(cpu);
+			if (!hwp_active)
+				intel_pstate_adjust_busy_pstate(cpu);
+		}
 	}
 }
 

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-04 11:56           ` Rafael J. Wysocki
@ 2016-05-04 12:04             ` Wanpeng Li
  0 siblings, 0 replies; 23+ messages in thread
From: Wanpeng Li @ 2016-05-04 12:04 UTC (permalink / raw)
  To: Rafael J. Wysocki
  Cc: Peter Zijlstra, kernel test robot, Steve Muckle, lkp,
	Linux Kernel Mailing List, Vincent Guittot, Thomas Gleixner,
	Patrick Bellasi, Morten Rasmussen, Mike Galbraith,
	Michael Turquette, Juri Lelli, Dietmar Eggemann, Steve Muckle,
	Ingo Molnar

2016-05-04 19:56 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
> On Wed, May 4, 2016 at 1:51 PM, Wanpeng Li <kernellwp@gmail.com> wrote:
>> 2016-05-04 19:44 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
>>> On Wed, May 4, 2016 at 2:58 AM, Wanpeng Li <kernellwp@gmail.com> wrote:
>>>> 2016-05-03 20:15 GMT+08:00 Rafael J. Wysocki <rafael@kernel.org>:
>>>>> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
>>>>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>>>>>>> FYI, we noticed the following commit:
>>>>>>>
>>>>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>>>>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>>>>>>
>>>
>>> [cut]
>>>
>>>>>>
>>>>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>>>>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>>>>>> so.
>>>>>
>>>>> Well, what's the tree based on?
>>>>>
>>>>> The mainline does this:
>>>>>
>>>>> bool sample_taken = intel_pstate_sample(cpu, time);
>>>>>
>>>>> if (sample_taken && !hwp_active)
>>>>>         intel_pstate_adjust_busy_pstate(cpu);
>>>>>
>>>>> and (the mainline version of) intel_pstate_sample() returns false when
>>>>> it is called for the first time after setting the update_util hook.
>>>>
>>>> The callsites in scheduler will set time to rq_clock(rq) when trigger
>>>> sample, so when time 0 will be used even if it is set just before
>>>> setting the update_util hook?
>>>
>>> I'm not sure what you mean.
>>>
>>> time=0 is special as it will cause intel_pstate_sample() to return
>>> false on the next invocation.
>>
>> Sample is driven by cpufreq_update_util() which uses rq_clock(rq) as
>> time parameter, so there is no opportunity to pass time 0 to
>> intel_pstate_sample().
>
> Right.
>
> So I should have said that had time=0 been passed to
> intel_pstate_sample(), it would have caused it to return false on the
> next invocation. :-)
>
> The way it works is that sample.time is 0 initially, so
> intel_pstate_sample() returns false first time it is called and the
> second invocation gets all of the deltas as needed.

I see, thanks Rafael. :-)

Regards,
Wanpeng Li

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-03 15:10             ` Rafael J. Wysocki
@ 2016-05-05  5:05               ` Wanpeng Li
  2016-05-05 13:46                 ` Rafael J. Wysocki
  0 siblings, 1 reply; 23+ messages in thread
From: Wanpeng Li @ 2016-05-05  5:05 UTC (permalink / raw)
  To: Rafael J. Wysocki
  Cc: Peter Zijlstra, Rafael J. Wysocki, kernel test robot,
	Steve Muckle, lkp, Linux Kernel Mailing List, Vincent Guittot,
	Thomas Gleixner, Patrick Bellasi, Morten Rasmussen,
	Mike Galbraith, Michael Turquette, Juri Lelli, Dietmar Eggemann,
	Steve Muckle, Ingo Molnar, Linux PM list, Srinivas Pandruvada

2016-05-03 23:10 GMT+08:00 Rafael J. Wysocki <rjw@rjwysocki.net>:
> On Tuesday, May 03, 2016 03:53:12 PM Rafael J. Wysocki wrote:
>> On Tuesday, May 03, 2016 03:22:24 PM Rafael J. Wysocki wrote:
>> > On Tue, May 3, 2016 at 2:58 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
>> > > On Tue, May 3, 2016 at 2:54 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
>> > >> On Tue, May 3, 2016 at 2:15 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
>> > >>> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
>> > >>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>> > >>>>> FYI, we noticed the following commit:
>> > >>>>>
>> > >>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>> > >>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>> > >>>>
>> > >>>>
>> > >>>>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
>> > >>>>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
>> > >>>>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
>> > >>>>> [   14.903975] divide error: 0000 [#1] SMP
>> > >>>>> [   14.908375] Modules linked in:
>> > >>>>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
>> > >>>>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
>> > >>>>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
>> > >>>>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>> > >>>>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
>> > >>>>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
>> > >>>>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
>> > >>>>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
>> > >>>>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
>> > >>>>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
>> > >>>>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
>> > >>>>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> > >>>>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
>> > >>>>> [   15.018359] Stack:
>> > >>>>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
>> > >>>>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
>> > >>>>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
>> > >>>>> [   15.045493] Call Trace:
>> > >>>>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
>> > >>>>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
>> > >>>>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
>> > >>>>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
>> > >>>>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
>> > >>>>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
>> > >>>>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
>> > >>>>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
>> > >>>>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
>> > >>>>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
>> > >>>>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
>> > >>>>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>> > >>>>> [   15.138875]  RSP <ffff88081ab23d70>
>> > >>>>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
>> > >>>>> [   15.149323] Kernel panic - not syncing: Fatal exception
>> > >>>>>
>> > >>>>
>> > >>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>> > >>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>> > >>>> so.
>> > >>>
>> > >>> Well, what's the tree based on?
>> > >>>
>> > >>> The mainline does this:
>> > >>>
>> > >>> bool sample_taken = intel_pstate_sample(cpu, time);
>> > >>>
>> > >>> if (sample_taken && !hwp_active)
>> > >>>         intel_pstate_adjust_busy_pstate(cpu);
>> > >>>
>> > >>> and (the mainline version of) intel_pstate_sample() returns false when
>> > >>> it is called for the first time after setting the update_util hook.
>> > >>
>> > >> If that helps, I can expose my pm-cpufreq-fixes branch to pull from.
>> > >> It contains all cpufreq material that went into the Linus' tree to
>> > >> date and is based on 4.5-rc3.
>> > >
>> > > In fact, it is exposed already:
>> > >
>> > > git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm.git \
>> > > pm-cpufreq-fixes
>> > >
>> > > and the top-most commit is 1becf03545a0859ceaaf9e8c2d9861882a71cb01
>> > > (cpufreq: intel_pstate: Fix processing for turbo activation ratio).
>> >
>> > Ah, that will fail as well.
>> >
>> > The problem is that intel_pstate_get() can be called before we take
>> > the first sample.
>> >
>> > I need to think about how to fix that.
>>
>> Maybe something like the below (untested, but builds).
>>
>> It will make intel_pstate_get() return 0 until avg_frequency gets populated
>> which is actually OK.
>
> The previous one would break the HWP case, so below is a new one (still
> untested).

I can reproduce the bug and your patch fix it.

Tested-by: Wanpeng Li <wanpeng.li@hotmail.com>

>
> ---
>  drivers/cpufreq/intel_pstate.c |   19 +++++++++----------
>  1 file changed, 9 insertions(+), 10 deletions(-)
>
> Index: linux-pm/drivers/cpufreq/intel_pstate.c
> ===================================================================
> --- linux-pm.orig/drivers/cpufreq/intel_pstate.c
> +++ linux-pm/drivers/cpufreq/intel_pstate.c
> @@ -114,6 +114,7 @@ struct cpudata {
>         u64     prev_mperf;
>         u64     prev_tsc;
>         u64     prev_cummulative_iowait;
> +       int     avg_frequency;
>         struct sample sample;
>  };
>
> @@ -1044,7 +1045,7 @@ static inline void intel_pstate_adjust_b
>                 sample->mperf,
>                 sample->aperf,
>                 sample->tsc,
> -               get_avg_frequency(cpu));
> +               cpu->avg_frequency);
>  }
>
>  static void intel_pstate_update_util(struct update_util_data *data, u64 time,
> @@ -1056,8 +1057,11 @@ static void intel_pstate_update_util(str
>         if ((s64)delta_ns >= pid_params.sample_rate_ns) {
>                 bool sample_taken = intel_pstate_sample(cpu, time);
>
> -               if (sample_taken && !hwp_active)
> -                       intel_pstate_adjust_busy_pstate(cpu);
> +               if (sample_taken) {
> +                       cpu->avg_frequency = get_avg_frequency(cpu);
> +                       if (!hwp_active)
> +                               intel_pstate_adjust_busy_pstate(cpu);
> +               }
>         }
>  }
>
> @@ -1123,14 +1127,9 @@ static int intel_pstate_init_cpu(unsigne
>
>  static unsigned int intel_pstate_get(unsigned int cpu_num)
>  {
> -       struct sample *sample;
> -       struct cpudata *cpu;
> +       struct cpudata *cpu = all_cpu_data[cpu_num];
>
> -       cpu = all_cpu_data[cpu_num];
> -       if (!cpu)
> -               return 0;
> -       sample = &cpu->sample;
> -       return get_avg_frequency(cpu);
> +       return cpu ? cpu->avg_frequency : 0;
>  }
>
>  static void intel_pstate_set_update_util_hook(unsigned int cpu_num)
>



-- 
Regards,
Wanpeng Li

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-05  5:05               ` Wanpeng Li
@ 2016-05-05 13:46                 ` Rafael J. Wysocki
  2016-05-06  7:06                   ` Wanpeng Li
  0 siblings, 1 reply; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-05 13:46 UTC (permalink / raw)
  To: Wanpeng Li
  Cc: Peter Zijlstra, Rafael J. Wysocki, kernel test robot,
	Steve Muckle, lkp, Linux Kernel Mailing List, Vincent Guittot,
	Thomas Gleixner, Patrick Bellasi, Morten Rasmussen,
	Mike Galbraith, Michael Turquette, Juri Lelli, Dietmar Eggemann,
	Steve Muckle, Ingo Molnar, Linux PM list, Srinivas Pandruvada

On Thursday, May 05, 2016 01:05:41 PM Wanpeng Li wrote:
> 2016-05-03 23:10 GMT+08:00 Rafael J. Wysocki <rjw@rjwysocki.net>:
> > On Tuesday, May 03, 2016 03:53:12 PM Rafael J. Wysocki wrote:
> >> On Tuesday, May 03, 2016 03:22:24 PM Rafael J. Wysocki wrote:
> >> > On Tue, May 3, 2016 at 2:58 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
> >> > > On Tue, May 3, 2016 at 2:54 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
> >> > >> On Tue, May 3, 2016 at 2:15 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
> >> > >>> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
> >> > >>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
> >> > >>>>> FYI, we noticed the following commit:
> >> > >>>>>
> >> > >>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
> >> > >>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
> >> > >>>>
> >> > >>>>
> >> > >>>>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
> >> > >>>>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
> >> > >>>>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
> >> > >>>>> [   14.903975] divide error: 0000 [#1] SMP
> >> > >>>>> [   14.908375] Modules linked in:
> >> > >>>>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
> >> > >>>>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
> >> > >>>>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
> >> > >>>>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
> >> > >>>>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
> >> > >>>>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
> >> > >>>>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
> >> > >>>>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
> >> > >>>>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
> >> > >>>>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
> >> > >>>>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
> >> > >>>>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> >> > >>>>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
> >> > >>>>> [   15.018359] Stack:
> >> > >>>>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
> >> > >>>>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
> >> > >>>>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
> >> > >>>>> [   15.045493] Call Trace:
> >> > >>>>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
> >> > >>>>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
> >> > >>>>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
> >> > >>>>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
> >> > >>>>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
> >> > >>>>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
> >> > >>>>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
> >> > >>>>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
> >> > >>>>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
> >> > >>>>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
> >> > >>>>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
> >> > >>>>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
> >> > >>>>> [   15.138875]  RSP <ffff88081ab23d70>
> >> > >>>>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
> >> > >>>>> [   15.149323] Kernel panic - not syncing: Fatal exception
> >> > >>>>>
> >> > >>>>
> >> > >>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
> >> > >>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
> >> > >>>> so.
> >> > >>>
> >> > >>> Well, what's the tree based on?
> >> > >>>
> >> > >>> The mainline does this:
> >> > >>>
> >> > >>> bool sample_taken = intel_pstate_sample(cpu, time);
> >> > >>>
> >> > >>> if (sample_taken && !hwp_active)
> >> > >>>         intel_pstate_adjust_busy_pstate(cpu);
> >> > >>>
> >> > >>> and (the mainline version of) intel_pstate_sample() returns false when
> >> > >>> it is called for the first time after setting the update_util hook.
> >> > >>
> >> > >> If that helps, I can expose my pm-cpufreq-fixes branch to pull from.
> >> > >> It contains all cpufreq material that went into the Linus' tree to
> >> > >> date and is based on 4.5-rc3.
> >> > >
> >> > > In fact, it is exposed already:
> >> > >
> >> > > git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm.git \
> >> > > pm-cpufreq-fixes
> >> > >
> >> > > and the top-most commit is 1becf03545a0859ceaaf9e8c2d9861882a71cb01
> >> > > (cpufreq: intel_pstate: Fix processing for turbo activation ratio).
> >> >
> >> > Ah, that will fail as well.
> >> >
> >> > The problem is that intel_pstate_get() can be called before we take
> >> > the first sample.
> >> >
> >> > I need to think about how to fix that.
> >>
> >> Maybe something like the below (untested, but builds).
> >>
> >> It will make intel_pstate_get() return 0 until avg_frequency gets populated
> >> which is actually OK.
> >
> > The previous one would break the HWP case, so below is a new one (still
> > untested).
> 
> I can reproduce the bug and your patch fix it.
> 
> Tested-by: Wanpeng Li <wanpeng.li@hotmail.com>

Thanks!

Please also try this one:

https://patchwork.kernel.org/patch/9012861/

which is the final fix for this bug.

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-05 13:46                 ` Rafael J. Wysocki
@ 2016-05-06  7:06                   ` Wanpeng Li
  2016-05-06 12:29                     ` Rafael J. Wysocki
  0 siblings, 1 reply; 23+ messages in thread
From: Wanpeng Li @ 2016-05-06  7:06 UTC (permalink / raw)
  To: Rafael J. Wysocki
  Cc: Peter Zijlstra, Rafael J. Wysocki, kernel test robot,
	Steve Muckle, lkp, Linux Kernel Mailing List, Vincent Guittot,
	Thomas Gleixner, Patrick Bellasi, Morten Rasmussen,
	Mike Galbraith, Michael Turquette, Juri Lelli, Dietmar Eggemann,
	Steve Muckle, Ingo Molnar, Linux PM list, Srinivas Pandruvada

2016-05-05 21:46 GMT+08:00 Rafael J. Wysocki <rjw@rjwysocki.net>:
> On Thursday, May 05, 2016 01:05:41 PM Wanpeng Li wrote:
>> 2016-05-03 23:10 GMT+08:00 Rafael J. Wysocki <rjw@rjwysocki.net>:
>> > On Tuesday, May 03, 2016 03:53:12 PM Rafael J. Wysocki wrote:
>> >> On Tuesday, May 03, 2016 03:22:24 PM Rafael J. Wysocki wrote:
>> >> > On Tue, May 3, 2016 at 2:58 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
>> >> > > On Tue, May 3, 2016 at 2:54 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
>> >> > >> On Tue, May 3, 2016 at 2:15 PM, Rafael J. Wysocki <rafael@kernel.org> wrote:
>> >> > >>> On Tue, May 3, 2016 at 10:32 AM, Peter Zijlstra <peterz@infradead.org> wrote:
>> >> > >>>> On Tue, May 03, 2016 at 09:10:51AM +0800, kernel test robot wrote:
>> >> > >>>>> FYI, we noticed the following commit:
>> >> > >>>>>
>> >> > >>>>> https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
>> >> > >>>>> commit 41e0d37f7ac81297c07ba311e4ad39465b8c8295 ("sched/fair: Do not call cpufreq hook unless util changed")
>> >> > >>>>
>> >> > >>>>
>> >> > >>>>> [   14.860950] Freeing unused kernel memory: 260K (ffff88103edbf000 - ffff88103ee00000)
>> >> > >>>>> [   14.873013] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
>> >> > >>>>> [   14.884474] random: systemd urandom read with 5 bits of entropy available
>> >> > >>>>> [   14.903975] divide error: 0000 [#1] SMP
>> >> > >>>>> [   14.908375] Modules linked in:
>> >> > >>>>> [   14.911793] CPU: 39 PID: 1 Comm: systemd Not tainted 4.6.0-rc4-00016-g41e0d37 #1
>> >> > >>>>> [   14.920051] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS SE5C600.86B.02.02.0002.122320131210 12/23/2013
>> >> > >>>>> [   14.931509] task: ffff8810101d8000 ti: ffff88081ab20000 task.ti: ffff88081ab20000
>> >> > >>>>> [   14.939862] RIP: 0010:[<ffffffff8176ad32>]  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>> >> > >>>>> [   14.949202] RSP: 0018:ffff88081ab23d70  EFLAGS: 00010006
>> >> > >>>>> [   14.955129] RAX: 0000000000000000 RBX: 0000000000000024 RCX: ffff8808091e0300
>> >> > >>>>> [   14.963094] RDX: 0000000000000000 RSI: 0000000000000100 RDI: 0000000000000024
>> >> > >>>>> [   14.971057] RBP: ffff88081ab23d88 R08: 0000000000001000 R09: 00000000096a1000
>> >> > >>>>> [   14.979022] R10: 0000000000ffff10 R11: 000000000000000f R12: 0000000000000202
>> >> > >>>>> [   14.986984] R13: ffff88101390a040 R14: ffff88100e48e180 R15: ffff88101390a040
>> >> > >>>>> [   14.994950] FS:  00007f66fe117880(0000) GS:ffff8810139c0000(0000) knlGS:0000000000000000
>> >> > >>>>> [   15.003982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> >> > >>>>> [   15.010393] CR2: 000055f78b760098 CR3: 000000103d759000 CR4: 00000000001406e0
>> >> > >>>>> [   15.018359] Stack:
>> >> > >>>>> [   15.020602]  ffffffff81764dad 0000000000000024 ffff88100e48e180 ffff88081ab23dc8
>> >> > >>>>> [   15.028899]  ffffffff81040267 ffff88101390a0ac 0000000000000340 ffff88081ab23f20
>> >> > >>>>> [   15.037197]  ffff88103cd7c400 ffff88100e48e180 ffff88101390a040 ffff88081ab23e30
>> >> > >>>>> [   15.045493] Call Trace:
>> >> > >>>>> [   15.048223]  [<ffffffff81764dad>] ? cpufreq_quick_get+0x3d/0x90
>> >> > >>>>> [   15.054832]  [<ffffffff81040267>] show_cpuinfo+0x3c7/0x410
>> >> > >>>>> [   15.060956]  [<ffffffff8121f5c4>] seq_read+0x2c4/0x3a0
>> >> > >>>>> [   15.066685]  [<ffffffff81266ea8>] proc_reg_read+0x48/0x70
>> >> > >>>>> [   15.072713]  [<ffffffff811f9d58>] __vfs_read+0x28/0xd0
>> >> > >>>>> [   15.078451]  [<ffffffff813bab63>] ? security_file_permission+0xa3/0xc0
>> >> > >>>>> [   15.085737]  [<ffffffff811faa97>] ? rw_verify_area+0x57/0xd0
>> >> > >>>>> [   15.092054]  [<ffffffff811fab96>] vfs_read+0x86/0x130
>> >> > >>>>> [   15.097691]  [<ffffffff811fbf96>] SyS_read+0x46/0xa0
>> >> > >>>>> [   15.103234]  [<ffffffff818f71b2>] entry_SYSCALL_64_fastpath+0x1a/0xa4
>> >> > >>>>> [   15.110421] Code: 05 dc 1b c3 00 89 ff 55 48 89 e5 48 8b 0c f8 48 85 c9 74 1f 48 63 51 1c 48 63 41 20 5d 48 0f af c2 31 d2 48 0f af 81 88 00 00 00 <48> f7 b1 90 00 00 00 c3 31 c0 5d c3 66 90 0f 1f 44 00 00 8b 77
>> >> > >>>>> [   15.132161] RIP  [<ffffffff8176ad32>] intel_pstate_get+0x32/0x40
>> >> > >>>>> [   15.138875]  RSP <ffff88081ab23d70>
>> >> > >>>>> [   15.142770] ---[ end trace e5d5a8bedf5502e1 ]---
>> >> > >>>>> [   15.149323] Kernel panic - not syncing: Fatal exception
>> >> > >>>>>
>> >> > >>>>
>> >> > >>>> That's intel_pstate.c:get_avg_frequency(), which assumes mperf != 0. It
>> >> > >>>> being 0 seems to suggest intel_pstate_sample() hasn't been called yet or
>> >> > >>>> so.
>> >> > >>>
>> >> > >>> Well, what's the tree based on?
>> >> > >>>
>> >> > >>> The mainline does this:
>> >> > >>>
>> >> > >>> bool sample_taken = intel_pstate_sample(cpu, time);
>> >> > >>>
>> >> > >>> if (sample_taken && !hwp_active)
>> >> > >>>         intel_pstate_adjust_busy_pstate(cpu);
>> >> > >>>
>> >> > >>> and (the mainline version of) intel_pstate_sample() returns false when
>> >> > >>> it is called for the first time after setting the update_util hook.
>> >> > >>
>> >> > >> If that helps, I can expose my pm-cpufreq-fixes branch to pull from.
>> >> > >> It contains all cpufreq material that went into the Linus' tree to
>> >> > >> date and is based on 4.5-rc3.
>> >> > >
>> >> > > In fact, it is exposed already:
>> >> > >
>> >> > > git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm.git \
>> >> > > pm-cpufreq-fixes
>> >> > >
>> >> > > and the top-most commit is 1becf03545a0859ceaaf9e8c2d9861882a71cb01
>> >> > > (cpufreq: intel_pstate: Fix processing for turbo activation ratio).
>> >> >
>> >> > Ah, that will fail as well.
>> >> >
>> >> > The problem is that intel_pstate_get() can be called before we take
>> >> > the first sample.
>> >> >
>> >> > I need to think about how to fix that.
>> >>
>> >> Maybe something like the below (untested, but builds).
>> >>
>> >> It will make intel_pstate_get() return 0 until avg_frequency gets populated
>> >> which is actually OK.
>> >
>> > The previous one would break the HWP case, so below is a new one (still
>> > untested).
>>
>> I can reproduce the bug and your patch fix it.
>>
>> Tested-by: Wanpeng Li <wanpeng.li@hotmail.com>
>
> Thanks!
>
> Please also try this one:
>
> https://patchwork.kernel.org/patch/9012861/
>
> which is the final fix for this bug.

The warning disappear.

Tested-by: Wanpeng Li <wanpeng.li@hotmail.com>

Regards,
Wanpeng Li

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP
  2016-05-06  7:06                   ` Wanpeng Li
@ 2016-05-06 12:29                     ` Rafael J. Wysocki
  0 siblings, 0 replies; 23+ messages in thread
From: Rafael J. Wysocki @ 2016-05-06 12:29 UTC (permalink / raw)
  To: Wanpeng Li
  Cc: Peter Zijlstra, Rafael J. Wysocki, kernel test robot,
	Steve Muckle, lkp, Linux Kernel Mailing List, Vincent Guittot,
	Thomas Gleixner, Patrick Bellasi, Morten Rasmussen,
	Mike Galbraith, Michael Turquette, Juri Lelli, Dietmar Eggemann,
	Steve Muckle, Ingo Molnar, Linux PM list, Srinivas Pandruvada

On Friday, May 06, 2016 03:06:44 PM Wanpeng Li wrote:
> 2016-05-05 21:46 GMT+08:00 Rafael J. Wysocki <rjw@rjwysocki.net>:
> > On Thursday, May 05, 2016 01:05:41 PM Wanpeng Li wrote:
> >> 2016-05-03 23:10 GMT+08:00 Rafael J. Wysocki <rjw@rjwysocki.net>:
> >> > On Tuesday, May 03, 2016 03:53:12 PM Rafael J. Wysocki wrote:

[cut]

> >>
> >> I can reproduce the bug and your patch fix it.
> >>
> >> Tested-by: Wanpeng Li <wanpeng.li@hotmail.com>
> >
> > Thanks!
> >
> > Please also try this one:
> >
> > https://patchwork.kernel.org/patch/9012861/
> >
> > which is the final fix for this bug.
> 
> The warning disappear.
> 
> Tested-by: Wanpeng Li <wanpeng.li@hotmail.com>

Thank you!

^ permalink raw reply	[flat|nested] 23+ messages in thread

end of thread, other threads:[~2016-05-06 12:26 UTC | newest]

Thread overview: 23+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
     [not found] <87mvo8gd44.fsf@yhuang-dev.intel.com>
2016-05-03  8:32 ` [lkp] [sched/fair] 41e0d37f7a: divide error: 0000 [#1] SMP Peter Zijlstra
2016-05-03  9:19   ` Wanpeng Li
2016-05-03  9:25     ` Wanpeng Li
2016-05-03 13:33       ` Rafael J. Wysocki
2016-05-04  0:53         ` Wanpeng Li
2016-05-04 11:41           ` Rafael J. Wysocki
2016-05-04 11:46             ` Wanpeng Li
2016-05-03 12:15   ` Rafael J. Wysocki
2016-05-03 12:54     ` Rafael J. Wysocki
2016-05-03 12:58       ` Rafael J. Wysocki
2016-05-03 13:22         ` Rafael J. Wysocki
2016-05-03 13:53           ` Rafael J. Wysocki
2016-05-03 15:10             ` Rafael J. Wysocki
2016-05-05  5:05               ` Wanpeng Li
2016-05-05 13:46                 ` Rafael J. Wysocki
2016-05-06  7:06                   ` Wanpeng Li
2016-05-06 12:29                     ` Rafael J. Wysocki
2016-05-04  0:58     ` Wanpeng Li
2016-05-04 11:44       ` Rafael J. Wysocki
2016-05-04 11:51         ` Wanpeng Li
2016-05-04 11:56           ` Rafael J. Wysocki
2016-05-04 12:04             ` Wanpeng Li
2016-05-04 12:01   ` [PATCH] intel_pstate: Fix intel_pstate_get() Rafael J. Wysocki

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).