From mboxrd@z Thu Jan 1 00:00:00 1970 From: "John Kacur" Subject: tracing WARN_ON in rt kernel Date: Wed, 6 Aug 2008 11:38:26 +0200 Message-ID: <520f0cf10808060238r513c2f35l16c0da5511cea0f1@mail.gmail.com> Mime-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Cc: rt-users , LKML To: "Steven Rostedt" Return-path: Received: from ik-out-1112.google.com ([66.249.90.182]:48752 "EHLO ik-out-1112.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1759304AbYHFJi3 (ORCPT ); Wed, 6 Aug 2008 05:38:29 -0400 Received: by ik-out-1112.google.com with SMTP id c28so3466099ika.5 for ; Wed, 06 Aug 2008 02:38:27 -0700 (PDT) Content-Disposition: inline Sender: linux-rt-users-owner@vger.kernel.org List-ID: Hi Steve, the following is one for you. The kernel is 2.6.26.1 plus the 2.6.26-rt1 patch (yes it applies against 2.6.26.1) and some of the patches that were discussed in the lists. I don't think it is relevant which patches, but if you need an exact list I will provide it. WARNING: at kernel/trace/trace_hist.c:396 tracing_hist_preempt_stop+0x23d/0x301() Modules linked in: Pid: 1, comm: init Not tainted 2.6.26.1-rt1.jk #4 Call Trace: [] warn_on_slowpath+0x5d/0x99 [] ? native_sched_clock+0x2b/0x76 [] ? sched_clock+0x9/0xc [] ? ftrace_now+0x9/0xb [] ? tracing_hist_preempt_stop+0xd9/0x301 [] ? do_notify_resume+0x14/0x8ef [] ? trace_hardirqs_on+0x1b/0x138 [] ? do_notify_resume+0x14/0x8ef [] tracing_hist_preempt_stop+0x23d/0x301 [] ? sysret_signal+0x30/0x4f [] trace_hardirqs_on+0x1b/0x138 [] ? do_notify_resume+0x0/0x8ef [] ? sysret_signal+0x30/0x4f [] do_notify_resume+0x6e/0x8ef [] ? rt_spin_lock+0xe/0x10 [] ? remove_wait_queue+0x3e/0x43 [] ? do_wait+0xb6b/0xbf7 [] ? native_sched_clock+0x2b/0x76 [] ? sched_clock+0x9/0xc [] ? ftrace_now+0x9/0xb [] ? tracing_hist_preempt_stop+0x2d7/0x301 [] ? sysret_signal+0x5/0x4f [] ? trace_hardirqs_on_thunk+0x3a/0x3c [] ? sysret_signal+0x30/0x4f [] ptregscall_common+0x67/0xb0 --------------------------- | preempt count: 00000000 ] | 0-level deep critical section nesting: ---------------------------------------- This above is triggered by the WARN_ON in the following code in function tracing_hist_preempt_stop() #if defined(CONFIG_INTERRUPT_OFF_HIST) && defined(CONFIG_PREEMPT_OFF_HIST) if (((!irqs_on && !irqs_disabled()) || (irqs_on && !preempt_count()) || (irqs_on == TRACE_STOP)) && per_cpu(hist_preemptirqsoff_tracing, cpu)) { WARN_ON(!preempt_count() && !irqs_disabled()); if (1 || !stop_set) stop = ftrace_now(cpu); start = per_cpu(hist_preemptirqsoff_start, cpu); latency = (long)nsecs_to_usecs(stop - start); if (latency > 1000000) { printk("%d: latency = %ld (%lu)\n", __LINE__, latency, latency); printk("%d: start=%Ld stop=%Ld\n", __LINE__, start, stop); } barrier(); per_cpu(hist_preemptirqsoff_tracing, cpu) = 0; latency_hist(PREEMPT_INTERRUPT_LATENCY, cpu, latency); } #endif