I2c producing crazy console messages [[Re: insanely-high interrupt rates -- PARTIAL resolution (Pi2)]]

[Per Hedeland]

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.)

So, your code like mine doesn't seem to use interrupts at all - do you
nevertheless have some interrupt-generating connection from the
device? 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