I2c producing crazy console messages [[Re: insanely-high interrupt rates -- PARTIAL resolution (Pi2)]]
Per Hedeland
per at hedeland.org
Fri Apr 19 15:28:10 UTC 2019
On 2019-04-19 16:16, Karl Denninger wrote:
> On 4/19/2019 06:32, Per Hedeland wrote:
>> On 2019-04-19 03:25, Karl Denninger wrote:
>>>
>>> On 4/18/2019 17:57, Ian Lepore wrote:
>>>> On Thu, 2019-04-18 at 16:51 -0500, Karl Denninger wrote:
>>>>> Up until 12.0 this code both worked and did *not* generate complaints
>>>>> about unhandled interrupts. It still runs fine and returns valid
>>>>> data
>>>>> BUT if there are any analog endpoints actually on the bus that the
>>>>> code
>>>>> can read then it generates a lot of these:
>>>>>
>>>>> local_intc0: Spurious interrupt detected
>>>>> local_intc0: Spurious interrupt detected
>>>>> intc0: Spurious interrupt detected
>>>>>
>>>>> .....
>>>>>
>>>>> If I do not connect the I2c device then there are no messages. If I
>>>>> stop the code that is running (e.g. no accesses to the i2c bus) then
>>>>> the
>>>>> messages stop as well, so it's not something that happens but remains
>>>>> active after the code halts; it's happening on the actual accesses to
>>>>> the bus from those ioctl's.
>>>> Hmm, another interesting question occurred to me: Can you tell whether
>>>> you are getting multiple spurious interrupt messages per single
>>>> transfer your code does, or is it one per transfer, or more
>>>> intermittent, like not on every transfer?
>>>>
>>>> -- Ian
>>>
>>> It logs the message on "many" accesses, but not all.
>>>
>>> The code scans each of the declared analogs once per second. There are
>>> two inputs defined on this unit right now, so if it was on every access
>>> there would be two messages per second logged, and there isn't; nor is
>>> it "one per cluster" of accesses. I removed the reset and restarted the
>>> code and this is the frequency of log entries I'm getting, which implies
>>> frequent and random, but much less than 1:1.
>>>
>>> Apr 18 20:22:25 Pool-MCP kernel: intc0: Spurious interrupt detected
>>> Apr 18 20:22:26 Pool-MCP kernel: local_intc0: Spurious interrupt detected
>>> Apr 18 20:22:27 Pool-MCP kernel: intc0: Spurious interrupt detected
>>> Apr 18 20:22:33 Pool-MCP kernel: local_intc0: Spurious interrupt detected
>>> Apr 18 20:22:36 Pool-MCP kernel: intc0: Spurious interrupt detected
>>> Apr 18 20:22:38 Pool-MCP kernel: local_intc0: Spurious interrupt detected
>>> Apr 18 20:22:39 Pool-MCP kernel: intc0: Spurious interrupt detected
>>> Apr 18 20:22:40 Pool-MCP syslogd: last message repeated 1 times
>>> Apr 18 20:22:40 Pool-MCP kernel: local_intc0: Spurious interrupt detected
>>> Apr 18 20:22:42 Pool-MCP kernel: intc0: Spurious interrupt detected
>>> Apr 18 20:22:49 Pool-MCP kernel: local_intc0: Spurious interrupt detected
>>> Apr 18 20:22:52 Pool-MCP kernel: intc0: Spurious interrupt detected
>>> Apr 18 20:22:53 Pool-MCP kernel: local_intc0: Spurious interrupt detected
>>
>> Hm, I've recently gotten an i2c device to work on RPi - FWIW it's an
>> ads1015 AD-converter, my code is pretty similar to yours - you may
>> actually be using the same device - and I don't see *any* "Spurious
>> interrupt" messages when using it. But a) I've only run it on RPi Zero
>> (currently connected) and RPi 1B (briefly when testing), and b) I
>> don't have a console connected (but I assume the messages should also
>> show up in dmesg and /var/log/messages, the above seems to be from the
>> log).
>>
>> But anyway I would be *extremely* surprised if I saw them, since AFAIU
>> the i2c bus per se has no concept of interrupts - you need to connect
>> some other wire from the device to e.g. a gpio pin (with appropriate
>> config) in order to generate interrupts - and I haven't done that. (The
>> ads1015 does have an ALERT/RDY pin that could potentially be used for
>> it, but since FreeBSD AFAIK doesn't have a way to deliver the
>> interrupts to userland code, I had no interest in it.)
>
> Correct. Indeed these are ADS1015s -- the code also supports ads1115s. The delay for conversion is different, thus the multiplier (you set a different constant in the config file) plus, of course,
> the shift required for 12-bit alignment into a 16-bit result.
>
>>
>> So, your code like mine doesn't seem to use interrupts at all - do you
>> nevertheless have some interrupt-generating connection from the
>> device?
>
> No. Thus the delay for conversion via usleep within my code since there's no way for a device on the I2c bus itself (at least as far as I know) to alert that the conversion is complete. While
> theoretically I could use the Alert/RDY pin I do not at present.
>
> The spurious interrupt message is coming from sys/arm/broadcom/bcm2835/bcm2835_intr.c -- which is, of course, not present in a RPI3 build since that's aarch64 (the "arm64" branch of the sys tree) and
> not arm.
OK, but... - the interrupts "have to" be generated by some "electrical
change" *somewhere* - if you haven't connected anything else, that
would seem to leave only the actual SDA/SCL lines of the i2c bus
itself. Which would be "crazy", and everyone using any i2c device
would see them - at least on the RPi 2...
> But the below is indeed interesting....
>
>> And if these interrupts really happen only on RPi 2 and not on
>> any of 0/1/3, I guess it makes sense to look at the dts/dtb files.
>> Diffing bcm2708-rpi-0-w.dts and bcm2709-rpi-2-b.dts, I see this:
>>
>> interrupt-controller at 7e00b200 {
>>
>> - compatible = "brcm,bcm2835-armctrl-ic";
>> + compatible = "brcm,bcm2836-armctrl-ic";
>> reg = <0x7e00b200 0x200>;
>> interrupt-controller;
>> #interrupt-cells = <0x2>;
>> + interrupt-parent = <0x3>;
>> + interrupts = <0x8>;
>> phandle = <0x1>;
>> };
>>
>> and this:
>>
>> + local_intc at 40000000 {
>> +
>> + compatible = "brcm,bcm2836-l1-intc";
>> + reg = <0x40000000 0x100>;
>> + interrupt-controller;
>> + #interrupt-cells = <0x1>;
>> + interrupt-parent = <0x3>;
>> + phandle = <0x3>;
>> + };
>>
>> I have (as yet) no idea what it actually means, but it clearly seems
>> to be interrupt-related... There are a few more "interrupt-related"
>> diffs, but those two kind of "stand out" for me. Btw, shouldn't these
>> .dts files exist somewhere under /usr/src/sys/gnu/dts/arm? I
>> decompiled them from the .dtb's in installed images to be able to
>> compare...
>>
>> --Per Hedeland
>
> The "newer build environment" has both rpi-firmware and u-boot running off packages/ports, which are nominally in /usr/local/share; in this case /usr/local/share/rpi-firmware. The dtb files are
> there, but not the source dts files. FreeBSD picks up the binary dtb files; it does not compile the .dts files at build time.
Thanks, all clear now!
--Per
> root at NewFS:/usr/local/share/rpi-firmware # ls -al
> total 9427
> drwxr-xr-x 3 root wheel 26 Feb 10 12:08 .
> drwxr-xr-x 112 root wheel 113 Mar 4 11:31 ..
> -rw-r--r-- 1 root wheel 18693 Nov 12 10:05 COPYING.linux
> -rw-r--r-- 1 root wheel 1494 Nov 12 10:05 LICENCE.broadcom
> -rw-r--r-- 1 root wheel 5888 Feb 8 11:55 armstub8.bin
> -rw-r--r-- 1 root wheel 23315 Nov 12 10:05 bcm2708-rpi-0-w.dtb
> -rw-r--r-- 1 root wheel 23071 Nov 12 10:05 bcm2708-rpi-b-plus.dtb
> -rw-r--r-- 1 root wheel 22812 Nov 12 10:05 bcm2708-rpi-b.dtb
> -rw-r--r-- 1 root wheel 22589 Nov 12 10:05 bcm2708-rpi-cm.dtb
> -rw-r--r-- 1 root wheel 24115 Nov 12 10:05 bcm2709-rpi-2-b.dtb
> -rw-r--r-- 1 root wheel 25574 Nov 12 10:05 bcm2710-rpi-3-b-plus.dtb
> -rw-r--r-- 1 root wheel 25311 Nov 12 10:05 bcm2710-rpi-3-b.dtb
> -rw-r--r-- 1 root wheel 24087 Nov 12 10:05 bcm2710-rpi-cm3.dtb
> -rw-r--r-- 1 root wheel 52116 Nov 12 10:05 bootcode.bin
> -rw-r--r-- 1 root wheel 89 Feb 8 11:55 config.txt
> -rw-r--r-- 1 root wheel 151 Feb 8 11:55 config_rpi3.txt
> -rw-r--r-- 1 root wheel 114 Feb 8 11:55 config_rpi_0_w.txt
> -rw-r--r-- 1 root wheel 6666 Nov 12 10:05 fixup.dat
> -rw-r--r-- 1 root wheel 2621 Nov 12 10:05 fixup_cd.dat
> -rw-r--r-- 1 root wheel 9895 Nov 12 10:05 fixup_db.dat
> -rw-r--r-- 1 root wheel 9895 Nov 12 10:05 fixup_x.dat
> drwxr-xr-x 2 root wheel 151 Feb 10 12:08 overlays
> -rw-r--r-- 1 root wheel 2857060 Nov 12 10:05 start.elf
> -rw-r--r-- 1 root wheel 678532 Nov 12 10:05 start_cd.elf
> -rw-r--r-- 1 root wheel 5120484 Nov 12 10:05 start_db.elf
> -rw-r--r-- 1 root wheel 4057956 Nov 12 10:05 start_x.elf
>
> root at NewFS:/usr/local/share/rpi-firmware # pkg info |grep rpi
> rpi-firmware-1.20181112 Firmware for RaspberryPi Single Board Computer
> u-boot-rpi2-2019.01 Cross-build das u-boot for model rpi2
> u-boot-rpi3-2019.01 Cross-build das u-boot for model rpi3
>
> --
> Karl Denninger
> karl at denninger.net <mailto:karl at denninger.net>
> /The Market Ticker/
> /[S/MIME encrypted email preferred]/
More information about the freebsd-arm
mailing list