Bug 202511

Created attachment 281011 [details]
4.17.19 working amdgpu dmesg

For reference here is my dmesg from the 4.17.19 which will modprobe amdgpu.

Can you bisect?

Created attachment 281033 [details]
bisect log

Here is the bisect log as requested.

Looks like it was caused by a pci core change.  Adding Bjorn.

The bisect log in comment #3 shows 3a3869f1c443 ("Merge tag 'pci-v4.18-changes' of git://git.kernel.org/pub/scm/linux/kernel/git/helgaas/pci") as the first bad commit.  That's a large merge commit so I can't pick out anything useful.  The previous good commit was 3036bc45364f ("Merge tag 'media/v4.18-2' of git://git.kernel.org/pub/scm/linux/kernel/git/mchehab/linux-media").

I'm not a bisect expert, but there must be a way to bisect between those two commits to zero in on something specific.  Is this any help?

05:49:21 ~/linux (junk)$ git bisect start
05:49:47 ~/linux (junk|BISECTING)$ git bisect good 3036bc45364f98515a2c446d7fac2c34dcfbeff4
05:50:01 ~/linux (junk|BISECTING)$ git bisect bad 3a3869f1c443383ef8354ffa0e5fb8df65d8b549
Bisecting: 88 revisions left to test after this (roughly 6 steps)
[13fbadcd512c225c907d6e8147fb48a88114bf03] Merge branch 'pci/sparc'

Since nobody else seems to be running into this problem: Are you sure that you are correctly building and installing a complete kernel?

That looks like something special with your installation/setup.

It could be special. If so I'd love to know what it is that I'm doing wrong. So far all of the 4.17 kernels I've tried works and Windows works on the laptop. I'll see if I can get an Ubuntu LiveCD working.

Even if this is "special", e.g., some strange kconfig or build/install issue, this is a really painful issue to debug.  It would be tremendous if we could fail more gracefully, with some hint about what went wrong and how the user could fix it.  But it's hard to know how we could improve that until we understand what's going on here.

Yeah, I also would be really interested what the root cause is.

As far as I know we don't have any large per CPU data in amdgpu, so no idea how this can happen.

I'd love to get it settled too (for obvious reasons). I guess a good place to start is the bisect that Bjorn Helgaas requested?

Yes.  I don't have any better ideas.  I'm not sure why git bisect wasn't smart enough to narrow it down further by itself.  Sorry, I know bisecting is painful.

Rather, I appreciate the help.

I'll start bisecting after work and post a reply as soon as I have the result.

Created attachment 281107 [details]
bisect log 2

I'm not sure if this is helpful. Basically all of the builds that I did in the bisect I marked "good" because they worked.

Is there anything else I can try? Should I do the first bisect again?

Created attachment 281143 [details]
per-cpu alloc debug patch

I think bisecting again would be a poor use of your time unless somebody knows a smarter way to do it (I don't).

I suspect amdgpu might be an innocent bystander.  I don't have any good ideas, so here's a lame one:

  - Apply this patch.
  - Figure out how to turn on pr_debug (see include/linux/printk.h and compare with your config -- you might need to enable CONFIG_DYNAMIC_DEBUG and and then figure out what boot parameter enables the output).  This is to turn on the debug in module_load().  Actually, the simpler way is to change those pr_debug() calls to pr_info().
  - Collect the dmesg log (probably large).

Created attachment 281247 [details]
dmesg 4.18.0 with debugs

Did I do this correctly? I see a lot more call track information in this file.

Created attachment 281259 [details]
per-cpu alloc info (broken)

FWIW, I pulled out the per-cpu alloc info and what looks like the caller for each (attached).  The big chunks look like IOMMU and iptables stuff.

This is from the 4.18 kernel with the problem.  Maybe we'd learn something by collecting the same info from the working 4.17 kernel and comparing?

I wonder if there's some config difference that could be relevant?  Could you attach the .config files for 4.17 and 4.18?

Created attachment 281261 [details]
4.17.19 config

Absolutely. Let me post the two configs then.

Created attachment 281263 [details]
4.18 config

Would you like me to build the 4.17.19 kernel with the print options also?

Created attachment 281269 [details]
Acutal 4.17.19 config

This is the actual 4.17.19 that I used to make the 4.18 config. The other one I uploaded was not the correct one.

Thanks!  Unless somebody has a better idea, I would try building 4.17.19 with the print options.

Config differences that might conceivably be related:

--- config-4.17.txt     2019-02-21 16:03:59.976990680 -0600
+++ config-4.18 2019-02-21 16:03:40.404831576 -0600
+CONFIG_IPV6_SEG6_BPF=y
+CONFIG_NF_TPROXY_IPV4=y
+CONFIG_NF_TPROXY_IPV6=y

You could try turning these off in 4.18 to see if that makes a difference.

As far as the bisection goes, from the original bisect report, both of the commits that were merged were good.  i.e. 3a3869f1 merged two good commits:  3036bc45364f and 488ad6d3678b.  Only when the commits were combined was the system bad.

Given it looks like a failure to do a percpu alloc, that makes sense - both branches could have had some change that when combined exhausted a resource.

From the error messages, these are 'reserved' percpu allocs:

[    4.176816] percpu: allocation failed, size=8192 align=4096 atomic=0, alloc from reserved chunk failed

The reserved space is rather small.  From the early output, we can see it's only 8KB (the r8192):

[    0.000000] percpu: Embedded 54 pages/cpu @(____ptrval____) s181144 r8192 d31848 u262144

The alloc that failed was 8192, which is the entire reserved space, so my guess is that there was another alloc already, such that there wasn't enough for the 8192 alloc.

It seems a little odd that there isn't enough reserved percpu space - or rather that someone is grabbing more space than they should.  These reserved allocs are only made by modules, and then only by modules that use percpu data (if I'm reading kernel/module.c right).  The default amount of 8192 is PERCPU_MODULE_RESERVE, which hasn't changed in years.

I'd be curious who else is making reserved per_cpu allocations, regardless of failure.  In kernel/module.c L652, we only print on failure.  If you print regardless of failure, particularly the mod name, then we might know who the other one is.  Maybe there are a bunch of benign small allocs, or maybe there's another 8192 out there.

Regardless, I'd guess the main culprit is the amdkfd and drm modules, asking for 8192 out of a total 8192.  I built with your 4.18 config from the merge commit.  Both amdkfd and drm have percpu sections, e.g.:

$ objdump -h drivers/gpu/drm/amd/amdkfd/amdkfd.ko

.data..percpu 00002000  0000000000000000  0000000000000000  00022000  2**12

That matches the size (8192) and alignment (2^12) that we saw in the allocation message.

drm.ko has something similar for its section.

Looking at amdkfd.ko (objdump -D), it has:

Disassembly of section .data..percpu:
0000000000000000 <kfd_processes_srcu_srcu_data>:

and drm.ko has: 

Disassembly of section .data..percpu:
0000000000000000 <drm_unplug_srcu_srcu_data>:

That looks like these two:

drivers/gpu/drm/amd/amdkfd/kfd_process.c:DEFINE_SRCU(kfd_processes_srcu);
drivers/gpu/drm/drm_drv.c:DEFINE_STATIC_SRCU(drm_unplug_srcu);

Those SRCU macros expand to a DEFINE_PER_CPU(struct srcu_data), though the struct doesn't look huge.  Not sure why it blows up to 8192 for its percpu section.

The amdkfd one was added in 64d1c3a43a6f ("drm/amdkfd: Centralize IOMMUv2 code and make it conditional"), and the DRM one was added in bee330f3d672 ("drm: Use srcu to protect drm_device.unplugged").  Both are relatively recent.

It doesn't look like there are a lot of drivers that use SRCU with those macros, so maybe that's something drm and amdkfd shouldn't be doing?  Either that, or maybe there's something wrong that causes the SRCU percpu structure to get so large?

Also, it's not clear that if these are the culprits, then why would they be working before the bisection point.  If one of them succeeded, then the other should have failed (given they both try to alloc 8192 out of a total 8192 reservation).  So maybe I'm missing something.

(In reply to Bjorn Helgaas from comment #21)
> Thanks!  Unless somebody has a better idea, I would try building 4.17.19
> with the print options.
> 
> Config differences that might conceivably be related:
> 
> --- config-4.17.txt     2019-02-21 16:03:59.976990680 -0600
> +++ config-4.18 2019-02-21 16:03:40.404831576 -0600
> +CONFIG_IPV6_SEG6_BPF=y
> +CONFIG_NF_TPROXY_IPV4=y
> +CONFIG_NF_TPROXY_IPV6=y
> 
> You could try turning these off in 4.18 to see if that makes a difference.

It didn't end up doing anything. Would you like me to post my dmesg output or .config?

Created attachment 281345 [details]
Print module reserved percpu allocations

Hi Michael -

Can you apply this patch and report back the dmesg output?  Ideally, I'd like to see this for the commit that fails (3a3869f1) as well as its two parents (3036bc45364f and 488ad6d3678b).

If you're just trying to get a working system, then maybe build with CONFIG_DRM and CONFIG_DRM_AMDGPU stuff as 'Y' instead of as modules.

It might be that the right fix would be for the DRM and AMD code to not use static SRCU objects.

Created attachment 281359 [details]
fb: switching to amdgpudrmfb from EFI VGA freeze 4.19.23

Barret,

I will apply the patch and post the output for the commits as you asked.

I have tried a couple of times to compile AMDGPU and DRM into the kernel and it freezes after "fb: switching to amdgpudrmfb from EFI VGA" and doesn't give any errors for me to see. I've also attached the output from kernel 4.19.23.

When the amdgpu driver is built into the kernel, so must be all the microcode files under /lib/firmware/amdgpu/ that it needs with your GPU.

(In reply to Michel Dänzer from comment #26)
> When the amdgpu driver is built into the kernel, so must be all the
> microcode files under /lib/firmware/amdgpu/ that it needs with your GPU.

Thanks for that! I had to include the raven* firmware files. I had only included the vega* firmware files.

Comment on attachment 281269 [details]
Acutal 4.17.19 config

There is a workaround, resolving this bug (for me at least) - disabling CONFIG_X86_VSMP parameter.
Hint to this solution was here: https://bugzilla.kernel.org/show_bug.cgi?id=201339

Ah, nice find.  That other bug (201339) looks like the root cause of this one.

Can confirm, disabling CONFIG_X86_VSMP corrects the issue.