r852 & r592 IRQ: DMA errors cause log files to grow *HUGE*

User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Firefox/31.0

I am seeing this problem on OpenSUSE with kernel-desktop versions 3.15.6 (stable repo) and 3.16.0 (HEAD repo).

The log files on my laptop, /var/log/messages and /var/log/warn, will grow HUGE with the following repeated over and over along with some extraneous related log entries:

2014-08-15T12:18:41.396981-04:00 localhost kernel: [17310.691176] r592: IRQ: card added
2014-08-15T12:18:41.396983-04:00 localhost kernel: [17310.691178] r592: IRQ: DMA error
.
<snip>
.
2014-08-15T12:18:41.397001-04:00 localhost kernel: [17311.223846] r592: IRQ: card added
2014-08-15T12:18:41.397004-04:00 localhost kernel: [17311.223847] r592: IRQ: DMA error

On any given day, there will be tens of thousands of these entries such that /var/log/messages and /var/log/warn will both exceed 3GB within a day (over 6GB total).

I believe that this bug is generated due to the presence of a Ricoh R5C592 Memory Stick Adapter on my laptop and which has never been properly recognized by the stock linux kernels. Apparently, the kernel developers keep trying to make it work but have now introduced a "bigger" problem so to speak since it is now causing all these extraneous error messages to be generated in the logs.

I am seeing this bug on OpenSUSE with kernel-desktop versions 3.15.6 and 3.16.0. This bug does not appear to be present in the OpenSUSE stock 3.11.6 and 3.11.10 kernels. I have since reverted back to the earlier kernels that don't have this problem.

This bug has also been reported at Red Hat's bugzilla at:

https://bugzilla.redhat.com/show_bug.cgi?id=1119361

IMHO, this bug needs to be fixed prior to the release of OpenSUSE 13.2.

FYI,

Gordon

Reproducible: Always

Steps to Reproduce:
1. Boot
2. Wait a while. It sometimes takes an hour or two for the log errors to begin at top volume.
Actual Results:
Logs grow *HUGE* with r592IRQ: DMA errors and related entries.

Expected Results:
Logger should not produce error messages of this magnitude and size.

Since it's endless irq wakeups, here is a blind shot: could you check whether the patch below works?

Created attachment 603338
Test patch

I am not a kernel developer and so I'm not sure how to build r592.c with the patch, however, I would be happy to test it if somebody else would build it for me. Alternatively, if its simple to do, then please provide some instructions and I will attempt to build it.

Also, the following is from a post at:

https://forums.opensuse.org/showthread.php/494706-openSUSE-13-1-KDE-inconsistant-resume-from-Suspend-to-RAM?p=2661131#post2661131

Quoting Romanator: "The most recent openSUSE kernel (3.11.10-21-desktop) Makefile for the r592.c from Maxim Levitsky is from 2010. His final patch wasn't submitted until Jan. 8, 2011. <snip> Ask the openSUSE kernel devs to look at and backport patch #5b945a6 from this link: https://gitorious.org/ricoh-kernel/ricoh-kernel.git ".

So, it doesn't look like the OpenSUSE kernel has the most recent r592 driver...

Also, there is a good bit of recent activity by the r592 developer, Maxim Levitsky, on this exact same bug at Red Hat's Bugzilla site here:

https://bugzilla.redhat.com/show_bug.cgi?id=1119361

The bottom line is that someone needs to make sure that OpenSUSE is using the most recent version of r592.c.

FYI,

Gordon

The ricoh-kernel project is maintained here:

https://gitorious.org/ricoh-kernel/ricoh-kernel/source/33138f5085346e1000bcab7ef83e2c88a200b6ec:

Also, there is a more recent (March 31, 2011) r592.c patch here:

https://gitorious.org/ricoh-kernel/ricoh-kernel/commit/33138f5085346e1000bcab7ef83e2c88a200b6ec

FYI,

Gordon

(In reply to comment #3)
> I am not a kernel developer and so I'm not sure how to build r592.c with the
> patch, however, I would be happy to test it if somebody else would build it for
> me. Alternatively, if its simple to do, then please provide some instructions
> and I will attempt to build it.

Yes, you should learn how to build a kernel and a patched module. There are a few good ways. I'll give some brief instructions later.

> Also, the following is from a post at:
>
> https://forums.opensuse.org/showthread.php/494706-openSUSE-13-1-KDE-inconsistant-resume-from-Suspend-to-RAM?p=2661131#post2661131
>
> Quoting Romanator: "The most recent openSUSE kernel (3.11.10-21-desktop)
> Makefile for the r592.c from Maxim Levitsky is from 2010. His final patch
> wasn't submitted until Jan. 8, 2011. <snip> Ask the openSUSE kernel devs to
> look at and backport patch #5b945a6 from this link:
> https://gitorious.org/ricoh-kernel/ricoh-kernel.git ".
>
> So, it doesn't look like the OpenSUSE kernel has the most recent r592 driver...

You're testing 3.15 and 3.16, so the above statement doesn't fit at all.

> Also, there is a good bit of recent activity by the r592 developer, Maxim
> Levitsky, on this exact same bug at Red Hat's Bugzilla site here:
>
> https://bugzilla.redhat.com/show_bug.cgi?id=1119361
>
> The bottom line is that someone needs to make sure that OpenSUSE is using the
> most recent version of r592.c.

No, r592 developer has to submit the fix to the upstream at first. This is the golden rule. In general, we take *only* the upstream fix (or the patch that is promised to upstream) to openSUSE kernels.

If there is a problem of upstreaming, put me in Cc in chain, so that I can assist for it.

(In reply to comment #5)
> (In reply to comment #3)
> > I am not a kernel developer and so I'm not sure how to build r592.c with the
> > patch, however, I would be happy to test it if somebody else would build it for
> > me. Alternatively, if its simple to do, then please provide some instructions
> > and I will attempt to build it.
>
> Yes, you should learn how to build a kernel and a patched module. There are a
> few good ways. I'll give some brief instructions later.

A quick way to rebuild a module is like below:

1. Install kernel-source and kernel-desktop-devel packages.

2. Copy the relevant driver code to the local directory. Suppose you'll work on a directory /somewhere/test to compile the module:
   % mkdir /somewhere/test
   % cp -a /usr/src/linux/drivers/memstick/host /somewhere/test

3. Patch the code. In this case, pass -p4 to strip the paths:
   % cd /somewhere/test
   % patch -p4 < /yetsomewhere/r592.patch

4. Build the module. This is the tricky part. Pass -C option to make.
   % make -C /usr/src/linux-obj/x86_64/desktop M=$(pwd) modules

5. If successful built, install it to the updates directory. Do this as root.
   % su
   ....
   # mkdir -p /lib/modules/$(uname -r)/updates
   # cp *.ko /lib/modules/$(uname -r)/updates
   # depmod -a

6. Confirm that the module will be loaded from the new path. The command below should give the path with "updates" path:
   % /usr/sbin/modinfo r592 | grep filename
   filename: /lib/modules/..../updates/r592.ko

7. Retest. If anything goes wrong, just remove the updated modules from /lib/modules/*/updates/* directory.

Since this rebuilds only a few modules, it won't take time at all, at most 5 minutes or so.

I have found a resolution to this problem as is described in the Red Hat bug report here:

https://bugzilla.redhat.com/show_bug.cgi?id=1119361

That is, set the following parameter in the kernel config file /boot/<kernel version>:

CONFIG_MMC_RICOH_MMC=n

On my recently upgraded OpenSUSE 13.2 machine, the kernel was 3.16.6-2-desktop so the file that I modified was /boot/config-3.16.6-2-desktop.

The log messages will then subside completely. Otherwise, if you have the ricoh r592 card reader then your logs will grow exponentially. For example, after I upgraded to OpenSUSE 13.2 two days ago, /var/log/journal had grown to over 5GB in less than 48 hours.

The problem is the default setting should be CONFIG_MMC_RICOH_MMC=n instead of CONFIG_MMC_RICOH_MMC=y. So, the kernel developers need to change this parameter for all OpenSUSE versions.

FYI,

Gordon

Thanks, that's a good information.

Though, CONFIG_MMC_RICOH_MMC was also y in the old working kernel, so disabling this is no real solution unless confirmed to *all* Ricoh MMC chips.

If the Kconfig matters, the bug must be in drivers/pci/quirks.c, and indeed there were a few changes regarding Ricoh MMC device there between 3.15 and 3.16 kernels.

Could you give hwinfo output of your machine? I particularly need the PCI IDs, but it's better to have all hwinfo in anyway.

Also, could you check whether the problem still exists with the recent kernels, 3.17.x and 3.18-rc? They are available in OBS Kernel:stable and Kernel:HEAD repos. We need to know this before reporting to the upstream.

I set CONFIG_MMC_RICOH_MMC=n since that was recommended by the maintainer of the device driver, Maxim Levitsky in the RedHat bug report that I previously referenced. Nevertheless, I apparently spoke to soon. Sorry! My PC was stable with minimal log entries for an hour or two last night. Then, today it started generating huge logs again even with CONFIG_MMC_RICOH_MMC=n. So, as a test, I blacklisted r592 in /etc/modprobe.d/50-blacklist.conf. Its been 5 hours since then without any excessive logging. Interestingly, the SD card reader works properly too even after I black listed r592. So, blacklisting r592 (with CONFIG_MMC_RICOH_MMC=n) has stopped the excessive logging and the SD card still works. I have attached the results of the lspci and hwinfo commands. As you can see, there are actually four RICOH devices listed. I hope that this helps.

Also, I am running nVidia proprietary drivers which I would have to recompile in order to try out the other more recent kernels so installing these kernels (and reverting back to stock) will be a bit more time consuming than otherwise. Nevertheless, if you still want me to test these newer kernels, I will do so within the next week or so.

Thanks very much for your assistance!

Gordon

Created attachment 614989
Results of hwinfo command

Created attachment 614990
Results of lspci command.

You may try a kernel package in OBS home:tiwai:bnc892249 repo. This should be compatible with openSUSE 13.2 (so Nvidia kmp should work as is) and yet includes a possible fix patch.

The massive logging started up again after about 7 hours.... Ugh...

Thanks for your repo for me to try! Its installed:

gordon@rhino:~> uname -a
Linux rhino 3.16.7-1.g632515b-desktop #1 SMP PREEMPT Tue Nov 25 07:11:35 UTC 2014 (632515b) x86_64 x86_64 x86_64 GNU/Linux

Lets see how it goes for a day or so.

Thanks again for your efforts!

Gordon

Created attachment 615124
12 second shapshot of the kernel log output.

Well, your kernel-desktop version 3.16.7-1.g632515b-desktop did not help. Like before, after installing your new kernel, everything was fine through a few hours or operation and 3 to 4 suspends/resumes. Then, following the most recent resume from suspend, the massive logging started back up again. I have attached a 12 second snippet of the log output that I hope helps you figure this out.

To review what is happening, everything is fine for a few hours of operation. Then the kernel logger goes crazy with huge massive logging. I believe that the massive logging has always begun following a resume from suspend, however, I cannot say that with 100% certainty. Then, following a reboot, everything is fine again for a little while.

Please review the attached log and reply with your advice. This is an unmanageable situation. If it cannot be fixed soon then I need to revert back to an earlier kernel version and, if necessary, an earlier OS version such as OpenSUSE 13.1.

As another test, I am going to blacklist r852 since it has been showing up in these logs too.

Thanks again for your help.

Gordon

OK, then maybe it isn't a regression that was introduced in 3.16 but did exist in the former versions, too.

Just to confirm: does the card reader work even without r592 module at all? I saw you blacklisted, but it isn't loaded at all when using the card reader?

I have recently run kernels 3.11, 3.15, 3.16. The problem did not exist with kernel 3.11 and I first saw issues in kernels 3.15 and 3.16. I did not test kernels 3.12, 3.13 or 3.14. So the problem started between kernel 3.12 and 3.15.

Yes, the card reader works without the r592 module. I have now blacklisted both r592 and r852 and there are no mention of either in the kernel logs at startup or when I plug the card in. Also, the hwinfo command indicates that both modules are not active even when the card is inserted during which I am able to browse the card.

I am adding another hwinfo output file with r592 and r852 blacklisted. This file was generated with the SD card inserted and working. The hwinfo output says that both R592 and r852 are not active. However, there are two other Ricoh devices:

Device 32: PCI 301.0: 0c00 FireWire (IEEE 1394) (OHCI)
Model: Model: "Ricoh R5C832 IEEE 1394 Controller"
Driver: "firewire_ohci"

Device 33: PCI 301.1: 0805 SD Host controller
Model: "Ricoh R5C822 SD/SDIO/MMC/MS/MSPro Host Adapter"
Driver: "sdhci-pci"

So, should I also blacklist both firewire_ohci and sdhci-pci?

Thanks,

Gordon

PS: As an FYI, I am now running OpenSUSE 13.2. Previous to three days ago, I was runing OpenSUSE 13.1. I don't know if it matters but I thought that I should mention this.

Created attachment 615145
Results of hwinfo command with both r592 and r852 blacklisted and the SD card inserted.

Ah, I have looked somehow at the wrong places.

Yes, you can keep using the SD-card, etc, without r592 and r852 modules. r592 module is only for the legacy memory stick device, and r852 is for xD. Unless you need these rare media, you can safely blacklist them.

Did you have to blacklist both modules, not only one of them? I wonder now whether disabling DMA in r592 and r852 modules make things calm down. Put the following in /etc/modprobe.d/*.conf:

  options r592 enable_dma=0
  options r852 r852_enable_dma=0

Yes, yesterday, I blacklisted both the r592 and r852 modules and its now been almost 24 hours without encountering the excessive logging problem. I am going to watch and wait before I disable DMA for the two modules. I want to see if blacklisting both RICOH devices solves the problem by itself. However, if/when the excessive logging next occurs then I will immediately disable DMA to see if that helps.

Thanks again for your support. Let me know if you have any other recommendations. I will report back with my findings.

Gordon

Hi Takashi,

I believe that we have achieved success! Blacklisting both the r592 and r852 modules appears to have fixed the problem. I have now been running your 3.16.7-1.g632515b-desktop kernel for 3 days with these two modules blacklisted and I have not seen any unusual or excessive logging at all. With this configuration, everything seems to be back to normal. As an FYI, I have not disabled DMA for the r592 and r852 modules; only blacklisted them.

I noticed that you posted an updated kernel on November 27 which I did install. Did that update contain anything special or significant regarding this problem?

Also, do you recommend that I stay on your kernel/repo or should I revert back to the stock kernel at some point?

Please advise.

Thank you very much for your help and assistance.

Gordon

I hope this is fixed in later kernels, so we can close it now. If not, please reopen.