New: configuring TRANSPARENT_HUGEPAGE_ALWAYS can make system unresponsive and reboot

Bug 49361 Andrew Morton 5 participants 7 messages Oct 23, 2012 – Nov 2, 2012 1 message not in the archive Memory management

lore

Share & tools

lore

A message that is not in the archive (sent off-list or not yet received): [email protected]/

Andrew Morton

author maintainer

2012-10-23 19:36 UTC #1 lore raw

(switched to email. Please respond via emailed reply-to-all, not via the bugzilla web interface).

Quoted 85 lines · On Tue, 23 Oct 2012 00:06:18 +0000 (UTC) [email protected]…

https://bugzilla.kernel.org/show_bug.cgi?id=49361
Summary: configuring TRANSPARENT_HUGEPAGE_ALWAYS can make
system unresponsive and reboot
Product: Memory Management
Version: 2.5
Kernel Version: 3.6.2
Platform: All
OS/Version: Linux
Tree: Mainline
Status: NEW
Severity: normal
Priority: P1
Component: Page Allocator
AssignedTo: [email protected]
ReportedBy: [email protected]
Regression: No
workaround: configure TRANSPARENT_HUGEPAGE_MADVISE instead
I run a bleeding edge gentoo with 2 6-core AMD CPUs. I daily updated
3 gentoo systems on this computer all using -j13. Until recently, I never experienced issues, CPUs may all go neer 100%, no problem.
Now, when building icedtea-7, for example, regardless of -j13 or -j1,
about 10 javac instances run threaded (either spreaded on multiple or one core) and go to about 1000% CPU together.
Nothing else can be started. This can take 24 hours, no improvement.
Only one way to recover: kill -9 javac.
One time kernel rebooted, I could not find any relevant kernel logs
before reboot.
I hd noticed khugepaged on top in top (just below 1000% CPU javac)
which made me look at HUGEPAGE settings.
FWIW, an strace on javac PID showed it doing nothing in futex
As said, MADVISE fixes issue.
I am not sure if this is really a kernel bug, however, no matter how
bad programs behave, other programs should be able to get CPU and reboot (unless perhaps watchdog) should not happen.
Even if not a kernel bug, it is strange that chanding one single
kernel config fixes issue and massive building works again.
I sincerely hope I provide hint to developers to fix/improve kernel
and I am willing to cooperate to get this happen. Note that for now I have workaround in place (to build/cross-build my other systems on this dedicated build host)
standby ~ # /usr/src/linux-3.6.2-gentoo/scripts/ver_linux If some fields are empty or look unusual you may have an old version. Compare to the current minimal requirements in Documentation/Changes.
Linux standby 3.6.2-gentoo #2 SMP Mon Oct 22 18:56:49 CEST 2012 x86_64 AMD Opteron(tm) Processor 4184 AuthenticAMD GNU/Linux
Gnu C                  4.7.2
Gnu make               3.82
binutils               2.22
util-linux             2.22.1
mount                  debug
module-init-tools      10
e2fsprogs              1.42.6
jfsutils               1.1.15
xfsprogs               3.1.8
quota-tools            4.00-pre1.
PPP                    2.4.5
Linux C Library        2.15
Dynamic linker (ldd)   2.15
Procps                 UNKNOWN
Net-tools              1.60_p20120127084908
Kbd                    1.15.3wip
Sh-utils               8.19
wireless-tools         30
Modules Loaded         fbcon bitblit softcursor font rfcomm w83627ehf hwmon_vid

Quoted 18 lines

fuse bnep autofs4 nfsd nfs_acl lockd sunrpc ipv6 af_packet quota_v2 quota_tree video usbmouse usbkbd usbhid scsi_tgt output nvram nls_utf8 nls_ascii msr mptspi scsi_transport_spi mptsas mptscsih mptbase libphy initio hid_apple drm dm_log dm_mod cpuid configs configfs cifs btusb bluetooth rfkill async_memcpy async_tx aic94xx libsas scsi_transport_sas nvidia usb_storage uas uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_core videodev ub snd_usb_audio snd_usbmidi_lib snd_hwdep snd_hda_codec_hdmi sp5100_tco nvidiafb vgastate sr_mod i2c_algo_bit fb_ddc powernow_k8 i2c_piix4 mperf freq_table ohci_hcd cdrom ehci_hcd ata_generic pata_acpi usbcore i2c_core usb_common k10temp e1000e pata_atiixp kvm_amd kvm snd_ca0106 microcode pcspkr snd_ac97_codec serio_raw ac97_bus firmware_class snd_rawmidi snd_seq_device snd_hda_intel snd_hda_codec snd_pcm snd_page_alloc snd_timer 8250_pnp rtc_cmos processor thermal_sys hwmon snd button soundcore unix
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

Ni zhan Chen

2012-10-24 00:34 UTC #2 lore raw

Quoted 5 lines · Andrew Morton

(switched to email. Please respond via emailed reply-to-all, not via the bugzilla web interface).
On Tue, 23 Oct 2012 00:06:18 +0000 (UTC)
[email protected] wrote:

How to subscribe this bugzilla ML?

Quoted 104 lines

Quoted 86 lines
https://bugzilla.kernel.org/show_bug.cgi?id=49361
Summary: configuring TRANSPARENT_HUGEPAGE_ALWAYS can make
system unresponsive and reboot
Product: Memory Management
Version: 2.5
Kernel Version: 3.6.2
Platform: All
OS/Version: Linux
Tree: Mainline
Status: NEW
Severity: normal
Priority: P1
Component: Page Allocator
AssignedTo: [email protected]
ReportedBy: [email protected]
Regression: No
workaround: configure TRANSPARENT_HUGEPAGE_MADVISE instead
I run a bleeding edge gentoo with 2 6-core AMD CPUs. I daily updated
3 gentoo systems on this computer all using -j13. Until recently, I never experienced issues, CPUs may all go neer 100%, no problem.
Now, when building icedtea-7, for example, regardless of -j13 or -j1,
about 10 javac instances run threaded (either spreaded on multiple or one core) and go to about 1000% CPU together.
Nothing else can be started. This can take 24 hours, no improvement.
Only one way to recover: kill -9 javac.
One time kernel rebooted, I could not find any relevant kernel logs
before reboot.
I hd noticed khugepaged on top in top (just below 1000% CPU javac)
which made me look at HUGEPAGE settings.
FWIW, an strace on javac PID showed it doing nothing in futex
As said, MADVISE fixes issue.
I am not sure if this is really a kernel bug, however, no matter how
bad programs behave, other programs should be able to get CPU and reboot (unless perhaps watchdog) should not happen.
Even if not a kernel bug, it is strange that chanding one single
kernel config fixes issue and massive building works again.
I sincerely hope I provide hint to developers to fix/improve kernel
and I am willing to cooperate to get this happen. Note that for now I have workaround in place (to build/cross-build my other systems on this dedicated build host)
standby ~ # /usr/src/linux-3.6.2-gentoo/scripts/ver_linux If some fields are empty or look unusual you may have an old version. Compare to the current minimal requirements in Documentation/Changes.
Linux standby 3.6.2-gentoo #2 SMP Mon Oct 22 18:56:49 CEST 2012 x86_64 AMD Opteron(tm) Processor 4184 AuthenticAMD GNU/Linux
Gnu C                  4.7.2
Gnu make               3.82
binutils               2.22
util-linux             2.22.1
mount                  debug
module-init-tools      10
e2fsprogs              1.42.6
jfsutils               1.1.15
xfsprogs               3.1.8
quota-tools            4.00-pre1.
PPP                    2.4.5
Linux C Library        2.15
Dynamic linker (ldd)   2.15
Procps                 UNKNOWN
Net-tools              1.60_p20120127084908
Kbd                    1.15.3wip
Sh-utils               8.19
wireless-tools         30
Modules Loaded         fbcon bitblit softcursor font rfcomm w83627ehf hwmon_vid
Quoted 18 lines
fuse bnep autofs4 nfsd nfs_acl lockd sunrpc ipv6 af_packet quota_v2 quota_tree video usbmouse usbkbd usbhid scsi_tgt output nvram nls_utf8 nls_ascii msr mptspi scsi_transport_spi mptsas mptscsih mptbase libphy initio hid_apple drm dm_log dm_mod cpuid configs configfs cifs btusb bluetooth rfkill async_memcpy async_tx aic94xx libsas scsi_transport_sas nvidia usb_storage uas uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_core videodev ub snd_usb_audio snd_usbmidi_lib snd_hwdep snd_hda_codec_hdmi sp5100_tco nvidiafb vgastate sr_mod i2c_algo_bit fb_ddc powernow_k8 i2c_piix4 mperf freq_table ohci_hcd cdrom ehci_hcd ata_generic pata_acpi usbcore i2c_core usb_common k10temp e1000e pata_atiixp kvm_amd kvm snd_ca0106 microcode pcspkr snd_ac97_codec serio_raw ac97_bus firmware_class snd_rawmidi snd_seq_device snd_hda_intel snd_hda_codec snd_pcm snd_page_alloc snd_timer 8250_pnp rtc_cmos processor thermal_sys hwmon snd button soundcore unix
Signature · 3 lines
Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

Quoted 6 lines

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

Andrew Morton

author maintainer

2012-10-24 00:41 UTC #3 lore raw

Quoted 8 lines · On Wed, 24 Oct 2012 08:34:35 +0800 Ni zhan Chen <[email protected]> wrote:

Quoted 5 lines · Andrew Morton
(switched to email. Please respond via emailed reply-to-all, not via the bugzilla web interface).
On Tue, 23 Oct 2012 00:06:18 +0000 (UTC)
[email protected] wrote:
How to subscribe this bugzilla ML?

I don't know, really. Create an account at bugzilla.kernel.org then work out how to get it to send you email for each new report ;)

David Rientjes

2012-10-24 05:54 UTC #4 lore raw

In reply to Andrew Morton

Quoted 16 lines · Andrew Morton

Quoted 16 lines
I run a bleeding edge gentoo with 2 6-core AMD CPUs. I daily updated
3 gentoo systems on this computer all using -j13. Until recently, I never experienced issues, CPUs may all go neer 100%, no problem.
Now, when building icedtea-7, for example, regardless of -j13 or -j1,
about 10 javac instances run threaded (either spreaded on multiple or one core) and go to about 1000% CPU together.
Nothing else can be started. This can take 24 hours, no improvement.
Only one way to recover: kill -9 javac.
One time kernel rebooted, I could not find any relevant kernel logs
before reboot.

Quoted 7 lines

Quoted 7 lines
I hd noticed khugepaged on top in top (just below 1000% CPU javac)
which made me look at HUGEPAGE settings.
FWIW, an strace on javac PID showed it doing nothing in futex
As said, MADVISE fixes issue.

We'll need to collect some information before we can figure out what the problem is with 3.5.2.

First, let's take a look at khugepaged. By default, it's supposed to wake up rarely (10s at minimum) and only scan 4K pages before going back to sleep. Having a consistent and very high cpu usage suggests the settings aren't the default. Can you do

cat /sys/kernel/mm/transparent_hugepage/khugepaged/{alloc,scan}_sleep_millisecs

The defaults should be 60000 and 10000, respectively. Then can you do

cat /sys/kernel/mm/transparent_hugepage/khugepaged/pages_to_scan

which should be 4096. If those are your settings, then it seems like khugepaged in 3.5.2 is going crazy and we'll need to look into that. Try collecting

grep -e "thp|compact" /proc/vmstat

and

	cat /proc/$(pidof khugepaged)/stack

appended to a logfile at regular intervals after your start the build with transparent hugepages enabled always. After the machine becomes unresponsive and reboots, post that log.

David Rientjes

2012-10-29 20:33 UTC #5 lore raw

Quoted 20 lines · David Rientjes

We'll need to collect some information before we can figure out what the problem is with 3.5.2.
First, let's take a look at khugepaged. By default, it's supposed to wake up rarely (10s at minimum) and only scan 4K pages before going back to sleep. Having a consistent and very high cpu usage suggests the settings aren't the default. Can you do
cat /sys/kernel/mm/transparent_hugepage/khugepaged/{alloc,scan}_sleep_millisecs
The defaults should be 60000 and 10000, respectively. Then can you do
cat /sys/kernel/mm/transparent_hugepage/khugepaged/pages_to_scan
which should be 4096. If those are your settings, then it seems like khugepaged in 3.5.2 is going crazy and we'll need to look into that. Try collecting
grep -e "thp|compact" /proc/vmstat

Quoted 8 lines

and
	cat /proc/$(pidof khugepaged)/stack
appended to a logfile at regular intervals after your start the build with transparent hugepages enabled always. After the machine becomes unresponsive and reboots, post that log.

This looks like an overly aggressive memory compaction issue; consider from your "49361.1" attachment:

Sat Oct 27 02:39:05 CEST 2012

	compact_blocks_moved 488381
	compact_pages_moved 581856
	compact_pagemigrate_failed 52533
	compact_stall 59
	compact_fail 36
	compact_success 23
Sat Oct 27 02:39:15 CEST 2012
	compact_blocks_moved 7797480
	compact_pages_moved 589996
	compact_pagemigrate_failed 53507
	compact_stall 90
	compact_fail 56
	compact_success 24
Sat Oct 27 02:43:07 CEST 2012
	compact_blocks_moved 276422153
	compact_pages_moved 597836
	compact_pagemigrate_failed 53886
	compact_stall 109
	compact_fail 76
	compact_success 26

In four minutes, transparent hugepage allocation has scanned 275933772 2MB pageblocks and only been successful three times in defragmenting enough memory for the allocation to succeed. It's scanning on average 5518675 pageblocks each time it is invoked.

And then, from your "49361.2" attachment:

Sat Oct 27 02:48:30 CEST 2012

	compact_blocks_moved 504039382
	compact_pages_moved 776820
	compact_pagemigrate_failed 58437
	compact_stall 209
	compact_fail 163
	compact_success 36
...
Sat Oct 27 02:51:50 CEST 2012
	compact_blocks_moved 722746600
	compact_pages_moved 776820
	compact_pagemigrate_failed 58437
	compact_stall 209
	compact_fail 173
	compact_success 36

For more than three minutes, compact_stall does not increase but compact_fail does (and compact_blocks_moved increases 43%), which suggests deferred compaction is kicking in but for some reason we are still scanning like crazy.

Reading the code, the only way this can happen is if nr_remaining is always 0 (compact_pagemigrate_failed never increases), but also nr_migrate is always 0 (compact_pages_moved never increases). So I think we're stuck in the while loop in compact_zone() and are constantly calling migrate_pages(). compact_finished() must be returning COMPACT_CONTINUE even though cc->nr_migratepages == 0?

Adding Mel Gorman to the cc.

Mel Gorman

2012-11-01 17:14 UTC #6 lore raw

Quoted 5 lines · David Rientjes

Quoted 3 lines · David Rientjes
We'll need to collect some information before we can figure out what the problem is with 3.5.2.

3.6.2 or 3.5.2?

The bug mentioned "recently" but does not say what the last known working kernel was. What is the most recent working kernel so the problem candidate can be narrowed down?

Quoted 51 lines

Quoted 17 lines
First, let's take a look at khugepaged. By default, it's supposed to wake up rarely (10s at minimum) and only scan 4K pages before going back to sleep. Having a consistent and very high cpu usage suggests the settings aren't the default. Can you do
cat /sys/kernel/mm/transparent_hugepage/khugepaged/{alloc,scan}_sleep_millisecs
The defaults should be 60000 and 10000, respectively. Then can you do
cat /sys/kernel/mm/transparent_hugepage/khugepaged/pages_to_scan
which should be 4096. If those are your settings, then it seems like khugepaged in 3.5.2 is going crazy and we'll need to look into that. Try collecting
grep -e "thp|compact" /proc/vmstat
Quoted 8 lines
and
	cat /proc/$(pidof khugepaged)/stack
appended to a logfile at regular intervals after your start the build with transparent hugepages enabled always. After the machine becomes unresponsive and reboots, post that log.
This looks like an overly aggressive memory compaction issue; consider from your "49361.1" attachment:
Sat Oct 27 02:39:05 CEST 2012
	compact_blocks_moved 488381
	compact_pages_moved 581856
	compact_pagemigrate_failed 52533
	compact_stall 59
	compact_fail 36
	compact_success 23
Sat Oct 27 02:39:15 CEST 2012
	compact_blocks_moved 7797480
	compact_pages_moved 589996
	compact_pagemigrate_failed 53507
	compact_stall 90
	compact_fail 56
	compact_success 24
Sat Oct 27 02:43:07 CEST 2012
	compact_blocks_moved 276422153
	compact_pages_moved 597836
	compact_pagemigrate_failed 53886
	compact_stall 109
	compact_fail 76
	compact_success 26

Quoted 5 lines

In four minutes, transparent hugepage allocation has scanned 275933772 2MB pageblocks and only been successful three times in defragmenting enough memory for the allocation to succeed. It's scanning on average 5518675 pageblocks each time it is invoked.

We had the bug recently about excessive scanning and lock contention within compaction after lumpy reclaim was removed between 3.4 and 3.5. The impact was not obvious because compaction was used less frequently when lumpy reclaim was in place but once the crutch went away, it fell over. The "solution" as it stands right now is the following patches on top of 3.6. Can they be tested please?

e64c5237cf6ff474cb2f3f832f48f2b441dd9979 mm: compaction: abort compaction loop if lock is contended or run too long 3cc668f4e30fbd97b3c0574d8cac7a83903c9bc7 mm: compaction: move fatal signal check out of compact_checklock_irqsave 661c4cb9b829110cb68c18ea05a56be39f75a4d2 mm: compaction: Update try_to_compact_pages()kerneldoc comment 2a1402aa044b55c2d30ab0ed9405693ef06fb07c mm: compaction: acquire the zone->lru_lock as late as possible f40d1e42bb988d2a26e8e111ea4c4c7bac819b7e mm: compaction: acquire the zone->lock as late as possible 753341a4b85ff337487b9959c71c529f522004f4 revert "mm: have order > 0 compaction start off where it left" bb13ffeb9f6bfeb301443994dfbf29f91117dfb3 mm: compaction: cache if a pageblock was scanned and no pages were isolated c89511ab2f8fe2b47585e60da8af7fd213ec877e mm: compaction: Restart compaction from near where it left off 62997027ca5b3d4618198ed8b1aba40b61b1137b mm: compaction: clear PG_migrate_skip based on compaction and reclaim activity 0db63d7e25f96e2c6da925c002badf6f144ddf30 mm: compaction: correct the nr_strict va isolated check for CMA

I can provide a monolithic patch of these commits if that is preferred.

Quoted 1 line

Adding Mel Gorman to the cc.

Thanks David.

Signature · 8 lines

Mel Gorman
SUSE Labs

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

Marc Duponcheel

2012-11-02 18:00 UTC #7 lore raw

Hi Mel

Thanks for your interest.

it is 3.6.2 that I tested

I am not sure when TRANSPARENT_HUGEPAGE_ALWAYS was introduced but it
could be that the problem started first time I had it configured.

In any case, I think I saw problem first on 3.6.0 or 3.5.x that came
just before 3.6.0

Looking into logs: first time it happened was on Oct 7. But I am not
sure what exact kernel I was running then (it -could- have been 3.5.6).

I sincerely hope this helps ...

As mentioned, reproduction is not hard.

Also: I can grant ssh access for you to troubleshoot.

Have a nice day

Quoted 88 lines · Mel Gorman

Quoted 5 lines · David Rientjes
Quoted 3 lines · David Rientjes
We'll need to collect some information before we can figure out what the problem is with 3.5.2.
3.6.2 or 3.5.2?
The bug mentioned "recently" but does not say what the last known working kernel was. What is the most recent working kernel so the problem candidate can be narrowed down?
Quoted 51 lines
Quoted 17 lines
First, let's take a look at khugepaged. By default, it's supposed to wake up rarely (10s at minimum) and only scan 4K pages before going back to sleep. Having a consistent and very high cpu usage suggests the settings aren't the default. Can you do
cat /sys/kernel/mm/transparent_hugepage/khugepaged/{alloc,scan}_sleep_millisecs
The defaults should be 60000 and 10000, respectively. Then can you do
cat /sys/kernel/mm/transparent_hugepage/khugepaged/pages_to_scan
which should be 4096. If those are your settings, then it seems like khugepaged in 3.5.2 is going crazy and we'll need to look into that. Try collecting
grep -e "thp|compact" /proc/vmstat
Quoted 8 lines
and
	cat /proc/$(pidof khugepaged)/stack
appended to a logfile at regular intervals after your start the build with transparent hugepages enabled always. After the machine becomes unresponsive and reboots, post that log.
This looks like an overly aggressive memory compaction issue; consider from your "49361.1" attachment:
Sat Oct 27 02:39:05 CEST 2012
	compact_blocks_moved 488381
	compact_pages_moved 581856
	compact_pagemigrate_failed 52533
	compact_stall 59
	compact_fail 36
	compact_success 23
Sat Oct 27 02:39:15 CEST 2012
	compact_blocks_moved 7797480
	compact_pages_moved 589996
	compact_pagemigrate_failed 53507
	compact_stall 90
	compact_fail 56
	compact_success 24
Sat Oct 27 02:43:07 CEST 2012
	compact_blocks_moved 276422153
	compact_pages_moved 597836
	compact_pagemigrate_failed 53886
	compact_stall 109
	compact_fail 76
	compact_success 26
Quoted 5 lines
In four minutes, transparent hugepage allocation has scanned 275933772 2MB pageblocks and only been successful three times in defragmenting enough memory for the allocation to succeed. It's scanning on average 5518675 pageblocks each time it is invoked.
We had the bug recently about excessive scanning and lock contention within compaction after lumpy reclaim was removed between 3.4 and 3.5. The impact was not obvious because compaction was used less frequently when lumpy reclaim was in place but once the crutch went away, it fell over. The "solution" as it stands right now is the following patches on top of 3.6. Can they be tested please?
e64c5237cf6ff474cb2f3f832f48f2b441dd9979 mm: compaction: abort compaction loop if lock is contended or run too long 3cc668f4e30fbd97b3c0574d8cac7a83903c9bc7 mm: compaction: move fatal signal check out of compact_checklock_irqsave 661c4cb9b829110cb68c18ea05a56be39f75a4d2 mm: compaction: Update try_to_compact_pages()kerneldoc comment 2a1402aa044b55c2d30ab0ed9405693ef06fb07c mm: compaction: acquire the zone->lru_lock as late as possible f40d1e42bb988d2a26e8e111ea4c4c7bac819b7e mm: compaction: acquire the zone->lock as late as possible 753341a4b85ff337487b9959c71c529f522004f4 revert "mm: have order > 0 compaction start off where it left" bb13ffeb9f6bfeb301443994dfbf29f91117dfb3 mm: compaction: cache if a pageblock was scanned and no pages were isolated c89511ab2f8fe2b47585e60da8af7fd213ec877e mm: compaction: Restart compaction from near where it left off 62997027ca5b3d4618198ed8b1aba40b61b1137b mm: compaction: clear PG_migrate_skip based on compaction and reclaim activity 0db63d7e25f96e2c6da925c002badf6f144ddf30 mm: compaction: correct the nr_strict va isolated check for CMA

Quoted 9 lines

I can provide a monolithic patch of these commits if that is preferred.
Quoted 1 line
Adding Mel Gorman to the cc.
Thanks David.
Signature · 2 lines
Mel Gorman
SUSE Labs

--
Marc Duponcheel
Velodroomstraat 74 - 2600 Berchem - Belgium
+32 (0)478 68.10.91 - [email protected]