Re: [BUG] OpenRISC exec init fails, bisected to 0886551 ("initramfs: finish fput() before accessing any binary from initramfs")

[Lokesh Vutla]

On Thursday 04 May 2017 02:05 PM, Stafford Horne wrote:
> On Thu, May 04, 2017 at 01:15:23PM +0530, Lokesh Vutla wrote:
>>
>>
>> On Thursday 04 May 2017 12:41 PM, Stafford Horne wrote:
>>> Hello,
>>>
>>> While booting the v4.11 kernel I found the below issue.
>>>
>>> The summary of the issue mentions
>>>
>>>     Commit 4a9d4b024a31 ("switch fput to task_work_add") implements a
>>>     schedule_work() for completing fput(), but did not guarantee calling
>>>     __fput() after unpacking initramfs.  Because of this, there is a
>>>     possibility that during boot a driver can see ETXTBSY when it tries to
>>>     load a binary from initramfs as fput() is still pending on that binary.
>>>
>>> It seems this patch (0886551) introduces that issue though?
>>>
>>> I am looking into it, but any suggestions would be helpful.
>>
>> Can you check if flush_delayed_fput() is being called? Do you have
>> CONFIG_INITRAMFS_FORCE enabled?
> 
> This is not enabled.  I debugged it and I cant see it getting called.  I
> see populate_rootfs getting called but initrd_start is 0, I think there is
> something different happening to unpack in initramfs since ours is compiled
> in.

What about __initramfs_start, __initramfs_size?

> 
> I am trying to look into it, but I need to relearn how the initramfs gets
> initted for OpenRISC.  Perhaps the fix it going to keep the
> flush_delayed_fput() call in init/main.c.

My initial version of the patch did not remove the call to
flush_delayed_fput() from init/main.c but Al Viro asked to drop it as it
is called in populate_rootfs().

May be Al Viro can give more data on what is happening here.

Thanks and regards,
Lokesh


> 
>> Can I see complete boot log?
> 
> I expect to see a line "Unpacking initramfs..." but I don't:
> 
> See below:
> 
> Compiled-in FDT at c0351200
> Linux version 4.10.0-10351-g0886551 (shorne@xxxxxxxxxxxxxxxxxxxxx) (gcc version 5.4.0 (GCC) ) #225 Thu May 4 17:21:27 JST 2017
> CPU: OpenRISC-0 (revision 0) @20 MHz
> -- dcache disabled
> -- icache disabled
> -- dmmu:   64 entries, 1 way(s)
> -- immu:   64 entries, 1 way(s)
> -- additional features:
> -- power management
> -- PIC
> -- timer
> setup_memory: Memory: 0x0-0x2000000
> Setting up paging and PTEs.
> map_ram: Memory: 0x0-0x2000000
> itlb_miss_handler c0002160
> dtlb_miss_handler c0002000
> OpenRISC Linux -- http://openrisc.io
> Built 1 zonelists in Zone order, mobility grouping off.  Total pages: 4080
> Kernel command line: console=uart,mmio,0x90000000,115200
> earlycon: uart0 at MMIO 0x90000000 (options '115200')
> bootconsole [uart0] enabled
> PID hash table entries: 128 (order: -4, 512 bytes)
> Dentry cache hash table entries: 4096 (order: 1, 16384 bytes)
> Inode-cache hash table entries: 2048 (order: 0, 8192 bytes)
> Sorting __ex_table...
> Memory: 26312K/32768K available (2846K kernel code, 112K rwdata, 312K rodata, 2856K init, 94K bss, 6456K reserved, 0K cma-reserved)
> mem_init_done ...........................................
> NR_IRQS:32 nr_irqs:32 0
> clocksource: openrisc_timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 95563022313 ns
> 40.00 BogoMIPS (lpj=200000)
> pid_max: default: 32768 minimum: 301
> Mount-cache hash table entries: 2048 (order: 0, 8192 bytes)
> Mountpoint-cache hash table entries: 2048 (order: 0, 8192 bytes)
> devtmpfs: initialized
> clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
> futex hash table entries: 256 (order: -2, 3072 bytes)
> NET: Registered protocol family 16
> clocksource: Switched to clocksource openrisc_timer
> NET: Registered protocol family 2
> TCP established hash table entries: 2048 (order: 0, 8192 bytes)
> TCP bind hash table entries: 2048 (order: 0, 8192 bytes)
> TCP: Hash tables configured (established 2048 bind 2048)
> UDP hash table entries: 512 (order: 0, 8192 bytes)
> UDP-Lite hash table entries: 512 (order: 0, 8192 bytes)
> NET: Registered protocol family 1
> RPC: Registered named UNIX socket transport module.
> RPC: Registered udp transport module.
> RPC: Registered tcp transport module.
> RPC: Registered tcp NFSv4.1 backchannel transport module.
> workingset: timestamp_bits=30 max_order=12 bucket_order=0
> Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
> 90000000.serial: ttyS0 at MMIO 0x90000000 (irq = 2, base_baud = 1250000) is a 16550A
> console [ttyS0] enabled
> console [ttyS0] enabled
> bootconsole [uart0] disabled
> bootconsole [uart0] disabled
> libphy: Fixed MDIO Bus: probed
> NET: Registered protocol family 17
> Freeing unused kernel memory: 2856K
> This architecture does not have kernel memory protection.
> Failed to execute /init (error -26)
> Starting init: /sbin/init exists but couldn't execute it (error -26)
> Starting init: /bin/sh exists but couldn't execute it (error -26)
> Kernel panic - not syncing: No working init found.  Try passing init= option to kernel. See Linux Documentation/admin-guide/init.rst for guidance.
> ---[ end Kernel panic - not syncing: No working init found.  Try passing init= option to kernel. See Linux Documentation/admin-guide/init.rst for guidance.
>