~carstengrohmann/OOMAnalyser#1: 
ERROR: Failed to extract kernel version from OOM text

Kind of expected it to parse this, from CentOS. Or at least give me instructions if I'm pasting in the wrong values somehow? Cheers!

[2003902.896009] salt-minion invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0
[2003902.896689] salt-minion cpuset=/ mems_allowed=0-1
[2003902.897143] CPU: 5 PID: 3000 Comm: salt-minion Kdump: loaded Tainted: G        W      ------------   3.10.0-1160.6.1.el7.x86_64 <a href="/~carstengrohmann/OOMAnalyser/1" title="~carstengrohmann/OOMAnalyser#1: ERROR: Failed to extract kernel version from OOM text">#1</a>
[2003902.898035] Hardware name: HP ProLiant DL380 Gen9/ProLiant DL380 Gen9, BIOS P89 07/21/2019
[2003902.898704] Call Trace:
[2003902.899165]  [<ffffffff93181400>] dump_stack+0x19/0x1b
[2003902.900973]  [<ffffffff9317bd20>] dump_header+0x90/0x229
[2003902.903162]  [<ffffffff92b063b2>] ? ktime_get_ts64+0x52/0xf0
[2003902.903640]  [<ffffffff92b5dbcf>] ? delayacct_end+0x8f/0xb0
[2003902.904114]  [<ffffffff92bc20cd>] oom_kill_process+0x2cd/0x490
[2003902.904590]  [<ffffffff92bc1abd>] ? oom_unkillable_task+0xcd/0x120
[2003902.905070]  [<ffffffff92bc27ba>] out_of_memory+0x31a/0x500
[2003902.905564]  [<ffffffff9317c83d>] __alloc_pages_slowpath+0x5db/0x729
[2003902.906056]  [<ffffffff92bc8db6>] __alloc_pages_nodemask+0x436/0x450
[2003902.906553]  [<ffffffff92c18a18>] alloc_pages_current+0x98/0x110
[2003902.907048]  [<ffffffff92bbdb87>] __page_cache_alloc+0x97/0xb0
[2003902.907549]  [<ffffffff92bc0b20>] filemap_fault+0x270/0x420
[2003902.908092]  [<ffffffffc048591e>] __xfs_filemap_fault+0x7e/0x1d0 [xfs]
[2003902.908629]  [<ffffffffc0485b1c>] xfs_filemap_fault+0x2c/0x30 [xfs]
[2003902.909150]  [<ffffffff92bede7a>] __do_fault.isra.61+0x8a/0x100
[2003902.909676]  [<ffffffff92bee42c>] do_read_fault.isra.63+0x4c/0x1b0
[2003902.910211]  [<ffffffff92bf5c70>] handle_mm_fault+0xa20/0xfb0
[2003902.910746]  [<ffffffff93186d4f>] ? __schedule+0x3af/0x860
[2003902.911282]  [<ffffffff9318f653>] __do_page_fault+0x213/0x500
[2003902.912022]  [<ffffffff9318f975>] do_page_fault+0x35/0x90
[2003902.912570]  [<ffffffff9318b778>] page_fault+0x28/0x30
[2003902.913102] Mem-Info:
[2003902.913815] active_anon:20439232 inactive_anon:11064761 isolated_anon:0
 active_file:2735 inactive_file:4097 isolated_file:0
 unevictable:0 dirty:4 writeback:198 unstable:0
 slab_reclaimable:205034 slab_unreclaimable:51897
 mapped:11464 shmem:14447592 pagetables:39090 bounce:0
 free:88803 free_pcp:33 free_cma:0
[2003902.916966] Node 0 DMA free:15748kB min:8kB low:8kB high:12kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15996kB managed:15908kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:160kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
[2003902.919862] lowmem_reserve[]: 0 1661 64103 64103
[2003902.920527] Node 0 DMA32 free:250816kB min:1160kB low:1448kB high:1740kB active_anon:1140996kB inactive_anon:96960kB active_file:0kB inactive_file:280kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1940480kB managed:1701100kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:145116kB slab_reclaimable:178704kB slab_unreclaimable:17104kB kernel_stack:976kB pagetables:564kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:1329 all_unreclaimable? yes
[2003902.924108] lowmem_reserve[]: 0 0 62442 62442
[2003902.924884] Node 0 Normal free:43512kB min:43744kB low:54680kB high:65616kB active_anon:41970892kB inactive_anon:19288868kB active_file:928kB inactive_file:4908kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:65011712kB managed:63943592kB mlocked:0kB dirty:0kB writeback:0kB mapped:8176kB shmem:24843808kB slab_reclaimable:355096kB slab_unreclaimable:91756kB kernel_stack:34128kB pagetables:79108kB unstable:0kB bounce:0kB free_pcp:76kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:11479 all_unreclaimable? yes
[2003902.929057] lowmem_reserve[]: 0 0 0 0
[2003902.929886] Node 1 Normal free:45136kB min:45192kB low:56488kB high:67788kB active_anon:38645040kB inactive_anon:24873216kB active_file:10044kB inactive_file:11200kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:67108864kB managed:66056508kB mlocked:0kB dirty:16kB writeback:792kB mapped:37696kB shmem:32801444kB slab_reclaimable:286336kB slab_unreclaimable:98568kB kernel_stack:15168kB pagetables:76688kB unstable:0kB bounce:0kB free_pcp:76kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:50641 all_unreclaimable? yes
[2003902.934247] lowmem_reserve[]: 0 0 0 0
[2003902.935149] Node 0 DMA: 1*4kB (U) 0*8kB 0*16kB 0*32kB 0*64kB 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15748kB
[2003902.937037] Node 0 DMA32: 8760*4kB (UEM) 2925*8kB (UEM) 2031*16kB (UEM) 440*32kB (UEM) 380*64kB (UEM) 144*128kB (UEM) 84*256kB (UEM) 73*512kB (UEM) 43*1024kB (UEM) 0*2048kB 0*4096kB = 250680kB
[2003902.941331] Node 0 Normal: 11231*4kB (U) 46*8kB (UM) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 45292kB
[2003902.943402] Node 1 Normal: 11819*4kB (UEM) 116*8kB (UM) 2*16kB (U) 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 48236kB
[2003902.945529] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
[2003902.946612] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
[2003902.947685] Node 1 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
[2003902.948752] Node 1 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
[2003902.949811] 14456469 total pagecache pages
[2003902.950868] 0 pages in swap cache
[2003902.951922] Swap cache stats: add 0, delete 0, find 0/0
[2003902.952983] Free swap  = 0kB
[2003902.954042] Total swap = 0kB
[2003902.955099] 33519263 pages RAM
[2003902.956147] 0 pages HighMem/MovableOnly
[2003902.957195] 589986 pages reserved
[2003902.958231] [ pid ]   uid  tgid total_vm      rss nr_ptes swapents oom_score_adj name
[2003902.959700] [ 1020]     0  1020    31374    17534      67        0             0 systemd-journal
[2003902.963042] [ 1042]     0  1042    49643      113      29        0             0 lvmetad
[2003902.964104] [ 1058]     0  1058    11421      207      25        0         -1000 systemd-udevd
[2003902.965174] [ 1852]     0  1852    57040      436      64        0             0 abrtd
[2003902.966214] [ 1853]    32  1853    17314      147      37        0             0 rpcbind
[2003902.967231] [ 1854]   998  1854     2145       37      10        0             0 lsmd
[2003902.968224] [ 1856]     0  1856    13225      217      29        0             0 smartd
[2003902.969195] [ 1857]     0  1857   340140     4985     104        0             0 sophos_watchdog
[2003902.970159] [ 1885]   999  1885   155264     1672      67        0             0 polkitd
[2003902.971110] [ 1887]    38  1887    14003      189      32        0             0 ntpd
[2003902.972029] [ 1913]    81  1913    16735      195      40        0          -900 dbus-daemon
[2003902.972931] [ 1919]   991  1919   100752      849      52        0             0 CommsComponent
[2003902.973815] [ 1924]   993  1924   121848      978      58        0             0 sophos_manageme
[2003902.974678] [ 1929]   991  1929   218813     8626     108        0             0 python3
[2003902.975754] [ 1934]   993  1934    72914      294      63        0             0 sdu
[2003902.976602] [ 1937]     0  1937     5490      168      16        0             0 irqbalance
[2003902.977421] [ 1940]   993  1940   107185      266      55        0             0 tscheduler
[2003902.978217] [ 1943]   990  1943   170745      504      84        0             0 UpdateScheduler
[2003902.978996] [ 1951]   992  1951    65181      516      50        0             0 CommsComponent
[2003902.981281] [ 1956]     0  1956    57150      170      33        0             0 liveresponse
[2003902.982038] [ 1968]   993  1968   116697      717      44        0             0 eventjournaler
[2003902.982779] [ 1979]     0  1979    56466      371      62        0             0 abrt-watch-log
[2003902.983499] [ 1989]   993  1989   191882     4108      52        0             0 runtimedetectio
[2003902.984197] [ 2002]   989  2002   158758      982      58        0             0 av
[2003902.984875] [ 2031]     0  2031    67283      649      42        0             0 gssproxy
[2003902.985532] [ 2045]     0  2045    22651      232      47        0             0 rngd
[2003902.986184] [ 2139]     0  2139     1653       36       7        0             0 mcelog
[2003902.986819] [ 2243]   993  2243       38        1       3        0             0 runtimedetectio
[2003902.987437] [ 2291]     0  2291    10616      100      25        0             0 rpc.gssd
[2003902.988030] [ 2684]     0  2684    73845     4351      99        0             0 salt-minion
[2003902.988606] [ 2685]     0  2685   146052     3812     104        0             0 tuned
[2003902.989156] [ 2690]     0  2690    28234      258      58        0         -1000 sshd
[2003902.989687] [ 2715]     0  2715    14172      275      32        0             0 .vasd
[2003902.990194] [ 2771]     0  2771    14682     1302      32        0             0 .vasd
[2003902.990678] [ 2793]     0  2793    15873     2497      36        0             0 .vasd
[2003902.991142] [ 2984]     0  2984     8792       93      22        0             0 systemd-logind
[2003902.991616] [ 3000]     0  3000   172788    12390     151        0             0 salt-minion
[2003902.992093] [ 3024]    29  3024    11668      243      27        0             0 rpc.statd
[2003902.992773] [ 3042]     0  3042    24124      270      45        0             0 master
[2003902.993243] [ 3051]    89  3051    24771      280      49        0             0 qmgr
[2003902.993713] [ 3068]   982  3068     4099       42      13        0             0 fs_zabbix_agent
[2003902.994182] [ 3069]   982  3069     4099      652      13        0             0 fs_zabbix_agent
[2003902.994645] [ 3070]   982  3070     4099       41      12        0             0 fs_zabbix_agent
[2003902.995105] [ 3071]   982  3071     4099       41      12        0             0 fs_zabbix_agent
[2003902.995564] [ 3072]   982  3072     4099       41      12        0             0 fs_zabbix_agent
[2003902.996014] [ 3073]   982  3073     5149       59      15        0             0 fs_zabbix_agent
[2003902.996463] [ 3127]     0  3127    34321      180      24        0             0 crond
[2003902.996900] [ 3151]     0  3151    95124     5897     101        0             0 salt-minion
[2003902.997330] [ 3181]     0  3181     6477       53      18        0             0 atd
[2003902.997943] [ 3229]     0  3229    27552       31      10        0             0 agetty
[2003902.998369] [ 3534]     0  3534     2213       48      10        0             0 ssi
[2003902.998787] [ 3848]     0  3848  9522623   181262     549        0             0 java
[2003902.999206] [ 4153]   974  4153   111369    58804     200        0             0 splunkd
[2003903.002089] [ 4159]   974  4159    25879     2773      36        0             0 splunkd
[2003903.002515] [ 6359]   988  6359    75873      252      53        0             0 sophos_threat_d
[2003903.002940] [ 5751]     0  5751    28638       39      11        0             0 daemon
[2003903.003555] [ 5754]     0  5754    28644      374      12        0             0 fs-sync-appdyna
[2003903.003979] [ 6047]   918  6047    31870       57      17        0             0 daemon
[2003903.004599] [ 6049]   918  6049  1714673   107550     435        0             0 java
[2003903.005020] [16715]   919 16715  9396197  1356348    3824        0             0 java
[2003903.005638] [15995]     0 15995   354866     7211     130        0             0 edr
[2003903.006059] [16272]     0 16272    63203      258      31        0             0 rsyslogd
[2003903.006484] [11356]   919 11356 22244545 15248364   30990        0             0 java
[2003903.006911] [ 6879]     0  6879    14586      676      33        0             0 .vasd
[2003903.007340] [ 6880]     0  6880    14280      364      31        0             0 .vasd
[2003903.007763] [ 6881]     0  6881    13803      429      33        0             0 .vasd
[2003903.008187] [ 1410]     0  1410    35305      739      38        0             0 osqueryd
[2003903.008607] [ 1414]     0  1414   473222    32970     211        0             0 osqueryd.0
[2003903.009021] [ 1415]     0  1415   606781      797      91        0             0 SophosMTR.ext
[2003903.009641] [25834]    89 25834    24728      263      50        0             0 pickup
[2003903.010057] [10737]     0 10737    27014       24       9        0             0 sleep
[2003903.010471] [10774]   918 10774    28387      124      11        0             0 bash
[2003903.010880] [10783]   918 10783    28387      120      11        0             0 bash
[2003903.011284] [10784]   918 10784    28387      122      10        0             0 bash
[2003903.011686] [10785]   918 10785    28387      115      11        0             0 bash
[2003903.012079] [10786]   918 10786    29260       37      12        0             0 sed
[2003903.012470] [10787]   918 10787    27020       26      10        0             0 tr
[2003903.012854] [10789]   918 10789    28387      127      11        0             0 bash
[2003903.013236] [10790]   918 10790    28443       68      11        0             0 awk
[2003903.013617] [10791]   918 10791    28321       47      12        0             0 sh
[2003903.013991] Out of memory: Kill process 11356 (java) score 464 or sacrifice child
[2003903.016060] Killed process 11356 (java), UID 919, total-vm:88978180kB, anon-rss:60993456kB, file-rss:0kB, shmem-rss:0kB
[2066744.948646] st 9:0:0:0: Mode parameters changed
[2066745.048368] st 10:0:0:0: Mode parameters changed
[2066745.063562] st 10:0:4:0: Mode parameters changed
[2066745.136207] st 11:0:0:0: Mode parameters changed
[2066745.140859] st 11:0:1:0: Mode parameters changed
[2066745.148868] st 11:0:3:0: Mode parameters changed
[2066745.225492] st 12:0:2:0: Mode parameters changed
[2088068.476149]  rport-12:0-0: blocked FC remote port time out: removing target and saving binding
[2088185.316989] scsi 12:0:0:0: Sequential-Access STK      T10000D          4.09 PQ: 0 ANSI: 5
[2088185.333816] scsi 12:0:0:0: alua: disable for non-disk devices
[2088185.335178] scsi 12:0:0:0: alua: not attached
[2088185.336428] st 12:0:0:0: Attached scsi tape st46
[2088185.336958] st 12:0:0:0: st46: try direct i/o: yes (alignment 8 B)
[2088185.337869] st 12:0:0:0: Attached scsi generic sg55 type 1
[2102931.172276] st 12:0:0:0: Power-on or device reset occurred
[2102931.173930] st 12:0:0:0: [st46] Block limits 1 - 2097152 bytes.
Status
RESOLVED FIXED
Submitter
~rogerdpack
Assigned to
Submitted
2 years ago
Updated
1 year, 4 months ago
Labels
No labels applied.

~carstengrohmann 1 year, 5 months ago*

I am sorry that I am only now replying to the bug report.

The line with the kernel version contains garbage - this looks like an issue with the sourcehut software. I guess the right line would be (the space between # and 1 can be ignored):

[2003902.897143] CPU: 5 PID: 3000 Comm: salt-minion Kdump: loaded Tainted: G        W      ------------   3.10.0-1160.6.1.el7.x86_64 # 1

Is this line correct?

I changes the regular expression to detect the kernel version to match with your reported line. Please try the current version at https://www.carstengrohmann.de/oom/

There are two other issues with your OOM. I'll check both within the next days and update the bug report accordingly.

~carstengrohmann REPORTED FIXED 1 year, 4 months ago

The OOM Analyser extracts the kernel version in a first step to choose the best fitting configuration for extracting all further values. The kernel version will be extracted based on the third OOM line:

[2003902.897143] CPU: 5 PID: 3000 Comm: salt-minion Kdump: loaded Tainted: G        W      ------------   3.10.0-1160.6.1.el7.x86_64 # 1

The line in your OOM contains the unexpected sequence ------------. Therefore, the extraction fails and the message ERROR: Failed to extract kernel version from OOM text should be shown. This bug is fixed in 8db40b50.

A second issue prevented a further memory analysis. Not all lines of the Mem-Info block contains a prefix:

[2003902.913102] Mem-Info:
[2003902.913815] active_anon:20439232 inactive_anon:11064761 isolated_anon:0
 active_file:2735 inactive_file:4097 isolated_file:0
 unevictable:0 dirty:4 writeback:198 unstable:0
 slab_reclaimable:205034 slab_unreclaimable:51897
 mapped:11464 shmem:14447592 pagetables:39090 bounce:0
 free:88803 free_pcp:33 free_cma:0

That's expected. But the code to handle this case, was broken and unfortunatelly the corresponding test also. The changeset e7bef145 solves this issue.

The current version now fully analyzes the example in this ticket.

The OOM analyzer uses complex regular expressions to extract all values from the input text. If one of these regular expressions does not match, then a message is displayed. This message contains a short description and not the regex, because it is too long and complex to be useful without much effort. Please contact me by mail or ticket if an error occurs.

Register here or Log in to comment, or comment via email.