Subject: "Can't analyze prologue code ..." at boot time

From: Thomas Petazzoni <[email-masked]>
Date: Fri, 24 Sep 2004 10:52:40 +0200

Hello,

In arch/mips/kernel/process.c, the function frame_info_init() called
at boot time, calls the get_frame_info() to a analyze the prologue of
a few functions (I don't know why, does anyone know ?).

At boot time, I have the following message on the console :

Can't analyze prologue code at 80315308

At 80315308 is the beginning of the schedule_timeout() function which
is one of the functions analyzed by the frame_info_init().

The get_frame_info() seems to search a sw or sd instruction, but here
is the beginning of the schedule_timeout() function :

80315308 <schedule_timeout>:
80315308:       3c027fff        lui     v0,0x7fff
8031530c:       27bdffc0        addiu   sp,sp,-64
80315310:       3442ffff        ori     v0,v0,0xffff
80315314:       afb10034        sw      s1,52(sp)
80315318:       afbf003c        sw      ra,60(sp)
8031531c:       afb20038        sw      s2,56(sp)
80315320:       afb00030        sw      s0,48(sp)
80315324:       1082002c        beq     a0,v0,803153d8 <schedule_timeout+0xd0>
80315328:       00808821        move    s1,a0

This error isn't fatal, the kernel perfectly boots, and I can use my
shell perfectly. I just wanted to know why it is reporting a problem,
why the kernel needs to analyze the prologues of a couple of
functions, and maybe report a possible problem ?

I'm using a quite outdated linux-mips CVS (from the beginning of the
month, a 2.6.9-rc1). I compiled using gcc 3.3.4, for an RM9000
processor.

Don't hesitate to ask for details,

Thomas
-- 
PETAZZONI Thomas - [email-masked] 
http://thomas.enix.org - Jabber: [email-masked]
KOS: http://kos.enix.org/ - Lolut: http://lolut.utbm.info
Fingerprint : 0BE1 4CF3 CEA4 AC9D CC6E  1624 F653 CB30 98D3 F7A7

---

From: Atsushi Nemoto <[email-masked]>
Date: Fri, 24 Sep 2004 19:06:40 +0900 (JST)

>>>>> On Fri, 24 Sep 2004 10:52:40 +0200, Thomas Petazzoni <[email-masked]> said:
thomas> In arch/mips/kernel/process.c, the function frame_info_init()
thomas> called at boot time, calls the get_frame_info() to a analyze
thomas> the prologue of a few functions (I don't know why, does anyone
thomas> know ?).

Because thread_saved_pc(), get_wchan() needs those information.

The information of 'schedule' function is required, others are
optional ("ps -l" shows better output with those informations).

thomas> The get_frame_info() seems to search a sw or sd instruction,
thomas> but here is the beginning of the schedule_timeout() function :

This is because now schedule_timeout is in kernel/timer.c (not
kernel/sched.c) which is compiled without -fno-omit-frame-pointer
option.

I rewrote get_wchan() to handle this problem.  Please try this patch.

Note that this patch still depends on order of address of sched
functions, so not gcc-3.4 proof.  Sorting minfo[] array will make it
more robust.  If anyone interested in, I will implement it.

diff -u linux-mips/arch/mips/kernel/process.c linux/arch/mips/kernel/process.c
--- linux-mips/arch/mips/kernel/process.c	Wed Sep 22 13:27:59 2004
+++ linux/arch/mips/kernel/process.c	Wed Sep 22 17:03:10 2004
@@ -177,21 +177,41 @@
 }
 
 struct mips_frame_info {
+	void *func;
+	int omit_fp;	/* compiled without fno-omit-frame-pointer */
 	int frame_offset;
 	int pc_offset;
+} mfinfo [] = {
+	/* must be in address order */
+	{ __down_interruptible, 1 },
+	{ schedule, 0 },
+#define schedule_frame 1
+#ifdef CONFIG_PREEMPT
+	{ preempt_schedule, 0 },
+#endif
+	{ wait_for_completion, 0 },
+	{ interruptible_sleep_on, 0 },
+	{ interruptible_sleep_on_timeout, 0 },
+	{ sleep_on, 0 },
+	{ sleep_on_timeout, 0 },
+	{ __cond_resched, 0 },
+	{ yield, 0 },
+	{ io_schedule, 0 },
+	{ io_schedule_timeout, 0 },
+	{ schedule_timeout, 1 },
+/*	{ nanosleep_restart, 1 }, */
+	{ __down_read, 1 },
+	{ __down_write, 1 },
 };
-static struct mips_frame_info schedule_frame;
-static struct mips_frame_info schedule_timeout_frame;
-static struct mips_frame_info sleep_on_frame;
-static struct mips_frame_info sleep_on_timeout_frame;
-static struct mips_frame_info wait_for_completion_frame;
+
 static int mips_frame_info_initialized;
-static int __init get_frame_info(struct mips_frame_info *info, void *func)
+static int __init get_frame_info(struct mips_frame_info *info)
 {
 	int i;
+	void *func = info->func;
 	union mips_instruction *ip = (union mips_instruction *)func;
 	info->pc_offset = -1;
-	info->frame_offset = -1;
+	info->frame_offset = info->omit_fp ? 0 : -1;
 	for (i = 0; i < 128; i++, ip++) {
 		/* if jal, jalr, jr, stop. */
 		if (ip->j_format.opcode == jal_op ||
@@ -237,13 +257,11 @@
 
 static int __init frame_info_init(void)
 {
-	mips_frame_info_initialized =
-		!get_frame_info(&schedule_frame, schedule) &&
-		!get_frame_info(&schedule_timeout_frame, schedule_timeout) &&
-		!get_frame_info(&sleep_on_frame, sleep_on) &&
-		!get_frame_info(&sleep_on_timeout_frame, sleep_on_timeout) &&
-		!get_frame_info(&wait_for_completion_frame, wait_for_completion);
-
+	int i;
+	for (i = 0; i < ARRAY_SIZE(mfinfo); i++)
+		if (get_frame_info(&mfinfo[i]))
+			return -1;
+	mips_frame_info_initialized = 1;
 	return 0;
 }
 
@@ -261,9 +279,9 @@
 	if (t->reg31 == (unsigned long) ret_from_fork)
 		return t->reg31;
 
-	if (schedule_frame.pc_offset < 0)
+	if (mfinfo[schedule_frame].pc_offset < 0)
 		return 0;
-	return ((unsigned long *)t->reg29)[schedule_frame.pc_offset];
+	return ((unsigned long *)t->reg29)[mfinfo[schedule_frame].pc_offset];
 }
 
 /* get_wchan - a maintenance nightmare^W^Wpain in the ass ...  */
@@ -277,48 +295,27 @@
 	if (!mips_frame_info_initialized)
 		return 0;
 	pc = thread_saved_pc(p);
+
 	if (!in_sched_functions(pc))
 		goto out;
 
-	if (pc >= (unsigned long) sleep_on_timeout)
-		goto schedule_timeout_caller;
-	if (pc >= (unsigned long) sleep_on)
-		goto schedule_caller;
-	if (pc >= (unsigned long) interruptible_sleep_on_timeout)
-		goto schedule_timeout_caller;
-	if (pc >= (unsigned long)interruptible_sleep_on)
-		goto schedule_caller;
-	if (pc >= (unsigned long)wait_for_completion)
-		goto schedule_caller;
-	goto schedule_timeout_caller;
-
-schedule_caller:
-	frame = ((unsigned long *)p->thread.reg30)[schedule_frame.frame_offset];
-	if (pc >= (unsigned long) sleep_on)
-		pc = ((unsigned long *)frame)[sleep_on_frame.pc_offset];
-	else
-		pc = ((unsigned long *)frame)[wait_for_completion_frame.pc_offset];
-	goto out;
-
-schedule_timeout_caller:
-	/*
-	 * The schedule_timeout frame
-	 */
-	frame = ((unsigned long *)p->thread.reg30)[schedule_frame.frame_offset];
-
-	/*
-	 * frame now points to sleep_on_timeout's frame
-	 */
-	pc    = ((unsigned long *)frame)[schedule_timeout_frame.pc_offset];
-
-	if (in_sched_functions(pc)) {
-		/* schedule_timeout called by [interruptible_]sleep_on_timeout */
-		frame = ((unsigned long *)frame)[schedule_timeout_frame.frame_offset];
-		pc    = ((unsigned long *)frame)[sleep_on_timeout_frame.pc_offset];
-	}
+	frame = ((unsigned long *)p->thread.reg30)[mfinfo[schedule_frame].frame_offset];
+	do {
+		int i;
+		for (i = ARRAY_SIZE(mfinfo) - 1; i >= 0; i--) {
+			if (pc >= (unsigned long) mfinfo[i].func)
+				break;
+		}
+		if (i < 0)
+			break;
 
-out:
+		if (mfinfo[i].omit_fp)
+			break;
+		pc = ((unsigned long *)frame)[mfinfo[i].pc_offset];
+		frame = ((unsigned long *)frame)[mfinfo[i].frame_offset];
+	} while (in_sched_functions(pc));
 
+out:
 #ifdef CONFIG_MIPS64
 	if (current->thread.mflags & MF_32BIT_REGS) /* Kludge for 32-bit ps  */
 		pc &= 0xffffffffUL;

---
Atsushi Nemoto

---

From: Thomas Petazzoni <[email-masked]>
Date: Fri, 24 Sep 2004 14:11:07 +0200

Hello,

> I rewrote get_wchan() to handle this problem.  Please try this patch.

This patch works for me. At least, the "Couldn't analyze prologue code
at ..." message doesn't appear anymore.

Thanks,

Thomas

---

From: Filip Onkelinx <[email-masked]>
Date: Sat, 25 Sep 2004 00:15:16 +0200

Hi Atsushi,

I just applied your patch to our current 2.6.9-rc2 kernel for the BE300 
project (Casio BE300/BE500 PDA with NEC vr4131 rev1.2), and the
"Couldn't analyze prologue code .." message is gone as well.

Before, the kernel was very unreliable, but I also sync'ed with the 
latest from CVS and switched gcc version , so I'm not sure if it is your 
patch that's responsible for the stabiltity or one of the other changes.

thanks,

Filip.

-- 
----

Do not follow where the path may lead. Go instead where there is no path and leave a trail  - Ralph Waldo Emerson

----

Filip Onkelinx
Heidebloemstraat 20, B-3500 Hasselt, BELGIUM
fax: +32 11 65 65 97, mobile: +32 475 69 47 63
[email-masked]

---

From: Atsushi Nemoto <[email-masked]>
Date: Sat, 25 Sep 2004 23:03:41 +0900 (JST)

>>>>> On Sat, 25 Sep 2004 00:15:16 +0200, Filip Onkelinx <[email-masked]> said:

Filip> I just applied your patch to our current 2.6.9-rc2 kernel for
Filip> the BE300 project (Casio BE300/BE500 PDA with NEC vr4131
Filip> rev1.2), and the "Couldn't analyze prologue code .." message is
Filip> gone as well.

Good to hear that.

Filip> Before, the kernel was very unreliable, but I also sync'ed with
Filip> the latest from CVS and switched gcc version , so I'm not sure
Filip> if it is your patch that's responsible for the stabiltity or
Filip> one of the other changes.

I'm pretty sure it is not my patch.  The problem fixed by my patch
should not be a so fatal.  Congratulation anyway.

---
Atsushi Nemoto