On Wed, 05 Mar 2008 18:45:13 +0100, Andi Kleen said:
> [email protected] writes:
> >
> > So we're in the same 4K as the VDSO64_* values, but some 0x4fe past the
> > gtod_data. Anybody got a hint as to what the heck it was doing?
>
> Try this patch:
>
> Remove unlikelies in vsyscall path

Nope, sorry... same behavior. Apparently it's a (un)likely someplace
else...

I'm trying to figure out what's at 0x9be into the vdso, but not having
a lot of luck.

Attachments:

(No filename) (226.00 B)

2008-03-05 21:55:54

by Andi Kleen

[permalink] [raw]

Subject: Re: 2.6.25-rc3-mm1 - PROFILE_LIKELY redux..

On Wed, Mar 05, 2008 at 02:59:57PM -0500, [email protected] wrote:
> On Wed, 05 Mar 2008 18:45:13 +0100, Andi Kleen said:
> > [email protected] writes:
> > >
> > > So we're in the same 4K as the VDSO64_* values, but some 0x4fe past the
> > > gtod_data. Anybody got a hint as to what the heck it was doing?
> >
> > Try this patch:
> >
> > Remove unlikelies in vsyscall path
>
> Nope, sorry... same behavior. Apparently it's a (un)likely someplace
> else...
>
> I'm trying to figure out what's at 0x9be into the vdso, but not having
> a lot of luck.

You can do objdump -Sr on the vdso/vsyscall object files and see
if there are any external references to unlikely related functions. If yes
the problem is in that function

-Andi

2008-03-05 21:56:25

by Andrew Morton

[permalink] [raw]

Subject: Re: 2.6.25-rc3-mm1 ppc64 boot hang

On Wed, 05 Mar 2008 13:34:14 -0800
Badari Pulavarty <[email protected]> wrote:

> On Tue, 2008-03-04 at 01:19 -0800, Andrew Morton wrote:
> > ftp://ftp.kernel.org/pub/linux/kernel/people/akpm/patches/2.6/2.6.25-rc3/2.6.25-rc3-mm1/
> >
>
> Hi Andrew,
>
> Not able to boot 2.6.25-rc3-mm1 my ppc64 box.
> 2.6.25-rc2-mm1 and 2.6.25-rc3 boots fine.
>
> I applied slab.c fix also.
>
> Any other known issues ? My config file attached.
> Here are the messages on the console.

The semaphore consolidation code enables interrupts early in boot, when it
shouldn't. This tends to make powerpc blow up. Could be that this is what
you're hitting.

Matthew, is this ging to be fixed soon?

Thanks.

Hi Andrew,

On Wed, 5 Mar 2008 13:54:25 -0800 Andrew Morton <[email protected]> wrote:
>
> The semaphore consolidation code enables interrupts early in boot, when it
> shouldn't. This tends to make powerpc blow up. Could be that this is what
> you're hitting.
>
> Matthew, is this ging to be fixed soon?

There is a new version of these patches in the current linux-next tree ...

--
Cheers,
Stephen Rothwell [email protected]

Attachments:

(No filename) (461.00 B)
(No filename) (189.00 B)
Download all attachments

2008-03-05 23:50:38

by Andrew Morton

[permalink] [raw]

Subject: Re: 2.6.25-rc3-mm1 - PROFILE_LIKELY redux..

On Wed, 05 Mar 2008 17:26:25 -0500
[email protected] wrote:

> On Wed, 05 Mar 2008 10:02:21 PST, Andrew Morton said:
>
> > at the top, so it'll be something else. Perhaps a `likely' snuck in via an
> > inline in a header file. It would be better to add a #define DONT_DO_THAT
> > at the top of arch/x86/kernel/vsyscall_64.c and
> > arch/x86/vdso/vclock_gettime.c, then use that to defeat likely-profiling.
> >
> > arch/x86/kernel/vsyscall_64.c | 11 ++---------
> > arch/x86/vdso/vclock_gettime.c | 11 ++---------
> > include/linux/compiler.h | 3 ++-
> > 3 files changed, 6 insertions(+), 19 deletions(-)
>
> Confirming that this patch works and my system goes multi-user cleanly.

Thanks.

> Actual numbers after about 10 minutes of uptime:
>
> % wc -l /proc/likely_prof
> 2635 /proc/likely_prof
> % grep '^[^ ]' /proc/likely_prof
> Likely Profiling Results
> [+- ] Type | # True | # False | Function:Filename@Line
> +unlikely | 1| 0 in_dev_get()@:include/linux/inetdevice.h@185
> +unlikely | 513| 0 dst_input()@:include/net/dst.h@254
> -likely | 0| 148 ip6_mc_input()@:net/ipv6/ip6_input.c@271
> -likely | 0| 1 sock_error()@:include/net/sock.h@1211
> -likely | 851| 1219 tcp_transmit_skb()@:net/ipv4/tcp_output.c@493
> +unlikely | 1| 0 signal_pending()@:include/linux/sched.h@1927
> -likely | 0| 1172946 audit_syscall_entry()@:kernel/auditsc.c@1522
> +unlikely | 1172716| 0 syscall_trace_enter()@:arch/x86/kernel/ptrace.c@1556
> -likely | 0| 1173020 audit_syscall_exit()@:kernel/auditsc.c@1551
> +unlikely | 1172831| 0 syscall_trace_leave()@:arch/x86/kernel/ptrace.c@1573
> -likely | 0| 1272 audit_alloc()@:kernel/auditsc.c@841
> +unlikely | 3| 0 icmp_unreach()@:net/ipv4/icmp.c@773
> +unlikely | 2| 1 nf_ct_attach()@:net/netfilter/core.c@230
> -likely | 0| 2 dst_gc_task()@:net/core/dst.c@82
> +unlikely | 143| 61 fput_light()@:include/linux/file.h@77
> +unlikely | 892| 424 _read_unlock_irqrestore()@:kernel/spinlock.c@375
> +unlikely | 28| 0 sched_move_task()@:kernel/sched.c@7835
> +unlikely | 28| 0 sched_move_task()@:kernel/sched.c@7828
> +unlikely | 108| 0 verify_export_symbols()@:kernel/module.c@1401
> +unlikely | 313| 0 verify_export_symbols()@:kernel/module.c@1393
> +unlikely | 14| 0 ll_front_merge_fn()@:block/blk-merge.c@347
> -likely | 17| 1150 audit_free()@:kernel/auditsc.c@1428
> -likely | 17| 1174290 audit_get_context()@:kernel/auditsc.c@711
> +unlikely | 33| 0 inotify_find_update_watch()@:fs/inotify.c@591
> +unlikely | 4360| 775 kill_pid_info()@:kernel/signal.c@1065
> +unlikely | 7239| 2767 next_pidmap()@:kernel/pid.c@194
> +unlikely | 42009| 33683 copy_pte_range()@:mm/memory.c@510
> -likely | 0| 1 qh_completions()@:drivers/usb/host/ehci-q.c@368
> +unlikely | 19934| 0 ll_back_merge_fn()@:block/blk-merge.c@309
> -likely | 927| 2323 load_elf_binary()@:fs/binfmt_elf.c@896
> +unlikely | 2435| 875 pmd_alloc()@:include/linux/mm.h@862
> +unlikely | 13| 12 psmouse_interrupt()@:drivers/input/mouse/psmouse-base.c@296
> +unlikely | 70| 25 psmouse_interrupt()@:drivers/input/mouse/psmouse-base.c@292
> -likely | 20| 80 qh_completions()@:drivers/usb/host/ehci-q.c@415
> -likely | 0| 30 qh_completions()@:drivers/usb/host/ehci-q.c@319
> -likely | 5| 14 submit_async()@:drivers/usb/host/ehci-q.c@975
> +unlikely | 19| 2 qh_append_tds()@:drivers/usb/host/ehci-q.c@876
> -likely | 6| 15 atapi_drain_needed()@:drivers/ata/libata-scsi.c@846
> +unlikely | 27395| 18153 add_timer_randomness()@:drivers/char/random.c@628
> +unlikely | 34665| 19948 bio_phys_segments()@:fs/bio.c@226
> -likely | 347| 678 clocksource_adjust()@:kernel/time/timekeeping.c@418
> -likely | 1| 4 __ata_qc_from_tag()@:include/linux/libata.h@1319
> -likely | 0| 15 __cancel_work_timer()@:kernel/workqueue.c@490
> +unlikely | 15638| 1127 queue_delayed_work_on()@:kernel/workqueue.c@233
> +unlikely | 2| 0 srcu_notifier_chain_register()@:kernel/notifier.c@419
> +unlikely | 6502| 2429 queue_work()@:kernel/workqueue.c@171
> +unlikely | 9| 2 blocking_notifier_chain_register()@:kernel/notifier.c@212
> +unlikely | 13631| 0 pre_schedule_rt()@:kernel/sched_rt.c@961
> +unlikely | 591400| 443725 __update_curr()@:kernel/sched_fair.c@313
> +unlikely | 233625| 205658 __switch_to()@:arch/x86/kernel/process_64.c@656
> +unlikely | 313057| 126225 __switch_to()@:arch/x86/kernel/process_64.c@641
> +unlikely | 313053| 126225 __switch_to()@:arch/x86/kernel/process_64.c@637
> +unlikely | 467383| 0 sched_info_switch()@:kernel/sched_stats.h@230
> +unlikely | 188448| 13628 pick_next_task_rt()@:kernel/sched_rt.c@522
> +unlikely | 240619| 0 sched_info_queued()@:kernel/sched_stats.h@188
> -likely | 61| 644 ifind()@:fs/inode.c@798
> +unlikely | 258562| 61703 scheduler_tick()@:kernel/sched.c@3756
> -likely | 61220| 241529 acct_update_integrals()@:kernel/tsacct.c@120
> +unlikely | 1189922| 902477 kfree()@:mm/slab.c@3785
> +unlikely | 23| 0 __rmqueue_fallback()@:mm/page_alloc.c@812
> +unlikely | 14376| 9655 rt_policy()@:kernel/sched.c@140

These are all the ones which we got wrong on your setup, yes?

I wonder if assuming that current->audit_context is NULL is realistic
nowadays.

2008-03-06 00:04:53

by Benjamin Herrenschmidt

[permalink] [raw]

Subject: Re: [BUG] 2.6.25-rc3-mm1 kernel panic while bootup on powerpc ()

> Yes, we are - it's the semaphore rewrite which is doing this in
> start_kernel(). It's being discussed.
>
> Enabling interrupts too early on powerpc was discovered to be fatal on
> powerpc years ago. It looks like that remains the case.

Regarding these issues. I could make it non fatal and just WARN_ON,
provided that I have a way to differentiate legal vs. illegal calls
to local_irq_enable(). We already have that function mostly out of
line in C code due to our lazy irq disabling scheme, so the overhead of
testing some global kernel state would be minimum here.

However, I don't see anything around init/main.c:start_kernel() that I
can use. What do you reckon here we should do ? Add some kind of global
we set before calling local_irq_enable() ? Or make early_boot_irqs_on()
do that generically

It's currently defined as an empty inline without CONFIG_TRACE_IRQFLAGS
but we could make it set a flag instead.

I'm pretty sure other archs have similar problems, especially in the
embedded world where you are booted with random junk firmwares that may
leave devices, interrupt controllers etc... in random state, and
enabling incoming IRQs before the arch code properly initializes the
main interrupt controller can be fatal. I know at least of an ARM board
I worked on a while ago that had a similar issues.

On ppc32, unfortunately, our local_irq_enable/restore are nice inlines
that whack the appropriate MSR bits directly, thus adding a test for a
global flag would add some bloat/overhead that I'd like to avoid, at
least until we decide to also do lazy disabling on those, if ever...

Cheers,
Ben.

2008-03-06 00:46:23

by Andrew Morton

[permalink] [raw]

Subject: Re: [BUG] 2.6.25-rc3-mm1 kernel panic while bootup on powerpc ()

by Andrew Morton

[permalink] [raw]

* [email protected] <[email protected]> wrote:

> Given that -mmotm isn't showing the problem, I'm having a hard time
> coming up with enthusiasm to keep chasing it. If I see it happen
> again in a -mm or Linus kernel, I'll restart the chase then....

if it ever reappears then please check x86/latest first (without any
other -mm bits) and notify us.

Ingo