"Can't analyze prologue code ..." at boot time
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
Signature · 4 lines
PETAZZONI Thomas - [email protected] http://thomas.enix.org - Jabber: [email protected] KOS: http://kos.enix.org/ - Lolut: http://lolut.utbm.info Fingerprint : 0BE1 4CF3 CEA4 AC9D CC6E 1624 F653 CB30 98D3 F7A7
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line · Thomas Petazzoni
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.
arch/mips/kernel/process.c +50 -53
@@ -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
Hello,
Quoted 1 line · Atsushi Nemoto
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
Signature · 4 lines
PETAZZONI Thomas - [email protected] http://thomas.enix.org - Jabber: [email protected] KOS: http://kos.enix.org/ - Lolut: http://lolut.utbm.info Fingerprint : 0BE1 4CF3 CEA4 AC9D CC6E 1624 F653 CB30 98D3 F7A7
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.
Quoted 18 lines · Thomas Petazzoni
Hello,
Quoted 3 lines · Atsushi Nemoto
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
Signature · 10 lines
---- 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 protected]
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line · Filip Onkelinx
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
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line · Atsushi Nemoto
anemo> This is because now schedule_timeout is in kernel/timer.c (not anemo> kernel/sched.c) which is compiled without
anemo> -fno-omit-frame-pointer option.
anemo> I rewrote get_wchan() to handle this problem. Please try this anemo> patch.
anemo> Note that this patch still depends on order of address of sched anemo> functions, so not gcc-3.4 proof. Sorting minfo[] array will anemo> make it more robust. If anyone interested in, I will implement anemo> it.
Here is a revised patch which can work with gcc 3.4.
Ralf, how about this patch? No more maintenance nightmare :-)
arch/mips/kernel/process.c +67 -48
@@ -186,21 +186,48 @@ }struct mips_frame_info { +void *func; +int omit_fp;/* compiled without fno-omit-frame-pointer */ int frame_offset;int pc_offset; +} schedule_frame, mfinfo[] = { + { schedule,0 },/* must be first */ +/* arch/mips/kernel/semaphore.c */ + { __down,1 }, + { __down_interruptible,1 }, +/* kernel/sched.c */ +#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 }, +#if defined(CONFIG_SMP) && defined(CONFIG_PREEMPT) + { __preempt_spin_lock,0 }, + { __preempt_write_lock,0 }, +#endif +/* kernel/timer.c */ + { schedule_timeout,1 }, +/* { nanosleep_restart, 1 }, */ +/* lib/rwsem-spinlock.c */ + { __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 ||
@@ -246,13 +273,25 @@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, found; +for (i =0 ; i <ARRAY_SIZE (mfinfo); i++) +if (get_frame_info (&mfinfo[i])) +return -1 ; + schedule_frame = mfinfo[0 ]; +/* bubble sort */ +do { +struct mips_frame_info tmp; + found =0 ; +for (i =1 ; i <ARRAY_SIZE (mfinfo); i++) { +if (mfinfo[i-1 ].func > mfinfo[i].func) { + tmp = mfinfo[i]; + mfinfo[i] = mfinfo[i-1 ]; + mfinfo[i-1 ] = tmp; + found =1 ; + } + } + }while (found); + mips_frame_info_initialized =1 ;return 0 ; }
@@ -286,45 +325,25 @@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]; +do { +int i; +for (i =ARRAY_SIZE (mfinfo) -1 ; i >=0 ; i--) { +if (pc >= (unsigned long ) mfinfo[i].func) +break ; + } +if (i <0 ) +break ; -/* -* 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]; - } +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:
---
Atsushi Nemoto
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line · Atsushi Nemoto
anemo> Here is a revised patch which can work with gcc 3.4.
anemo> Ralf, how about this patch? No more maintenance nightmare :-)
I found that still "Can't analyze" message displayed with gcc 3.4. Revised again.
arch/mips/kernel/process.c +70 -49
@@ -185,22 +185,49 @@return do_fork (flags |CLONE_VM |CLONE_UNTRACED ,0 , ®s,0 ,NULL ,NULL ); } -struct mips_frame_info { +static struct mips_frame_info { +void *func; +int omit_fp;/* compiled without fno-omit-frame-pointer */ int frame_offset;int pc_offset; +} schedule_frame, mfinfo[] = { + { schedule,0 },/* must be first */ +/* arch/mips/kernel/semaphore.c */ + { __down,1 }, + { __down_interruptible,1 }, +/* kernel/sched.c */ +#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 }, +#if defined(CONFIG_SMP) && defined(CONFIG_PREEMPT) + { __preempt_spin_lock,0 }, + { __preempt_write_lock,0 }, +#endif +/* kernel/timer.c */ + { schedule_timeout,1 }, +/* { nanosleep_restart, 1 }, */ +/* lib/rwsem-spinlock.c */ + { __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 ||
@@ -227,8 +254,10 @@ }/* sw / sd $s8, offset($sp) */ if (ip->i_format.rt ==30 ) { +#if 0 /* gcc 3.4 does aggressive optimization... */ if (info->frame_offset !=-1 )break ; +#endif info->frame_offset = ip->i_format.simmediate /sizeof (long ); }
@@ -246,13 +275,25 @@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, found; +for (i =0 ; i <ARRAY_SIZE (mfinfo); i++) +if (get_frame_info (&mfinfo[i])) +return -1 ; + schedule_frame = mfinfo[0 ]; +/* bubble sort */ +do { +struct mips_frame_info tmp; + found =0 ; +for (i =1 ; i <ARRAY_SIZE (mfinfo); i++) { +if (mfinfo[i-1 ].func > mfinfo[i].func) { + tmp = mfinfo[i]; + mfinfo[i] = mfinfo[i-1 ]; + mfinfo[i-1 ] = tmp; + found =1 ; + } + } + }while (found); + mips_frame_info_initialized =1 ;return 0 ; }
@@ -286,45 +327,25 @@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]; +do { +int i; +for (i =ARRAY_SIZE (mfinfo) -1 ; i >=0 ; i--) { +if (pc >= (unsigned long ) mfinfo[i].func) +break ; + } +if (i <0 ) +break ; -/* -* 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]; - } +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:
---
Atsushi Nemoto