[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