raspberrypi / linux

Kernel source tree for Raspberry Pi-provided kernel builds. Issues unrelated to the linux kernel should be posted on the community forum at https://forums.raspberrypi.com/
Other
11.16k stars 5.01k forks source link

Python smbus2 trying to read data leads to kernel panic #3429

Open JsBergbau opened 4 years ago

JsBergbau commented 4 years ago

I'm new to read data from I2c-Bus. However a kernel panic shouldn't happen from a user space script.

Describe the bug Trying to read data from SMBus leads to kernel panic. To reproduce pip3 install smbus2 Then execute

#!/usr/bin/python3 -u

import smbus2

bus = smbus2.SMBus(1)
address = 0x44
res=bus.read_block_data(address,0x7F)
print (res)

Expected behaviour Any error but no kernel panic

Actual behaviour Whole PI crashes with Kernel stack is corruputed in i2cdev_ioctl_smbus+0x268 [i2c_dev]

System

 System Information
------------------

Raspberry Pi 3 Model B Rev 1.2
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"

Raspberry Pi reference 2019-09-26
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 80d486687ea77d31fc                                                                                         3fc13cf3a2f8b464e129be, stage2

Linux raspberrypi 4.19.93-v7+ #1290 SMP Fri Jan 10 16:39:50 GMT 2020 armv7l GNU/                                                                                         Linux
Revision        : a02082
Serial          : 00000000xxxxxxxxxxx
Model           : Raspberry Pi 3 Model B Rev 1.2
Throttled flag  : throttled=0x0
Camera          : supported=0 detected=0

Videocore information
---------------------

Jan 10 2020 17:01:16
Copyright (c) 2012 Broadcom
version f3e39fed4763ce4efbffabb2d4787aaacddeda0f (clean) (release) (start)

alloc failures:     0
compactions:        0
legacy block fails: 0

Filesystem information
----------------------
Filesystem     1K-blocks    Used Available Use% Mounted on
/dev/root       15022716 1744368  12632488  13% /
devtmpfs          469540       0    469540   0% /dev
tmpfs             474148       0    474148   0% /dev/shm
tmpfs             474148    6300    467848   2% /run
tmpfs               5120       4      5116   1% /run/lock
tmpfs             474148       0    474148   0% /sys/fs/cgroup
/dev/mmcblk0p1    258095   53443    204653  21% /boot
tmpfs              94828       0     94828   0% /run/user/1000

Filename                                Type            Size    Used    Priority
/var/swap                               file            102396  0       -2

Package version information
---------------------------
raspberrypi-ui-mods:
  Installed: (none)
raspberrypi-sys-mods:
  Installed: 20191105
openbox:
  Installed: (none)
lxpanel:
  Installed: (none)
pcmanfm:
  Installed: (none)
rpd-plym-splash:
  Installed: (none)

Networking Information
----------------------

eth0: flags=4099<UP,BROADCAST,MULTICAST>  mtu 1500
        ether m.m.m.m  txqueuelen 1000  (Ethernet)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 65536
        inet x.x.x.x  netmask x.x.x.x
        inet6 ::1  prefixlen 128  scopeid 0x10<host>
        loop  txqueuelen 1000  (Local Loopback)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

wlan0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        ether m.m.m.m  txqueuelen 1000  (Ethernet)
        RX packets 2281  bytes 155959 (152.3 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 1784  bytes 329649 (321.9 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

USB Information
---------------

/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=dwc_otg/1p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/5p, 480M
        |__ Port 1: Dev 3, If 0, Class=Vendor Specific Class, Driver=smsc95xx, 4                                                                                         80M

config.txt
----------

aphy_params_current=819
arm_freq=1200
audio_pwm_mode=514
config_hdmi_boost=5
core_freq=400
desired_osc_freq=0x36ee80
disable_commandline_tags=2
disable_l2cache=1
display_hdmi_rotate=-1
display_lcd_rotate=-1
dphy_params_current=547
force_eeprom_read=1
force_pwm_open=1
framebuffer_ignore_alpha=1
framebuffer_swap=1
gpu_freq=300
init_uart_clock=0x2dc6c00
lcd_framerate=60
over_voltage_avs=0x186a0
pause_burst_frames=1
program_serial_random=1
sdram_freq=450
hdmi_force_cec_address:0=65535
hdmi_force_cec_address:1=65535
hdmi_pixel_freq_limit:0=0x9a7ec80
hdmi_pixel_freq_limit:1=0x9a7ec80
device_tree=-
overlay_prefix=overlays/
hdmi_cvt:0=
hdmi_cvt:1=
hdmi_edid_filename:0=
hdmi_edid_filename:1=
hdmi_timings:0=
hdmi_timings:1=

cmdline.txt
-----------
coherent_pool=1M 8250.nr_uarts=0 bcm2708_fb.fbwidth=1824 bcm2708_fb.fbheight=984                                                                                          bcm2708_fb.fbswap=1 smsc95xx.macaddr=B8:27:EB:5D:C9:E7 vc_mem.mem_base=0x3ec000                                                                                         00 vc_mem.mem_size=0x40000000  console=ttyS0,115200 console=tty1 root=PARTUUID=6                                                                                         c586e13-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait

raspi-gpio settings
-------------------

BANK0 (GPIO 0 to 27):
GPIO 0: level=1 fsel=0 func=INPUT
GPIO 1: level=1 fsel=0 func=INPUT
GPIO 2: level=1 fsel=4 alt=0 func=SDA1
GPIO 3: level=1 fsel=4 alt=0 func=SCL1
GPIO 4: level=1 fsel=0 func=INPUT
GPIO 5: level=1 fsel=0 func=INPUT
GPIO 6: level=1 fsel=0 func=INPUT
GPIO 7: level=1 fsel=0 func=INPUT
GPIO 8: level=1 fsel=0 func=INPUT
GPIO 9: level=0 fsel=0 func=INPUT
GPIO 10: level=0 fsel=0 func=INPUT
GPIO 11: level=0 fsel=0 func=INPUT
GPIO 12: level=0 fsel=0 func=INPUT
GPIO 13: level=0 fsel=0 func=INPUT
GPIO 14: level=0 fsel=0 func=INPUT
GPIO 15: level=1 fsel=0 func=INPUT
GPIO 16: level=0 fsel=0 func=INPUT
GPIO 17: level=0 fsel=0 func=INPUT
GPIO 18: level=0 fsel=0 func=INPUT
GPIO 19: level=0 fsel=0 func=INPUT
GPIO 20: level=0 fsel=0 func=INPUT
GPIO 21: level=0 fsel=0 func=INPUT
GPIO 22: level=0 fsel=0 func=INPUT
GPIO 23: level=0 fsel=0 func=INPUT
GPIO 24: level=0 fsel=0 func=INPUT
GPIO 25: level=0 fsel=0 func=INPUT
GPIO 26: level=0 fsel=0 func=INPUT
GPIO 27: level=0 fsel=0 func=INPUT
BANK1 (GPIO 28 to 45):
GPIO 28: level=0 fsel=0 func=INPUT
GPIO 29: level=1 fsel=0 func=INPUT
GPIO 30: level=0 fsel=0 func=INPUT
GPIO 31: level=0 fsel=0 func=INPUT
GPIO 32: level=1 fsel=7 alt=3 func=TXD0
GPIO 33: level=1 fsel=7 alt=3 func=RXD0
GPIO 34: level=0 fsel=7 alt=3 func=SD1_CLK
GPIO 35: level=1 fsel=7 alt=3 func=SD1_CMD
GPIO 36: level=1 fsel=7 alt=3 func=SD1_DAT0
GPIO 37: level=1 fsel=7 alt=3 func=SD1_DAT1
GPIO 38: level=1 fsel=7 alt=3 func=SD1_DAT2
GPIO 39: level=1 fsel=7 alt=3 func=SD1_DAT3
GPIO 40: level=0 fsel=4 alt=0 func=PWM0
GPIO 41: level=0 fsel=4 alt=0 func=PWM1
GPIO 42: level=0 fsel=4 alt=0 func=GPCLK1
GPIO 43: level=1 fsel=4 alt=0 func=GPCLK2
GPIO 44: level=1 fsel=0 func=INPUT
GPIO 45: level=1 fsel=0 func=INPUT
BANK2 (GPIO 46 to 53):
GPIO 46: level=1 fsel=0 func=INPUT
GPIO 47: level=1 fsel=1 func=OUTPUT
GPIO 48: level=0 fsel=4 alt=0 func=SD0_CLK
GPIO 49: level=1 fsel=4 alt=0 func=SD0_CMD
GPIO 50: level=1 fsel=4 alt=0 func=SD0_DAT0
GPIO 51: level=1 fsel=4 alt=0 func=SD0_DAT1
GPIO 52: level=1 fsel=4 alt=0 func=SD0_DAT2
GPIO 53: level=1 fsel=4 alt=0 func=SD0_DAT3

vcdbg log messages
------------------

001592.169: brfs: File read: /mfs/sd/config.txt
001593.194: brfs: File read: 1783 bytes
001674.552: brfs: File read: /mfs/sd/config.txt
001675.556: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
001873.427: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
001874.699: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
001874.780: *** Restart logging
001874.843: brfs: File read: 1783 bytes
001905.564: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state                                                                                          instead
001917.594: brfs: File read: /mfs/sd/bcm2710-rpi-3-b.dtb
001917.659: Loading 'bcm2710-rpi-3-b.dtb' to 0x100 size 0x6743
002127.251: brfs: File read: 26435 bytes
002132.150: brfs: File read: /mfs/sd/config.txt
002132.688: dtparam: i2c_arm=on
002157.788: dtparam: audio=on
002188.698: brfs: File read: 1783 bytes
002192.250: brfs: File read: /mfs/sd/cmdline.txt
002192.338: Read command line from file 'cmdline.txt':
002192.397: 'console=serial0,115200 console=tty1 root=PARTUUID=6c586e13-02 rootf                                                                                         stype=ext4 elevator=deadline fsck.repair=yes rootwait'
004444.881: gpioman: gpioman_get_pin_num: pin EMMC_ENABLE not defined
004609.050: brfs: File read: 121 bytes
004985.633: brfs: File read: /mfs/sd/kernel7.img
004985.698: Loading 'kernel7.img' to 0x8000 size 0x52b718
004985.772: Device tree loaded to 0x2eff9400 (size 0x6b66)
004987.840: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined
006527.633: vchiq_core: vchiq_init_state: slot_zero = 0xfad80000, is_master = 1
006532.620: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state                                                                                          instead
006538.635: TV service:host side not connected, dropping notification 0x00000002                                                                                         , 0x00000001, 0x00000010
007414.432: TV service:host side not connected, dropping notification 0x00000001                                                                                         , 0x00000002, 0x00000000
007743.778: TV service:host side not connected, dropping notification 0x00000002                                                                                         , 0x00000001, 0x00000010
010901.348: brfs: File read: 5420824 bytes

dmesg log
---------

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.19.93-v7+ (dom@buildbot) (gcc version 4.9.3 (cros                                                                                         stool-NG crosstool-ng-1.22.0-88-g8460611)) #1290 SMP Fri Jan 10 16:39:50 GMT 202                                                                                         0
[    0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instructio                                                                                         n cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi 3 Model B Rev 1.2
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] cma: Reserved 8 MiB at 0x3ac00000
[    0.000000] On node 0 totalpages: 242688
[    0.000000]   Normal zone: 2133 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 242688 pages, LIFO batch:63
[    0.000000] random: get_random_bytes called from start_kernel+0xac/0x4b4 with                                                                                          crng_init=0
[    0.000000] percpu: Embedded 16 pages/cpu s36864 r8192 d20480 u65536
[    0.000000] pcpu-alloc: s36864 r8192 d20480 u65536 alloc=16*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 240555
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 bcm2708_fb.                                                                                         fbwidth=1824 bcm2708_fb.fbheight=984 bcm2708_fb.fbswap=1 smsc95xx.macaddr=m.m.m.                                                                                         m vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=ttyS0,115200 co                                                                                         nsole=tty1 root=PARTUUID=6c586e13-02 rootfstype=ext4 elevator=deadline fsck.repa                                                                                         ir=yes rootwait
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 939084K/970752K available (8192K kernel code, 653K rwdata                                                                                         , 2220K rodata, 1024K init, 822K bss, 23476K reserved, 8192K cma-reserved)
[    0.000000] Virtual kernel memory layout:
                   vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                   fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                   vmalloc : 0xbb800000 - 0xff800000   (1088 MB)
                   lowmem  : 0x80000000 - 0xbb400000   ( 948 MB)
                   modules : 0x7f000000 - 0x80000000   (  16 MB)
                     .text : 0x(ptrval) - 0x(ptrval)   (9184 kB)
                     .init : 0x(ptrval) - 0x(ptrval)   (1024 kB)
                     .data : 0x(ptrval) - 0x(ptrval)   ( 654 kB)
                      .bss : 0x(ptrval) - 0x(ptrval)   ( 823 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 26853 entries in 79 pages
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] arch_timer: cp15 timer(s) running at 19.20MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles:                                                                                          0x46d987e47, max_idle_ns: 440795202767 ns
[    0.000008] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 43980                                                                                         46511078ns
[    0.000024] Switching to timer-based delay loop, resolution 52ns
[    0.000289] Console: colour dummy device 80x30
[    0.000910] console [tty1] enabled
[    0.000966] Calibrating delay loop (skipped), value calculated using timer fr                                                                                         equency.. 38.40 BogoMIPS (lpj=192000)
[    0.001009] pid_max: default: 32768 minimum: 301
[    0.001370] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001406] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.002377] CPU: Testing write buffer coherency: ok
[    0.002856] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.003528] Setting up static identity map for 0x100000 - 0x10003c
[    0.003696] rcu: Hierarchical SRCU implementation.
[    0.004516] smp: Bringing up secondary CPUs ...
[    0.005416] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.006397] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.007300] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.007424] smp: Brought up 1 node, 4 CPUs
[    0.007506] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.007530] CPU: All CPU(s) started in HYP mode.
[    0.007551] CPU: Virtualization extensions available.
[    0.008540] devtmpfs: initialized
[    0.021495] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3                                                                                          rev 4
[    0.021768] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, ma                                                                                         x_idle_ns: 19112604462750000 ns
[    0.021818] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    0.022427] pinctrl core: initialized pinctrl subsystem
[    0.023309] NET: Registered protocol family 16
[    0.026298] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.031993] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint                                                                                          registers.
[    0.032029] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.032241] Serial: AMBA PL011 UART driver
[    0.034544] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.069659] bcm2835-dma 3f007000.dma: DMA legacy API manager at (ptrval), dma                                                                                         chans=0x1
[    0.071564] SCSI subsystem initialized
[    0.071811] usbcore: registered new interface driver usbfs
[    0.071885] usbcore: registered new interface driver hub
[    0.071995] usbcore: registered new device driver usb
[    0.090303] raspberrypi-firmware soc:firmware: Attached to firmware from 2020                                                                                         -01-10 17:01, variant start
[    0.100124] raspberrypi-firmware soc:firmware: Firmware hash is f3e39fed4763c                                                                                         e4efbffabb2d4787aaacddeda0f
[    0.111880] clocksource: Switched to clocksource arch_sys_counter
[    0.200426] VFS: Disk quotas dquot_6.6.0
[    0.200538] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.200741] FS-Cache: Loaded
[    0.200974] CacheFiles: Loaded
[    0.210973] NET: Registered protocol family 2
[    0.211830] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144                                                                                          bytes)
[    0.211952] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    0.212085] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    0.212290] TCP: Hash tables configured (established 8192 bind 8192)
[    0.212446] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.212516] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.212776] NET: Registered protocol family 1
[    0.213378] RPC: Registered named UNIX socket transport module.
[    0.213405] RPC: Registered udp transport module.
[    0.213427] RPC: Registered tcp transport module.
[    0.213448] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.215071] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counter                                                                                         s available
[    0.218128] Initialise system trusted keyrings
[    0.218339] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    0.228158] FS-Cache: Netfs 'nfs' registered for caching
[    0.228758] NFS: Registering the id_resolver key type
[    0.228813] Key type id_resolver registered
[    0.228834] Key type id_legacy registered
[    0.228865] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.231155] Key type asymmetric registered
[    0.231183] Asymmetric key parser 'x509' registered
[    0.231249] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 2                                                                                         50)
[    0.231452] io scheduler noop registered
[    0.231477] io scheduler deadline registered (default)
[    0.231676] io scheduler cfq registered
[    0.231700] io scheduler mq-deadline registered (default)
[    0.231724] io scheduler kyber registered
[    0.235047] bcm2708_fb soc:fb: FB found 1 display(s)
[    0.285838] Console: switching to colour frame buffer device 228x61
[    0.314552] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 182                                                                                         4x984
[    0.317021] bcm2835-rng 3f104000.rng: hwrng registered
[    0.317497] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000                                                                                         000(1024 MiB)
[    0.318268] vc-sm: Videocore shared memory driver
[    0.318733] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f2                                                                                         00000
[    0.329843] brd: module loaded
[    0.340622] loop: module loaded
[    0.341384] Loading iSCSI transport class v2.0-870.
[    0.342323] libphy: Fixed MDIO Bus: probed
[    0.342553] usbcore: registered new interface driver lan78xx
[    0.342768] usbcore: registered new interface driver smsc95xx
[    0.342941] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    0.370956] dwc_otg 3f980000.usb: base=(ptrval)
[    0.571330] Core Release: 2.80a
[    0.571440] Setting default values for core params
[    0.571613] Finished setting default values for core params
[    0.772117] Using Buffer DMA mode
[    0.772226] Periodic Transfer Interrupt Enhancement - disabled
[    0.772398] Multiprocessor Interrupt Enhancement - disabled
[    0.772563] OTG VER PARAM: 0, OTG VER FLAG: 0
[    0.772707] Dedicated Tx FIFOs mode
[    0.773296] WARN::dwc_otg_hcd_init:1045: FIQ DMA bounce buffers: virt = bad04                                                                                         000 dma = 0xfad04000 len=9024
[    0.773593] FIQ FSM acceleration enabled for :
               Non-periodic Split Transactions
               Periodic Split Transactions
               High-Speed Isochronous Endpoints
               Interrupt/Control Split Transaction hack enabled
[    0.787844] dwc_otg: Microframe scheduler enabled
[    0.787900] WARN::hcd_init_fiq:457: FIQ on core 1
[    0.794786] WARN::hcd_init_fiq:458: FIQ ASM at 8067f620 length 36
[    0.801705] WARN::hcd_init_fiq:497: MPHI regs_base at bb810000
[    0.808587] dwc_otg 3f980000.usb: DWC OTG Controller
[    0.815418] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number                                                                                          1
[    0.822387] dwc_otg 3f980000.usb: irq 56, io mem 0x00000000
[    0.829267] Init: Port Power? op_state=1
[    0.836235] Init: Power Port (0)
[    0.843355] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bc                                                                                         dDevice= 4.19
[    0.850398] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=                                                                                         1
[    0.857416] usb usb1: Product: DWC OTG Controller
[    0.864327] usb usb1: Manufacturer: Linux 4.19.93-v7+ dwc_otg_hcd
[    0.871298] usb usb1: SerialNumber: 3f980000.usb
[    0.878801] hub 1-0:1.0: USB hub found
[    0.885737] hub 1-0:1.0: 1 port detected
[    0.893116] dwc_otg: FIQ enabled
[    0.893122] dwc_otg: NAK holdoff enabled
[    0.893127] dwc_otg: FIQ split-transaction FSM enabled
[    0.893138] Module dwc_common_port init
[    0.893404] usbcore: registered new interface driver usb-storage
[    0.900532] mousedev: PS/2 mouse device common for all mice
[    0.908386] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    0.915529] bcm2835-cpufreq: min=600000 max=1200000
[    0.922973] sdhci: Secure Digital Host Controller Interface driver
[    0.929860] sdhci: Copyright(c) Pierre Ossman
[    0.937144] mmc-bcm2835 3f300000.mmcnr: could not get clk, deferring probe
[    0.944486] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe
[    0.951662] sdhci-pltfm: SDHCI platform and OF driver helper
[    0.960301] ledtrig-cpu: registered to indicate activity on CPUs
[    0.967657] hidraw: raw HID events driver (C) Jiri Kosina
[    0.975066] usbcore: registered new interface driver usbhid
[    0.982212] usbhid: USB HID core driver
[    0.990177] vchiq: vchiq_init_state: slot_zero = (ptrval), is_master = 0
[    0.999004] [vc_sm_connected_init]: start
[    1.009275] [vc_sm_connected_init]: end - returning 0
[    1.017442] Initializing XFRM netlink socket
[    1.024417] NET: Registered protocol family 17
[    1.031327] Key type dns_resolver registered
[    1.038565] Registering SWP/SWPB emulation handler
[    1.046020] registered taskstats version 1
[    1.052858] Loading compiled-in X.509 certificates
[    1.066462] uart-pl011 3f201000.serial: cts_event_workaround enabled
[    1.073541] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 81, base_baud                                                                                          = 0) is a PL011 rev2
[    1.082653] mmc-bcm2835 3f300000.mmcnr: mmc_debug:0 mmc_debug2:0
[    1.089792] mmc-bcm2835 3f300000.mmcnr: DMA channel allocated
[    1.112024] Indeed it is in host mode hprt0 = 00021501
[    1.180108] sdhost: log_buf @ (ptrval) (fad07000)
[    1.206644] random: fast init done
[    1.227354] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    1.236044] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.243050] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    1.251345] of_cfs_init
[    1.258491] of_cfs_init: OK
[    1.266042] Waiting for root device PARTUUID=6c586e13-02...
[    1.271227] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.282486] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    1.331925] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    1.338834] Indeed it is in host mode hprt0 = 00001101
[    1.417116] mmc0: host does not support reading read-only switch, assuming wr                                                                                         ite-enable
[    1.430739] mmc0: new high speed SDHC card at address aaaa
[    1.439154] mmcblk0: mmc0:aaaa SC16G 14.8 GiB
[    1.452534]  mmcblk0: p1 p2
[    1.485508] mmc1: new high speed SDIO card at address 0001
[    1.487060] EXT4-fs (mmcblk0p2): INFO: recovery required on readonly filesyst                                                                                         em
[    1.499588] EXT4-fs (mmcblk0p2): write access will be enabled during recovery
[    1.577953] EXT4-fs (mmcblk0p2): recovery complete
[    1.582266] usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcd                                                                                         Device= 2.00
[    1.589931] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. O                                                                                         pts: (null)
[    1.592316] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    1.599543] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    1.614424] hub 1-1:1.0: USB hub found
[    1.621759] hub 1-1:1.0: 5 ports detected
[    1.625294] devtmpfs: mounted
[    1.641180] Freeing unused kernel memory: 1024K
[    1.648804] Run /sbin/init as init process
[    1.941951] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    2.072336] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, b                                                                                         cdDevice= 2.00
[    2.079707] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber                                                                                         =0
[    2.089935] smsc95xx v1.0.6
[    2.185541] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-                                                                                         1.1, smsc95xx USB 2.0 Ethernet, m.m.m.m
[    2.267220] systemd[1]: System time before build time, advancing clock.
[    2.407673] NET: Registered protocol family 10
[    2.416709] Segment Routing with IPv6
[    2.473655] systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SEL                                                                                         INUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +                                                                                         XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybr                                                                                         id)
[    2.491012] systemd[1]: Detected architecture arm.
[    2.546940] systemd[1]: Set hostname to <raspberrypi>.
[    2.560159] systemd[1]: Failed to bump fs.file-max, ignoring: Invalid argumen                                                                                         t
[    3.349602] random: systemd: uninitialized urandom read (16 bytes read)
[    3.369177] random: systemd: uninitialized urandom read (16 bytes read)
[    3.383371] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[    3.401780] random: systemd: uninitialized urandom read (16 bytes read)
[    3.410440] systemd[1]: Started Dispatch Password Requests to Console Directo                                                                                         ry Watch.
[    3.429719] systemd[1]: Listening on Journal Socket.
[    3.453714] systemd[1]: Mounting Kernel Debug File System...
[    3.478612] systemd[1]: Mounting RPC Pipe File System...
[    3.498440] systemd[1]: Reached target Swap.
[    3.607822] i2c /dev entries driver
[    4.481269] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    4.601517] systemd-journald[121]: Received request to flush runtime journal                                                                                          from PID 1
[    5.240263] vc_sm_cma: module is from the staging directory, the quality is u                                                                                         nknown, you have been warned.
[    5.244123] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    5.244150] [vc_sm_connected_init]: start
[    5.253187] [vc_sm_connected_init]: installed successfully
[    5.262149] media: Linux media interface: v0.10
[    5.312565] videodev: Linux video capture interface: v2.00
[    5.342877] bcm2835_mmal_vchiq: module is from the staging directory, the qua                                                                                         lity is unknown, you have been warned.
[    5.343049] bcm2835_mmal_vchiq: module is from the staging directory, the qua                                                                                         lity is unknown, you have been warned.
[    5.356133] bcm2835_v4l2: module is from the staging directory, the quality i                                                                                         s unknown, you have been warned.
[    5.363567] bcm2835_codec: module is from the staging directory, the quality                                                                                          is unknown, you have been warned.
[    5.378307] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[    5.378352] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[    5.385107] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[    5.385151] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[    5.395366] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[    5.395408] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[    5.494741] snd_bcm2835: module is from the staging directory, the quality is                                                                                          unknown, you have been warned.
[    5.502342] bcm2835_audio soc:audio: card created with 8 channels
[    5.689038] cfg80211: Loading compiled-in X.509 certificates for regulatory d                                                                                         atabase
[    5.824974] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    5.917382] brcmfmac: F1 signature read @0x18000000=0x1541a9a6
[    5.928558] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio f                                                                                         or chip BCM43430/1
[    5.928846] usbcore: registered new interface driver brcmfmac
[    6.139275] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio f                                                                                         or chip BCM43430/1
[    6.139378] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available (err=-2                                                                                         ), device may have limited channels available
[    6.140067] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Oct 23                                                                                          2017 03:55:53 version 7.45.98.38 (r674442 CY) FWID 01-e58d219f
[    7.965776] random: crng init done
[    7.965795] random: 7 urandom warning(s) missed due to ratelimiting
[    8.225090] uart-pl011 3f201000.serial: no DMA platform data
[    8.377946] 8021q: 802.1Q VLAN Support v1.8
[    8.491958] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:1                                                                                         02396k SSFS
[    8.655939] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[    8.655980] brcmfmac: power management disabled
[    9.063073] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[    9.063273] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   10.137229] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   13.091012] Bluetooth: Core ver 2.22
[   13.091124] NET: Registered protocol family 31
[   13.091131] Bluetooth: HCI device and connection manager initialized
[   13.091165] Bluetooth: HCI socket layer initialized
[   13.091179] Bluetooth: L2CAP socket layer initialized
[   13.091224] Bluetooth: SCO socket layer initialized
[   13.110935] Bluetooth: HCI UART driver ver 2.3
[   13.110953] Bluetooth: HCI UART protocol H4 registered
[   13.111057] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   13.111293] Bluetooth: HCI UART protocol Broadcom registered
[   13.387899] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   13.387913] Bluetooth: BNEP filters: protocol multicast
[   13.387936] Bluetooth: BNEP socket layer initialized
6by9 commented 4 years ago

You haven't quoted the actual kernel dump from the error, nor what the connected device is.

When I try this I get

OSError: [Errno 121] Remote I/O error

which is what I expect as there isn't a device connected. Providing the address of an IMX219 camera module and I don't see any bad behaviour, however it's an I2C device rather than SMBus.

JsBergbau commented 4 years ago

ou haven't quoted the actual kernel dump from the error

Where is it stored? I couldn't find. I've only found that you should connect a serial console to get the full dump.

Connected is a OPT3001 https://www.aliexpress.com/item/33049813978.html Sensor. I've created another script with smbus (not smbus2) and there it is working. Still a userspace application shouldn't cause a kernel panic.

6by9 commented 4 years ago

Where is it stored? I couldn't find. I've only found that you should connect a serial console to get the full dump.

It'll normally be dumped to the screen, or to the SSH session that tripped it up. Very few kernel crashes take out everything, so having two SSH sessions open with one running dmesg -w and the other running your script would normally work.

Connected is a OPT3001 https://www.aliexpress.com/item/33049813978.html Sensor. I've created another script with smbus (not smbus2) and there it is working. Still a userspace application shouldn't cause a kernel panic.

Agreed, but without any debug it's near impossible to determine what is going wrong.

JsBergbau commented 4 years ago

It'll normally be dumped to the screen, or to the SSH session that tripped it up. Very few kernel crashes take out everything, so having two SSH sessions open with one running dmesg -w and the other running your script would normally work.

Saidly no. SSH session just crashes. Even the trick with the second ssh session didn't work. I've setup another Raspberry-PI to get the full kernel dump. BTW: After the crash even the last modified files aren't saved to disk.

raspberrypi login: [  154.872851] Kernel panic - not syncing: stack-protector: Kernel stack is corrupted in: i2cdev_ioctl_smbus+0x268/0x268 [i2c_dev]
[  154.886523] CPU: 1 PID: 1333 Comm: crash.sh Tainted: G         C        4.19.93-v7+ #1290
[  154.896900] Hardware name: BCM2835
[  154.901413] [<801120c0>] (unwind_backtrace) from [<8010d5f4>] (show_stack+0x20/0x24)
[  154.911513] [<8010d5f4>] (show_stack) from [<808453e8>] (dump_stack+0xe0/0x124)
[  154.920155] [<808453e8>] (dump_stack) from [<80120ef8>] (panic+0x104/0x288)
[  154.928453] [<80120ef8>] (panic) from [<801209f8>] (print_tainted+0x0/0xa8)
[  154.936788] CPU0: stopping
[  154.940794] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G         C        4.19.93-v7+ #1290
[  154.951530] Hardware name: BCM2835
[  154.956302] [<801120c0>] (unwind_backtrace) from [<8010d5f4>] (show_stack+0x20/0x24)
[  154.966926] [<8010d5f4>] (show_stack) from [<808453e8>] (dump_stack+0xe0/0x124)
[  154.975805] [<808453e8>] (dump_stack) from [<801104d8>] (handle_IPI+0x388/0x3a8)
[  154.986153] [<801104d8>] (handle_IPI) from [<801021f4>] (bcm2836_arm_irqchip_handle_irq+0xa0/0xa4)
[  154.998240] [<801021f4>] (bcm2836_arm_irqchip_handle_irq) from [<801019bc>] (__irq_svc+0x5c/0x7c)
[  155.010254] Exception stack(0x80d01ee8 to 0x80d01f30)
[  155.016892] 1ee0:                   80109ae4 00000000 40000093 40000093 80d04d70 80d00000
[  155.028251] 1f00: 80d04db8 00000001 80d8efbe babff9c0 80c64a38 80d01f44 80d0517c 80d01f38
[  155.039585] 1f20: 00000000 80109ae8 40000013 ffffffff
[  155.046248] [<801019bc>] (__irq_svc) from [<80109ae8>] (arch_cpu_idle+0x34/0x4c)
[  155.056851] [<80109ae8>] (arch_cpu_idle) from [<808624d4>] (default_idle_call+0x34/0x48)
[  155.068246] [<808624d4>] (default_idle_call) from [<80152e80>] (do_idle+0xec/0x16c)
[  155.079320] [<80152e80>] (do_idle) from [<801531c0>] (cpu_startup_entry+0x28/0x2c)
[  155.090312] [<801531c0>] (cpu_startup_entry) from [<8085bb80>] (rest_init+0xbc/0xc0)
[  155.101555] [<8085bb80>] (rest_init) from [<80c00fb0>] (start_kernel+0x484/0x4b4)
[  155.112536] CPU2: stopping
[  155.116916] CPU: 2 PID: 0 Comm: swapper/2 Tainted: G         C        4.19.93-v7+ #1290
[  155.128272] Hardware name: BCM2835
[  155.133304] [<801120c0>] (unwind_backtrace) from [<8010d5f4>] (show_stack+0x20/0x24)
[  155.144358] [<8010d5f4>] (show_stack) from [<808453e8>] (dump_stack+0xe0/0x124)
[  155.153419] [<808453e8>] (dump_stack) from [<801104d8>] (handle_IPI+0x388/0x3a8)
[  155.164104] [<801104d8>] (handle_IPI) from [<801021f4>] (bcm2836_arm_irqchip_handle_irq+0xa0/0xa4)
[  155.176409] [<801021f4>] (bcm2836_arm_irqchip_handle_irq) from [<801019bc>] (__irq_svc+0x5c/0x7c)
[  155.188622] Exception stack(0xb9d4ff38 to 0xb9d4ff80)
[  155.195326] ff20:                                                       80109ae4 00000000
[  155.206661] ff40: 40000093 40000093 80d04d70 b9d4e000 80d04db8 00000004 80d8efbe 410fd034
[  155.217929] ff60: 00000000 b9d4ff94 80d0517c b9d4ff88 00000000 80109ae8 40000013 ffffffff
[  155.229199] [<801019bc>] (__irq_svc) from [<80109ae8>] (arch_cpu_idle+0x34/0x4c)
[  155.239801] [<80109ae8>] (arch_cpu_idle) from [<808624d4>] (default_idle_call+0x34/0x48)
[  155.251219] [<808624d4>] (default_idle_call) from [<80152e80>] (do_idle+0xec/0x16c)
[  155.262262] [<80152e80>] (do_idle) from [<801531c0>] (cpu_startup_entry+0x28/0x2c)
[  155.273255] [<801531c0>] (cpu_startup_entry) from [<8010fedc>] (secondary_start_kernel+0x134/0x140)
[  155.285798] [<8010fedc>] (secondary_start_kernel) from [<0010270c>] (0x10270c)
[  155.294841] CPU3: stopping
[  155.299242] CPU: 3 PID: 0 Comm: swapper/3 Tainted: G         C        4.19.93-v7+ #1290
[  155.310644] Hardware name: BCM2835
[  155.315717] [<801120c0>] (unwind_backtrace) from [<8010d5f4>] (show_stack+0x20/0x24)
[  155.326922] [<8010d5f4>] (show_stack) from [<808453e8>] (dump_stack+0xe0/0x124)
[  155.336059] [<808453e8>] (dump_stack) from [<801104d8>] (handle_IPI+0x388/0x3a8)
[  155.346837] [<801104d8>] (handle_IPI) from [<801021f4>] (bcm2836_arm_irqchip_handle_irq+0xa0/0xa4)
[  155.359224] [<801021f4>] (bcm2836_arm_irqchip_handle_irq) from [<801019bc>] (__irq_svc+0x5c/0x7c)
[  155.371521] Exception stack(0xb9d51f38 to 0xb9d51f80)
[  155.378268] 1f20:                                                       80109ae4 00000000
[  155.389690] 1f40: 40000093 40000093 80d04d70 b9d50000 80d04db8 00000008 80d8efbe 410fd034
[  155.401041] 1f60: 00000000 b9d51f94 80d0517c b9d51f88 00000000 80109ae8 40000013 ffffffff
[  155.412396] [<801019bc>] (__irq_svc) from [<80109ae8>] (arch_cpu_idle+0x34/0x4c)
[  155.422998] [<80109ae8>] (arch_cpu_idle) from [<808624d4>] (default_idle_call+0x34/0x48)
[  155.434412] [<808624d4>] (default_idle_call) from [<80152e80>] (do_idle+0xec/0x16c)
[  155.445454] [<80152e80>] (do_idle) from [<801531c0>] (cpu_startup_entry+0x28/0x2c)
[  155.456445] [<801531c0>] (cpu_startup_entry) from [<8010fedc>] (secondary_start_kernel+0x134/0x140)
[  155.468987] [<8010fedc>] (secondary_start_kernel) from [<0010270c>] (0x10270c)
[  155.478038] ---[ end Kernel panic - not syncing: stack-protector: Kernel stack is corrupted in: i2cdev_ioctl_smbus+0x268/0x268 [i2c_dev] ]---
pelwell commented 4 years ago

I've got a reasonable I2C knowledge, but I'm a total noob w.r.t. SMBus. However, from reading the Python and some kernel code, it looks like read_block_data is expecting the device to send a sequence of bytes in which the first byte indicates the number of following bytes. It also appears that the maximum block length supported by the kernel is about 32 bytes:

/*
 * Data for SMBus Messages
 */
#define I2C_SMBUS_BLOCK_MAX 32  /* As specified in SMBus standard */
union i2c_smbus_data {
    __u8 byte;
    __u16 word;
    __u8 block[I2C_SMBUS_BLOCK_MAX + 2]; /* block[0] is used for length */
                   /* and one more for user-space compatibility */
};

Looking at the OPT3001 datasheet I don't see any mention of that kind of transfer, just 16-bit reads and writes where the MSB is sent first. Is it possible that the device is performing a simple register read of 0x7e, which would return 0x30 0x01, and the first returned byte (0x30 = 48) is being interpreted as a length? This could easily cause it to overflow the stack frame.

Try read_word_data instead.

6by9 commented 4 years ago

I think your reading of the spec is correct. Random post via Google: https://www.microchip.com/forums/FindPost/1033077

In smbus there is a thing called block read. It can only be used on registers that support it. For example the battery name and manufacturer name on a standard smbus battery.

Spec http://www.smbus.org/specs/SMBus_3_1_20180319.pdf, section 6.5.7 (page 42) also says the device has to return the length count

I'd agree that the kernel shouldn't allow the transfer to smash the stack. I suspect it is the loop copying the data back out at https://elixir.bootlin.com/linux/v5.4.15/source/drivers/i2c/i2c-core-smbus.c#L498 that is at fault as it is relying totally on the value reported back by the SMBus device. I think there should be a guard along the lines of

for (i = 0; i < msg[1].buf[0] + 1 && i <  I2C_SMBUS_BLOCK_MAX + 1; i++)

would prevent it. Or base it on the test for write at line 426 and return an error and no data instead of truncating.

        if (msg[1].buf[0] > I2C_SMBUS_BLOCK_MAX) {
            dev_err(&adapter->dev, "Invalid block %s size %d returned\n",
                read_write == I2C_SMBUS_READ ? "read" : "write",
                msg[1].buf[0]);
            return -EINVAL;
        }

I guess this ought to be reported upstream as things shouldn't crash the kernel.