Skip to contentSkip to conversation

New: WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

Bug 201631 [email protected] 1 participant 77 messages Nov 8, 2018 – Feb 7, 2019 PowerPC

lore
Share & tools
lore
#0 lore raw

https://bugzilla.kernel.org/show_bug.cgi?id=201631

            Bug ID: 201631
           Summary: WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927
                    .ext4_set_page_dirty+0x70/0xb0
           Product: File System
           Version: 2.5
    Kernel Version: 4.20-rc1
          Hardware: PPC-64
                OS: Linux
              Tree: Mainline
            Status: NEW
          Severity: normal
          Priority: P1
         Component: ext4
          Assignee: [email protected]
          Reporter: [email protected]
        Regression: No

Created attachment 279373
--> https://bugzilla.kernel.org/attachment.cgi?id=279373&action=edit
kernel config

[ 3894.535640] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927
.ext4_set_page_dirty+0x70/0xb0
[ 3894.535794] Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4

dns_resolver nfs lockd grace sunrpc cfg80211 rfkill radeon evdev ghash_generic i2c_algo_bit gf128mul snd_hda_codec_hdmi ttm ecb drm_kms_helper snd_hda_intel snd_hda_codec cfbfillrect cfbimgblt mptsas syscopyarea sysimgblt xts snd_hwdep sysfillrect snd_hda_core scsi_transport_sas fb_sys_fops cfbcopyarea xhci_pci drm snd_pcm xhci_hcd mptscsih mptbase snd_timer ctr usbcore tg3 scsi_mod cbc at24 snd powernv_flash drm_panel_orientation_quirks backlight libphy usb_common mtd soundcore ibmpowernv vmx_crypto opal_prd hwmon crc32c_vpmsum lz4 lz4_compress lz4_decompress zram zsmalloc

[ 3894.535880] CPU: 11 PID: 29593 Comm: debugedit Not tainted 4.20.0-rc1 #1
[ 3894.535886] NIP:  c000000000401d40 LR: c000000000250440 CTR:
c000000000401cd0
[ 3894.535893] REGS: c0000003c6d9f560 TRAP: 0700   Not tainted  (4.20.0-rc1)
[ 3894.535898] MSR:  9000000000029032 <SF,HV,EE,ME,IR,DR,RI>  CR: 24082488 
XER: 20040000
[ 3894.535913] CFAR: c000000000401d14 IRQMASK: 0 
               GPR00: c000000000250440 c0000003c6d9f7e8 c0000000011d5d00
c00a00800786e640 
               GPR04: 00003fffb263e000 c0002001e1b99186 0000000000000001
0000000000000000 
               GPR08: 0000000000000000 0000000000000000 c00a0080095480c8
0000000000000000 
               GPR12: 0000000024082488 c0000003ffffb400 1000000000000000
c0000000011e3918 
               GPR16: 00003fffb263e000 e61fffffffffffff c0002001e1b99186
c0002003e3a30960 
               GPR20: 00003fffb263f000 c00a00800786e640 c00000035c777ab8
c0000003c7692850 
               GPR24: c0000003645aa1f0 fffffffffffffe7f c0000003c55b3c98
0000000000000000 
               GPR28: ffffffffffffffff 00003fffb2649000 0000000000000000
c00a00800786e640 
[ 3894.535957] NIP [c000000000401d40] .ext4_set_page_dirty+0x70/0xb0
[ 3894.535965] LR [c000000000250440] .set_page_dirty+0xa0/0x150
[ 3894.535970] Call Trace:
[ 3894.535976] [c0000003c6d9f7e8] [c000000000247908]
.__get_free_pages+0x18/0x70 (unreliable)
[ 3894.535984] [c0000003c6d9f858] [c000000000250440] .set_page_dirty+0xa0/0x150
[ 3894.535994] [c0000003c6d9f8d8] [c000000000298de0]
.unmap_page_range+0xbf0/0xe10
[ 3894.536001] [c0000003c6d9fa68] [c000000000299364] .unmap_vmas+0x84/0x130
[ 3894.536009] [c0000003c6d9fb08] [c0000000002a3d98] .unmap_region+0xe8/0x190
[ 3894.536016] [c0000003c6d9fc38] [c0000000002a6470] .__do_munmap+0x2f0/0x510
[ 3894.536024] [c0000003c6d9fcf8] [c0000000002a6710] .__vm_munmap+0x80/0x110
[ 3894.536031] [c0000003c6d9fdb8] [c0000000002a67d4] .__se_sys_munmap+0x14/0x30
[ 3894.536040] [c0000003c6d9fe28] [c00000000000b3a4] system_call+0x5c/0x70
[ 3894.536046] Instruction dump:
[ 3894.536053] 71290008 4182002c e9230000 71292000 41820030 4bf6e8fd 60000000
38210070 
[ 3894.536066] e8010010 7c0803a6 4e800020 60000000 <0fe00000> e9230000 71292000
4082ffd8 
[ 3894.536080] irq event stamp: 18532
[ 3894.536087] hardirqs last  enabled at (18531): [<c00000000024a120>]
.get_page_from_freelist+0x2b0/0x1940
[ 3894.536094] hardirqs last disabled at (18532): [<c000000000008f2c>]
program_check_common+0x14c/0x160
[ 3894.536103] softirqs last  enabled at (18306): [<c0000000009b2384>]
.__do_softirq+0x4b4/0x5e4
[ 3894.536111] softirqs last disabled at (18299): [<c0000000000b2128>]
.irq_exit+0xf8/0x1b0
[ 3894.536117] ---[ end trace ca79a42e82947be5 ]---
Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#2 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

Theodore Tso ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------
CC| |[email protected]

--- Comment #2 from Theodore Tso ([email protected]) --- Can you reproduce this?

And you may also want to send a report to [email protected], since although it was tripped in ext4_set_page_dirty, the WARN_ON check which is it doing are fundamentally page specific, so this may very well be an mm problem:

static int ext4_set_page_dirty(struct page *page)

{
        WARN_ON_ONCE(!PageLocked(page) && !PageDirty(page));
        WARN_ON_ONCE(!page_has_buffers(page));
        return __set_page_dirty_buffers(page);
}
Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#3 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #3 from [email protected] ---
(In reply to Theodore Tso from comment #2)

Quoted 1 line

Can you reproduce this?

I will continue to run 4.20-rc kernels and report back if this occurs again. It has not popped up on 4.19.x on my ppc machines so far.

Quoted 4 lines

And you may also want to send a report to [email protected], since although it was tripped in ext4_set_page_dirty, the WARN_ON check which is it doing are fundamentally page specific, so this may very well be an mm problem:
[...]

Done.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#4 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #4 from [email protected] --- Next occurrence on 4.20-rc4, during building clang:

[ 1211.616339] WARNING: CPU: 18 PID: 15049 at fs/ext4/inode.c:3927
.ext4_set_page_dirty+0x70/0xb0
[ 1211.616469] Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4

dns_resolver nfs lockd grace sunrpc cfg80211 rfkill evdev radeon ghash_generic gf128mul ecb snd_hda_codec_hdmi xts snd_hda_intel i2c_algo_bit ttm mptsas snd_hda_codec scsi_transport_sas drm_kms_helper xhci_pci mptscsih cbc mptbase snd_hwdep xhci_hcd snd_hda_core cfbfillrect cfbimgblt syscopyarea tg3 vmx_crypto powernv_flash sysimgblt scsi_mod snd_pcm sysfillrect mtd fb_sys_fops opal_prd cfbcopyarea ibmpowernv crc32c_vpmsum drm usbcore snd_timer at24 snd libphy drm_panel_orientation_quirks backlight usb_common soundcore hwmon nx_compress 842 842_decompress 842_compress lz4 lz4_compress lz4_decompress zram zsmalloc

[ 1211.616544] CPU: 18 PID: 15049 Comm: debugedit Not tainted 4.20.0-rc4 #1
[ 1211.616549] NIP:  c0000000004279a0 LR: c000000000275740 CTR:
c000000000427930
[ 1211.616554] REGS: c0002001b5e73550 TRAP: 0700   Not tainted  (4.20.0-rc4)
[ 1211.616557] MSR:  9000000000029032 <SF,HV,EE,ME,IR,DR,RI>  CR: 24082488 
XER: 20040000
[ 1211.616568] CFAR: c000000000427974 IRQMASK: 0 
               GPR00: c000000000275740 c0002001b5e737e0 c0000000011ee200
c00a00000bb46ac0 
               GPR04: 00003fffa52a0000 c0000002ed1ab186 0000000000000001
0000000000000000 
               GPR08: 0000000000000000 0000000000000000 c00a00000a60e948
0000000000000000 
               GPR12: 0000000024082482 c0002003ff7ff280 1000000000000000
c0000000011fd918 
               GPR16: 00003fffa52a0000 e61fffffffffffff c0000002ed1ab186
c0000001b3442d48 
               GPR20: 00003fffa52a1000 c00a00000bb46ac0 c0000003ee23c7a8
c0002003f061a850 
               GPR24: c0002001b53a9500 fffffffffffffe7f c0002000d3450948
0000000000000000 
               GPR28: ffffffffffffffff 00003fffa530f000 0000000000000000
c00a00000bb46ac0 
[ 1211.616602] NIP [c0000000004279a0] .ext4_set_page_dirty+0x70/0xb0
[ 1211.616607] LR [c000000000275740] .set_page_dirty+0xa0/0x150
[ 1211.616611] Call Trace:
[ 1211.616616] [c0002001b5e737e0] [c00000000027fa40] .activate_page+0xf0/0x160
(unreliable)
[ 1211.616622] [c0002001b5e73850] [c000000000275740] .set_page_dirty+0xa0/0x150
[ 1211.616629] [c0002001b5e738d0] [c0000000002be260]
.unmap_page_range+0xbf0/0xe10
[ 1211.616635] [c0002001b5e73a60] [c0000000002be7e4] .unmap_vmas+0x84/0x130
[ 1211.616640] [c0002001b5e73b00] [c0000000002c9218] .unmap_region+0xe8/0x190
[ 1211.616646] [c0002001b5e73c30] [c0000000002cb8f0] .__do_munmap+0x2f0/0x510
[ 1211.616651] [c0002001b5e73cf0] [c0000000002cbb90] .__vm_munmap+0x80/0x110
[ 1211.616656] [c0002001b5e73db0] [c0000000002cbc54] .__se_sys_munmap+0x14/0x30
[ 1211.616664] [c0002001b5e73e20] [c00000000000b3a4] system_call+0x5c/0x70
[ 1211.616668] Instruction dump:
[ 1211.616674] 71290008 4182002c e9230000 71292000 41820030 4bf6e5dd 60000000
38210070 
[ 1211.616684] e8010010 7c0803a6 4e800020 60000000 <0fe00000> e9230000 71292000
4082ffd8 
[ 1211.616694] irq event stamp: 22098
[ 1211.616699] hardirqs last  enabled at (22097): [<c00000000026ec5c>]
.free_unref_page_list+0x21c/0x3e0
[ 1211.616705] hardirqs last disabled at (22098): [<c000000000008f2c>]
program_check_common+0x14c/0x160
[ 1211.616712] softirqs last  enabled at (22008): [<c0000000009f9144>]
.__do_softirq+0x4b4/0x5e4
[ 1211.616718] softirqs last disabled at (22001): [<c0000000000d1c28>]
.irq_exit+0xf8/0x1b0
[ 1211.616722] ---[ end trace 97217f5745b818a0 ]---
Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#5 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

[email protected] changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #279375|0                           |1

is obsolete| |

--- Comment #5 from [email protected] ---
Created attachment 279691
--> https://bugzilla.kernel.org/attachment.cgi?id=279691&action=edit
dmesg

Some more lockupgs after re-trying:

[ 2088.802884] INFO: task watch:20375 blocked for more than 120 seconds.
[ 2088.803203]       Tainted: G        W         4.20.0-rc4 #1
[ 2088.803209] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
message.
[ 2088.803215] watch           D    0 20375    762 0x00000000
[ 2088.803224] Call Trace:
[ 2088.803232] [c00000033c50f210] [c00000033c50f2b0] 0xc00000033c50f2b0
(unreliable)
[ 2088.803244] [c00000033c50f3f0] [c0000000000217f0] .__switch_to+0x310/0x510
[ 2088.803256] [c00000033c50f4a0] [c0000000009f0000] .__schedule+0x320/0xcd0
[ 2088.803262] [c00000033c50f590] [c0000000009f09e0] .schedule+0x30/0xb0
[ 2088.803270] [c00000033c50f600] [c000000000365090]
.d_alloc_parallel+0x5d0/0xb00
[ 2088.803277] [c00000033c50f750] [c00000000034bdc8] .__lookup_slow+0xc8/0x250
[ 2088.803284] [c00000033c50f890] [c00000000034bf94] .lookup_slow+0x44/0x70
[ 2088.803291] [c00000033c50f920] [c000000000350928]
.walk_component+0x298/0x4d0
[ 2088.803297] [c00000033c50fa00] [c0000000003516f0] .path_lookupat+0xa0/0x280
[ 2088.803307] [c00000033c50fac0] [c000000000353744]
.filename_lookup+0xb4/0x190
[ 2088.803313] [c00000033c50fc40] [c000000000342df8] .vfs_statx+0xa8/0x190
[ 2088.803320] [c00000033c50fd10] [c0000000003437b4]
.__se_sys_newstat+0x54/0xa0
[ 2088.803332] [c00000033c50fe20] [c00000000000b3a4] system_call+0x5c/0x70

[...]

More info see full dmesg.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#6 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

[email protected] changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #279373|0                           |1

is obsolete| |

--- Comment #6 from [email protected] ---
Created attachment 279713
--> https://bugzilla.kernel.org/attachment.cgi?id=279713&action=edit
kernel .config (4.19.5)

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#7 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #7 from [email protected] ---
Created attachment 279715
--> https://bugzilla.kernel.org/attachment.cgi?id=279715&action=edit
kernel config (4.20-rc4)

The 2nd lockup from this bug seems reproducible. Happens every time at a certain stage when I try to build clang-7.0.1-rc2 when running the Talos II on kernel 4.20-rc4. I need to sigkill the build process or it stalls forever. When I run the machine on kernel 4.19.5 the build runs flawlessly, no lockups.

Building takes place on a zram-partition (842 compressed, ext4), root filesystem is btrfs (zstd compressed).

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#8 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

Jan Kara ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------

                 CC|                            |[email protected],
                   |                            |[email protected],
                   |                            |[email protected]

--- Comment #8 from Jan Kara ([email protected]) ---
The lockups and ext4 warnings are likely a different thing. So please report the lockup to [email protected] and also CC Al Viro <[email protected]> on it.

The WARN_ON we hit in ext4 is likely:

WARN_ON_ONCE(!PageLocked(page) && !PageDirty(page));

because we don't expect page cache page to be marked dirty when unmapping it from page tables. It could be a powerpc specific race in handling of page table entry (PTE) flags as I don't see how PTE could be marked dirty without a page being already dirty.

Seeing you hit this already twice on 4.20-rc's and never on 4.19.x, it could be some recent powerpc change that is triggering this. I've skimmed through powerpc changelogs and didn't find anything obviously matching but there were quite some mm changes pulled in this merge window. Powerpc guys, any idea how could _PAGE_DIRTY PTE bit get spuriously set? Normally, we should clear the _PAGE_DIRTY bit in page_mkclean() together with write-protecting the PTE and we are marking the page dirty whenever writeable PTE is created... So clean pagecache page with _PAGE_DIRTY in PTE is an invalid combination.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#9 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #9 from [email protected] ---
Created attachment 280031
--> https://bugzilla.kernel.org/attachment.cgi?id=280031&action=edit
dmesg (4.20-rc6 on a PowerMac G5 7,3)

Also seeing this on my G5 with kernel 4.20-rc6.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#10 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #10 from [email protected] ---
Created attachment 280033
--> https://bugzilla.kernel.org/attachment.cgi?id=280033&action=edit
kernel .config (4.20-rc6, PowerMac G5 7,3)

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#11 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #11 from Benjamin Herrenschmidt ([email protected]) --- Jan, I don't know for sure what problems triggers it here, but there definitely is a HW bug on POWER9 with the "NestMMU" (the MMU that services coprocessors and the nvlink), which can cause a dirty bit to be set on a read-only PTE if it races with the PTE update & invalidation.

It was "assumed" this was ok. If not I don't know how to work around it.

However, at least in the above cases, I don't see how we would be setting dirty if we don't have RW access permission. A PowerMac G5 uses the hash MMU, we set dirty atomically with checking the PTE permission when hashing a PTE in.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#12 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #12 from Jan Kara ([email protected]) ---
Thanks for info Ben! First one slightly off-topic comment: Spuriously setting dirty bits in page tables is certainly not OK for file systems. This results in set_page_dirty() being called for a page when it gets unmapped and that means that file system is told there's new data in the page. But the file system is not prepared for that - it needs to prepare its structures for data modification (usually happens in ->page_mkwrite callback during page fault) like making sure there's enough free space, do COW on the page in case it was reflinked etc. As you say, this is likely not a problem of this particular reporter but I wanted to make sure the message gets across :).

Now to this report: It's good to know that setting of PTE dirty bit should be atomic at least on G5 wrt concurrent invalidation and page write protection. But something seems to have happened with 4.20-rcs that dirty bits do get set as Erhard started to see these warnings. I haven't heard any report of this from x86, this seems to be ppc specific. Since it happens once in couple of weeks, bisection is not really an option. I guess, I'll write a debug patch to dump PTE and page state when such problematic situation occurs and maybe that'll tell us something more to debug this.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#13 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #13 from Jan Kara ([email protected]) ---
Created attachment 280051
--> https://bugzilla.kernel.org/attachment.cgi?id=280051&action=edit
mm: Dump page and PTE state

Erhard, could you please run your machines with this patch applied and report what gets recorded when the warning hits again? Thanks!

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#14 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #14 from [email protected] ---
(In reply to Jan Kara from comment #13)

Quoted 2 lines

Erhard, could you please run your machines with this patch applied and report what gets recorded when the warning hits again? Thanks!

Sure! How do I apply the patch? Should I stay at rc6 or use the new rc7?

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#15 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #15 from Jan Kara ([email protected]) ---
rc6 or rc7 doesn't really matter. You can apply the patch as any other kernel patch:

cd "kernel-source-directory"
patch -p1 <"downloaded-patch"

now compile & install the kernel - I'm assuming that since you test rcs, you know how to do that. If not, I can dig out some instructions for that.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#16 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #16 from [email protected] ---
Created attachment 280053
--> https://bugzilla.kernel.org/attachment.cgi?id=280053&action=edit
dmesg (4.20-rc7 on a PowerMac G5 7,3)

Interesting! Both machines did not trigger the bug yet, but your patch reports "Clean page (index 0, ino 4223082, flags 3ff00000002014) with dirty PTE (pte_val c82000025beab386) on unmap!"-like messages during boot. 2 times on the G5, one time on the Talos II.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#17 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #17 from [email protected] ---
Created attachment 280055
--> https://bugzilla.kernel.org/attachment.cgi?id=280055&action=edit
dmesg (4.20-rc7 on a Talos II)

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#18 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #18 from [email protected] ---
Created attachment 280057
--> https://bugzilla.kernel.org/attachment.cgi?id=280057&action=edit
journalctl -k (4.20-rc7 on a Talos II)

Ok, here we go now. The bug has been triggered again by building a large project (llvm), seemingly during the install phase. Building takes place on a zram-partition (lz4 compressed, ext4), root filesystem is btrfs (zstd compressed).

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#19 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #19 from Jan Kara ([email protected]) ---
Hum, interesting. The page we barfed on is:

Clean page (index 92, ino 1163533, flags 3ffe0000002016) with dirty PTE (pte_val c0000001ef7b3186) on unmap!

Page flags thus decode to: PG_referenced | PG_uptodate | PG_lru | PG_private PTE bits decode to: _PAGE_WRITE | _PAGE_READ | _PAGE_DIRTY | _PAGE_ACCESSED | _PAGE_PTE | _PAGE_PRESENT

So indeed the page was writeably mapped. The question now is, how the page could have been writeably mapped without getting marked dirty or how could the dirty bit get cleared while the page stayed writeably mapped.

I'll poke more into the code and probably come up with further debugging patch.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#20 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #20 from Benjamin Herrenschmidt ([email protected]) --- Pardon my ignorance here, but I was under the impression that this was normal :) The whole point being that the PTE dirty bit gets set when accesses happen, and latter on gets harvested into the struct page dirty bit.

Otherwise, what would be the point of having a PTE dirty bit in the PTE at all or transferring a dirty bit from PTE to struct page in try_to_unmap_one() (for example) if a writable page is always mapped dirty ?

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#21 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #21 from Jan Kara ([email protected]) --- (In reply to Benjamin Herrenschmidt from comment #20)

Quoted 7 lines

Pardon my ignorance here, but I was under the impression that this was normal :) The whole point being that the PTE dirty bit gets set when accesses happen, and latter on gets harvested into the struct page dirty bit.

Otherwise, what would be the point of having a PTE dirty bit in the PTE at all or transferring a dirty bit from PTE to struct page in try_to_unmap_one() (for example) if a writable page is always mapped dirty ?

The PTE dirty bit is used for anonymous pages as you describe. File pages are marked dirty immediately during page fault (look for example at mm/memory.c:wp_page_shared() and its call to fault_dirty_shared_page()). When page gets written back, clear_page_dirty_for_io() is used which writeprotects all PTEs, clears PTE dirty bits, and then page dirty bit is cleared as well. So for shared file mappings PTE dirty bits could be ignored.

The reason why PTE dirty bits are not ignored are partly heritage from before 2006 when this mechanism was introduced and party because people do it "just to be sure"...

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#22 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

Jan Kara ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #280051|0                           |1

is obsolete| |

--- Comment #22 from Jan Kara ([email protected]) ---
Created attachment 280097
--> https://bugzilla.kernel.org/attachment.cgi?id=280097&action=edit
mm: Dump page and PTE state and some history

New debug patch to try which will also dump more about what was happening with the page. Can you please try running with this patch and report when the warning hits? Thanks!

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#23 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

[email protected] changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #280057|0                           |1

is obsolete| |

--- Comment #23 from [email protected] ---
Created attachment 280101
--> https://bugzilla.kernel.org/attachment.cgi?id=280101&action=edit
journalctl -k (4.20-rc7 on a Talos II)

Results with newest patch.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#24 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #24 from Benjamin Herrenschmidt ([email protected]) --- Out of curiosity, how does this work in the context of pages that are GUPed either by a driver or by KVM when using file backed guest memory ?

GUP will not "see" the mkclean or attempt at making read only...

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#25 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

[email protected] changed:

What |Removed |Added
----------------------------------------------------------------------------
CC| |[email protected]

--- Comment #25 from [email protected] --- (In reply to Benjamin Herrenschmidt from comment #24)

Quoted 4 lines

Out of curiosity, how does this work in the context of pages that are GUPed either by a driver or by KVM when using file backed guest memory ?

GUP will not "see" the mkclean or attempt at making read only...

page_mkclean_one do call

        mmu_notifier_invalidate_range_start(vma->vm_mm, start, end);
Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#26 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #26 from [email protected] ---
Dez 19 23:53:09 T1000 kernel: BUG: Bad rss-counter state mm:0000000065804292 idx:1 val:2
Dez 19 23:53:09 T1000 kernel: BUG: non-zero pgtables_bytes on freeing mm: 16384

I am wondering whether we have a wrong usage of a page here? One of the feature we enabled in the the recent kernel is THP migration (a0820ff33451aa1a12ec66812e229ac58beb3f24) . But I guess we are not using that feature. Maybe to isolate this further, can we disable transparent huge page for all the tests?

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#27 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

Jan Kara ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #280097|0                           |1

is obsolete| |

--- Comment #27 from Jan Kara ([email protected]) ---
Created attachment 280103
--> https://bugzilla.kernel.org/attachment.cgi?id=280103&action=edit
mm: Dump page and PTE state and some history (v2)

I'm sorry but the patch had a bug and didn't set time when page_mkwrite() has been called for the most common ext4 path which is taken on your machine. Here is a fixed up patch. Can you please test again!

Also it seems you are now able to trigger the warning in under an hour? In that case it would be plausible to bisect the kernel if the directed debugging fails. We'll see...

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#28 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #28 from Jan Kara ([email protected]) --- (In reply to Benjamin Herrenschmidt from comment #24)

Quoted 4 lines

Out of curiosity, how does this work in the context of pages that are GUPed either by a driver or by KVM when using file backed guest memory ?

GUP will not "see" the mkclean or attempt at making read only...

That's a good question :) Well behaved GUP users use mmu notifiers as Aneesh wrote to "see" mkclean. Badly behaved GUP users (and there's quite a few of them) don't and that can result in kernel crashes, data loss, or checksum failures in storage stack. The latest discussion on this topic is here if you're interested: https://lwn.net/Articles/774411/

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#29 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #29 from Benjamin Herrenschmidt ([email protected]) --- The problem is of course that not everybody *can* use the MMU notifiers.

Say I am KVM on POWER9, with the currently work-in-progress feature (unmerged patches) of exploiting the new HW support for interrupt virtualization.

In that context, the guest allocates a page for receiving interrupt events (it's a ring buffer) and "registers" it with the hypervisor (a hypercall). The HV gups it and passes the physical address to the HW, which will write to it from then on.

There's *nothing* KVM can do when getting the MMU notifier. The MM simply MUST NOT try to get rid of that page, it's going to be actively under HW use until the VM terminates.

How do we do that safely ?

There is a very similar problem when doing PCI pass-through. The guest pages are GUP'ed and put into the IOMMU so the devices can DMA to them. Here too, there's nothing useful KVM can do on an MMU notifier, those pages must remain pinned until either the guest is terminated or the IOMMU mapping is removed (in the case where it's done via hypercalls).

So how do we do that in such a way that doesn't involve all the crashes, data loss etc... that you mention ?

Talking of which, I noticed the AMD GPU driver in the call traces above, could it be a similar case of fun with GUP ?

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#30 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #30 from Aneesh Kumar KV ([email protected]) --- Dez 19 23:53:25 T1000 kernel: Clean page (index 72, ino 681324, i_size 715000, flags 3ffe0000002016) with dirty PTE (pte_val c0000006d3ea9186) on unmap!

Those pte bits value doesn't look correct. We expect the pfn value to be 64k aligned. ie, I should have found the last 4 values to be 0186. What is the page size configured? is that 64K?

-aneesh

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#31 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #31 from Jan Kara ([email protected]) ---
(In reply to Aneesh Kumar KV from comment #30)

Quoted 7 lines

Dez 19 23:53:25 T1000 kernel: Clean page (index 72, ino 681324, i_size 715000, flags 3ffe0000002016) with dirty PTE (pte_val c0000006d3ea9186) on unmap!

Those pte bits value doesn't look correct. We expect the pfn value to be 64k aligned. ie, I should have found the last 4 values to be 0186. What is the page size configured? is that 64K?

There's .config attached to this bugzilla. It has:

CONFIG_PPC_4K_PAGES=y
# CONFIG_PPC_64K_PAGES is not set

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#32 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #32 from Jan Kara ([email protected]) --- (In reply to Benjamin Herrenschmidt from comment #29)

Quoted 1 line

The problem is of course that not everybody *can* use the MMU notifiers.

Yes, I'm aware of that. So my comment about "well-behaved users" was probably a bit overstated ;)

Quoted 9 lines

Say I am KVM on POWER9, with the currently work-in-progress feature (unmerged patches) of exploiting the new HW support for interrupt virtualization.

In that context, the guest allocates a page for receiving interrupt events (it's a ring buffer) and "registers" it with the hypervisor (a hypercall). The HV gups it and passes the physical address to the HW, which will write to it from then on.

Quoted 5 lines

There's *nothing* KVM can do when getting the MMU notifier. The MM simply MUST NOT try to get rid of that page, it's going to be actively under HW use until the VM terminates.

How do we do that safely ?

Well, unless that page allocated by KVM comes from shared file mapping (and from what you write there's no reason for it to be from such mapping), there's nothing to worry about. GUP will get you page reference so that stops page reclaim from reclaiming the page and for anonymous pages, there's no filesystem trying to do anything clever about the page (like writing it back to disk).

Quoted 8 lines

There is a very similar problem when doing PCI pass-through. The guest pages are GUP'ed and put into the IOMMU so the devices can DMA to them. Here too, there's nothing useful KVM can do on an MMU notifier, those pages must remain pinned until either the guest is terminated or the IOMMU mapping is removed (in the case where it's done via hypercalls).

So how do we do that in such a way that doesn't involve all the crashes, data loss etc... that you mention ?

This case is more difficult as often the pages you want to DMA into can eventually come from userspace and thus can be from a shared file mapping (if not, then again there's no problem). Essentially what you describe seems to be a similar problem like RDMA (Infiniband and similar drivers) currently has. And currently there's no good solution for that. We're trying to figure out how to fix this but it's difficult - tons of GUP users, tons of filesystems, some GUP users are very performance sensitive, and it's not like you have much space in struct page for any tracking...

Quoted 2 lines

Talking of which, I noticed the AMD GPU driver in the call traces above, could it be a similar case of fun with GUP ?

Where did you see AMD GPU? I didn't find it in the last dmesg and .config doesn't seem to have anything GPU-related enabled. Also this particular problem seems to be triggered by heavy compilation so it seems to be something else than these GUP issues.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#33 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #33 from Benjamin Herrenschmidt ([email protected]) --- Jan,

For KVM, it can... you can back the guest using a file, and there's some interest in doing just that to back guests using large "new memory" pmem stuff for example.

This actually leads to more generic variant of that issue which is the need to be able to provide proper "pinned" memory for some adapters in guest even if they use ATSD, as not all adapters can deal with faults on everything (for example they might be able to deal with fault on user buffers but not the descriptor ring).

A discussion for another day I suppose..

As for AMD, I was looking at attachment
https://bugzilla.kernel.org/attachment.cgi?id=280057 posted in comment 18

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#34 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #34 from [email protected] ---
(In reply to Jan Kara from comment #27)

Quoted 4 lines

[...]
Also it seems you are now able to trigger the warning in under an hour? In that case it would be plausible to bisect the kernel if the directed debugging fails. We'll see...

For now building llvm-7.0.1-rc2 with tests in my ext4 zram disk (lz4 compressed) triggers the bug reliably. I could try to bisect, but not the next few days or so. ;)

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#35 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

[email protected] changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #280101|0                           |1

is obsolete| |

--- Comment #35 from [email protected] ---
Created attachment 280117
--> https://bugzilla.kernel.org/attachment.cgi?id=280117&action=edit
journalctl -k (4.20-rc7 on a Talos II)

Results with latest patch.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#36 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #36 from [email protected] --- (In reply to Benjamin Herrenschmidt from comment #29)

Quoted 3 lines

[...]
Talking of which, I noticed the AMD GPU driver in the call traces above, could it be a similar case of fun with GUP ?

If you are talking about the "[ 4.883250] radeon: No suitable DMA available"
message, this has also been the case before kernel 4.20-rc*. There also have been some DMA-related patches from
https://git.raptorengineering.com/git/op-kernel-dev/log/?h=raptor-dma-dev-4.18-pre.
Don't know if they reslove this error message of if they have been taken upstream already.

The card is BTW a Radeon HD 6450, which is running fine on the Talos II.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#37 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #37 from Benjamin Herrenschmidt ([email protected]) --- I would advise against those DMA patches. If the GPU tries to map an sglist entry that crosses a 1G boundary, bad things will happen.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#38 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #38 from [email protected] --- (In reply to Benjamin Herrenschmidt from comment #37)

Quoted 2 lines

I would advise against those DMA patches. If the GPU tries to map an sglist entry that crosses a 1G boundary, bad things will happen.

Did not install them, I am running a vanilla kernel. So if they have not been upstreamed they are not in my kernel. ;)

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#39 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #39 from Jan Kara ([email protected]) ---
(In reply to erhard_f from comment #35)

Quoted 4 lines

Created attachment 280117 [details]
journalctl -k (4.20-rc7 on a Talos II)

Results with latest patch.

Thanks for the results! Erhard, are you sure this kernel was with the latest version of the patch? Because the line:

page 137: b_state 21, b_blocknr 2726281, b_mapped 0, b_cleaned 1498120697108, now 1498125595648

shows that b_mapped is zero effectively meaning that ext4_block_mkwrite() was never called for the page. Which would be very strange for a page that has writeable PTE.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#40 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #40 from [email protected] ---
(In reply to Jan Kara from comment #39)

Quoted 2 lines

Thanks for the results! Erhard, are you sure this kernel was with the latest version of the patch?

I am pretty sure it was the latest patch at that time. But I can re-test with 4.20 or 4.21-rc1 when it's out.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#41 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

[email protected] changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #280117|0                           |1

is obsolete| |

--- Comment #41 from [email protected] ---
Created attachment 280345
--> https://bugzilla.kernel.org/attachment.cgi?id=280345&action=edit
journalctl -k (5.0-rc1 on a Talos II)

Results with latest patch (20.12.2018).

So far building llvm-7 + tests in my ext4-zramdisk reliably triggers it.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#42 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

[email protected] changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #279715|0                           |1

is obsolete| |

--- Comment #42 from [email protected] ---
Created attachment 280347
--> https://bugzilla.kernel.org/attachment.cgi?id=280347&action=edit
kernel .config (5.0-rc1, Talos II)

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#43 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #43 from Jan Kara ([email protected]) ---
Thanks for gathering the results and sorry for not replying earlier. I've been busy with other work... So again I can see in the logs:

Clean page (index 137, ino 1820427, i_size 1144448, flags 3ffe0000002016) with dirty PTE (pte_val c0000005f899f186) on unmap!

WARNING: CPU: 3 PID: 1532 at fs/ext4/inode.c:3935
.ext4_set_page_dirty+0x80/0x170

...
page 137: b_state 21, b_blocknr 2726281, b_mapped 0, b_cleaned 1498120697108, now 1498125595648

So the page has been submitted for writeout some 5 ms ago but still we didn't get b_mapped set at all which would mean that ext4_page_mkwrite() got never called for the page - which is very weird. I'll ponder more about it possibly come up with more debugging.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#44 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

Jan Kara ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #280103|0                           |1

is obsolete| |

--- Comment #44 from Jan Kara ([email protected]) ---
Created attachment 280551
--> https://bugzilla.kernel.org/attachment.cgi?id=280551&action=edit
mm: Dump page and PTE state and some history (v3)

OK, new version of the debug patch that also tracks when last PTE for a page got set and dumps some more information about VMA and the page. Please report what the kernel prints now. Thanks a lot!

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#45 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #45 from [email protected] ---
(In reply to Jan Kara from comment #44)

Quoted 3 lines

OK, new version of the debug patch that also tracks when last PTE for a page got set and dumps some more information about VMA and the page. Please report what the kernel prints now. Thanks a lot!

Thanks for being persistent though this bug does not seem to affect many people!

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#46 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

[email protected] changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #280345|0                           |1

is obsolete| |

--- Comment #46 from [email protected] ---
Created attachment 280679
--> https://bugzilla.kernel.org/attachment.cgi?id=280679&action=edit
journalctl -k (5.0-rc3 on a Talos II)

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#47 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #47 from Jan Kara ([email protected]) ---
OK, so it seems to be more and more clear that PPC indeed has some race in page table updates. What I can see in the latest report is:

Clean page (index 92, ino 681741, i_size 828368, flags 7fff0000002016, mapcount
1) with dirty PTE (pte_val c0000005f7fae186) on unmap! Vma flags fb, pgoff 0, file ino 681741
...
page 92: b_state 21, b_blocknr 2801084, b_mapped 1452389112002, b_mapped2 0, b_cleaned 1452396217779, now 1452400395514

So "Vma flags fb" shows its a normal shared, writeable file mapping. Page is somewhere in the middle of the file (file size is 828368, page is at offset 376832). The page has been writeably mapped 11ms ago (you are using ext2 filesystem which was confusing my previous debug attempts so only this one has shown proper times) and written back 4ms ago (which should have writeprotected the pte) but we still have writeable pte now on which the assertion hits. So either page_mkclean() failed to clear the PTE or someone created new writeable PTE without telling ext4.

I'll attach a new version of debug patch to distinguish these two cases.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#48 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #48 from Jan Kara ([email protected]) ---
Created attachment 280697
--> https://bugzilla.kernel.org/attachment.cgi?id=280697&action=edit
mm: Dump page and PTE state and some history (v4)

Please run with this new version of the debug patch and report results. Thanks!

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#49 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

Jan Kara ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #280551|0                           |1

is obsolete| |

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#50 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #49 from Aneesh Kumar KV ([email protected]) --- Can you try this change?

arch/powerpc/mm/tlb-radix.c +0 -0
index 6a23b9ebd2a1..c42f91ba7067 100644
@@ -644,10 +644,12 @@ void radix__flush_tlb_page_psize(struct mm_struct *mm,

unsigned long vmaddr,

        preempt_disable();
        smp_mb(); /* see radix__flush_tlb_mm */
        if (!mm_is_thread_local(mm)) {
+/*
                if (unlikely(mm_is_singlethreaded(mm))) {
                        exit_flush_lazy_tlbs(mm);
                        goto local;
                }
+*/
                _tlbie_va(vmaddr, pid, psize, RIC_FLUSH_TLB);
        } else {

local:

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#51 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #50 from Aneesh Kumar KV ([email protected]) --- (In reply to Jan Kara from comment #47)

Quoted 19 lines

OK, so it seems to be more and more clear that PPC indeed has some race in page table updates. What I can see in the latest report is:

Clean page (index 92, ino 681741, i_size 828368, flags 7fff0000002016, mapcount 1) with dirty PTE (pte_val c0000005f7fae186) on unmap! Vma flags fb, pgoff 0, file ino 681741
...
page 92: b_state 21, b_blocknr 2801084, b_mapped 1452389112002, b_mapped2 0, b_cleaned 1452396217779, now 1452400395514

So "Vma flags fb" shows its a normal shared, writeable file mapping. Page is somewhere in the middle of the file (file size is 828368, page is at offset 376832). The page has been writeably mapped 11ms ago (you are using ext2 filesystem which was confusing my previous debug attempts so only this one has shown proper times) and written back 4ms ago (which should have writeprotected the pte) but we still have writeable pte now on which the assertion hits. So either page_mkclean() failed to clear the PTE or someone created new writeable PTE without telling ext4.

Quoted 1 line

I'll attach a new version of debug patch to distinguish these two cases.

The fact that we did try to write out the page at (bh_cleaned 1452396217779)implies we should have cleared the _PAGE_WRITE bit right (clear_page_dirty_for_io())? So we should either find that bit cleared in pte (if we missed a related tlb flush and tlb still has that pte with _PAGE_WRITE) or we find that set. In this case, we find _PAGE_WRITE set in the pte during zap. Does that imply we did call finish_fault()? which should have ideally resulted in we calling page_mkwrite().

I am still not clear what could be a possible race that can result in this?

-aneesh

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#52 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #51 from Jan Kara ([email protected]) ---
(In reply to Aneesh Kumar KV from comment #50)

Quoted 22 lines

(In reply to Jan Kara from comment #47)

Quoted 8 lines

OK, so it seems to be more and more clear that PPC indeed has some race in page table updates. What I can see in the latest report is:

Clean page (index 92, ino 681741, i_size 828368, flags 7fff0000002016, mapcount 1) with dirty PTE (pte_val c0000005f7fae186) on unmap! Vma flags fb, pgoff 0, file ino 681741
...
page 92: b_state 21, b_blocknr 2801084, b_mapped 1452389112002, b_mapped2

0,

Quoted 3 lines

b_cleaned 1452396217779, now 1452400395514

So "Vma flags fb" shows its a normal shared, writeable file mapping. Page

is

Quoted 8 lines

somewhere in the middle of the file (file size is 828368, page is at offset 376832). The page has been writeably mapped 11ms ago (you are using ext2 filesystem which was confusing my previous debug attempts so only this one has shown proper times) and written back 4ms ago (which should have writeprotected the pte) but we still have writeable pte now on which the assertion hits. So either page_mkclean() failed to clear the PTE or someone created new writeable PTE without telling ext4.

Quoted 5 lines
Quoted 1 line

I'll attach a new version of debug patch to distinguish these two cases.

The fact that we did try to write out the page at (bh_cleaned 1452396217779)implies we should have cleared the _PAGE_WRITE bit right (clear_page_dirty_for_io())?

Yes, clear_page_dirty_for_io() calls page_mkclean() which clears _PAGE_WRITE bit. So at b_cleaned time there should be no writeable PTE.

Quoted 5 lines

So we should either find that bit cleared in
pte (if we missed a related tlb flush and tlb still has that pte with _PAGE_WRITE) or we find that set. In this case, we find _PAGE_WRITE set in the pte during zap. Does that imply we did call finish_fault()? which should have ideally resulted in we calling page_mkwrite().

The race is not clear to me either but the rule is that if you are creating writeable PTE for a page, you must call ->page_mkwrite(). And from the debug output page_mkclean() was called and no ->page_mkwrite() after that so there should be no writeable PTE. But somehow there is one as zapping reports so we need to find out who and when creates it without calling ->page_mkwrite(). New version of my debug patch should tell us a bit more.

Note that there are other places that play with PTEs other than fault - like page migration, mremap, mprotect, etc. All these seem to properly use PTE locks to serialize with page_mkclean() but well... reality is what it is and there must be bug somewhere :) After all there are close to 200 calls of set_pte_at() in the kernel...

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#53 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #52 from [email protected] ---
(In reply to Aneesh Kumar KV from comment #49)

Quoted 19 lines

Can you try this change?

arch/powerpc/mm/tlb-radix.c +2 -0
index 6a23b9ebd2a1..c42f91ba7067 100644
@@ -644,10 +644,12 @@ void radix__flush_tlb_page_psize(struct mm_struct *mm,
 unsigned long vmaddr,
        preempt_disable();
        smp_mb(); /* see radix__flush_tlb_mm */
        if (!mm_is_thread_local(mm)) {
+/*
                if (unlikely(mm_is_singlethreaded(mm))) {
                        exit_flush_lazy_tlbs(mm);
                        goto local;
                }
+*/
                _tlbie_va(vmaddr, pid, psize, RIC_FLUSH_TLB);
        } else {
Quoted 1 line

local:

Should I apply this in addition to Jan's patch or standalone?

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#54 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

[email protected] changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #280679|0                           |1

is obsolete| |

--- Comment #53 from [email protected] ---
Created attachment 280809
--> https://bugzilla.kernel.org/attachment.cgi?id=280809&action=edit
journalctl -k (5.0-rc3 on a Talos II)

Results with Jans v4 patch.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#55 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #54 from Jan Kara ([email protected]) ---
Thanks for the results Erhard. Finally something to go on in the debug results. The pages have been normally faulted in for writing and PTE got set at time 1036580120591 from wp_page_reuse(). But then, although we've called clear_page_dirty_for_io() which calls page_mkclean() (at time 1036587452118), we've never reached the debug point in page_mkclean_one() where PTE write bit gets cleared. So it looks that for some reason page_mkclean() doesn't do what it should on your machines.

I was considering a race with munmap() but page_mkclean() uses mapping->i_mmap tree to find the VMA and we remove vmas from that tree only after unmap_page_range() is complete so that does not look possible. Also it is very strange because this is common code for all architectures but you seem to be the only one hitting the problem so far.

Aneesh, any idea?

Anyway, I've added more debugging to page_mkclean() to see which paths it is taking and maybe that'll tell us something.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#56 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #55 from Jan Kara ([email protected]) ---
Created attachment 280841
--> https://bugzilla.kernel.org/attachment.cgi?id=280841&action=edit
mm: Dump page and PTE state and some history (v5)

Erhard, please test with this debug patch. Thanks!

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#57 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #56 from [email protected] --- (In reply to Jan Kara from comment #55)

Quoted 4 lines

Created attachment 280841 [details]
mm: Dump page and PTE state and some history (v5)

Erhard, please test with this debug patch. Thanks!

I would, but the patch does not apply against -rc4. ;)

/usr/src/linux-5.0-rc4 # patch -p1 < mm.patch patching file fs/ext4/file.c
patching file fs/ext4/inode.c
Hunk #3 succeeded at 3933 (offset 1 line).
Hunk #4 succeeded at 6327 (offset 26 lines).
patching file include/linux/buffer_head.h
patching file mm/memory.c
Hunk #2 succeeded at 1081 (offset -1 lines).
Hunk #6 succeeded at 3253 (offset 23 lines).
patching file mm/page_vma_mapped.c
patching file mm/rmap.c
Hunk #3 succeeded at 894 with fuzz 2.
Hunk #4 FAILED at 902.
Hunk #5 succeeded at 921 (offset 2 lines).
Hunk #6 succeeded at 979 (offset 2 lines).
1 out of 6 hunks FAILED -- saving rejects to file mm/rmap.c.rej

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#58 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #57 from Aneesh Kumar KV ([email protected]) --- Wondering whether that rmap_walk_file and copy_page_range running in parallel can result in something like that?

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#59 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

Jan Kara ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #280697|0                           |1
        is obsolete|                            |
 Attachment #280841|0                           |1
        is obsolete|                            |

--- Comment #58 from Jan Kara ([email protected]) ---
Created attachment 280871
--> https://bugzilla.kernel.org/attachment.cgi?id=280871&action=edit
mm: Dump page and PTE state and some history (v6)

Yeah, that was just a context difference. Rebased the patch on top of 5.0-rc4.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#60 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #59 from Jan Kara ([email protected]) ---
(In reply to Aneesh Kumar KV from comment #57)

Quoted 2 lines

Wondering whether that rmap_walk_file and copy_page_range running in parallel can result in something like that?

Well, but we have shared file VMA here so I believe copy_page_range() will just bail early and won't do anything?

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#61 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #60 from [email protected] ---
(In reply to Jan Kara from comment #54)

Quoted 2 lines

Also it is very strange because this is common code for all architectures but seem to be the only one hitting the problem so far.

Maybe there are not that may people running a debug kernel on ppc64, building loads of stuff on an ext2 (sorry for originally stating it as ext4, I just forgot to pay attention to this detail) zram disk. ;)

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#62 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

[email protected] changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #280809|0                           |1

is obsolete| |

--- Comment #61 from [email protected] ---
Created attachment 280881
--> https://bugzilla.kernel.org/attachment.cgi?id=280881&action=edit
journalctl -k (5.0-rc4 on a Talos II)

Results with Jans v6 patch.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#63 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #62 from Jan Kara ([email protected]) ---
Erhard, thanks for the results! They are very weird but pretty clear: cleaned state is 0x10 so page_vma_mapped_walk() called from page_mkclean() has bailed out somewhere between:

        if (bh)
                bh->b_cleaned_state |= 16;
restart:
        pgd = pgd_offset(mm, pvmw->address);
        if (!pgd_present(*pgd))
                return false;
        p4d = p4d_offset(pgd, pvmw->address);
        if (!p4d_present(*p4d))
                return false;
        pud = pud_offset(p4d, pvmw->address);
        if (!pud_present(*pud))
                return false;
        if (bh)
                bh->b_cleaned_state |= 32;

I really don't understand how any of these tests could fail when later unmap_page_range() has found the pte. But I somehow suspect commit da7ad366b497f5 "powerpc/mm/book3s: Update pmd_present to look at _PAGE_PRESENT bit" could be related since it was introduced in the window where the problems started happening and it touches relevant code.

Aneesh, what needs to be reverted so that we can test that this commit is indeed the problematic one? I suppose:

da7ad366b497 "powerpc/mm/book3s: Update pmd_present to look at _PAGE_PRESENT bit"
f1981b5b302f "powerpc/mm/hugetlb/book3s: add _PAGE_PRESENT to hugepd pointer." ae28f17b5eeb "powerpc/mm/book3s: Check for pmd_large instead of pmd_trans_huge" 75646c480fde "arch/powerpc/mm/hash: validate the pte entries before handling the hash fault"
8890e03380d3 "powerpc/mm/thp: update pmd_trans_huge to check for pmd_present" a0820ff33451 "powerpc/mm:book3s: Enable THP migration support"

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#64 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #63 from Aneesh Kumar KV ([email protected]) --- (In reply to Jan Kara from comment #62)

Quoted 28 lines

Erhard, thanks for the results! They are very weird but pretty clear:
cleaned state is 0x10 so page_vma_mapped_walk() called from page_mkclean() has bailed out somewhere between:

        if (bh)
                bh->b_cleaned_state |= 16;
restart:
        pgd = pgd_offset(mm, pvmw->address);
        if (!pgd_present(*pgd))
                return false;
        p4d = p4d_offset(pgd, pvmw->address);
        if (!p4d_present(*p4d))
                return false;
        pud = pud_offset(p4d, pvmw->address);
        if (!pud_present(*pud))
                return false;
        if (bh)
                bh->b_cleaned_state |= 32;

I really don't understand how any of these tests could fail when later unmap_page_range() has found the pte. But I somehow suspect commit da7ad366b497f5 "powerpc/mm/book3s: Update pmd_present to look at _PAGE_PRESENT bit" could be related since it was introduced in the window where the problems started happening and it touches relevant code.

Aneesh, what needs to be reverted so that we can test that this commit is indeed the problematic one? I suppose:

Quoted 10 lines

da7ad366b497 "powerpc/mm/book3s: Update pmd_present to look at _PAGE_PRESENT bit"
f1981b5b302f "powerpc/mm/hugetlb/book3s: add _PAGE_PRESENT to hugepd pointer."
ae28f17b5eeb "powerpc/mm/book3s: Check for pmd_large instead of pmd_trans_huge"
75646c480fde "arch/powerpc/mm/hash: validate the pte entries before handling the hash fault"
8890e03380d3 "powerpc/mm/thp: update pmd_trans_huge to check for pmd_present" a0820ff33451 "powerpc/mm:book3s: Enable THP migration support"

We can revert the first and the last patch. I am attaching the patches this got the revert failures fixed.

-aneesh

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#65 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #64 from Aneesh Kumar KV ([email protected]) --- Created attachment 280941
--> https://bugzilla.kernel.org/attachment.cgi?id=280941&action=edit
Revert-powerpc-mm-book3s-Update-pmd_present

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#66 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #65 from Aneesh Kumar KV ([email protected]) --- Created attachment 280943
--> https://bugzilla.kernel.org/attachment.cgi?id=280943&action=edit
Revert-powerpc-mm-book3s-Enable-THP-migration

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#67 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #66 from [email protected] ---
Currently I am testing this, the 2 patches from Aneesh applied and the one from Jan. So far I was not able to provoke the original bug. I faced however another one, don't know wether it's related:

[...]

Feb 04 23:11:43 T1000 kernel: BUG: Kernel NULL pointer dereference at
0x00000028
Feb 04 23:11:43 T1000 kernel: Faulting instruction address: 0xc0000000002a20ac
Feb 04 23:11:43 T1000 kernel: Oops: Kernel access of bad area, sig: 11 [#1]
Feb 04 23:11:43 T1000 kernel: BE SMP NR_CPUS=192 NUMA PowerNV
Feb 04 23:11:43 T1000 kernel: Modules linked in: rpcsec_gss_krb5 auth_rpcgss
nfsv4 dns_resolver nfs lockd grace sunrpc sr_mod cdrom cfg80211 rfkill evdev
radeon ghash_generic gf128mul ecb xts snd_hda_codec_hdmi>
Feb 04 23:11:43 T1000 kernel: CPU: 0 PID: 218 Comm: kswapd0 Not tainted
5.0.0-rc4 #2
Feb 04 23:11:43 T1000 kernel: NIP:  c0000000002a20ac LR: c0000000002a209c CTR:
c0000000002bd280
Feb 04 23:11:43 T1000 kernel: REGS: c0000007f8c76fa0 TRAP: 0300   Not tainted 
(5.0.0-rc4)
Feb 04 23:11:43 T1000 kernel: MSR:  900000000280b032
<SF,HV,VEC,VSX,EE,FP,ME,IR,DR,RI>  CR: 44222288  XER: 00000000
Feb 04 23:11:43 T1000 kernel: CFAR: c000000000281724 DAR: 0000000000000028
DSISR: 40000000 IRQMASK: 0 
                              GPR00: c0000000002a5a48 c0000007f8c77230
c0000000011e2a00 c0000007e2cb8000 
                              GPR04: c000000000bebb70 00003fff92170000
0000000000000040 c0000007f4f9e600 
                              GPR08: c0000000011f54d8 0000000000000000
0000000000000000 0000000000000000 
                              GPR12: 0000000024222282 c000000001e2b000
c0000007e2cb8000 0000000000000000 
                              GPR16: 0000000000000001 c00a00001ed74ac0
c0000007f8c77798 0000000000000000 
                              GPR20: c00a00001ed74ac8 5deadbeef0000100
0000000020000000 c0000007f4f9e718 
                              GPR24: c0000007f4f9ea40 7c00000000000000
7800000000000000 c0000007f4f9ea38 
                              GPR28: c0000007f4f9e600 c0000007d18cfa90
c00a00001ed74ac0 c00a00001ed74ac0 
Feb 04 23:11:43 T1000 kernel: NIP [c0000000002a20ac] .is_ext4_page+0x3c/0x4b0
Feb 04 23:11:43 T1000 kernel: LR [c0000000002a209c] .is_ext4_page+0x2c/0x4b0
Feb 04 23:11:43 T1000 kernel: Call Trace:
Feb 04 23:11:43 T1000 kernel: [c0000007f8c77230] [c0000007f9d0d880]
0xc0000007f9d0d880 (unreliable)
Feb 04 23:11:43 T1000 kernel: [c0000007f8c772b0] [c0000000002a5a48]
.get_ext4_bh_nowarn+0x18/0x80
Feb 04 23:11:43 T1000 kernel: [c0000007f8c77330] [c0000000002b963c]
.page_vma_mapped_walk+0x3c/0x9d0
Feb 04 23:11:43 T1000 kernel: [c0000007f8c77410] [c0000000002bd3d8]
.try_to_unmap_one+0x158/0x950
Feb 04 23:11:43 T1000 kernel: [c0000007f8c77560] [c0000000002bc018]
.rmap_walk_anon+0x148/0x3a0
Feb 04 23:11:43 T1000 kernel: [c0000007f8c77610] [c0000000002bf364]
.try_to_unmap+0x104/0x160
Feb 04 23:11:43 T1000 kernel: [c0000007f8c776c0] [c000000000270958]
.shrink_page_list+0x738/0x11e0
Feb 04 23:11:43 T1000 kernel: [c0000007f8c77840] [c000000000271f7c]
.shrink_inactive_list+0x34c/0x7f0
Feb 04 23:11:43 T1000 kernel: [c0000007f8c77950] [c000000000272e94]
.shrink_node_memcg+0x3c4/0x7e0
Feb 04 23:11:43 T1000 kernel: [c0000007f8c77ab0] [c0000000002733c4]
.shrink_node+0x114/0x670
Feb 04 23:11:43 T1000 kernel: [c0000007f8c77bd0] [c000000000275158]
.kswapd+0x3f8/0xc30
Feb 04 23:11:43 T1000 kernel: [c0000007f8c77d60] [c0000000000dfb6c]
.kthread+0x19c/0x1b0
Feb 04 23:11:43 T1000 kernel: [c0000007f8c77e20] [c00000000000b790]
.ret_from_kernel_thread+0x58/0x68
Feb 04 23:11:43 T1000 kernel: Instruction dump:
Feb 04 23:11:43 T1000 kernel: f8010010 f821ff81 4bfdf62d 60000000 2fa30000
419e0150 7fe3fb78 4bfdf619 
Feb 04 23:11:43 T1000 kernel: 60000000 3c82ffa1 e9230000 38849170 <e9290028>
e9290028 e8690000 78690520 
Feb 04 23:11:43 T1000 kernel: ---[ end trace 9d98850d9aa63397 ]---

[...]

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#68 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #67 from [email protected] ---
Created attachment 280957
--> https://bugzilla.kernel.org/attachment.cgi?id=280957&action=edit
journalctl -k (5.0-rc4 on a Talos II, "Kernel NULL pointer dereference")

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#69 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #68 from Jan Kara ([email protected]) ---
That looks like some problem with my debug patch. So just ignore it for now. If it happens frequently, just run a kernel without my debug patch.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#70 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #69 from Aneesh Kumar KV ([email protected]) --- Ok, can we try with only Revert-powerpc-mm-book3s-Enable-THP-migration patch? I am looking at whether we are getting the migration check on page table entries wrong.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#71 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #70 from [email protected] ---
(In reply to Aneesh Kumar KV from comment #69)

Quoted 3 lines

Ok, can we try with only Revert-powerpc-mm-book3s-Enable-THP-migration patch? I am looking at whether we are getting the migration check on page table entries wrong.

Applied only Revert-powerpc-mm-book3s-Enable-THP-migration to -rc5. This provokes the bug after 1 x llvm debug build (my usual test case):

[...]

[ 1596.523635] WARNING: CPU: 15 PID: 1709 at fs/ext4/inode.c:3928
.ext4_set_page_dirty+0x70/0xb0
[ 1596.523768] Modules linked in: rpcsec_gss_krb5 auth_rpcgss nfsv4

dns_resolver nfs lockd grace sunrpc
sr_mod cdrom cfg80211 rfkill radeon evdev ghash_generic gf128mul snd_hda_codec_hdmi i2c_algo_bit ttm ecb
drm_kms_helper snd_hda_intel snd_hda_codec xts snd_hwdep cfbfillrect
snd_hda_core cfbimgblt xhci_pci sy
scopyarea sysimgblt snd_pcm sysfillrect fb_sys_fops cbc xhci_hcd mptsas cfbcopyarea scsi_transport_sas u
sbcore mptscsih drm tg3 vmx_crypto powernv_flash snd_timer snd libphy mtd mptbase at24 crc32c_vpmsum ibm
powernv opal_prd scsi_mod hwmon soundcore drm_panel_orientation_quirks backlight usb_common lz4 lz4_comp
ress lz4_decompress zram zsmalloc

[ 1596.523840] CPU: 15 PID: 1709 Comm: debugedit Not tainted 5.0.0-rc5 #1
[ 1596.523846] NIP:  c00000000040f330 LR: c00000000025bd20 CTR:
c00000000040f2c0
[ 1596.523851] REGS: c0000007b56b7530 TRAP: 0700   Not tainted  (5.0.0-rc5)
[ 1596.523854] MSR:  9000000000029032 <SF,HV,EE,ME,IR,DR,RI>  CR: 24082498 
XER: 20040000
[ 1596.523866] CFAR: c00000000040f304 IRQMASK: 0
               GPR00: c00000000025bd20 c0000007b56b77c0 c0000000011e2b00
c00a00001a63ff40
               GPR04: 00003fffa7a33000 c000000698ffd186 0000000000000001
0000000000000000
               GPR08: 0000000000000000 0000000000000000 c00a00001a63ff08
0000000000000000
               GPR12: 0000000024082492 c0000007ffffa400 c000000698ffd186
1000000000000000
               GPR16: 00003fffa7a33000 e61fffffffffffff c0000007ab96a190
c0000000011f3918
               GPR20: 00003fffa7a34000 c00a00001a63ff40 c0000004bdc64ce8
c0000007ce95fc50
               GPR24: c0000007ab5069e8 c0000007de586198 fffffffffffffe7f
0000000000000000
               GPR28: 00003fffa7a9b000 ffffffffffffffff 0000000000000000
c00a00001a63ff40
[ 1596.523898] NIP [c00000000040f330] .ext4_set_page_dirty+0x70/0xb0
[ 1596.523903] LR [c00000000025bd20] .set_page_dirty+0xa0/0x150
[ 1596.523907] Call Trace:
[ 1596.523913] [c0000007b56b77c0] [c000000000266070] .activate_page+0xf0/0x160
(unreliable)
[ 1596.523920] [c0000007b56b7830] [c00000000025bd20] .set_page_dirty+0xa0/0x150
[ 1596.523927] [c0000007b56b78b0] [c0000000002a4c90]
.unmap_page_range+0xc10/0xe10
[ 1596.523932] [c0000007b56b7a40] [c0000000002a5224] .unmap_vmas+0xa4/0x150
[ 1596.523938] [c0000007b56b7b00] [c0000000002afc18] .unmap_region+0xe8/0x190
[ 1596.523944] [c0000007b56b7c30] [c0000000002b22f0] .__do_munmap+0x2f0/0x510
[ 1596.523949] [c0000007b56b7cf0] [c0000000002b2590] .__vm_munmap+0x80/0x110
[ 1596.523955] [c0000007b56b7db0] [c0000000002b2654] .__se_sys_munmap+0x14/0x30
[ 1596.523962] [c0000007b56b7e20] [c00000000000b3a4] system_call+0x5c/0x70
[ 1596.523966] Instruction dump:
[ 1596.523971] 71290008 4182002c e9230000 71292000 41820030 4bf6d80d 60000000
38210070
[ 1596.523981] e8010010 7c0803a6 4e800020 60000000 <0fe00000> e9230000 71292000

4082ffd8 C

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#72 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

[email protected] changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #280957|0                           |1

is obsolete| |

--- Comment #71 from [email protected] ---
Created attachment 280965
--> https://bugzilla.kernel.org/attachment.cgi?id=280965&action=edit
journalctl -k (5.0-rc5 on a Talos II)

Results with Revert-powerpc-mm-book3s-Enable-THP-migration + mm: Dump page and PTE state and some history (v6).

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#73 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #72 from Jan Kara ([email protected]) ---
Just a suggestion to PPC maintainers / Aneesh: This bug can lead to data corruption (lost data written to a file) or potential security issues (writes to file user is no longer supposed to be able to write to) because it leads to PPC leaving writeably mapped pages behind. So since we are at -rc5 I think considering just reverting the patches and figuring out what's going on separately without exposing general users to these issues is a fair question...

Note that the problem affects already 4.20 so -stable needs to be included regardless how you decide to solve these issues.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#74 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

--- Comment #73 from Aneesh Kumar KV ([email protected]) --- (In reply to Jan Kara from comment #72)

Quoted 10 lines

Just a suggestion to PPC maintainers / Aneesh: This bug can lead to data corruption (lost data written to a file) or potential security issues (writes to file user is no longer supposed to be able to write to) because it leads to PPC leaving writeably mapped pages behind. So since we are at -rc5 I think considering just reverting the patches and figuring out what's going on separately without exposing general users to these issues is a fair question...

Note that the problem affects already 4.20 so -stable needs to be included regardless how you decide to solve these issues.

I understand the urgency. But we are still not able to work out why the revert the change helps. Few things which are different from other commonly used kernel configs are

1) 4K page size
2) Big endian kernel.

One thing we could do is just revert the definition of pud_present and pgd_present. ( I already shared a patch to try that). If this helps, we could take that to upstream. But that is still not the fix because we still don't know who is clearing the top bit of the page table tree. This Level1 and Level2 entries are not modified in between. They are set during fault and cleared on page table free.

Another debugging effort we could try is with little-endian config. Erhard, how easy/difficult it will be you try a little-endian config?

All my effort to recreate this on my POWER9 system with 4k config has not been successful. The difference here is I have a little-endian config.

-aneesh

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
#76 lore raw

[Bug 201631] WARNING: CPU: 11 PID: 29593 at fs/ext4/inode.c:3927 .ext4_set_page_dirty+0x70/0xb0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=201631

Michael Ellerman ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------

          Component|ext4                        |PPC-64
           Assignee|[email protected] |platform_ppc-64@kernel-bugs
                   |g                           |.osdl.org
            Product|File System                 |Platform Specific/Hardware
Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.