[PATCH] tracing: use raw spinlocks instead of spinlocks

[PATCH] tracing: use raw spinlocks instead of spinlocks

[Frederic Weisbecker]

When I tried to figure out why my experimental function's return tracer was hanging, I discovered
that it was partially caused by the fact that the ring buffer might use the usual spinlocks during
entry insertion.

ring_buffer_lock_reserve() -> rb_reserve_next_event() -> __rb_reserve_next() -> spin_lock_irqsave()

Since this last function is traced, the result is a recursion during the trace. I guess it
happens too with the function tracer.

We should use the raw_spin_locks which are not traced.

Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com>
---
 kernel/trace/ring_buffer.c |   33 ++++++++++++++++++++-------------
 1 files changed, 20 insertions(+), 13 deletions(-)

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index cedf4e2..3e5a723 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -152,7 +152,7 @@ static inline int test_time_stamp(u64 delta)
 struct ring_buffer_per_cpu {
 	int				cpu;
 	struct ring_buffer		*buffer;
-	spinlock_t			lock;
+	raw_spinlock_t			lock;
 	struct lock_class_key		lock_key;
 	struct list_head		pages;
 	struct buffer_page		*head_page;	/* read from head */
@@ -289,7 +289,7 @@ rb_allocate_cpu_buffer(struct ring_buffer *buffer, int cpu)
 
 	cpu_buffer->cpu = cpu;
 	cpu_buffer->buffer = buffer;
-	spin_lock_init(&cpu_buffer->lock);
+	cpu_buffer->lock = (raw_spinlock_t)__RAW_SPIN_LOCK_UNLOCKED;
 	INIT_LIST_HEAD(&cpu_buffer->pages);
 
 	page = kzalloc_node(ALIGN(sizeof(*page), cache_line_size()),
@@ -851,8 +851,8 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
 	/* See if we shot pass the end of this buffer page */
 	if (write > BUF_PAGE_SIZE) {
 		struct buffer_page *next_page = tail_page;
-
-		spin_lock_irqsave(&cpu_buffer->lock, flags);
+		raw_local_irq_save(flags);
+		__raw_spin_lock(&cpu_buffer->lock);
 
 		rb_inc_page(cpu_buffer, &next_page);
 
@@ -927,8 +927,8 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
 		    tail == rb_commit_index(cpu_buffer)) {
 			rb_set_commit_to_write(cpu_buffer);
 		}
-
-		spin_unlock_irqrestore(&cpu_buffer->lock, flags);
+		__raw_spin_unlock(&cpu_buffer->lock);
+		raw_local_irq_restore(flags);
 
 		/* fail and let the caller try again */
 		return ERR_PTR(-EAGAIN);
@@ -951,7 +951,8 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
 	return event;
 
  out_unlock:
-	spin_unlock_irqrestore(&cpu_buffer->lock, flags);
+	__raw_spin_unlock(&cpu_buffer->lock);
+	raw_local_irq_restore(flags);
 	return NULL;
 }
 
@@ -1533,7 +1534,8 @@ rb_get_reader_page(struct ring_buffer_per_cpu *cpu_buffer)
 	struct buffer_page *reader = NULL;
 	unsigned long flags;
 
-	spin_lock_irqsave(&cpu_buffer->lock, flags);
+	raw_local_irq_save(flags);
+	__raw_spin_lock(&cpu_buffer->lock);
 
  again:
 	reader = cpu_buffer->reader_page;
@@ -1583,7 +1585,8 @@ rb_get_reader_page(struct ring_buffer_per_cpu *cpu_buffer)
 	goto again;
 
  out:
-	spin_unlock_irqrestore(&cpu_buffer->lock, flags);
+	__raw_spin_unlock(&cpu_buffer->lock);
+	raw_local_irq_restore(flags);
 
 	return reader;
 }
@@ -1824,9 +1827,11 @@ ring_buffer_read_start(struct ring_buffer *buffer, int cpu)
 	atomic_inc(&cpu_buffer->record_disabled);
 	synchronize_sched();
 
-	spin_lock_irqsave(&cpu_buffer->lock, flags);
+	raw_local_irq_save(flags);
+	__raw_spin_lock(&cpu_buffer->lock);
 	ring_buffer_iter_reset(iter);
-	spin_unlock_irqrestore(&cpu_buffer->lock, flags);
+	__raw_spin_unlock(&cpu_buffer->lock);
+	raw_local_irq_restore(flags);
 
 	return iter;
 }
@@ -1912,11 +1917,13 @@ void ring_buffer_reset_cpu(struct ring_buffer *buffer, int cpu)
 	if (!cpu_isset(cpu, buffer->cpumask))
 		return;
 
-	spin_lock_irqsave(&cpu_buffer->lock, flags);
+	raw_local_irq_save(flags);
+	__raw_spin_lock(&cpu_buffer->lock);
 
 	rb_reset_cpu(cpu_buffer);
 
-	spin_unlock_irqrestore(&cpu_buffer->lock, flags);
+	__raw_spin_unlock(&cpu_buffer->lock);
+	raw_local_irq_restore(flags);
 }
 
 /**

Re: [PATCH] tracing: use raw spinlocks instead of spinlocks

[Steven Rostedt]

On Mon, 3 Nov 2008, Frederic Weisbecker wrote:

> When I tried to figure out why my experimental function's return tracer was hanging, I discovered
> that it was partially caused by the fact that the ring buffer might use the usual spinlocks during
> entry insertion.
> 
> ring_buffer_lock_reserve() -> rb_reserve_next_event() -> __rb_reserve_next() -> spin_lock_irqsave()
> 
> Since this last function is traced, the result is a recursion during the trace. I guess it
> happens too with the function tracer.
> 
> We should use the raw_spin_locks which are not traced.
> 
> Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com>

Frederic,

Ingo has been very adamant about not using raw_spin_locks in the ring 
buffers. My original code did this, and he nacked it. The reason being 
(and he eventually convinced me) was that by using raw, we not only do not 
trace the locking, we also remove the lock checking. This code can easily 
produce deadlocks, so we do not want the lock checking removed.

The real fix is to find a way in your tracer to detect the recursion, and 
be able to prevent it. Like the atomic disables I use in ftrace. It does 
the same thing. It leaves the lockdep checking on its own locks, but can 
also detect if the lock checking caused it to recurse. When the recusion 
is detected, the tracer itself will not trace.

[ I hope this makes sense, I'm writing this on 3 hours of sleep ]

Thanks,

-- Steve

Re: [PATCH] tracing: use raw spinlocks instead of spinlocks

[Frédéric Weisbecker]

2008/11/3 Steven Rostedt <rostedt@goodmis.org>:
> Frederic,
>
> Ingo has been very adamant about not using raw_spin_locks in the ring
> buffers. My original code did this, and he nacked it. The reason being
> (and he eventually convinced me) was that by using raw, we not only do not
> trace the locking, we also remove the lock checking. This code can easily
> produce deadlocks, so we do not want the lock checking removed.

Ok. I understand...

> The real fix is to find a way in your tracer to detect the recursion, and
> be able to prevent it. Like the atomic disables I use in ftrace. It does
> the same thing. It leaves the lockdep checking on its own locks, but can
> also detect if the lock checking caused it to recurse. When the recusion
> is detected, the tracer itself will not trace.

You mean this part in function_trace_call?

disabled = atomic_inc_return(&data->disabled);
if (likely(disabled == 1))
		trace_function(tr, data, ip, parent_ip, flags, pc);

atomic_dec(&data->disabled);

That's a good idea. Since it applies on one cpu_data specific and
preempt and irq are disabled, the function
tracer doesn't risk to loose a trace. I think I will apply the same method.

Thanks!

> [ I hope this makes sense, I'm writing this on 3 hours of sleep ]

Yes, don't worry :-)

Re: [PATCH] tracing: use raw spinlocks instead of spinlocks

[Ingo Molnar]

* Steven Rostedt <rostedt@goodmis.org> wrote:

> On Mon, 3 Nov 2008, Frederic Weisbecker wrote:
> 
> > When I tried to figure out why my experimental function's return 
> > tracer was hanging, I discovered that it was partially caused by 
> > the fact that the ring buffer might use the usual spinlocks during 
> > entry insertion.
> > 
> > ring_buffer_lock_reserve() -> rb_reserve_next_event() -> 
> > __rb_reserve_next() -> spin_lock_irqsave()
> > 
> > Since this last function is traced, the result is a recursion 
> > during the trace. I guess it happens too with the function tracer.
> > 
> > We should use the raw_spin_locks which are not traced.
> > 
> > Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com>
> 
> Frederic,
> 
> Ingo has been very adamant about not using raw_spin_locks in the 
> ring buffers. My original code did this, and he nacked it. The 
> reason being (and he eventually convinced me) was that by using raw, 
> we not only do not trace the locking, we also remove the lock 
> checking. This code can easily produce deadlocks, so we do not want 
> the lock checking removed.
> 
> The real fix is to find a way in your tracer to detect the 
> recursion, and be able to prevent it. Like the atomic disables I use 
> in ftrace. It does the same thing. It leaves the lockdep checking on 
> its own locks, but can also detect if the lock checking caused it to 
> recurse. When the recusion is detected, the tracer itself will not 
> trace.

i'm wondering, does the changing to raw-spinlocks fix the deadlock? 
It's generally just the lack of recursion checking that is causing 
lockdep troubles - and recursion checking we want for all the more 
intrusive ftrace plugins anyway.

Frederic, do you have trouble finding the source of the deadlock? In 
theory the NMI watchdog should be able to punch through it. (if not 
then we need to improve things so that it can)

	Ingo

Re: [PATCH] tracing: use raw spinlocks instead of spinlocks

[Frédéric Weisbecker]

2008/11/3 Ingo Molnar <mingo@elte.hu>:
> i'm wondering, does the changing to raw-spinlocks fix the deadlock?

Yes. The real problem was that insertion hold a spinlock, and then the spinlock
was traced, and then it could hold anymore the spinlock in insertion
....deadlock.
It fixed the problem with this solution.

> It's generally just the lack of recursion checking that is causing
> lockdep troubles - and recursion checking we want for all the more
> intrusive ftrace plugins anyway.

This problem wasn't lockdep relative. _But_ I had to deactivate lockdep for my
plugin to work. It seems there are some deadlock encountered with lockdep
enabled but I'm not sure why...
But of course it's just to make easy its implementation, I will adapt
it to rely on lockdep
in the end.

> Frederic, do you have trouble finding the source of the deadlock? In
> theory the NMI watchdog should be able to punch through it. (if not
> then we need to improve things so that it can)

I haven't any deadlock more (I hope) since I implemented the solution
of Steven (
and deactivated lockdep). But I discovered other problems that seem to
rely on page
faults (or it causes them). But I'm not sure yet, it was late at
night. I went to bed after some awful Oops.

The good news is that I now have backtraces to debug it :-)

Re: [PATCH] tracing: use raw spinlocks instead of spinlocks

[Frédéric Weisbecker]

2008/11/3 Ingo Molnar <mingo@elte.hu>:
> Frederic, do you have trouble finding the source of the deadlock? In
> theory the NMI watchdog should be able to punch through it. (if not
> then we need to improve things so that it can)

Ok...actually I still have a deadlock. Or it seems to. I launch the
return tracer and then...the system
can block after several seconds, typically after I try to write some
characters on the terminal.

It happens more easily on SMP.

I enabled all I could for lock debugging, but I don't have any errors printed...
Lockdep uses an NMI wachdog?

Re: [PATCH] tracing: use raw spinlocks instead of spinlocks

[Ingo Molnar]

* Frédéric Weisbecker <fweisbec@gmail.com> wrote:

> 2008/11/3 Ingo Molnar <mingo@elte.hu>:
> > Frederic, do you have trouble finding the source of the deadlock? In
> > theory the NMI watchdog should be able to punch through it. (if not
> > then we need to improve things so that it can)
> 
> Ok...actually I still have a deadlock. Or it seems to. I launch the 
> return tracer and then...the system can block after several seconds, 
> typically after I try to write some characters on the terminal.
> 
> It happens more easily on SMP.
> 
> I enabled all I could for lock debugging, but I don't have any 
> errors printed... Lockdep uses an NMI wachdog?

lockdep works via a completely different principle: it instruments all 
the actual lock acquire/release calls and builds a graph of lock 
dependencies in the system, as it happens.

It also guarantees that all the observed locking rules are followed 
(i.e. it proves that as long as you dont get any messages from 
lockdep, all the locking patterns are mathematically safe).

So a lockdep message will most of the time occur much easier than a 
real lockup would occur - as lockdep only needs to observe 
inconsistent locking patterns to prove that a lockup _could_ occur.

The NMI watchdog just observes the system and complains if it sees 
hardirqs not progressing (i.e. a hard lockup). It will detect anything 
that causes a hard lockup. (assuming that the NMI watchdog itself is 
not locked up)

Regarding your lockup ... it's quite hard. Maybe you can get more 
output out of the system by using:

  earlyprintk=vga,keep

plus disablig regular tty output. (i.e. not passing any 'console=tty' 
line to the kernel bootup.)

this way you wont get any normal printk activities (which might lock 
up), you should only get the very simple early-printk output.

it is also probably useful to mark the early-printk code notrace in 
arch/x86/kernel/Makefile, via the patch below. (i've just applied to 
to tip/x86/debug and pushed it out into tip/master)

... but that's still not a guarantee that you'll be able to debug it 
this way :-/ Bootstrapping something this intrusive and wide is one of 
the hardest kernel development activities possible.

	Ingo

---------------->
>From 6cf87efbc7a3676e0ad7c9622ec6aec244a593bc Mon Sep 17 00:00:00 2001
From: Ingo Molnar <mingo@elte.hu>
Date: Tue, 4 Nov 2008 10:42:23 +0100
Subject: [PATCH] x86 debug: mark early_printk.o as notrace

Impact: do not do function-tracing in the early-printk code

this is useful when earlyprintk=vga,keep is used to debug tracer
plugins.

Signed-off-by: Ingo Molnar <mingo@elte.hu>
---
 arch/x86/kernel/Makefile |    1 +
 1 files changed, 1 insertions(+), 0 deletions(-)

diff --git a/arch/x86/kernel/Makefile b/arch/x86/kernel/Makefile
index e489ff9..943fe60 100644
--- a/arch/x86/kernel/Makefile
+++ b/arch/x86/kernel/Makefile
@@ -12,6 +12,7 @@ CFLAGS_REMOVE_tsc.o = -pg
 CFLAGS_REMOVE_rtc.o = -pg
 CFLAGS_REMOVE_paravirt-spinlocks.o = -pg
 CFLAGS_REMOVE_ftrace.o = -pg
+CFLAGS_REMOVE_early_printk.o = -pg
 endif
 
 #

Re: [PATCH] tracing: use raw spinlocks instead of spinlocks

[Frédéric Weisbecker]

2008/11/4 Ingo Molnar <mingo@elte.hu>:
> lockdep works via a completely different principle: it instruments all
> the actual lock acquire/release calls and builds a graph of lock
> dependencies in the system, as it happens.
>
> It also guarantees that all the observed locking rules are followed
> (i.e. it proves that as long as you dont get any messages from
> lockdep, all the locking patterns are mathematically safe).
>
> So a lockdep message will most of the time occur much easier than a
> real lockup would occur - as lockdep only needs to observe
> inconsistent locking patterns to prove that a lockup _could_ occur.


Ok, so if there is such an error, I could (hopefully) see it with
early_printk....


> The NMI watchdog just observes the system and complains if it sees
> hardirqs not progressing (i.e. a hard lockup). It will detect anything
> that causes a hard lockup. (assuming that the NMI watchdog itself is
> not locked up)
>
> Regarding your lockup ... it's quite hard. Maybe you can get more
> output out of the system by using:
>
>  earlyprintk=vga,keep
>
> plus disablig regular tty output. (i.e. not passing any 'console=tty'
> line to the kernel bootup.)
>
> this way you wont get any normal printk activities (which might lock
> up), you should only get the very simple early-printk output.



Good idea. After reading your mail, I had a look on early_printk and
it shoudn't cause any tracing recursion after
your patch: the strings are directly writed to the vga. Great.


> ... but that's still not a guarantee that you'll be able to debug it
> this way :-/ Bootstrapping something this intrusive and wide is one of
> the hardest kernel development activities possible.


I've been on it for two weeks now. Yes it's very hard. But exciting!

>        Ingo
>
> ---------------->
> From 6cf87efbc7a3676e0ad7c9622ec6aec244a593bc Mon Sep 17 00:00:00 2001
> From: Ingo Molnar <mingo@elte.hu>
> Date: Tue, 4 Nov 2008 10:42:23 +0100
> Subject: [PATCH] x86 debug: mark early_printk.o as notrace
>
> Impact: do not do function-tracing in the early-printk code
>
> this is useful when earlyprintk=vga,keep is used to debug tracer
> plugins.
>
> Signed-off-by: Ingo Molnar <mingo@elte.hu>
> ---
>  arch/x86/kernel/Makefile |    1 +
>  1 files changed, 1 insertions(+), 0 deletions(-)
>
> diff --git a/arch/x86/kernel/Makefile b/arch/x86/kernel/Makefile
> index e489ff9..943fe60 100644
> --- a/arch/x86/kernel/Makefile
> +++ b/arch/x86/kernel/Makefile
> @@ -12,6 +12,7 @@ CFLAGS_REMOVE_tsc.o = -pg
>  CFLAGS_REMOVE_rtc.o = -pg
>  CFLAGS_REMOVE_paravirt-spinlocks.o = -pg
>  CFLAGS_REMOVE_ftrace.o = -pg
> +CFLAGS_REMOVE_early_printk.o = -pg
>  endif
>
>  #
>

I will test your advices this evening and pull latest -tip to get this
patch. Thanks!

Re: [PATCH] tracing: use raw spinlocks instead of spinlocks

[Ingo Molnar]

* Frédéric Weisbecker <fweisbec@gmail.com> wrote:

> 2008/11/4 Ingo Molnar <mingo@elte.hu>:
> > lockdep works via a completely different principle: it instruments all
> > the actual lock acquire/release calls and builds a graph of lock
> > dependencies in the system, as it happens.
> >
> > It also guarantees that all the observed locking rules are followed
> > (i.e. it proves that as long as you dont get any messages from
> > lockdep, all the locking patterns are mathematically safe).
> >
> > So a lockdep message will most of the time occur much easier than a
> > real lockup would occur - as lockdep only needs to observe
> > inconsistent locking patterns to prove that a lockup _could_ occur.
> 
> 
> Ok, so if there is such an error, I could (hopefully) see it with
> early_printk....
> 
> 
> > The NMI watchdog just observes the system and complains if it sees
> > hardirqs not progressing (i.e. a hard lockup). It will detect anything
> > that causes a hard lockup. (assuming that the NMI watchdog itself is
> > not locked up)
> >
> > Regarding your lockup ... it's quite hard. Maybe you can get more
> > output out of the system by using:
> >
> >  earlyprintk=vga,keep
> >
> > plus disablig regular tty output. (i.e. not passing any 'console=tty'
> > line to the kernel bootup.)
> >
> > this way you wont get any normal printk activities (which might lock
> > up), you should only get the very simple early-printk output.
> 
> 
> 
> Good idea. After reading your mail, I had a look on early_printk and 
> it shoudn't cause any tracing recursion after your patch: the 
> strings are directly writed to the vga. Great.

just make sure normal printk is totally silent. (otherwise you get 
double lines on the console plus no reduction in recursion risk)

i usually add a return; hack to kernel/printk.c:printk(), to make sure 
it never executes anything. (and add a notrace to it as well) Maybe we 
could even make this dependent on early_printk=...,keep.

	Ingo

Re: [PATCH] tracing: use raw spinlocks instead of spinlocks

[Frédéric Weisbecker]

2008/11/4 Ingo Molnar <mingo@elte.hu>:
> just make sure normal printk is totally silent. (otherwise you get
> double lines on the console plus no reduction in recursion risk)
>
> i usually add a return; hack to kernel/printk.c:printk(), to make sure
> it never executes anything. (and add a notrace to it as well) Maybe we
> could even make this dependent on early_printk=...,keep.

Thanks for your help!

I tried the earlyprintk=vga,keep and I thought that the normal printk
output would
be replaced by early_printk output but that's not the case...
So I replaced the content of printk by this of early_printk and it worked.
But it seems that after the setting of the console, the early_printk
doesn't work anymore.

Should I disable something else? I haven't any console=.... parameter
but I guess I missed
something there...

But, I set the parameter nmi_watchdog=2 (I didn't know I had to start
explicitly the nmi watchdog)
and at last... I had my backtraces :-)

All these backtraces were related to time function. And one of the
special things of the time functions
is that they often manipulate 64 bits numbers. Actually I totally
forgot that a function could return a
long long, so I had to save edx register in the return handler to
restore it in its end because 64 bits
numbers are returned as a couple into eax and edx in x86-32.

So the main problem is now solved. But it remains a last (but more
rare) deadlock somewhere. I don't
know why at this time and the nmi watchdog doesn't tell anything. So I
will have to use early_printk
to see the last functions traced. But the problem is that it doesn't
print on the console...

Re: [PATCH] tracing: use raw spinlocks instead of spinlocks

[Ingo Molnar]

* Frédéric Weisbecker <fweisbec@gmail.com> wrote:

> 2008/11/4 Ingo Molnar <mingo@elte.hu>:
> > just make sure normal printk is totally silent. (otherwise you get
> > double lines on the console plus no reduction in recursion risk)
> >
> > i usually add a return; hack to kernel/printk.c:printk(), to make sure
> > it never executes anything. (and add a notrace to it as well) Maybe we
> > could even make this dependent on early_printk=...,keep.
> 
> Thanks for your help!
> 
> I tried the earlyprintk=vga,keep and I thought that the normal printk
> output would
> be replaced by early_printk output but that's not the case...
> So I replaced the content of printk by this of early_printk and it worked.
> But it seems that after the setting of the console, the early_printk
> doesn't work anymore.
> 
> Should I disable something else? I haven't any console=.... parameter
> but I guess I missed
> something there...

perhaps try a "console=tty 3" bootup - to boot into non-graphics 
initlevel 3, and to have a vga tty set up. Then comment out the 
regular printk(), to make sure it never tries to output to the regular 
tty.

does earlyprintk=vga,keep work in that case?

> But, I set the parameter nmi_watchdog=2 (I didn't know I had to 
> start explicitly the nmi watchdog) and at last... I had my 
> backtraces :-)

heh :-)

> All these backtraces were related to time function. And one of the 
> special things of the time functions is that they often manipulate 
> 64 bits numbers. Actually I totally forgot that a function could 
> return a long long, so I had to save edx register in the return 
> handler to restore it in its end because 64 bits numbers are 
> returned as a couple into eax and edx in x86-32.
> 
> So the main problem is now solved. But it remains a last (but more 
> rare) deadlock somewhere. I don't know why at this time and the nmi 
> watchdog doesn't tell anything. So I will have to use early_printk 
> to see the last functions traced. But the problem is that it doesn't 
> print on the console...

hm. Let me know if you cannot get this to work. I regularly use 
earlyprintk=serial,...,keep myself, and it works there - but i dont 
use earlyprintk=vga,keep that often.

	Ingo

Re: [PATCH] tracing: use raw spinlocks instead of spinlocks

[Frédéric Weisbecker]

2008/11/5 Ingo Molnar <mingo@elte.hu>:
>
> * Frédéric Weisbecker <fweisbec@gmail.com> wrote:
>
>> 2008/11/4 Ingo Molnar <mingo@elte.hu>:
>> > just make sure normal printk is totally silent. (otherwise you get
>> > double lines on the console plus no reduction in recursion risk)
>> >
>> > i usually add a return; hack to kernel/printk.c:printk(), to make sure
>> > it never executes anything. (and add a notrace to it as well) Maybe we
>> > could even make this dependent on early_printk=...,keep.
>>
>> Thanks for your help!
>>
>> I tried the earlyprintk=vga,keep and I thought that the normal printk
>> output would
>> be replaced by early_printk output but that's not the case...
>> So I replaced the content of printk by this of early_printk and it worked.
>> But it seems that after the setting of the console, the early_printk
>> doesn't work anymore.
>>
>> Should I disable something else? I haven't any console=.... parameter
>> but I guess I missed
>> something there...
>
> perhaps try a "console=tty 3" bootup - to boot into non-graphics
> initlevel 3, and to have a vga tty set up. Then comment out the
> regular printk(), to make sure it never tries to output to the regular
> tty.
>
> does earlyprintk=vga,keep work in that case?
>
>> But, I set the parameter nmi_watchdog=2 (I didn't know I had to
>> start explicitly the nmi watchdog) and at last... I had my
>> backtraces :-)
>
> heh :-)
>
>> All these backtraces were related to time function. And one of the
>> special things of the time functions is that they often manipulate
>> 64 bits numbers. Actually I totally forgot that a function could
>> return a long long, so I had to save edx register in the return
>> handler to restore it in its end because 64 bits numbers are
>> returned as a couple into eax and edx in x86-32.
>>
>> So the main problem is now solved. But it remains a last (but more
>> rare) deadlock somewhere. I don't know why at this time and the nmi
>> watchdog doesn't tell anything. So I will have to use early_printk
>> to see the last functions traced. But the problem is that it doesn't
>> print on the console...
>
> hm. Let me know if you cannot get this to work. I regularly use
> earlyprintk=serial,...,keep myself, and it works there - but i dont
> use earlyprintk=vga,keep that often.
>
>        Ingo
>


Actually, I didn't need it. I just turned off the nmi watchdog and I
don't have anymore deadlock. The good news is that I have now
something that seems stable. I will have some time this week-end to
try to make a proper patch with this feature.

Thanks for your help!