April 2018 - openSUSE Kernel - openSUSE Mailing Lists

[opensuse-kernel] Reliability test for hard drives and SSD
by Andrey Ponomarenko 29 Jul '18

29 Jul '18

Hi there! Good news for all interested in hardware compatibility and reliability. I've started a new project to estimate reliability of hard drives and SSD in real-life conditions based on the SMART data reports collected by Linux users in the Linux-Hardware.org database since 2014. The initial data (SMART reports), analysis methods and results are publicly shared in a new github repository: https://github.com/linuxhw/SMART. Everyone can contribute to the report by uploading probes of their computers by the hw-probe tool! The primary aim of the project is to find drives with longest "power on hours" and minimal number of errors. The following formula is used to measure reliability: Power_On_Hours / (1 + Number_Of_Errors), i.e. time to the first error/between errors. Please be careful when reading the results table. Pay attention not only to the rating, but also to the number of checked model samples. If rating is low, then look at the number of power-on days and number of errors occurred. New drive models will appear at the end of the rating table and will move to the top in the case of long error-free operation. Thanks to ROSA, openSUSE, Gentoo, Ubuntu, Debian, Mint, Arch, Fedora users and others who had made this work possible by contribution to the database! -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe(a)opensuse.org To contact the owner, e-mail: opensuse-kernel+owner(a)opensuse.org

3 4

[opensuse-kernel] Heavy performance loss since 4.16.0-rc6
by Michael Zapf 28 Apr '18

28 Apr '18

Hello all, I was recommended to post my observation to this mailing list; hope that this is appropriate. Since mid-March, my Tumbleweed suffers a drastic performance loss. I observed this during my work on MAME (the emulator framework) which is an application with high CPU load. For benchmark purposes, MAME offers a command line option that suppresses screen output and turns off real-time synchronization so that the emulator core is running at the maximum speed. Typically you should expect a multiple of the real speed, expressed by a percentage of far above 100%. At some time in mid-March, the benchmark speed for a selected system dropped from 900% to 300%, for another emulated system from 450% to 150%, which is already too low to ensure a full emulation speed with screen output. To rule out any effects from the MAME application, I have been using a version that I built almost a year ago, leaving it unchanged. The described slowdown occurs on three separate desktop PCs, which means that a hardware issue is unlikely. All PCs have a Core-i7 architecture. Interestingly, on two laptops that I could use to test, the effect does not occur. Consequently, this means that now my old laptop from 2012 with a Core i5-3320M(a)2.6 GHz runs MAME faster than my Core i7-6700K(a)4.0 GHz. The slowdown also occurs in other applications. Notably, the Leawo Bluray Player that runs in WINE is not able to sustain the frame rate any longer, delivering chopped replay, which was perfect before. During the last days I tried to bisect the kernel source from Github in order to isolate the point where the effect started (remote origin: git@github.com:openSUSE/kernel.git). Interestingly, the effect did not show up until 4.16.0-rc6, while that same desktop PC already showed the effect during the distro upgrade around 4.15.13 (which was in March). The result is: bad: 646d6e114288 Update to 4.16-rc6. good: aec6bb8e2770 - Refresh patches.suse/kernel-add-release-status-to-kernel-build.patch. If desired, I can give you a small bundle of the MAME executable to run the benchmark by yourself. Here is the effect: michael@capella:~/susekernel> uname -a Linux capella 4.16.0-rc5-1-default+ #26 SMP PREEMPT Sun Apr 22 14:26:13 CEST 2018 x86_64 x86_64 x86_64 GNU/Linux michael@capella:~/susekernel> git status HEAD detached at aec6bb8e2770 nothing to commit, working tree clean michael@capella:~/susekernel> cd ~/mame michael@capella:~/mame> ./mame64_0186 ti99_4a -bench 20 Average speed: 883.31% (19 seconds) michael@capella:~/mame> michael@capella:~/susekernel> uname -a Linux capella 4.16.0-rc6-1-default+ #27 SMP PREEMPT Sun Apr 22 16:17:52 CEST 2018 x86_64 x86_64 x86_64 GNU/Linux michael@capella:~/susekernel> git status HEAD detached at 646d6e114288 nothing to commit, working tree clean michael@capella:~/susekernel> cd ~/mame michael@capella:~/mame> ./mame64_0186 ti99_4a -bench 20 Average speed: 305.27% (19 seconds) michael@capella:~/mame> Greetings, Michael -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe(a)opensuse.org To contact the owner, e-mail: opensuse-kernel+owner(a)opensuse.org

5 7

[opensuse-kernel] Why the big jump in initrd size in 4.16?
by Felix Miata 27 Apr '18

27 Apr '18

-rw------- 1 root root 7.4M Jan 1 22:22 initrd-4.13.12-1-default -rw------- 1 root root 7.5M Mar 9 13:38 initrd-4.14.15-2-default -rw------- 1 root root 7.4M Apr 26 23:08 initrd-4.15.13-2-default -rw------- 1 root root 8.4M Apr 27 00:51 initrd-4.16.3-1-default -rw-r--r-- 1 root root 7.0M Nov 12 13:36 vmlinuz-4.13.12-1-default -rw-r--r-- 1 root root 7.2M Jan 31 21:05 vmlinuz-4.14.15-2-default -rw-r--r-- 1 root root 7.3M Apr 4 22:13 vmlinuz-4.15.13-2-default -rw-r--r-- 1 root root 7.4M Apr 22 15:57 vmlinuz-4.16.3-1-default I thought I read somewhere in recent weeks to expect kernel package size to shrink in 4.16 or 4.17. Installed size of rpm of 4.16.3 is 106.7% of 4.13.12, so it doesn't seem to have happened yet - if it's ever going to. Obviously whatever I saw wasn't about initrd sizes. What happened to cause the 13.5% jump in initrd size in TW's 4.16? -- "Wisdom is supreme; therefore get wisdom. Whatever else you get, get wisdom." Proverbs 4:7 (New Living Translation) Team OS/2 ** Reg. Linux User #211409 ** a11y rocks! Felix Miata *** http://fm.no-ip.com/ -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe(a)opensuse.org To contact the owner, e-mail: opensuse-kernel+owner(a)opensuse.org

3 2

[opensuse-kernel] SLES12-SP3 or opensuse 42.3 deadlocks under memory pressure?
by Stefan Priebe - Profihost AG 10 Apr '18

10 Apr '18

Hello, under memory pressure on a hypervisor running ksmd i had two deadlocks today where the machines rebootet due to lockups. Kernel was build from commit: 4fe1fb26557d69a4d0397113eb89d2dd7d6021b4 What i could grab from netconsole is: 018-04-05 18:05:45 Leftover inexact backtrace: 2018-04-05 18:05:45 2018-04-05 18:05:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:05:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:05:45 [<ffffffff811d514e>] SyS_open+0x1e/0x20 2018-04-05 18:05:45 [<ffffffff811d504c>] do_sys_open+0x12c/0x210 2018-04-05 18:05:45 [<ffffffff811e591e>] do_filp_open+0x7e/0xe0 2018-04-05 18:05:45 [<ffffffff811e2ef4>] path_openat+0x3b4/0x1200 2018-04-05 18:05:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 2018-04-05 18:05:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 2018-04-05 18:05:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 2018-04-05 18:05:45 [<ffffffff816e15f5>] schedule+0x35/0x80 2018-04-05 18:05:45 Call Trace: 2018-04-05 18:05:45 ffff887f69748368 ffff887f69793cb0 ffffffff816e15f5 ffff887f69748360 2018-04-05 18:05:45 ffff887f69794000 ffff887f69748364 ffff887f735a0000 00000000ffffffff 2018-04-05 18:05:45 ffff887f69793c98 ffff887f69793c68 ffffffff00000035 ffff887f735a0000 2018-04-05 18:05:45 pve-firewall D ffff887f69793c98 0 2914 1 0x00080000 2018-04-05 18:05:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2018-04-05 18:05:45 Not tainted 4.4.126+557-ph #1 2018-04-05 18:05:45 INFO: task pve-firewall:2914 blocked for more than 120 seconds. 2018-04-05 18:07:45 Leftover inexact backtrace: 2018-04-05 18:07:45 2018-04-05 18:07:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:07:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:07:45 [<ffffffff811d514e>] SyS_open+0x1e/0x20 2018-04-05 18:07:45 [<ffffffff811d504c>] do_sys_open+0x12c/0x210 2018-04-05 18:07:45 [<ffffffff811e591e>] do_filp_open+0x7e/0xe0 2018-04-05 18:07:45 [<ffffffff811e2ef4>] path_openat+0x3b4/0x1200 2018-04-05 18:07:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 2018-04-05 18:07:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 2018-04-05 18:07:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 2018-04-05 18:07:45 [<ffffffff816e15f5>] schedule+0x35/0x80 2018-04-05 18:07:45 Call Trace: 2018-04-05 18:07:45 ffff887f69748368 ffff887f69793cb0 ffffffff816e15f5 ffff887f69748360 2018-04-05 18:07:45 ffff887f69794000 ffff887f69748364 ffff887f735a0000 00000000ffffffff 2018-04-05 18:07:45 ffff887f69793c98 ffff887f69793c68 ffffffff00000035 ffff887f735a0000 2018-04-05 18:07:45 INFO: task pve-firewall:2914 blocked for more than 120 seconds. 2018-04-05 18:09:45 Leftover inexact backtrace: 2018-04-05 18:09:45 2018-04-05 18:09:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:09:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:09:45 [<ffffffff811d514e>] SyS_open+0x1e/0x20 2018-04-05 18:09:45 [<ffffffff811d504c>] do_sys_open+0x12c/0x210 2018-04-05 18:09:45 [<ffffffff811e591e>] do_filp_open+0x7e/0xe0 2018-04-05 18:09:45 [<ffffffff811e2ef4>] path_openat+0x3b4/0x1200 2018-04-05 18:09:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 2018-04-05 18:09:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 2018-04-05 18:09:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 2018-04-05 18:09:45 [<ffffffff816e15f5>] schedule+0x35/0x80 2018-04-05 18:09:45 Call Trace: 2018-04-05 18:09:45 ffff887f69748368 ffff887f69793cb0 ffffffff816e15f5 ffff887f69748360 2018-04-05 18:09:45 ffff887f69794000 ffff887f69748364 ffff887f735a0000 00000000ffffffff 2018-04-05 18:09:45 ffff887f69793c98 ffff887f69793c68 ffffffff00000035 ffff887f735a0000 2018-04-05 18:09:45 pve-firewall D ffff887f69793c98 0 2914 1 0x00080000 2018-04-05 18:09:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2018-04-05 18:09:45 INFO: task pve-firewall:2914 blocked for more than 120 seconds. 2018-04-05 18:11:45 Leftover inexact backtrace: 2018-04-05 18:11:45 2018-04-05 18:11:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:11:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:11:45 [<ffffffff811d514e>] SyS_open+0x1e/0x20 2018-04-05 18:11:45 [<ffffffff811d504c>] do_sys_open+0x12c/0x210 2018-04-05 18:11:45 [<ffffffff811e591e>] do_filp_open+0x7e/0xe0 2018-04-05 18:11:45 [<ffffffff811e2ef4>] path_openat+0x3b4/0x1200 2018-04-05 18:11:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 2018-04-05 18:11:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 2018-04-05 18:11:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 2018-04-05 18:11:45 [<ffffffff816e15f5>] schedule+0x35/0x80 2018-04-05 18:11:45 Call Trace: 2018-04-05 18:11:45 ffff887f69748368 ffff887f69793cb0 ffffffff816e15f5 ffff887f69748360 2018-04-05 18:11:45 ffff887f69794000 ffff887f69748364 ffff887f735a0000 00000000ffffffff 2018-04-05 18:11:45 ffff887f69793c98 ffff887f69793c68 ffffffff00000035 ffff887f735a0000 2018-04-05 18:11:45 pve-firewall D ffff887f69793c98 0 2914 1 0x00080000 2018-04-05 18:11:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2018-04-05 18:11:45 Not tainted 4.4.126+557-ph #1 2018-04-05 18:11:45 INFO: task pve-firewall:2914 blocked for more than 120 seconds. 2018-04-05 18:13:45 Leftover inexact backtrace: 2018-04-05 18:13:45 2018-04-05 18:13:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:13:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:13:45 [<ffffffff811d514e>] SyS_open+0x1e/0x20 2018-04-05 18:13:45 [<ffffffff811d504c>] do_sys_open+0x12c/0x210 2018-04-05 18:13:45 [<ffffffff811e591e>] do_filp_open+0x7e/0xe0 2018-04-05 18:13:45 [<ffffffff811e2ef4>] path_openat+0x3b4/0x1200 2018-04-05 18:13:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 2018-04-05 18:13:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 2018-04-05 18:13:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 2018-04-05 18:13:45 [<ffffffff816e15f5>] schedule+0x35/0x80 2018-04-05 18:13:45 Call Trace: 2018-04-05 18:13:45 ffff887f69748368 ffff887f69793cb0 ffffffff816e15f5 ffff887f69748360 2018-04-05 18:13:45 ffff887f69794000 ffff887f69748364 ffff887f735a0000 00000000ffffffff 2018-04-05 18:13:45 ffff887f69793c98 ffff887f69793c68 ffffffff00000035 ffff887f735a0000 2018-04-05 18:13:45 pve-firewall D ffff887f69793c98 0 2914 1 0x00080000 2018-04-05 18:13:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2018-04-05 18:13:45 Not tainted 4.4.126+557-ph #1 2018-04-05 18:13:45 INFO: task pve-firewall:2914 blocked for more than 120 seconds. 2018-04-05 18:15:45 Leftover inexact backtrace: 2018-04-05 18:15:45 2018-04-05 18:15:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:15:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:15:45 [<ffffffff811d514e>] SyS_open+0x1e/0x20 2018-04-05 18:15:45 [<ffffffff811d504c>] do_sys_open+0x12c/0x210 2018-04-05 18:15:45 [<ffffffff811e591e>] do_filp_open+0x7e/0xe0 2018-04-05 18:15:45 [<ffffffff811e2ef4>] path_openat+0x3b4/0x1200 2018-04-05 18:15:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 2018-04-05 18:15:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 2018-04-05 18:15:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 2018-04-05 18:15:45 [<ffffffff816e15f5>] schedule+0x35/0x80 2018-04-05 18:15:45 Call Trace: 2018-04-05 18:15:45 ffff887f69748368 ffff887f69793cb0 ffffffff816e15f5 ffff887f69748360 2018-04-05 18:15:45 ffff887f69794000 ffff887f69748364 ffff887f735a0000 00000000ffffffff 2018-04-05 18:15:45 ffff887f69793c98 ffff887f69793c68 ffffffff00000035 ffff887f735a0000 2018-04-05 18:15:45 pve-firewall D ffff887f69793c98 0 2914 1 0x00080000 2018-04-05 18:15:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2018-04-05 18:15:45 Not tainted 4.4.126+557-ph #1 2018-04-05 18:15:45 INFO: task pve-firewall:2914 blocked for more than 120 seconds. 2018-04-05 18:15:45 Leftover inexact backtrace: 2018-04-05 18:15:45 2018-04-05 18:15:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:15:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:15:45 [<ffffffff811d71c6>] SyS_write+0x46/0xa0 2018-04-05 18:15:45 [<ffffffff811d60a9>] vfs_write+0xa9/0x190 2018-04-05 18:15:45 [<ffffffff811d548b>] __vfs_write+0x2b/0x130 2018-04-05 18:15:45 [<ffffffff81250903>] kernfs_fop_write+0x143/0x180 2018-04-05 18:15:45 [<ffffffff81250d5c>] sysfs_kf_write+0x3c/0x50 2018-04-05 18:15:45 [<ffffffff813d44d2>] kobj_attr_store+0x12/0x20 2018-04-05 18:15:45 [<ffffffff811b21c8>] run_store+0x48/0x2c0 2018-04-05 18:15:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 2018-04-05 18:15:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 2018-04-05 18:15:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 2018-04-05 18:15:45 [<ffffffff816e15f5>] schedule+0x35/0x80 2018-04-05 18:15:45 Call Trace: 2018-04-05 18:15:45 ffffffff81e8d588 ffff883e8d0afd20 ffffffff816e15f5 ffffffff81e8d580 2018-04-05 18:15:45 ffff883e8d0b0000 ffffffff81e8d584 ffff887f7a228000 00000000ffffffff 2018-04-05 18:15:45 ffff883e8d0afd08 ffffffff811d3ca2 ffff883e0000001e ffff887f7a228000 2018-04-05 18:15:45 ksmtuned D ffff883e8d0afd08 0 2259 1 0x00080000 2018-04-05 18:15:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2018-04-05 18:15:45 Not tainted 4.4.126+557-ph #1 2018-04-05 18:15:45 INFO: task ksmtuned:2259 blocked for more than 120 seconds. 2018-04-05 18:15:45 [<ffffffff810a49f0>] ? kthread_park+0x60/0x60 2018-04-05 18:15:45 Leftover inexact backtrace: 2018-04-05 18:15:45 2018-04-05 18:15:45 DWARF2 unwinder stuck at ret_from_fork+0x55/0x80 2018-04-05 18:15:45 [<ffffffff816e60c5>] ret_from_fork+0x55/0x80 2018-04-05 18:15:45 [<ffffffff810a4add>] kthread+0xed/0x110 2018-04-05 18:15:45 [<ffffffff811b32c5>] ksm_scan_thread+0x85/0x1b0 2018-04-05 18:15:45 [<ffffffff811b2adb>] ksm_do_scan+0x69b/0xe00 2018-04-05 18:15:45 [<ffffffff8116b18d>] lru_add_drain_all+0x13d/0x190 2018-04-05 18:15:45 [<ffffffff8109ecae>] flush_work+0xfe/0x170 2018-04-05 18:15:45 [<ffffffff816e2998>] wait_for_completion+0xa8/0x110 2018-04-05 18:15:45 [<ffffffff816e4a4a>] schedule_timeout+0x23a/0x2d0 2018-04-05 18:15:45 [<ffffffff816e15f5>] schedule+0x35/0x80 2018-04-05 18:15:45 Call Trace: 2018-04-05 18:15:45 0000000000000038 ffff883f7fbb7c20 ffffffff816e15f5 7fffffffffffffff 2018-04-05 18:15:45 ffff883f7fbb8000 ffff883f7fbb7d58 ffff883f7fbb7d50 ffff883f7fbfa580 2018-04-05 18:15:45 ffff883f7fbb7c08 ffff887f7dad81c0 ffff883f00000031 ffff883f7fbfa580 2018-04-05 18:15:45 ksmd D ffff883f7fbb7c08 0 409 2 0x00080000 2018-04-05 18:15:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2018-04-05 18:15:45 Not tainted 4.4.126+557-ph #1 2018-04-05 18:15:45 INFO: task ksmd:409 blocked for more than 120 seconds. 2018-04-05 18:17:45 Leftover inexact backtrace: 2018-04-05 18:17:45 2018-04-05 18:17:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:17:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 2018-04-05 18:17:45 [<ffffffff811d71c6>] SyS_write+0x46/0xa0 2018-04-05 18:17:45 [<ffffffff811d60a9>] vfs_write+0xa9/0x190 2018-04-05 18:17:45 [<ffffffff811d548b>] __vfs_write+0x2b/0x130 2018-04-05 18:17:45 [<ffffffff81250903>] kernfs_fop_write+0x143/0x180 2018-04-05 18:17:45 [<ffffffff81250d5c>] sysfs_kf_write+0x3c/0x50 2018-04-05 18:17:45 [<ffffffff813d44d2>] kobj_attr_store+0x12/0x20 2018-04-05 18:17:45 [<ffffffff811b21c8>] run_store+0x48/0x2c0 2018-04-05 18:17:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 2018-04-05 18:17:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 2018-04-05 18:17:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 2018-04-05 18:17:45 [<ffffffff816e15f5>] schedule+0x35/0x80 2018-04-05 18:17:45 Call Trace: 2018-04-05 18:17:45 ffffffff81e8d588 ffff883e8d0afd20 ffffffff816e15f5 ffffffff81e8d580 2018-04-05 18:17:45 ffff883e8d0b0000 ffffffff81e8d584 ffff887f7a228000 00000000ffffffff 2018-04-05 18:17:45 ffff883e8d0afd08 ffffffff811d3ca2 ffff883e0000001e ffff887f7a228000 2018-04-05 18:17:45 ksmtuned D ffff883e8d0afd08 0 2259 1 0x00080000 2018-04-05 18:17:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2018-04-05 18:17:45 Not tainted 4.4.126+557-ph #1 2018-04-05 18:17:45 INFO: task ksmtuned:2259 blocked for more than 120 seconds. 2018-04-05 18:17:45 [<ffffffff810a49f0>] ? kthread_park+0x60/0x60 2018-04-05 18:17:45 Leftover inexact backtrace: 2018-04-05 18:17:45 2018-04-05 18:17:45 DWARF2 unwinder stuck at ret_from_fork+0x55/0x80 2018-04-05 18:17:45 [<ffffffff816e60c5>] ret_from_fork+0x55/0x80 2018-04-05 18:17:45 [<ffffffff810a4add>] kthread+0xed/0x110 2018-04-05 18:17:45 [<ffffffff811b32c5>] ksm_scan_thread+0x85/0x1b0 2018-04-05 18:17:45 [<ffffffff811b2adb>] ksm_do_scan+0x69b/0xe00 2018-04-05 18:17:45 [<ffffffff8116b18d>] lru_add_drain_all+0x13d/0x190 2018-04-05 18:17:45 [<ffffffff8109ecae>] flush_work+0xfe/0x170 2018-04-05 18:17:45 [<ffffffff816e2998>] wait_for_completion+0xa8/0x110 2018-04-05 18:17:45 [<ffffffff816e4a4a>] schedule_timeout+0x23a/0x2d0 2018-04-05 18:17:45 [<ffffffff816e15f5>] schedule+0x35/0x80 2018-04-05 18:17:45 Call Trace: 2018-04-05 18:17:45 0000000000000038 ffff883f7fbb7c20 ffffffff816e15f5 7fffffffffffffff 2018-04-05 18:17:45 ffff883f7fbb8000 ffff883f7fbb7d58 ffff883f7fbb7d50 ffff883f7fbfa580 2018-04-05 18:17:45 ffff883f7fbb7c08 ffff887f7dad81c0 ffff883f00000031 ffff883f7fbfa580 2018-04-05 18:17:45 ksmd D ffff883f7fbb7c08 0 409 2 0x00080000 2018-04-05 18:17:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2018-04-05 18:17:45 INFO: task ksmd:409 blocked for more than 120 seconds. Greets, Stefan -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe(a)opensuse.org To contact the owner, e-mail: opensuse-kernel+owner(a)opensuse.org

5 9

Re: [opensuse-kernel] SLES12-SP3 or opensuse 42.3 deadlocks under memory pressure?
by Stefan Priebe - Profihost AG 09 Apr '18

09 Apr '18

Am 09.04.2018 um 19:29 schrieb Michal Hocko: > On Mon 09-04-18 16:39:11, Stefan Priebe - Profihost AG wrote: >> >> Am 09.04.2018 um 16:19 schrieb Michal Hocko: >>> On Mon 09-04-18 16:05:09, Vlastimil Babka wrote: >>>> On 04/06/2018 08:07 PM, Stefan Priebe - Profihost AG wrote: >>>>> Hello, >>>>> >>>>> under memory pressure on a hypervisor running ksmd i had two deadlocks >>>>> today where the machines rebootet due to lockups. >>>> >>>> I see some of them wait in lru_add_drain_all(), I recall some recent >>>> issues with that upstream, Michal might know more, adding to CC. >>> >>> Right. There were some locking changes which cure theoretical deadlocks >>> on cpu hotplug locks. Then we have created a dedicated workqueue for lru >>> draining (ce612879ddc78). Traces below show that lru_add_drain_all is >>> blocked waiting for a kworker to finish its job. If there are many work >>> items and all the kworkers are busy then it can take quite some time. >>> ksm_scan_thread shouldn't be critical to the system operation so I do >>> not think that the lru_add_drain_all is really a bottle neck here. I >>> suspect that it just shows up as a victim of the overal problem with the >>> system. How many workers are there and how busy they are? Sysrq+t should >>> display that IIRC. >>> >>> Other tasks seem to be in the VFS layer (maybe i_mutex) lock. Hard to >>> tell who they are waiting for from the given list. >> >> I had this trace on 3 different Servers in a row while they all had >> memory pressure due to a lot of virtual machine migrations. All of them >> are production servers so i'm not really willing to reproduce this... >> >> Might it help to post the traces from the other two servers as well? > > There is always chance there will be some pattern there. Btw. what is > the hypervisor. I was not on the CC from the beginning so so if this has > been answered already. Hypervisor is kvm / qemu - but i sadly can't prodide the other logs. A collegue delered the history on the weekend to fix a reverse order bug in our netconsole server. Sorry. So i'll post again if i see this error again. Greets. Stefan -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe(a)opensuse.org To contact the owner, e-mail: opensuse-kernel+owner(a)opensuse.org

1 0

Re: [opensuse-kernel] SLES12-SP3 or opensuse 42.3 deadlocks under memory pressure?
by Stefan Priebe - Profihost AG 09 Apr '18

09 Apr '18

Am 09.04.2018 um 16:19 schrieb Michal Hocko: > On Mon 09-04-18 16:05:09, Vlastimil Babka wrote: >> On 04/06/2018 08:07 PM, Stefan Priebe - Profihost AG wrote: >>> Hello, >>> >>> under memory pressure on a hypervisor running ksmd i had two deadlocks >>> today where the machines rebootet due to lockups. >> >> I see some of them wait in lru_add_drain_all(), I recall some recent >> issues with that upstream, Michal might know more, adding to CC. > > Right. There were some locking changes which cure theoretical deadlocks > on cpu hotplug locks. Then we have created a dedicated workqueue for lru > draining (ce612879ddc78). Traces below show that lru_add_drain_all is > blocked waiting for a kworker to finish its job. If there are many work > items and all the kworkers are busy then it can take quite some time. > ksm_scan_thread shouldn't be critical to the system operation so I do > not think that the lru_add_drain_all is really a bottle neck here. I > suspect that it just shows up as a victim of the overal problem with the > system. How many workers are there and how busy they are? Sysrq+t should > display that IIRC. > > Other tasks seem to be in the VFS layer (maybe i_mutex) lock. Hard to > tell who they are waiting for from the given list. I had this trace on 3 different Servers in a row while they all had memory pressure due to a lot of virtual machine migrations. All of them are production servers so i'm not really willing to reproduce this... Might it help to post the traces from the other two servers as well? Stefan > >>> Kernel was build from commit: >>> 4fe1fb26557d69a4d0397113eb89d2dd7d6021b4 >>> >>> What i could grab from netconsole is: >> >> Let me paste after running via tac to fix the reversed order of lines: >> >> 18:17:45 INFO: task ksmd:409 blocked for more than 120 seconds. >> 18:17:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >> 18:17:45 ksmd D ffff883f7fbb7c08 0 409 2 0x00080000 >> 18:17:45 ffff883f7fbb7c08 ffff887f7dad81c0 ffff883f00000031 ffff883f7fbfa580 >> 18:17:45 ffff883f7fbb8000 ffff883f7fbb7d58 ffff883f7fbb7d50 ffff883f7fbfa580 >> 18:17:45 0000000000000038 ffff883f7fbb7c20 ffffffff816e15f5 7fffffffffffffff >> 18:17:45 Call Trace: >> 18:17:45 [<ffffffff816e15f5>] schedule+0x35/0x80 >> 18:17:45 [<ffffffff816e4a4a>] schedule_timeout+0x23a/0x2d0 >> 18:17:45 [<ffffffff816e2998>] wait_for_completion+0xa8/0x110 >> 18:17:45 [<ffffffff8109ecae>] flush_work+0xfe/0x170 >> 18:17:45 [<ffffffff8116b18d>] lru_add_drain_all+0x13d/0x190 >> 18:17:45 [<ffffffff811b2adb>] ksm_do_scan+0x69b/0xe00 >> 18:17:45 [<ffffffff811b32c5>] ksm_scan_thread+0x85/0x1b0 >> 18:17:45 [<ffffffff810a4add>] kthread+0xed/0x110 >> 18:17:45 [<ffffffff816e60c5>] ret_from_fork+0x55/0x80 >> 18:17:45 DWARF2 unwinder stuck at ret_from_fork+0x55/0x80 >> 18:17:45 >> 18:17:45 Leftover inexact backtrace: >> 18:17:45 [<ffffffff810a49f0>] ? kthread_park+0x60/0x60 >> 18:17:45 INFO: task ksmtuned:2259 blocked for more than 120 seconds. >> 18:17:45 Not tainted 4.4.126+557-ph #1 >> 18:17:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >> 18:17:45 ksmtuned D ffff883e8d0afd08 0 2259 1 0x00080000 >> 18:17:45 ffff883e8d0afd08 ffffffff811d3ca2 ffff883e0000001e ffff887f7a228000 >> 18:17:45 ffff883e8d0b0000 ffffffff81e8d584 ffff887f7a228000 00000000ffffffff >> 18:17:45 ffffffff81e8d588 ffff883e8d0afd20 ffffffff816e15f5 ffffffff81e8d580 >> 18:17:45 Call Trace: >> 18:17:45 [<ffffffff816e15f5>] schedule+0x35/0x80 >> 18:17:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 >> 18:17:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 >> 18:17:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 >> 18:17:45 [<ffffffff811b21c8>] run_store+0x48/0x2c0 >> 18:17:45 [<ffffffff813d44d2>] kobj_attr_store+0x12/0x20 >> 18:17:45 [<ffffffff81250d5c>] sysfs_kf_write+0x3c/0x50 >> 18:17:45 [<ffffffff81250903>] kernfs_fop_write+0x143/0x180 >> 18:17:45 [<ffffffff811d548b>] __vfs_write+0x2b/0x130 >> 18:17:45 [<ffffffff811d60a9>] vfs_write+0xa9/0x190 >> 18:17:45 [<ffffffff811d71c6>] SyS_write+0x46/0xa0 >> 18:17:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:17:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:17:45 >> 18:17:45 Leftover inexact backtrace: >> 18:15:45 INFO: task ksmd:409 blocked for more than 120 seconds. >> 18:15:45 Not tainted 4.4.126+557-ph #1 >> 18:15:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >> 18:15:45 ksmd D ffff883f7fbb7c08 0 409 2 0x00080000 >> 18:15:45 ffff883f7fbb7c08 ffff887f7dad81c0 ffff883f00000031 ffff883f7fbfa580 >> 18:15:45 ffff883f7fbb8000 ffff883f7fbb7d58 ffff883f7fbb7d50 ffff883f7fbfa580 >> 18:15:45 0000000000000038 ffff883f7fbb7c20 ffffffff816e15f5 7fffffffffffffff >> 18:15:45 Call Trace: >> 18:15:45 [<ffffffff816e15f5>] schedule+0x35/0x80 >> 18:15:45 [<ffffffff816e4a4a>] schedule_timeout+0x23a/0x2d0 >> 18:15:45 [<ffffffff816e2998>] wait_for_completion+0xa8/0x110 >> 18:15:45 [<ffffffff8109ecae>] flush_work+0xfe/0x170 >> 18:15:45 [<ffffffff8116b18d>] lru_add_drain_all+0x13d/0x190 >> 18:15:45 [<ffffffff811b2adb>] ksm_do_scan+0x69b/0xe00 >> 18:15:45 [<ffffffff811b32c5>] ksm_scan_thread+0x85/0x1b0 >> 18:15:45 [<ffffffff810a4add>] kthread+0xed/0x110 >> 18:15:45 [<ffffffff816e60c5>] ret_from_fork+0x55/0x80 >> 18:15:45 DWARF2 unwinder stuck at ret_from_fork+0x55/0x80 >> 18:15:45 >> 18:15:45 Leftover inexact backtrace: >> 18:15:45 [<ffffffff810a49f0>] ? kthread_park+0x60/0x60 >> 18:15:45 INFO: task ksmtuned:2259 blocked for more than 120 seconds. >> 18:15:45 Not tainted 4.4.126+557-ph #1 >> 18:15:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >> 18:15:45 ksmtuned D ffff883e8d0afd08 0 2259 1 0x00080000 >> 18:15:45 ffff883e8d0afd08 ffffffff811d3ca2 ffff883e0000001e ffff887f7a228000 >> 18:15:45 ffff883e8d0b0000 ffffffff81e8d584 ffff887f7a228000 00000000ffffffff >> 18:15:45 ffffffff81e8d588 ffff883e8d0afd20 ffffffff816e15f5 ffffffff81e8d580 >> 18:15:45 Call Trace: >> 18:15:45 [<ffffffff816e15f5>] schedule+0x35/0x80 >> 18:15:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 >> 18:15:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 >> 18:15:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 >> 18:15:45 [<ffffffff811b21c8>] run_store+0x48/0x2c0 >> 18:15:45 [<ffffffff813d44d2>] kobj_attr_store+0x12/0x20 >> 18:15:45 [<ffffffff81250d5c>] sysfs_kf_write+0x3c/0x50 >> 18:15:45 [<ffffffff81250903>] kernfs_fop_write+0x143/0x180 >> 18:15:45 [<ffffffff811d548b>] __vfs_write+0x2b/0x130 >> 18:15:45 [<ffffffff811d60a9>] vfs_write+0xa9/0x190 >> 18:15:45 [<ffffffff811d71c6>] SyS_write+0x46/0xa0 >> 18:15:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:15:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:15:45 >> 18:15:45 Leftover inexact backtrace: >> 18:15:45 INFO: task pve-firewall:2914 blocked for more than 120 seconds. >> 18:15:45 Not tainted 4.4.126+557-ph #1 >> 18:15:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >> 18:15:45 pve-firewall D ffff887f69793c98 0 2914 1 0x00080000 >> 18:15:45 ffff887f69793c98 ffff887f69793c68 ffffffff00000035 ffff887f735a0000 >> 18:15:45 ffff887f69794000 ffff887f69748364 ffff887f735a0000 00000000ffffffff >> 18:15:45 ffff887f69748368 ffff887f69793cb0 ffffffff816e15f5 ffff887f69748360 >> 18:15:45 Call Trace: >> 18:15:45 [<ffffffff816e15f5>] schedule+0x35/0x80 >> 18:15:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 >> 18:15:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 >> 18:15:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 >> 18:15:45 [<ffffffff811e2ef4>] path_openat+0x3b4/0x1200 >> 18:15:45 [<ffffffff811e591e>] do_filp_open+0x7e/0xe0 >> 18:15:45 [<ffffffff811d504c>] do_sys_open+0x12c/0x210 >> 18:15:45 [<ffffffff811d514e>] SyS_open+0x1e/0x20 >> 18:15:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:15:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:15:45 >> 18:15:45 Leftover inexact backtrace: >> 18:13:45 INFO: task pve-firewall:2914 blocked for more than 120 seconds. >> 18:13:45 Not tainted 4.4.126+557-ph #1 >> 18:13:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >> 18:13:45 pve-firewall D ffff887f69793c98 0 2914 1 0x00080000 >> 18:13:45 ffff887f69793c98 ffff887f69793c68 ffffffff00000035 ffff887f735a0000 >> 18:13:45 ffff887f69794000 ffff887f69748364 ffff887f735a0000 00000000ffffffff >> 18:13:45 ffff887f69748368 ffff887f69793cb0 ffffffff816e15f5 ffff887f69748360 >> 18:13:45 Call Trace: >> 18:13:45 [<ffffffff816e15f5>] schedule+0x35/0x80 >> 18:13:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 >> 18:13:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 >> 18:13:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 >> 18:13:45 [<ffffffff811e2ef4>] path_openat+0x3b4/0x1200 >> 18:13:45 [<ffffffff811e591e>] do_filp_open+0x7e/0xe0 >> 18:13:45 [<ffffffff811d504c>] do_sys_open+0x12c/0x210 >> 18:13:45 [<ffffffff811d514e>] SyS_open+0x1e/0x20 >> 18:13:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:13:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:13:45 >> 18:13:45 Leftover inexact backtrace: >> 18:11:45 INFO: task pve-firewall:2914 blocked for more than 120 seconds. >> 18:11:45 Not tainted 4.4.126+557-ph #1 >> 18:11:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >> 18:11:45 pve-firewall D ffff887f69793c98 0 2914 1 0x00080000 >> 18:11:45 ffff887f69793c98 ffff887f69793c68 ffffffff00000035 ffff887f735a0000 >> 18:11:45 ffff887f69794000 ffff887f69748364 ffff887f735a0000 00000000ffffffff >> 18:11:45 ffff887f69748368 ffff887f69793cb0 ffffffff816e15f5 ffff887f69748360 >> 18:11:45 Call Trace: >> 18:11:45 [<ffffffff816e15f5>] schedule+0x35/0x80 >> 18:11:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 >> 18:11:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 >> 18:11:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 >> 18:11:45 [<ffffffff811e2ef4>] path_openat+0x3b4/0x1200 >> 18:11:45 [<ffffffff811e591e>] do_filp_open+0x7e/0xe0 >> 18:11:45 [<ffffffff811d504c>] do_sys_open+0x12c/0x210 >> 18:11:45 [<ffffffff811d514e>] SyS_open+0x1e/0x20 >> 18:11:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:11:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:11:45 >> 18:11:45 Leftover inexact backtrace: >> 18:09:45 INFO: task pve-firewall:2914 blocked for more than 120 seconds. >> 18:09:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >> 18:09:45 pve-firewall D ffff887f69793c98 0 2914 1 0x00080000 >> 18:09:45 ffff887f69793c98 ffff887f69793c68 ffffffff00000035 ffff887f735a0000 >> 18:09:45 ffff887f69794000 ffff887f69748364 ffff887f735a0000 00000000ffffffff >> 18:09:45 ffff887f69748368 ffff887f69793cb0 ffffffff816e15f5 ffff887f69748360 >> 18:09:45 Call Trace: >> 18:09:45 [<ffffffff816e15f5>] schedule+0x35/0x80 >> 18:09:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 >> 18:09:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 >> 18:09:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 >> 18:09:45 [<ffffffff811e2ef4>] path_openat+0x3b4/0x1200 >> 18:09:45 [<ffffffff811e591e>] do_filp_open+0x7e/0xe0 >> 18:09:45 [<ffffffff811d504c>] do_sys_open+0x12c/0x210 >> 18:09:45 [<ffffffff811d514e>] SyS_open+0x1e/0x20 >> 18:09:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:09:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:09:45 >> 18:09:45 Leftover inexact backtrace: >> 18:07:45 INFO: task pve-firewall:2914 blocked for more than 120 seconds. >> 18:07:45 ffff887f69793c98 ffff887f69793c68 ffffffff00000035 ffff887f735a0000 >> 18:07:45 ffff887f69794000 ffff887f69748364 ffff887f735a0000 00000000ffffffff >> 18:07:45 ffff887f69748368 ffff887f69793cb0 ffffffff816e15f5 ffff887f69748360 >> 18:07:45 Call Trace: >> 18:07:45 [<ffffffff816e15f5>] schedule+0x35/0x80 >> 18:07:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 >> 18:07:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 >> 18:07:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 >> 18:07:45 [<ffffffff811e2ef4>] path_openat+0x3b4/0x1200 >> 18:07:45 [<ffffffff811e591e>] do_filp_open+0x7e/0xe0 >> 18:07:45 [<ffffffff811d504c>] do_sys_open+0x12c/0x210 >> 18:07:45 [<ffffffff811d514e>] SyS_open+0x1e/0x20 >> 18:07:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:07:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:07:45 >> 18:07:45 Leftover inexact backtrace: >> 18:05:45 INFO: task pve-firewall:2914 blocked for more than 120 seconds. >> 18:05:45 Not tainted 4.4.126+557-ph #1 >> 18:05:45 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. >> 18:05:45 pve-firewall D ffff887f69793c98 0 2914 1 0x00080000 >> 18:05:45 ffff887f69793c98 ffff887f69793c68 ffffffff00000035 ffff887f735a0000 >> 18:05:45 ffff887f69794000 ffff887f69748364 ffff887f735a0000 00000000ffffffff >> 18:05:45 ffff887f69748368 ffff887f69793cb0 ffffffff816e15f5 ffff887f69748360 >> 18:05:45 Call Trace: >> 18:05:45 [<ffffffff816e15f5>] schedule+0x35/0x80 >> 18:05:45 [<ffffffff816e18fe>] schedule_preempt_disabled+0xe/0x10 >> 18:05:45 [<ffffffff816e3325>] __mutex_lock_slowpath+0x95/0x110 >> 18:05:45 [<ffffffff816e33b7>] mutex_lock+0x17/0x30 >> 18:05:45 [<ffffffff811e2ef4>] path_openat+0x3b4/0x1200 >> 18:05:45 [<ffffffff811e591e>] do_filp_open+0x7e/0xe0 >> 18:05:45 [<ffffffff811d504c>] do_sys_open+0x12c/0x210 >> 18:05:45 [<ffffffff811d514e>] SyS_open+0x1e/0x20 >> 18:05:45 [<ffffffff816e5c85>] entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:05:45 DWARF2 unwinder stuck at entry_SYSCALL_64_fastpath+0x1e/0xc9 >> 18:05:45 >> 18:05:45 Leftover inexact backtrace: > -- To unsubscribe, e-mail: opensuse-kernel+unsubscribe(a)opensuse.org To contact the owner, e-mail: opensuse-kernel+owner(a)opensuse.org

1 0

[opensuse-kernel] Problems with Intel wlan 3160 on kernel 4.16
by Manfred Hollstein 09 Apr '18

09 Apr '18

Hi there, my Intel wlan device 3160 (rev 83) on a Kaby Lake chipset used to work properly up to 4.15.* On 4.16 loading the "iwlwifi" driver fails with the following: iwlwifi 0000:06:00.0: hwdev DMA mask = 0x0000000fffffffff, dev_addr = 0x0000000079d83000 iwlwifi 0000:06:00.0: swiotlb: coherent allocation failed, size=4096 iwl_pcie_alloc_ict+0x7c/0xf0 [iwlwifi] iwl_trans_pcie_alloc+0x7c4/0xc70 [iwlwifi] iwl_pci_probe+0x18/0x1b0 [iwlwifi] iwl_pci_register_driver+0x20/0x40 [iwlwifi] iwlwifi: probe of 0000:06:00.0 failed with error -12 I found some messages in the internet describing that unloading the driver, followed by a modprobe worked for some people around rc1 time. When I try this, I get a call trace, and the hardware still does not work. Does this ring a bell for anybody? Shall I create a bugzilla? FWIW, this is with 4.16.0-3.g2592f12-default from Kernel:stable Thx, cheers. l8er manfred

2 2

Re: [opensuse-kernel] Problem with memory allocation / management on SLES 11 SP4
by Lukáš Krejza 06 Apr '18

06 Apr '18

Dne pátek 6. dubna 2018 14:17:17 CEST, Michal Hocko napsal(a): > On Fri 06-04-18 13:36:47, Lukáš Krejza wrote: > [...] > > > So, the main advice that has led me to the resolution was, that i should > > use "/proc/PID/limits" directly, instead of "ulimit -a" invoked as mysql > > user. Thank you very much! > > Good to hear! It smelled very much like a different start up > configuration. Is this something to be handled for all users? In other > words, worth filing a bug against SLES and see whether we should do the > same thing in general? Please note that I am not really sure which part > is distro and what is the 3rd party land so maybe this would be > something for the vendor rather than distro. > > Just my 2c Well, this is directly related to our configuration of openais/corosync/ heartbeat, so i do not think it needs any fixing in SLES, unless SLES provides some own configuration for high availability services (which i think it does not) or unless mysql service should _not_ inherit limits from openais/ corosync/heartbeat process. Anyway, thanks again very much for the support. Regards Lukáš

1 0

Re: [opensuse-kernel] Problem with memory allocation / management on SLES 11 SP4
by Lukáš Krejza 06 Apr '18

06 Apr '18

Dne čtvrtek 5. dubna 2018 11:13:31 CEST, Michal Hocko napsal(a): > On Wed 04-04-18 15:12:33, Lukáš Krejza wrote: > > Dear list, > > > > We are facing a strange behaviour regarding memory allocation for mysqld ( > > MySQL community release 5.7.21 ) on SLES 11 SP4. > > > > We have a database server ( tested on both virtualized and bare metal > > hardware ) with 24GB of RAM and 8GB of swap. This mysqld is configured > > for our special needs ( not many connections, but there could be 1 - 2 > > transactions that needs big caches and 512MB tmp table in memory, ... ). > > We are hosting it on RHEL 7 and SLES 11 SP4. On RHEL, everything is > > working smoothly, but on SLES, we are getting constant out of memory > > messages from mysqld (nor from kernel) and mysqld crashes. > > Are there any trace in the kernel log? Can you trace the allocation > failre from mysql? No, there is not a single message regarding memory allocation in both dmesg and /var/log/messages. Only in mysqld.log. > > > During investigation, i have noticed, that RHEL apparently allows to > > allocate more memory than actually available ( the mysqld uses roughly 20 > > - 40% of the allocated memory ). I first thought that this is a feature > > enabled in RHEL and disabled in SLES ( i have found out that the feature > > name is "memory overcommit" ), but it is set exactly the same on RHEL and > > on SLES, so the issue must be elsewhere (but anyway, i have tried to set > > vm.overcommit_ratio = 100, vm.overcommit_memory = 1, but without any > > change) . > > Hmm overcommit_memory = 1 should rule the overcommit management > completely out of picture. Thanks for confirmation. > > > So, i would like to ask anyone with knowledge of linux kernel memory > > management and knowledge of SLES 11 kernel or mysqld, to give us any > > advice on why is SLES acting differently than RHEL. > > > > Some debug info: > > > > top, free, mysqld.log, /proc/meminfo and ulimit -a shortly before the > > crash: https://paste.opensuse.org/24626549 > > What are ulimits for the mysql process? /proc/pid/limits should tell > you. Maybe there are different configurations depending on the detected > OS? https://paste.opensuse.org/56447994 There could be a problem. Why do i get "unlimited" from "ulimit -a" when switched to mysql user, but in /proc/PID/limits i get "Max address space 26853785600"? This has led me to following investigation: I started launching mysqld via various different ways (we are using openais clustering solution) 1) First i tried to launch mysqld from mysql user directly. The issue was gone and /proc/PID/limits showed Max address space: "unlimited". 2) Then i tried to launch it via a "service". The issue was again "fixed" with same symptoms as in 1) 3) Then i tried to launch it again by crm (openais). The /proc/PID/limits now showed Max address space: "26853785600"! So i revised our openais configuration and i noticed, that on RHEL, we are using "primitive service:mysql" which in turn invokes "service mysql start", but on SLES, we are using "primitive mysql", which launches mysqld (mysqld_safe) directly. This most probably (if my assumption is correct) led to the fact, that mysqld inherited limits from openais user "hacluster" - which are default. After changing "primitive mysql" to "primitive service:mysql" in openais configuration, everything started working correctly. Currently, mysqld is running with over 48 GB of RAM allocated: https://paste.opensuse.org/37596511 And everything runs smooth and fast. So, the main advice that has led me to the resolution was, that i should use "/proc/PID/limits" directly, instead of "ulimit -a" invoked as mysql user. Thank you very much! > > It would be also useful to catch strace log of mysql at the time when > the allocation fails. Not needed anymore - issue is solved :).

1 0

[opensuse-kernel] Problem with memory allocation / management on SLES 11 SP4
by Lukáš Krejza 04 Apr '18

04 Apr '18

Dear list, We are facing a strange behaviour regarding memory allocation for mysqld ( MySQL community release 5.7.21 ) on SLES 11 SP4. We have a database server ( tested on both virtualized and bare metal hardware ) with 24GB of RAM and 8GB of swap. This mysqld is configured for our special needs ( not many connections, but there could be 1 - 2 transactions that needs big caches and 512MB tmp table in memory, ... ). We are hosting it on RHEL 7 and SLES 11 SP4. On RHEL, everything is working smoothly, but on SLES, we are getting constant out of memory messages from mysqld (nor from kernel) and mysqld crashes. During investigation, i have noticed, that RHEL apparently allows to allocate more memory than actually available ( the mysqld uses roughly 20 - 40% of the allocated memory ). I first thought that this is a feature enabled in RHEL and disabled in SLES ( i have found out that the feature name is "memory overcommit" ), but it is set exactly the same on RHEL and on SLES, so the issue must be elsewhere (but anyway, i have tried to set vm.overcommit_ratio = 100, vm.overcommit_memory = 1, but without any change) . So, i would like to ask anyone with knowledge of linux kernel memory management and knowledge of SLES 11 kernel or mysqld, to give us any advice on why is SLES acting differently than RHEL. Some debug info: top, free, mysqld.log, /proc/meminfo and ulimit -a shortly before the crash: https://paste.opensuse.org/24626549 mysql "show variables like '%buffer%'; show variables like '%cache%';" https://paste.opensuse.org/58205484 mysql buffer pool and some other info: https://paste.opensuse.org/56264627 https://paste.opensuse.org/48434446 And some of the mysqld backtraces: https://paste.opensuse.org/88004779 The symptoms and steps to reproduce are: 1) Start mysqld 2) in top, VIRT immidiatelly raises to 21 GB, RES about 2 GB, %MEM is on 11% 3) In about 5 minutes, VIRT raises to 25 GB, RES to 4-5 GB and %MEM to about 19% 4) Now i start getting messages in mysqld log "[ERROR] /usr/sbin/mysqld: Out of memory (Needed 269312 bytes)", but "free" utility reports still 17 GB of ram free (and 0GB of swap used) 5) mysqld crashes On my last try, i got crash at: 19.3% MEM, 25G VIRT, 4.5G RES but, free reported: Mem: 24018M total, 7679M used, 16339M free, 104M buffers, Swap: 7993M total, 0M used, 7993M free, 2331M cached So, i am lost here. What exactly denies mysqld more memory and what are the possible configuration (kernel most probably, since RHEL works without problems) options for memory allocation? Thanks anyone for your time to think about this. I have already tried to solve this with some of the mysql experts, but with no outcome. Best regards Lukáš Krejza

1 0