[Letux-kernel] 5.4-rc1 woes

Andreas Kemnade andreas at kemnade.info
Thu Oct 3 12:04:57 CEST 2019


On Thu, 3 Oct 2019 11:46:48 +0200
Andreas Kemnade <andreas at kemnade.info> wrote:

> On Thu, 3 Oct 2019 10:47:16 +0200
> "H. Nikolaus Schaller" <hns at goldelico.com> wrote:
> 
> > > Am 03.10.2019 um 10:44 schrieb Andreas Kemnade <andreas at kemnade.info>:
> > > 
> > > On Thu, 3 Oct 2019 08:26:46 +0200
> > > "H. Nikolaus Schaller" <hns at goldelico.com> wrote:
> > >     
> > >>> Am 02.10.2019 um 23:16 schrieb Andreas Kemnade <andreas at kemnade.info>:
> > >>> 
> > >>> On Wed, 2 Oct 2019 22:19:31 +0200
> > >>> Andreas Kemnade <andreas at kemnade.info> wrote:
> > >>> 
> > >>> [..]      
> > >>>> # first bad commit: [ac7c3e4ff401b304489a031938dbeaab585bfe0a] compiler: enable CONFIG_OPTIMIZE_INLINING forcibly
> > >>>> 
> > >>>> hmmmm...
> > >>>> Now it depends on compliers?!
> > >>>> andi at aktux:~/gta04/gta04-autotest-kernel$ arm-linux-gnueabihf-gcc --version
> > >>>> arm-linux-gnueabihf-gcc (Debian 8.3.0-2) 8.3.0
> > >>>> Copyright (C) 2018 Free Software Foundation, Inc.
> > >>>> This is free software; see the source for copying conditions.  There is NO
> > >>>> warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
> > >>>> 
> > >>>> And how to debug it? Well, lets first check whether reverting that
> > >>>> improves things on 5.4-rc1.
> > >>>>     
> > >>> ok, tested to revert it: I had to disable it in .config afterwards,
> > >>> seems to have crept into letux_defconfig.      
> > >> 
> > >> Was automatically set if undefined...
> > >> 
> > >> git show f863a359c2b2 | fgrep CONFIG_OPTIMIZE_INLINING
> > >> -# CONFIG_OPTIMIZE_INLINING is not set
> > >> +CONFIG_OPTIMIZE_INLINING=y
> > >>     
> > >>> And so weird error messages.      
> > >> 
> > >> Indeed.
> > >>     
> > >>> No bad addresses. I guess it somehow incfluences some copy_to_user
> > >>> stuff.
> > >>> Weird. So where to ask...?      
> > >> 
> > >> fgrep OPTIMIZE_INLINING -R *
> > >> arch/arm/boot/src/FULLCONFIG:CONFIG_OPTIMIZE_INLINING=y
> > >> arch/arm/configs/letux_defconfig:CONFIG_OPTIMIZE_INLINING=y
> > >> arch/arm/configs/letux_defconfig.bak:CONFIG_OPTIMIZE_INLINING=y
> > >> arch/arm/configs/letux_lpae_defconfig:CONFIG_OPTIMIZE_INLINING=y
> > >> arch/arm/configs/letux_lpae_defconfig.bak:CONFIG_OPTIMIZE_INLINING=y
> > >> arch/arm/configs/omap3_beagle_defconfig:# CONFIG_OPTIMIZE_INLINING is not set
> > >> arch/mips/boot/src/CONFIG:# CONFIG_OPTIMIZE_INLINING is not set
> > >> arch/mips/boot/src/FULLCONFIG:CONFIG_OPTIMIZE_INLINING=y
> > >> arch/mips/configs/letux_defconfig:CONFIG_OPTIMIZE_INLINING=y
> > >> arch/sparc/vdso/vdso32/vclock_gettime.c:#undef	CONFIG_OPTIMIZE_INLINING
> > >> arch/x86/configs/i386_defconfig:CONFIG_OPTIMIZE_INLINING=y
> > >> arch/x86/configs/x86_64_defconfig:CONFIG_OPTIMIZE_INLINING=y
> > >> arch/x86/entry/vdso/vdso32/vclock_gettime.c:#undef CONFIG_OPTIMIZE_INLINING
> > >> include/linux/compiler_types.h:#if !defined(CONFIG_OPTIMIZE_INLINING)
> > >> kernel/configs/tiny.config:CONFIG_OPTIMIZE_INLINING=y
> > >> lib/Kconfig.debug:config OPTIMIZE_INLINING
> > >> 
> > >> So it is defined in lib/Kconfig.debug. Do we still have debugging enabled?
> > >>     
> > > well, that Kconfig.debug is enabled unconditionally.
> > >     
> > >> Only minimally:
> > >> 
> > >> fgrep DEBUG arch/arm/configs/letux_defconfig | fgrep -v '#'
> > >> CONFIG_DEBUG_FS=y
> > >> CONFIG_HAVE_DEBUG_KMEMLEAK=y
> > >> CONFIG_ARCH_HAS_DEBUG_VIRTUAL=y
> > >> CONFIG_DEBUG_MEMORY_INIT=y
> > >> CONFIG_LOCK_DEBUGGING_SUPPORT=y
> > >> CONFIG_DEBUG_BUGVERBOSE=y
> > >> CONFIG_DEBUG_LL_INCLUDE="mach/debug-macro.S"
> > >> 
> > >> It is used in only one place: include/linux/compiler-gcc.h
> > >> 
> > >> But why was it set automatically? Because the new patch forces it to be so...
> > >>     
> > >>> Weird.      
> > >> 
> > >> Indeed.
> > >>     
> > >>> So where to ask...?      
> > >> 
> > >> Author: Masahiro Yamada <yamada.masahiro at socionext.com>
> > >> 
> > >>    I am keeping the config option just in case any problem crops up for other
> > >>    architectures.
> > >>     
> > > well, the answer is not so easy. That option is e.g. enabled on x86_64
> > > debian buster kernels. So I am actually writing an email on a kernel
> > > with that flag turned on.
> > > 
> > > So it must be a combination of CONFIGs which
> > > trigger some bug in the code (probably arm-specific).
> > > Maybe trying omap2plus_defconfig will be interesting.    
> > 
> > Yes, that is one test I was also thinking of.
> >   
> seems to work normally. Besides of having aa ttyS2 instead of ttyO2...
> ok, now I am enabling CONFIG_PREEMPT. And...
> 
> [    0.000000] Booting Linux on physical CPU 0x0
> [    0.000000] Linux version 5.4.0-rc1 (andi at aktux) (gcc version 8.3.0 (Debian 8.3.0-2)) #3 SMP PREEMPT Thu Oc9
> [    0.000000] CPU: ARMv7 Processor [413fc082] revision 2 (ARMv7), cr=10c5387d
> [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
> [    0.000000] OF: fdt: Machine model: Goldelico GTA04b2/Letux 3704
> [    0.000000] earlycon: omap8250 at MMIO 0x49020000 (options '')
> [    0.000000] printk: bootconsole [omap8250] enabled
> [    0.000000] Memory policy: Data cache writeback
> [    0.000000] cma: Reserved 16 MiB at 0x9e800000
> [    0.000000] CPU: All CPU(s) started in SVC mode.
> [    0.000000] OMAP3630/DM3730 ES1.2 (l2cache iva sgx neon isp 192mhz_clk)
> [    0.000000] percpu: Embedded 19 pages/cpu s49036 r8192 d20596 u77824
> [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 129412
> [    0.000000] Kernel command line: root=/dev/mmcblk0p2 earlycon console=ttyO2,115200n8
> [    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
> [    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes, linear)
> [    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
> [    0.000000] Memory: 482412K/522240K available (8192K kernel code, 715K rwdata, 2060K rodata, 1024K init, 25)
> [    0.000000] rcu: Preemptible hierarchical RCU implementation.
> [    0.000000] rcu:     RCU event tracing is enabled.
> [    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=2 to nr_cpu_ids=1.
> [    0.000000]  Tasks RCU enabled.
> [    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
> [    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
> [    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
> [    0.000000] IRQ: Found an INTC at 0x(ptrval) (revision 4.0) with 96 interrupts
> [    0.000000] random: get_random_bytes called from start_kernel+0x2b0/0x4dc with crng_init=0
> [    0.000000] Clocking rate (Crystal/Core/MPU): 26.0/400/600 MHz
> [    0.000000] OMAP clockevent source: timer1 at 32768 Hz
> [    0.000000] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 s
> [    0.000000] sched_clock: 32 bits at 32kHz, resolution 30517ns, wraps every 65535999984741ns
> [    0.008605] OMAP clocksource: 32k_counter at 32768 Hz
> [    0.015167] Console: colour dummy device 80x30
> [    0.019775] WARNING: Your 'console=ttyO2' has been replaced by 'ttyS2'
> [    0.026519] This ensures that you still see kernel messages. Please
> [    0.032989] update your kernel commandline.
> [    0.037353] Calibrating delay loop... 597.60 BogoMIPS (lpj=2988032)
> [    0.099060] pid_max: default: 32768 minimum: 301
> [    0.104064] LSM: Security Framework initializing
> [    0.108947] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
> [    0.116546] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
> [    0.125946] CPU: Testing write buffer coherency: ok
> [    0.131042] CPU0: Spectre v2: using BPIALL workaround
> [    0.136810] CPU0: thread -1, cpu 0, socket -1, mpidr 0
> [    0.192565] Setting up static identity map for 0x80100000 - 0x80100078
> [    0.199584] rcu: Hierarchical SRCU implementation.
> [    0.242340] smp: Bringing up secondary CPUs ...
> [    0.247009] smp: Brought up 1 node, 1 CPU
> [    0.251159] SMP: Total of 1 processors activated (597.60 BogoMIPS).
> [    0.257659] CPU: All CPU(s) started in SVC mode.
> [    0.263275] devtmpfs: initialized
> [    0.302398] VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 3
> [    0.311065] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
> [    0.321319] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
> [    0.329864] pinctrl core: initialized pinctrl subsystem
> [    0.337066] NET: Registered protocol family 16
> [    0.355682] DMA: preallocated 256 KiB pool for atomic coherent allocations
> [    0.399139] omap_hwmod: mcbsp2_sidetone using broken dt data from mcbsp
> [    0.407104] omap_hwmod: mcbsp3_sidetone using broken dt data from mcbsp
> [    0.501922] audit: initializing netlink subsys (disabled)
> [    0.509002] cpuidle: using governor menu
> [    0.513153] audit: type=2000 audit(0.500:1): state=initialized audit_enabled=0 res=1
> [    0.521575] Reprogramming SDRC clock to 400000000 Hz
> [    0.534729] OMAP GPIO hardware version 2.5
> [    0.560485] omap-gpmc 6e000000.gpmc: GPMC revision 5.0
> [    0.565887] gpmc_mem_init: disabling cs 0 mapped at 0x0-0x1000000
> [    0.583526] No ATAGs?
> [    0.583526] hw-breakpoint: debug architecture 0x4 unsupported.
> [    0.593780] OMAP DMA hardware revision 5.0
> [    0.665710] omap-dma-engine 48056000.dma-controller: OMAP DMA engine driver (LinkedList1/2/3 supported)
> [    0.681762] iommu: Default domain type: Translated 
> [    0.688751] omap-iommu 480bd400.mmu: 480bd400.mmu registered
> [    0.695556] platform 480bc000.isp: Adding to iommu group 0
> [    0.703460] vgaarb: loaded
> [    0.707000] SCSI subsystem initialized
> [    0.713195] omap_i2c 48070000.i2c: bus 0 rev4.4 at 2600 kHz
> [    0.721618] i2c i2c-1: of_i2c: modalias failure on /ocp at 68000000/i2c at 48072000/tps61050 at 33
> [    0.730041] i2c i2c-1: Failed to create I2C device for /ocp at 68000000/i2c at 48072000/tps61050 at 33
> [    0.738891] omap_i2c 48072000.i2c: bus 1 rev4.4 at 400 kHz
> [    0.745544] omap_i2c 48060000.i2c: bus 2 rev4.4 at 100 kHz
> [    0.751831] pps_core: LinuxPPS API ver. 1 registered
> [    0.756958] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti at linux.it>
> [    0.766448] PTP clock support registered
> [    0.771820] clocksource: Switched to clocksource 32k_counter
> [    1.535247] VFS: Disk quotas dquot_6.6.0
> [    1.539428] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
> [    1.562377] thermal_sys: Registered thermal governor 'fair_share'
> [    1.562377] thermal_sys: Registered thermal governor 'step_wise'
> [    1.568664] thermal_sys: Registered thermal governor 'user_space'
> [    1.575622] NET: Registered protocol family 2
> [    1.587677] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
> [    1.596496] TCP established hash table entries: 4096 (order: 2, 16384 bytes, linear)
> [    1.604644] TCP bind hash table entries: 4096 (order: 3, 32768 bytes, linear)
> [    1.612182] TCP: Hash tables configured (established 4096 bind 4096)
> [    1.618865] UDP hash table entries: 256 (order: 1, 8192 bytes, linear)
> [    1.625671] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear)
> [    1.633178] NET: Registered protocol family 1
> [    1.669403] RPC: Registered named UNIX socket transport module.
> [    1.675659] RPC: Registered udp transport module.
> [    1.680511] RPC: Registered tcp transport module.
> [    1.685424] RPC: Registered tcp NFSv4.1 backchannel transport module.
> [    1.692077] PCI: CLS 0 bytes, default 64
> [    1.699127] Trying to unpack rootfs image as initramfs...
> [    2.331512] Freeing initrd memory: 4756K
> [    2.337005] hw perfevents: enabled with armv7_cortex_a8 PMU driver, 5 counters available
> [    2.348358] Initialise system trusted keyrings
> [    2.353454] workingset: timestamp_bits=14 max_order=17 bucket_order=3
> [    2.372192] NFS: Registering the id_resolver key type
> [    2.377441] Key type id_resolver registered
> [    2.381744] Key type id_legacy registered
> [    2.386047] jffs2: version 2.2. (NAND) (SUMMARY)  �© 2001-2006 Red Hat, Inc.
> [    2.393890] Key type asymmetric registered
> [    2.398101] Asymmetric key parser 'x509' registered
> [    2.403228] io scheduler mq-deadline registered
> [    2.407897] io scheduler kyber registered
> [    2.419769] pinctrl-single 48002030.pinmux: 284 pins, size 568
> [    2.426574] pinctrl-single 48002a00.pinmux: 46 pins, size 92
> [    2.433319] pinctrl-single 480025a0.pinmux: 46 pins, size 92
> [    2.439697] pinctrl-single 48002274.pinmux_mcbsp1: initialized with no interrupts
> [    2.447479] pinctrl-single 48002274.pinmux_mcbsp1: 10 pins, size 4
> [    2.454254] pinctrl-single 480022d8.pinmux_tv_out: initialized with no interrupts
> [    2.462127] pinctrl-single 480022d8.pinmux_tv_out: 4 pins, size 4
> [    2.475616] Serial: 8250/16550 driver, 6 ports, IRQ sharing enabled
> [    2.486846] 4806a000.serial: ttyS0 at MMIO 0x4806a000 (irq = 88, base_baud = 3000000) is a 8250
> [    2.496307] serial serial0: tty port ttyS0 registered
> [    2.502807] 4806c000.serial: ttyS1 at MMIO 0x4806c000 (irq = 89, base_baud = 3000000) is a 8250
> [    2.512268] serial serial1: tty port ttyS1 registered
> [    2.518646] 49020000.serial: ttyS2 at MMIO 0x49020000 (irq = 90, base_baud = 3000000) is a 8250
> [    2.527893] printk: console [ttyS2] enabled
> [    2.527893] printk: console [ttyS2] enabled
> [    2.536529] printk: bootconsole [omap8250] disabled
> [    2.536529] printk: bootconsole [omap8250] disabled
> [    2.548339] 49042000.serial: ttyS3 at MMIO 0x49042000 (irq = 96, base_baud = 3000000) is a 8250
> [    2.557159] random: fast init done
> [    2.580474] brd: module loaded
> [    2.598449] loop: module loaded
> [    2.636688] twl 0-0048: PIH (irq 23) chaining IRQs 147..155
> [    2.642517] twl 0-0048: power (irq 152) chaining IRQs 155..162
> [    2.655914] VAUX3: Bringing 2800000uV into 2500000-2500000uV
> [    2.676544] VMMC2: Bringing 2600000uV into 1800000-1800000uV
> [    2.682647] VMMC2: failed to apply 1800000-1800000uV constraint(-22)
> [    2.689056] twl4030_reg 48070000.i2c:twl at 48:regulator-vmmc2: can't register VMMC2, -22
> [    2.697082] twl4030_reg: probe of 48070000.i2c:twl at 48:regulator-vmmc2 failed with error -22
> [    2.713043] VSIM: Bringing 1800000uV into 2800000-2800000uV
> [    2.721405] twl4030_gpio twl4030-gpio: gpio (irq 147) chaining IRQs 163..180
> [    2.749938] mtdoops: mtd device (mtddev=name/number) must be supplied
> [    2.758300] nand: device found, Manufacturer ID: 0x2c, Chip ID: 0xbc
> [    2.764770] nand: Micron MT29F4G16ABBDA3W
> [    2.768798] nand: 512 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
> [    2.776458] omap2-nand 30000000.nand: nand: using OMAP_ECC_HAM1_CODE_HW
> [    2.783203] nand: WARNING: omap2-nand.0: the ECC used on your system is too weak compared to the one requirp
> [    2.794799] 5 fixed-partitions partitions found on MTD device omap2-nand.0
> [    2.801727] Creating 5 MTD partitions on "omap2-nand.0":
> [    2.807098] 0x000000000000-0x000000080000 : "X-Loader"
> [    2.823455] 0x000000080000-0x000000240000 : "U-Boot"
> [    2.843353] 0x000000240000-0x000000280000 : "U-Boot Env"
> [    2.863342] 0x000000280000-0x000000880000 : "Kernel"
> [    2.883331] 0x000000880000-0x000020000000 : "File System"
> [    3.109069] libphy: Fixed MDIO Bus: probed
> [    3.116912] i2c /dev entries driver
> [    3.125427] sdhci: Secure Digital Host Controller Interface driver
> [    3.131652] sdhci: Copyright(c) Pierre Ossman
> [                         
> and ... nothing. So that kernel option triggered a CONFIG_PREEMPT-related bug.
> Hmm, no mmc. so maybe a mmc+CONFIG_PREEMPT related bug triggered by that kernel option.
> 
not clearly reproducible... grr... so there must be another difference.
I also tried ifconfig lo + ping in a busybox initrd. No problems.

Regards,
Andreas


More information about the Letux-kernel mailing list