Delay on starting init

Delay on starting init

[jim]

I pulled the lastest 2.4 devel tree from Monte Vista's mirror a couple of
days ago and the behaviour of the boot process changed.  Now, the process
pauses for a long time after the message; "Freeing unused kernel memory".  To
make sure this was a kernel issue, I reverted to the previous kernel and it
booted with no delay.  Also, the delay is apparent on both Hard Hat Linux 2.0
and ELDK from Denx.

Is anyone aware of what changed?

Thanks,
Jim

** Sent via the linuxppc-embedded mail list. See http://lists.linuxppc.org/

Re: Delay on starting init

[David Gibson]

On Wed, Sep 11, 2002 at 12:34:54PM +0000, jim wrote:
>
> I pulled the lastest 2.4 devel tree from Monte Vista's mirror a couple of
> days ago and the behaviour of the boot process changed.  Now, the process
> pauses for a long time after the message; "Freeing unused kernel memory".  To
> make sure this was a kernel issue, I reverted to the previous kernel and it
> booted with no delay.  Also, the delay is apparent on both Hard Hat Linux 2.0
> and ELDK from Denx.
>
> Is anyone aware of what changed?

I've observed this as well, but I haven't tracked it down much.  When
I looked into it the delay seemed to be due to NFS delays and timeouts
(I'm using an NFS root), but that doesn't explain why it is so much
worse in recent 2.4 and (especially) 2.5.

--
David Gibson			| For every complex problem there is a
david@gibson.dropbear.id.au	| solution which is simple, neat and
				| wrong.
http://www.ozlabs.org/people/dgibson

** Sent via the linuxppc-embedded mail list. See http://lists.linuxppc.org/

Re: Delay on starting init

[Jin Cheng]

I have seen this also for a NFS root. But when I move the root file
systems into a local SCSI disk, it seems the delay is almost gone.

I am using the kernel 2.4.20.

Jin

David Gibson wrote:

> On Wed, Sep 11, 2002 at 12:34:54PM +0000, jim wrote:
> >
> > I pulled the lastest 2.4 devel tree from Monte Vista's mirror a couple of
> > days ago and the behaviour of the boot process changed.  Now, the process
> > pauses for a long time after the message; "Freeing unused kernel memory".  To
> > make sure this was a kernel issue, I reverted to the previous kernel and it
> > booted with no delay.  Also, the delay is apparent on both Hard Hat Linux 2.0
> > and ELDK from Denx.
> >
> > Is anyone aware of what changed?
>
> I've observed this as well, but I haven't tracked it down much.  When
> I looked into it the delay seemed to be due to NFS delays and timeouts
> (I'm using an NFS root), but that doesn't explain why it is so much
> worse in recent 2.4 and (especially) 2.5.
>
> --
> David Gibson                    | For every complex problem there is a
> david@gibson.dropbear.id.au     | solution which is simple, neat and
>                                 | wrong.
> http://www.ozlabs.org/people/dgibson
>


** Sent via the linuxppc-embedded mail list. See http://lists.linuxppc.org/

Re: Delay on starting init

[jim]

Well, that's three datapoints.  I'm also using an NFS root.  I tracked it as
far as the sys_execve call that's in arch/ppc/kernel/process.c.  It seems to
execute that function fast enough.  I got hung up trying to determine exactly
what was going on in include/asm-ppc/unistd.h with the _syscall3 macro.
Those two files are where I'd start looking.

If anyone finds the cause of the delay on starting init with NFS root file
systems, please post to the list.

Jim

On Thursday 12 September 2002 01:24 am, David Gibson wrote:
>
> I've observed this as well, but I haven't tracked it down much.  When
> I looked into it the delay seemed to be due to NFS delays and timeouts
> (I'm using an NFS root), but that doesn't explain why it is so much
> worse in recent 2.4 and (especially) 2.5.

** Sent via the linuxppc-embedded mail list. See http://lists.linuxppc.org/

Re: Delay on starting init

[Scott Anderson]

jim wrote:
> If anyone finds the cause of the delay on starting init with NFS root file
> systems, please post to the list.

I don't know the cause of the delay, but as I was debugging another
kernel problem, I remembered this and hit ^C in gdb a few times to see what
was going on.  In both cases, it was handling mm faults.  I attached
the output from my gdb macros just in case it jogs anyone's brain cells.
To really figure out what is going on, we may have to compare old vs.
new.
  Scott

(gdb) ps
Address      PID State      User NIP  Kernel NIP device comm
0xC013DFD0     0<Running              0xC00060E4        swapper
0xC0344000     1 Disksleep 0x30003578 0xC0006FD8        init
0xC03DA000     2 Sleeping             0xC0006FD8        keventd
0xC03D6000     3 Sleeping             0xC0006FD8        ksoftirqd_CPU0
0xC03D4000     4 Sleeping             0xC0006FD8        kswapd
0xC03D2000     5 Sleeping             0xC0006FD8        bdflush
0xC03D0000     6 Sleeping             0xC0006FD8        kupdated
0xC7DD4000     7 Sleeping             0xC0006FD8        rpciod
(gdb) kbt 1
Task "init":
0xC0345D40: 0xc0006fd8 <_switch_to+96>: stw     r3,0(r30)
0xC0345D60: 0xc0010f30 <schedule+1368>: lwz     r9,8(r31)
0xC0345D90: 0xc0028cd4 <__lock_page+192>:       lwarx   r0,r0,r28
0xC0345DC0: 0xc0028d48 <lock_page+52>:  lwz     r0,20(r1)
0xC0345DD0: 0xc002a528 <filemap_nopage+376>:    lwz     r0,8(r31)
0xC0345E00: 0xc0025b08 <do_no_page+116>:        mr.     r31,r3
0xC0345E30: 0xc0025ce0 <handle_mm_fault+112>:
    b   0xc0025d58 <handle_mm_fault+232>
0xC0345E60: 0xc000ea74 <do_page_fault+652>:     cmpwi   r3,1
0xC0345F20: 0xc0004854 <ret_from_except>:       lwz     r3,148(r1)
(gdb) cont
Continuing.

Program received signal SIGSTOP, Stopped (signal).
idled () at idle.c:110
110                     if (current->need_resched) {
(gdb) ps
Address      PID State      User NIP  Kernel NIP device comm
0xC013DFD0     0<Running              0xC00060E4        swapper
0xC0344000     1 Disksleep 0x30003578 0xC0006FD8        init
0xC03DA000     2 Sleeping             0xC0006FD8        keventd
0xC03D6000     3 Sleeping             0xC0006FD8        ksoftirqd_CPU0
0xC03D4000     4 Sleeping             0xC0006FD8        kswapd
0xC03D2000     5 Sleeping             0xC0006FD8        bdflush
0xC03D0000     6 Sleeping             0xC0006FD8        kupdated
0xC7DD4000     7 Sleeping             0xC0006FD8        rpciod
(gdb) kbt 1
Task "init":
0xC0345D40: 0xc0006fd8 <_switch_to+96>: stw     r3,0(r30)
0xC0345D60: 0xc0010f30 <schedule+1368>: lwz     r9,8(r31)
0xC0345D90: 0xc0028cd4 <__lock_page+192>:       lwarx   r0,r0,r28
0xC0345DC0: 0xc0028d48 <lock_page+52>:  lwz     r0,20(r1)
0xC0345DD0: 0xc002a528 <filemap_nopage+376>:    lwz     r0,8(r31)
0xC0345E00: 0xc0025b08 <do_no_page+116>:        mr.     r31,r3
0xC0345E30: 0xc0025ce0 <handle_mm_fault+112>:
    b   0xc0025d58 <handle_mm_fault+232>
0xC0345E60: 0xc000ea74 <do_page_fault+652>:     cmpwi   r3,1
0xC0345F20: 0xc0004854 <ret_from_except>:       lwz     r3,148(r1)

** Sent via the linuxppc-embedded mail list. See http://lists.linuxppc.org/