oom-killer / Out of memory: Killed process 1026641 (/usr/share/koha)
Hi Our host "bib" owns 4 virtual CPU, 8 GB RAM and 18 GB swap space. It runs on Debian GNU/Linux 12 with Koha 24.05.01 and around 78'000 bibliographic records. Since some time Koha sporadically just stops (today already twice), in such cases log file "/var/log/syslog" contains messages as attached at the end of this e-mail (the "oom-killer" is not always invoked by memcached). The messages say the host is out of memory so the Koha process was killed... I have already increased the swap space from 2 GB to 18 GB but to no avail. How can we find out what is consuming so much memory causing Koha to get killed? How can we avoid this? Best wishes: Michael -- Geschäftsführer · Diplombibliothekar BBS, Informatiker eidg. Fachausweis Admin Kuhn GmbH · Pappelstrasse 20 · 4123 Allschwil · Schweiz T 0041 (0)61 261 55 61 · E mik@adminkuhn.ch · W www.adminkuhn.ch 2025-03-10T12:48:00.668764+01:00 bib kernel: [769596.762201] memcached invoked oom-killer: gfp_mask=0x140cca(GFP_HIGHUSER_MOVABLE|__GFP_COMP), order=0, oom_score_adj=0 2025-03-10T12:48:00.670036+01:00 bib kernel: [769596.762885] CPU: 3 PID: 2332685 Comm: memcached Not tainted 6.1.0-31-amd64 #1 Debian 6.1.128-1 2025-03-10T12:48:00.670038+01:00 bib kernel: [769596.763487] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.14.0-2 04/01/2014 2025-03-10T12:48:00.670039+01:00 bib kernel: [769596.764019] Call Trace: 2025-03-10T12:48:00.670039+01:00 bib kernel: [769596.764528] <TASK> 2025-03-10T12:48:00.670040+01:00 bib kernel: [769596.765027] dump_stack_lvl+0x44/0x5c 2025-03-10T12:48:00.670040+01:00 bib kernel: [769596.765539] dump_header+0x4a/0x211 2025-03-10T12:48:00.670041+01:00 bib kernel: [769596.766045] oom_kill_process.cold+0xb/0x10 2025-03-10T12:48:00.670041+01:00 bib kernel: [769596.766535] out_of_memory+0x1fd/0x4c0 2025-03-10T12:48:00.670042+01:00 bib kernel: [769596.767046] __alloc_pages_slowpath.constprop.0+0xc83/0xe40 2025-03-10T12:48:00.670042+01:00 bib kernel: [769596.767537] __alloc_pages+0x305/0x330 2025-03-10T12:48:00.670043+01:00 bib kernel: [769596.768014] folio_alloc+0x17/0x50 2025-03-10T12:48:00.670043+01:00 bib kernel: [769596.768499] __filemap_get_folio+0x155/0x340 2025-03-10T12:48:00.670044+01:00 bib kernel: [769596.768967] filemap_fault+0x139/0x910 2025-03-10T12:48:00.670044+01:00 bib kernel: [769596.769395] ? filemap_map_pages+0x153/0x700 2025-03-10T12:48:00.670044+01:00 bib kernel: [769596.769820] __do_fault+0x33/0x110 2025-03-10T12:48:00.670045+01:00 bib kernel: [769596.770303] do_fault+0x1b9/0x410 2025-03-10T12:48:00.670157+01:00 bib kernel: [769596.770734] __handle_mm_fault+0x660/0xfa0 2025-03-10T12:48:00.670298+01:00 bib kernel: [769596.771189] handle_mm_fault+0xdb/0x2d0 2025-03-10T12:48:00.670299+01:00 bib kernel: [769596.771594] do_user_addr_fault+0x191/0x550 2025-03-10T12:48:00.670300+01:00 bib kernel: [769596.771982] exc_page_fault+0x70/0x170 2025-03-10T12:48:00.670300+01:00 bib kernel: [769596.772411] asm_exc_page_fault+0x22/0x30 2025-03-10T12:48:00.670301+01:00 bib kernel: [769596.772829] RIP: 0033:0x557b12827140 2025-03-10T12:48:00.670302+01:00 bib kernel: [769596.773207] Code: Unable to access opcode bytes at 0x557b12827116. 2025-03-10T12:48:00.670302+01:00 bib kernel: [769596.773589] RSP: 002b:00007ffc7f74a9c8 EFLAGS: 00010246 2025-03-10T12:48:00.670303+01:00 bib kernel: [769596.773991] RAX: 00007fc1802bd440 RBX: 0000557b44749ac0 RCX: 0000000000000669 2025-03-10T12:48:00.670303+01:00 bib kernel: [769596.774387] RDX: 0000000000000000 RSI: 0000000000000001 RDI: 00000000ffffffff 2025-03-10T12:48:00.670303+01:00 bib kernel: [769596.774723] RBP: 0000000000000001 R08: 0000557b12827140 R09: 00007fc1802dd000 2025-03-10T12:48:00.670304+01:00 bib kernel: [769596.775111] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001 2025-03-10T12:48:00.670305+01:00 bib kernel: [769596.775506] R13: 0000000000000000 R14: 000000007fffffff R15: 0000557b1285cb80 2025-03-10T12:48:00.670305+01:00 bib kernel: [769596.775831] </TASK> 2025-03-10T12:48:00.670305+01:00 bib kernel: [769596.776226] Mem-Info: 2025-03-10T12:48:00.670365+01:00 bib kernel: [769596.776592] active_anon:550829 inactive_anon:1391840 isolated_anon:0 2025-03-10T12:48:00.670366+01:00 bib kernel: [769596.776592] active_file:0 inactive_file:94 isolated_file:0 2025-03-10T12:48:00.670366+01:00 bib kernel: [769596.776592] unevictable:0 dirty:0 writeback:0 2025-03-10T12:48:00.670367+01:00 bib kernel: [769596.776592] slab_reclaimable:9935 slab_unreclaimable:13188 2025-03-10T12:48:00.670367+01:00 bib kernel: [769596.776592] mapped:1134 shmem:5697 pagetables:5740 2025-03-10T12:48:00.670367+01:00 bib kernel: [769596.776592] sec_pagetables:0 bounce:0 2025-03-10T12:48:00.670368+01:00 bib kernel: [769596.776592] kernel_misc_reclaimable:0 2025-03-10T12:48:00.670368+01:00 bib kernel: [769596.776592] free:25298 free_pcp:0 free_cma:0 2025-03-10T12:48:00.670368+01:00 bib kernel: [769596.789186] Node 0 active_anon:2203316kB inactive_anon:5567360kB active_file:80kB inactive_file:156kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:4536kB dirty:0kB writeback:0kB shmem:22788kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 876544kB writeback_tmp:0kB kernel_stack:9056kB pagetables:22960kB sec_pagetables:0kB all_unreclaimable? no 2025-03-10T12:48:00.670369+01:00 bib kernel: [769596.790069] Node 0 DMA free:14336kB boost:0kB min:128kB low:160kB high:192kB reserved_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15360kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 2025-03-10T12:48:00.670370+01:00 bib kernel: [769596.790924] lowmem_reserve[]: 0 2899 7843 7843 7843 2025-03-10T12:48:00.670370+01:00 bib kernel: [769596.791252] Node 0 DMA32 free:44376kB boost:0kB min:24936kB low:31168kB high:37400kB reserved_highatomic:0KB active_anon:842432kB inactive_anon:2119316kB active_file:0kB inactive_file:84kB unevictable:0kB writepending:0kB present:3129196kB managed:3018408kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 2025-03-10T12:48:00.670370+01:00 bib kernel: [769596.792175] lowmem_reserve[]: 0 0 4943 4943 4943 2025-03-10T12:48:00.670371+01:00 bib kernel: [769596.792455] Node 0 Normal free:42480kB boost:0kB min:42516kB low:53144kB high:63772kB reserved_highatomic:0KB active_anon:1360884kB inactive_anon:3447664kB active_file:120kB inactive_file:0kB unevictable:0kB writepending:0kB present:5242880kB managed:5062604kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 2025-03-10T12:48:00.670371+01:00 bib kernel: [769596.793398] lowmem_reserve[]: 0 0 0 0 0 2025-03-10T12:48:00.670372+01:00 bib kernel: [769596.793716] Node 0 DMA: 0*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 1*2048kB (M) 3*4096kB (M) = 14336kB 2025-03-10T12:48:00.670372+01:00 bib kernel: [769596.794404] Node 0 DMA32: 115*4kB (UME) 68*8kB (UME) 110*16kB (UME) 94*32kB (UME) 78*64kB (UME) 56*128kB (UE) 40*256kB (UME) 15*512kB (E) 3*1024kB (UE) 3*2048kB (E) 0*4096kB = 45068kB 2025-03-10T12:48:00.670373+01:00 bib kernel: [769596.795118] Node 0 Normal: 412*4kB (UME) 307*8kB (UME) 166*16kB (UME) 167*32kB (UME) 83*64kB (UME) 50*128kB (UME) 23*256kB (E) 13*512kB (ME) 7*1024kB (ME) 0*2048kB 0*4096kB = 43528kB 2025-03-10T12:48:00.670373+01:00 bib kernel: [769596.795916] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB 2025-03-10T12:48:00.670373+01:00 bib kernel: [769596.796271] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB 2025-03-10T12:48:00.670374+01:00 bib kernel: [769596.796713] 155111 total pagecache pages 2025-03-10T12:48:00.670374+01:00 bib kernel: [769596.797122] 149255 pages in swap cache 2025-03-10T12:48:00.670374+01:00 bib kernel: [769596.797463] Free swap = 0kB 2025-03-10T12:48:00.670375+01:00 bib kernel: [769596.797848] Total swap = 1998844kB 2025-03-10T12:48:00.670922+01:00 bib kernel: [769596.798238] 2097017 pages RAM 2025-03-10T12:48:00.670926+01:00 bib kernel: [769596.798577] 0 pages HighMem/MovableOnly 2025-03-10T12:48:00.670926+01:00 bib kernel: [769596.798954] 72924 pages reserved 2025-03-10T12:48:00.671386+01:00 bib kernel: [769596.799356] 0 pages hwpoisoned 2025-03-10T12:48:00.671388+01:00 bib kernel: [769596.799693] Tasks state (memory values in pages): 2025-03-10T12:48:00.671388+01:00 bib kernel: [769596.800070] [ pid ] uid tgid total_vm rss pgtables_bytes swapents oom_score_adj name 2025-03-10T12:48:00.671389+01:00 bib kernel: [769596.800463] [ 274] 0 274 30075 22 241664 274 -250 systemd-journal 2025-03-10T12:48:00.671389+01:00 bib kernel: [769596.800839] [ 295] 0 295 6770 278 86016 221 -1000 systemd-udevd 2025-03-10T12:48:00.671390+01:00 bib kernel: [769596.801224] [ 524] 997 524 22521 154 77824 82 0 systemd-timesyn 2025-03-10T12:48:00.671390+01:00 bib kernel: [769596.801603] [ 609] 0 609 2372 35 53248 28 0 cron 2025-03-10T12:48:00.671390+01:00 bib kernel: [769596.801997] [ 610] 100 610 2011 143 61440 8 -900 dbus-daemon 2025-03-10T12:48:00.671391+01:00 bib kernel: [769596.802387] [ 612] 0 612 55447 184 81920 116 0 rsyslogd 2025-03-10T12:48:00.671391+01:00 bib kernel: [769596.802749] [ 613] 0 613 4185 203 73728 73 0 systemd-logind 2025-03-10T12:48:00.671391+01:00 bib kernel: [769596.803147] [ 629] 0 629 895 40 49152 3 0 atd 2025-03-10T12:48:00.671392+01:00 bib kernel: [769596.803558] [ 666] 0 666 1499 202 53248 45 0 dhclient 2025-03-10T12:48:00.671392+01:00 bib kernel: [769596.803913] [ 715] 0 715 1435 100 49152 105 0 dhclient 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.804313] [ 747] 104 747 2208 550 61440 34 0 epmd 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.804716] [ 753] 0 753 173229 3280 430080 880 0 fail2ban-server 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.805078] [ 774] 106 774 920414 28673 1294336 23431 -500 beam.smp 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.805494] [ 797] 0 797 2188 20 53248 2 0 agetty 2025-03-10T12:48:00.671394+01:00 bib kernel: [769596.806006] [ 812] 0 812 3859 213 65536 120 -1000 sshd 2025-03-10T12:48:00.671394+01:00 bib kernel: [769596.806567] [ 841] 106 841 616 19 53248 6 -500 erl_child_setup 2025-03-10T12:48:00.671395+01:00 bib kernel: [769596.807045] [ 1774] 0 1774 10665 108 69632 53 0 master 2025-03-10T12:48:00.671395+01:00 bib kernel: [769596.807442] [ 1779] 102 1779 10700 127 81920 48 0 qmgr 2025-03-10T12:48:00.671396+01:00 bib kernel: [769596.807848] [ 2023] 106 2023 848 11 45056 14 -500 inet_gethost 2025-03-10T12:48:00.671396+01:00 bib kernel: [769596.808192] [ 2026] 106 2026 848 24 45056 8 -500 inet_gethost 2025-03-10T12:48:00.671397+01:00 bib kernel: [769596.808560] [ 2034] 106 2034 644 14 40960 14 -500 sh 2025-03-10T12:48:00.671397+01:00 bib kernel: [769596.808953] [ 3262] 103 3262 2058793 518769 7716864 392357 0 mariadbd 2025-03-10T12:48:00.671397+01:00 bib kernel: [769596.809287] [ 392666] 102 392666 12109 128 90112 225 0 tlsmgr 2025-03-10T12:48:00.671398+01:00 bib kernel: [769596.809647] [2332677] 0 2332677 3456 434 61440 303 0 apache2 2025-03-10T12:48:00.671398+01:00 bib kernel: [769596.810031] [2332685] 105 2332685 107470 2677 159744 2787 0 memcached 2025-03-10T12:48:00.671399+01:00 bib kernel: [769596.810358] [2332735] 1003 2332735 2128 21 49152 15 0 daemon 2025-03-10T12:48:00.671399+01:00 bib kernel: [769596.810703] [2332737] 1003 2332737 14826 161 110592 256 0 zebrasrv 2025-03-10T12:48:00.671399+01:00 bib kernel: [769596.811075] [2332802] 1003 2332802 6211 2612 94208 287 0 starman master 2025-03-10T12:48:00.671400+01:00 bib kernel: [769596.811400] [2332846] 1003 2332846 2128 37 49152 0 0 daemon 2025-03-10T12:48:00.671400+01:00 bib kernel: [769596.811734] [2332847] 1003 2332847 29751 13047 221184 414 0 background_jobs 2025-03-10T12:48:00.671401+01:00 bib kernel: [769596.812076] [2332875] 1003 2332875 2128 21 45056 14 0 daemon 2025-03-10T12:48:00.671401+01:00 bib kernel: [769596.812396] [2332877] 1003 2332877 41320 19112 323584 4526 0 background_jobs 2025-03-10T12:48:00.671401+01:00 bib kernel: [769596.812718] [2332902] 1003 2332902 2128 13 49152 22 0 daemon 2025-03-10T12:48:00.671402+01:00 bib kernel: [769596.813044] [2332904] 1003 2332904 73759 36200 540672 6622 0 rebuild_zebra.p 2025-03-10T12:48:00.671402+01:00 bib kernel: [769596.813369] [1011996] 102 1011996 10671 154 73728 0 0 pickup 2025-03-10T12:48:00.671402+01:00 bib kernel: [769596.813651] [1014020] 33 1014020 3517 422 61440 316 0 apache2 2025-03-10T12:48:00.671403+01:00 bib kernel: [769596.813976] [1015250] 33 1015250 3517 426 61440 311 0 apache2 2025-03-10T12:48:00.671403+01:00 bib kernel: [769596.814307] [1018044] 33 1018044 3517 472 61440 265 0 apache2 2025-03-10T12:48:00.671403+01:00 bib kernel: [769596.814583] [1018109] 33 1018109 3517 465 61440 272 0 apache2 2025-03-10T12:48:00.671404+01:00 bib kernel: [769596.814882] [1018113] 33 1018113 3517 473 61440 265 0 apache2 2025-03-10T12:48:00.671404+01:00 bib kernel: [769596.815171] [1020113] 33 1020113 3517 473 61440 264 0 apache2 2025-03-10T12:48:00.671404+01:00 bib kernel: [769596.815506] [1024635] 33 1024635 3517 474 61440 264 0 apache2 2025-03-10T12:48:00.671405+01:00 bib kernel: [769596.815796] [1026139] 33 1026139 3517 474 61440 264 0 apache2 2025-03-10T12:48:00.671405+01:00 bib kernel: [769596.816089] [1026170] 33 1026170 3517 473 61440 264 0 apache2 2025-03-10T12:48:00.671405+01:00 bib kernel: [769596.816378] [1026641] 1003 1026641 1185289 1122584 9445376 29621 0 /usr/share/koha 2025-03-10T12:48:00.671406+01:00 bib kernel: [769596.816688] [1026652] 33 1026652 3517 473 61440 264 0 apache2 2025-03-10T12:48:00.671406+01:00 bib kernel: [769596.816972] [1027075] 1003 1027075 99496 34733 749568 33424 0 /usr/share/koha 2025-03-10T12:48:00.671407+01:00 bib kernel: [769596.817289] [1027426] 1003 1027426 3594 624 65536 241 0 apache2 2025-03-10T12:48:00.671416+01:00 bib kernel: [769596.817615] [1027453] 1003 1027453 3592 669 61440 240 0 apache2 2025-03-10T12:48:00.671416+01:00 bib kernel: [769596.817890] [1027749] 1003 1027749 16877 179 114688 2268 0 zebrasrv 2025-03-10T12:48:00.671416+01:00 bib kernel: [769596.818218] [1027761] 1003 1027761 3538 563 61440 244 0 apache2 2025-03-10T12:48:00.671417+01:00 bib kernel: [769596.818501] [1027769] 1003 1027769 16966 2354 114688 229 0 zebrasrv 2025-03-10T12:48:00.671417+01:00 bib kernel: [769596.818812] [1027770] 1003 1027770 3523 559 61440 241 0 apache2 2025-03-10T12:48:00.671417+01:00 bib kernel: [769596.819085] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/system.slice/koha-common.service,task=/usr/share/koha,pid=1026641,uid=1003 2025-03-10T12:48:00.671418+01:00 bib kernel: [769596.819717] Out of memory: Killed process 1026641 (/usr/share/koha) total-vm:4741156kB, anon-rss:4490332kB, file-rss:4kB, shmem-rss:0kB, UID:1003 pgtables:9224kB oom_score_adj:0 2025-03-10T12:48:00.721396+01:00 bib systemd[1]: koha-common.service: A process of this unit has been killed by the OOM killer. 2025-03-10T12:48:03.702481+01:00 bib koha-common[1027819]: Stopping Plack daemon for bib:. 2025-03-10T12:48:03.755927+01:00 bib koha-common[1027861]: Stopping Koha worker daemon for bib (default):. 2025-03-10T12:48:03.789372+01:00 bib koha-common[1027886]: Stopping Koha worker daemon for bib (long_tasks):. 2025-03-10T12:48:03.825612+01:00 bib koha-common[1027911]: Stopping Koha indexing daemon for bib:. 2025-03-10T12:48:05.057975+01:00 bib systemd[1]: koha-common.service: Failed with result 'oom-kill'. 2025-03-10T12:48:05.058217+01:00 bib systemd[1]: koha-common.service: Consumed 2d 22h 25min 610ms CPU time.
Memcached was the process requesting more memory, not necessary the process using a lot of memory. Looking through the logs you attached it seems Beam.smp (which I believe is RabbitMQ), MariaDB, and Koha Plack are the top three memory processes. rebuild_zebra is also using a lot of paged memory, but its total vm usage isn't high; I'm not sure how that factors in here. There may be processes (like Kernel processes) that aren't in that list, I'm not going to do the math to see if all the processes are listed. I'm not even sure if the values here are bytes or memory pages. The OOM Killer decided that Plack was the most expendable process, that's why it killed it. Basically, all you can do is reduce memory usage or add memory. I don't know if adding more swap space is a good solution, swap memory is a lot slower than physical ram, but it's also a lot cheaper. Looks like all the swap space is allocated too, so it is being used as far as I can tell. I might see if all of the Plack processes are in use, and reduce that if it's higher than the peak active requests (Maybe Apache can provide that number). That's the plack_workers tag in the config file, and defaults to 2, so that only works if you have increased the number significantly past the default. You can also look at the plack_max_requests tag, to recycle the workers quicker. That may free up ram quicker, but spawning workers takes time. That setting defaults to 50 (requests). On Mon, Mar 10, 2025 at 10:27 AM Michael Kuhn via Koha-devel < koha-devel@lists.koha-community.org> wrote:
Hi
Our host "bib" owns 4 virtual CPU, 8 GB RAM and 18 GB swap space. It runs on Debian GNU/Linux 12 with Koha 24.05.01 and around 78'000 bibliographic records.
Since some time Koha sporadically just stops (today already twice), in such cases log file "/var/log/syslog" contains messages as attached at the end of this e-mail (the "oom-killer" is not always invoked by memcached). The messages say the host is out of memory so the Koha process was killed... I have already increased the swap space from 2 GB to 18 GB but to no avail.
How can we find out what is consuming so much memory causing Koha to get killed? How can we avoid this?
Best wishes: Michael -- Geschäftsführer · Diplombibliothekar BBS, Informatiker eidg. Fachausweis Admin Kuhn GmbH · Pappelstrasse 20 · 4123 Allschwil · Schweiz T 0041 (0)61 261 55 61 · E mik@adminkuhn.ch · W www.adminkuhn.ch
2025-03-10T12:48:00.668764+01:00 bib kernel: [769596.762201] memcached invoked oom-killer: gfp_mask=0x140cca(GFP_HIGHUSER_MOVABLE|__GFP_COMP), order=0, oom_score_adj=0 2025-03-10T12:48:00.670036+01:00 bib kernel: [769596.762885] CPU: 3 PID: 2332685 Comm: memcached Not tainted 6.1.0-31-amd64 #1 Debian 6.1.128-1 2025-03-10T12:48:00.670038+01:00 bib kernel: [769596.763487] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.14.0-2 04/01/2014 2025-03-10T12:48:00.670039+01:00 bib kernel: [769596.764019] Call Trace: 2025-03-10T12:48:00.670039+01:00 bib kernel: [769596.764528] <TASK> 2025-03-10T12:48:00.670040+01:00 bib kernel: [769596.765027] dump_stack_lvl+0x44/0x5c 2025-03-10T12:48:00.670040+01:00 bib kernel: [769596.765539] dump_header+0x4a/0x211 2025-03-10T12:48:00.670041+01:00 bib kernel: [769596.766045] oom_kill_process.cold+0xb/0x10 2025-03-10T12:48:00.670041+01:00 bib kernel: [769596.766535] out_of_memory+0x1fd/0x4c0 2025-03-10T12:48:00.670042+01:00 bib kernel: [769596.767046] __alloc_pages_slowpath.constprop.0+0xc83/0xe40 2025-03-10T12:48:00.670042+01:00 bib kernel: [769596.767537] __alloc_pages+0x305/0x330 2025-03-10T12:48:00.670043+01:00 bib kernel: [769596.768014] folio_alloc+0x17/0x50 2025-03-10T12:48:00.670043+01:00 bib kernel: [769596.768499] __filemap_get_folio+0x155/0x340 2025-03-10T12:48:00.670044+01:00 bib kernel: [769596.768967] filemap_fault+0x139/0x910 2025-03-10T12:48:00.670044+01:00 bib kernel: [769596.769395] ? filemap_map_pages+0x153/0x700 2025-03-10T12:48:00.670044+01:00 bib kernel: [769596.769820] __do_fault+0x33/0x110 2025-03-10T12:48:00.670045+01:00 bib kernel: [769596.770303] do_fault+0x1b9/0x410 2025-03-10T12:48:00.670157+01:00 bib kernel: [769596.770734] __handle_mm_fault+0x660/0xfa0 2025-03-10T12:48:00.670298+01:00 bib kernel: [769596.771189] handle_mm_fault+0xdb/0x2d0 2025-03-10T12:48:00.670299+01:00 bib kernel: [769596.771594] do_user_addr_fault+0x191/0x550 2025-03-10T12:48:00.670300+01:00 bib kernel: [769596.771982] exc_page_fault+0x70/0x170 2025-03-10T12:48:00.670300+01:00 bib kernel: [769596.772411] asm_exc_page_fault+0x22/0x30 2025-03-10T12:48:00.670301+01:00 bib kernel: [769596.772829] RIP: 0033:0x557b12827140 2025-03-10T12:48:00.670302+01:00 bib kernel: [769596.773207] Code: Unable to access opcode bytes at 0x557b12827116. 2025-03-10T12:48:00.670302+01:00 bib kernel: [769596.773589] RSP: 002b:00007ffc7f74a9c8 EFLAGS: 00010246 2025-03-10T12:48:00.670303+01:00 bib kernel: [769596.773991] RAX: 00007fc1802bd440 RBX: 0000557b44749ac0 RCX: 0000000000000669 2025-03-10T12:48:00.670303+01:00 bib kernel: [769596.774387] RDX: 0000000000000000 RSI: 0000000000000001 RDI: 00000000ffffffff 2025-03-10T12:48:00.670303+01:00 bib kernel: [769596.774723] RBP: 0000000000000001 R08: 0000557b12827140 R09: 00007fc1802dd000 2025-03-10T12:48:00.670304+01:00 bib kernel: [769596.775111] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001 2025-03-10T12:48:00.670305+01:00 bib kernel: [769596.775506] R13: 0000000000000000 R14: 000000007fffffff R15: 0000557b1285cb80 2025-03-10T12:48:00.670305+01:00 bib kernel: [769596.775831] </TASK> 2025-03-10T12:48:00.670305+01:00 bib kernel: [769596.776226] Mem-Info: 2025-03-10T12:48:00.670365+01:00 bib kernel: [769596.776592] active_anon:550829 inactive_anon:1391840 isolated_anon:0 2025-03-10T12:48:00.670366+01:00 bib kernel: [769596.776592] active_file:0 inactive_file:94 isolated_file:0 2025-03-10T12:48:00.670366+01:00 bib kernel: [769596.776592] unevictable:0 dirty:0 writeback:0 2025-03-10T12:48:00.670367+01:00 bib kernel: [769596.776592] slab_reclaimable:9935 slab_unreclaimable:13188 2025-03-10T12:48:00.670367+01:00 bib kernel: [769596.776592] mapped:1134 shmem:5697 pagetables:5740 2025-03-10T12:48:00.670367+01:00 bib kernel: [769596.776592] sec_pagetables:0 bounce:0 2025-03-10T12:48:00.670368+01:00 bib kernel: [769596.776592] kernel_misc_reclaimable:0 2025-03-10T12:48:00.670368+01:00 bib kernel: [769596.776592] free:25298 free_pcp:0 free_cma:0 2025-03-10T12:48:00.670368+01:00 bib kernel: [769596.789186] Node 0 active_anon:2203316kB inactive_anon:5567360kB active_file:80kB inactive_file:156kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:4536kB dirty:0kB writeback:0kB shmem:22788kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 876544kB writeback_tmp:0kB kernel_stack:9056kB pagetables:22960kB sec_pagetables:0kB all_unreclaimable? no 2025-03-10T12:48:00.670369+01:00 bib kernel: [769596.790069] Node 0 DMA free:14336kB boost:0kB min:128kB low:160kB high:192kB reserved_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15360kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 2025-03-10T12:48:00.670370+01:00 bib kernel: [769596.790924] lowmem_reserve[]: 0 2899 7843 7843 7843 2025-03-10T12:48:00.670370+01:00 bib kernel: [769596.791252] Node 0 DMA32 free:44376kB boost:0kB min:24936kB low:31168kB high:37400kB reserved_highatomic:0KB active_anon:842432kB inactive_anon:2119316kB active_file:0kB inactive_file:84kB unevictable:0kB writepending:0kB present:3129196kB managed:3018408kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 2025-03-10T12:48:00.670370+01:00 bib kernel: [769596.792175] lowmem_reserve[]: 0 0 4943 4943 4943 2025-03-10T12:48:00.670371+01:00 bib kernel: [769596.792455] Node 0 Normal free:42480kB boost:0kB min:42516kB low:53144kB high:63772kB reserved_highatomic:0KB active_anon:1360884kB inactive_anon:3447664kB active_file:120kB inactive_file:0kB unevictable:0kB writepending:0kB present:5242880kB managed:5062604kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 2025-03-10T12:48:00.670371+01:00 bib kernel: [769596.793398] lowmem_reserve[]: 0 0 0 0 0 2025-03-10T12:48:00.670372+01:00 bib kernel: [769596.793716] Node 0 DMA: 0*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 1*2048kB (M) 3*4096kB (M) = 14336kB 2025-03-10T12:48:00.670372+01:00 bib kernel: [769596.794404] Node 0 DMA32: 115*4kB (UME) 68*8kB (UME) 110*16kB (UME) 94*32kB (UME) 78*64kB (UME) 56*128kB (UE) 40*256kB (UME) 15*512kB (E) 3*1024kB (UE) 3*2048kB (E) 0*4096kB = 45068kB 2025-03-10T12:48:00.670373+01:00 bib kernel: [769596.795118] Node 0 Normal: 412*4kB (UME) 307*8kB (UME) 166*16kB (UME) 167*32kB (UME) 83*64kB (UME) 50*128kB (UME) 23*256kB (E) 13*512kB (ME) 7*1024kB (ME) 0*2048kB 0*4096kB = 43528kB 2025-03-10T12:48:00.670373+01:00 bib kernel: [769596.795916] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB 2025-03-10T12:48:00.670373+01:00 bib kernel: [769596.796271] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB 2025-03-10T12:48:00.670374+01:00 bib kernel: [769596.796713] 155111 total pagecache pages 2025-03-10T12:48:00.670374+01:00 bib kernel: [769596.797122] 149255 pages in swap cache 2025-03-10T12:48:00.670374+01:00 bib kernel: [769596.797463] Free swap = 0kB 2025-03-10T12:48:00.670375+01:00 bib kernel: [769596.797848] Total swap = 1998844kB 2025-03-10T12:48:00.670922+01:00 bib kernel: [769596.798238] 2097017 pages RAM 2025-03-10T12:48:00.670926+01:00 bib kernel: [769596.798577] 0 pages HighMem/MovableOnly 2025-03-10T12:48:00.670926+01:00 bib kernel: [769596.798954] 72924 pages reserved 2025-03-10T12:48:00.671386+01:00 bib kernel: [769596.799356] 0 pages hwpoisoned 2025-03-10T12:48:00.671388+01:00 bib kernel: [769596.799693] Tasks state (memory values in pages): 2025-03-10T12:48:00.671388+01:00 bib kernel: [769596.800070] [ pid ] uid tgid total_vm rss pgtables_bytes swapents oom_score_adj name 2025-03-10T12:48:00.671389+01:00 bib kernel: [769596.800463] [ 274] 0 274 30075 22 241664 274 -250 systemd-journal 2025-03-10T12:48:00.671389+01:00 bib kernel: [769596.800839] [ 295] 0 295 6770 278 86016 221 -1000 systemd-udevd 2025-03-10T12:48:00.671390+01:00 bib kernel: [769596.801224] [ 524] 997 524 22521 154 77824 82 0 systemd-timesyn 2025-03-10T12:48:00.671390+01:00 bib kernel: [769596.801603] [ 609] 0 609 2372 35 53248 28 0 cron 2025-03-10T12:48:00.671390+01:00 bib kernel: [769596.801997] [ 610] 100 610 2011 143 61440 8 -900 dbus-daemon 2025-03-10T12:48:00.671391+01:00 bib kernel: [769596.802387] [ 612] 0 612 55447 184 81920 116 0 rsyslogd 2025-03-10T12:48:00.671391+01:00 bib kernel: [769596.802749] [ 613] 0 613 4185 203 73728 73 0 systemd-logind 2025-03-10T12:48:00.671391+01:00 bib kernel: [769596.803147] [ 629] 0 629 895 40 49152 3 0 atd 2025-03-10T12:48:00.671392+01:00 bib kernel: [769596.803558] [ 666] 0 666 1499 202 53248 45 0 dhclient 2025-03-10T12:48:00.671392+01:00 bib kernel: [769596.803913] [ 715] 0 715 1435 100 49152 105 0 dhclient 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.804313] [ 747] 104 747 2208 550 61440 34 0 epmd 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.804716] [ 753] 0 753 173229 3280 430080 880 0 fail2ban-server 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.805078] [ 774] 106 774 920414 28673 1294336 23431 -500 beam.smp 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.805494] [ 797] 0 797 2188 20 53248 2 0 agetty 2025-03-10T12:48:00.671394+01:00 bib kernel: [769596.806006] [ 812] 0 812 3859 213 65536 120 -1000 sshd 2025-03-10T12:48:00.671394+01:00 bib kernel: [769596.806567] [ 841] 106 841 616 19 53248 6 -500 erl_child_setup 2025-03-10T12:48:00.671395+01:00 bib kernel: [769596.807045] [ 1774] 0 1774 10665 108 69632 53 0 master 2025-03-10T12:48:00.671395+01:00 bib kernel: [769596.807442] [ 1779] 102 1779 10700 127 81920 48 0 qmgr 2025-03-10T12:48:00.671396+01:00 bib kernel: [769596.807848] [ 2023] 106 2023 848 11 45056 14 -500 inet_gethost 2025-03-10T12:48:00.671396+01:00 bib kernel: [769596.808192] [ 2026] 106 2026 848 24 45056 8 -500 inet_gethost 2025-03-10T12:48:00.671397+01:00 bib kernel: [769596.808560] [ 2034] 106 2034 644 14 40960 14 -500 sh 2025-03-10T12:48:00.671397+01:00 bib kernel: [769596.808953] [ 3262] 103 3262 2058793 518769 7716864 392357 0 mariadbd 2025-03-10T12:48:00.671397+01:00 bib kernel: [769596.809287] [ 392666] 102 392666 12109 128 90112 225 0 tlsmgr 2025-03-10T12:48:00.671398+01:00 bib kernel: [769596.809647] [2332677] 0 2332677 3456 434 61440 303 0 apache2 2025-03-10T12:48:00.671398+01:00 bib kernel: [769596.810031] [2332685] 105 2332685 107470 2677 159744 2787 0 memcached 2025-03-10T12:48:00.671399+01:00 bib kernel: [769596.810358] [2332735] 1003 2332735 2128 21 49152 15 0 daemon 2025-03-10T12:48:00.671399+01:00 bib kernel: [769596.810703] [2332737] 1003 2332737 14826 161 110592 256 0 zebrasrv 2025-03-10T12:48:00.671399+01:00 bib kernel: [769596.811075] [2332802] 1003 2332802 6211 2612 94208 287 0 starman master 2025-03-10T12:48:00.671400+01:00 bib kernel: [769596.811400] [2332846] 1003 2332846 2128 37 49152 0 0 daemon 2025-03-10T12:48:00.671400+01:00 bib kernel: [769596.811734] [2332847] 1003 2332847 29751 13047 221184 414 0 background_jobs 2025-03-10T12:48:00.671401+01:00 bib kernel: [769596.812076] [2332875] 1003 2332875 2128 21 45056 14 0 daemon 2025-03-10T12:48:00.671401+01:00 bib kernel: [769596.812396] [2332877] 1003 2332877 41320 19112 323584 4526 0 background_jobs 2025-03-10T12:48:00.671401+01:00 bib kernel: [769596.812718] [2332902] 1003 2332902 2128 13 49152 22 0 daemon 2025-03-10T12:48:00.671402+01:00 bib kernel: [769596.813044] [2332904] 1003 2332904 73759 36200 540672 6622 0 rebuild_zebra.p 2025-03-10T12:48:00.671402+01:00 bib kernel: [769596.813369] [1011996] 102 1011996 10671 154 73728 0 0 pickup 2025-03-10T12:48:00.671402+01:00 bib kernel: [769596.813651] [1014020] 33 1014020 3517 422 61440 316 0 apache2 2025-03-10T12:48:00.671403+01:00 bib kernel: [769596.813976] [1015250] 33 1015250 3517 426 61440 311 0 apache2 2025-03-10T12:48:00.671403+01:00 bib kernel: [769596.814307] [1018044] 33 1018044 3517 472 61440 265 0 apache2 2025-03-10T12:48:00.671403+01:00 bib kernel: [769596.814583] [1018109] 33 1018109 3517 465 61440 272 0 apache2 2025-03-10T12:48:00.671404+01:00 bib kernel: [769596.814882] [1018113] 33 1018113 3517 473 61440 265 0 apache2 2025-03-10T12:48:00.671404+01:00 bib kernel: [769596.815171] [1020113] 33 1020113 3517 473 61440 264 0 apache2 2025-03-10T12:48:00.671404+01:00 bib kernel: [769596.815506] [1024635] 33 1024635 3517 474 61440 264 0 apache2 2025-03-10T12:48:00.671405+01:00 bib kernel: [769596.815796] [1026139] 33 1026139 3517 474 61440 264 0 apache2 2025-03-10T12:48:00.671405+01:00 bib kernel: [769596.816089] [1026170] 33 1026170 3517 473 61440 264 0 apache2 2025-03-10T12:48:00.671405+01:00 bib kernel: [769596.816378] [1026641] 1003 1026641 1185289 1122584 9445376 29621 0 /usr/share/koha 2025-03-10T12:48:00.671406+01:00 bib kernel: [769596.816688] [1026652] 33 1026652 3517 473 61440 264 0 apache2 2025-03-10T12:48:00.671406+01:00 bib kernel: [769596.816972] [1027075] 1003 1027075 99496 34733 749568 33424 0 /usr/share/koha 2025-03-10T12:48:00.671407+01:00 bib kernel: [769596.817289] [1027426] 1003 1027426 3594 624 65536 241 0 apache2 2025-03-10T12:48:00.671416+01:00 bib kernel: [769596.817615] [1027453] 1003 1027453 3592 669 61440 240 0 apache2 2025-03-10T12:48:00.671416+01:00 bib kernel: [769596.817890] [1027749] 1003 1027749 16877 179 114688 2268 0 zebrasrv 2025-03-10T12:48:00.671416+01:00 bib kernel: [769596.818218] [1027761] 1003 1027761 3538 563 61440 244 0 apache2 2025-03-10T12:48:00.671417+01:00 bib kernel: [769596.818501] [1027769] 1003 1027769 16966 2354 114688 229 0 zebrasrv 2025-03-10T12:48:00.671417+01:00 bib kernel: [769596.818812] [1027770] 1003 1027770 3523 559 61440 241 0 apache2 2025-03-10T12:48:00.671417+01:00 bib kernel: [769596.819085]
oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/system.slice/koha-common.service,task=/usr/share/koha,pid=1026641,uid=1003 2025-03-10T12:48:00.671418+01:00 bib kernel: [769596.819717] Out of memory: Killed process 1026641 (/usr/share/koha) total-vm:4741156kB, anon-rss:4490332kB, file-rss:4kB, shmem-rss:0kB, UID:1003 pgtables:9224kB oom_score_adj:0 2025-03-10T12:48:00.721396+01:00 bib systemd[1]: koha-common.service: A process of this unit has been killed by the OOM killer. 2025-03-10T12:48:03.702481+01:00 bib koha-common[1027819]: Stopping Plack daemon for bib:. 2025-03-10T12:48:03.755927+01:00 bib koha-common[1027861]: Stopping Koha worker daemon for bib (default):. 2025-03-10T12:48:03.789372+01:00 bib koha-common[1027886]: Stopping Koha worker daemon for bib (long_tasks):. 2025-03-10T12:48:03.825612+01:00 bib koha-common[1027911]: Stopping Koha indexing daemon for bib:. 2025-03-10T12:48:05.057975+01:00 bib systemd[1]: koha-common.service: Failed with result 'oom-kill'. 2025-03-10T12:48:05.058217+01:00 bib systemd[1]: koha-common.service: Consumed 2d 22h 25min 610ms CPU time. _______________________________________________ Koha-devel mailing list Koha-devel@lists.koha-community.org https://lists.koha-community.org/cgi-bin/mailman/listinfo/koha-devel website : https://www.koha-community.org/ git : https://git.koha-community.org/ bugs : https://bugs.koha-community.org/
-- Michael Hafen Washington County School District Technology Department Systems & Security Analyst
Hi Michael Yesterday you wrote:
Memcached was the process requesting more memory, not necessary the process using a lot of memory. Looking through the logs you attached it seems Beam.smp (which I believe is RabbitMQ), MariaDB, and Koha Plack are the top three memory processes. rebuild_zebra is also using a lot of paged memory, but its total vm usage isn't high; I'm not sure how that factors in here. There may be processes (like Kernel processes) that aren't in that list, I'm not going to do the math to see if all the processes are listed. I'm not even sure if the values here are bytes or memory pages. The OOM Killer decided that Plack was the most expendable process, that's why it killed it. Basically, all you can do is reduce memory usage or add memory. I don't know if adding more swap space is a good solution, swap memory is a lot slower than physical ram, but it's also a lot cheaper. Looks like all the swap space is allocated too, so it is being used as far as I can tell.
I just added the additional swap space because with 8 GB of RAM there were initially only 2 GB of swap space; also because it was easy to do. Meanwhile I have removed the additional swap space since it didn't seem to be of any use. If necessary I will ask the library rto add more physical RAM.
I might see if all of the Plack processes are in use, and reduce that if it's higher than the peak active requests (Maybe Apache can provide that number). That's the plack_workers tag in the config file, and defaults to 2, so that only works if you have increased the number significantly past the default. You can also look at the plack_max_requests tag, to recycle the workers quicker. That may free up ram quicker, but spawning workers takes time. That setting defaults to 50 (requests).
plack_workers and plack_max_requests both showed the default value, I have now increased the value of tag plack_workers from 2 to 4 (the CPU core count) but it doesn't seem to have boosted the page load. Tomas wrote:
Kill the rabbit :-D
systemctl stop rabbitmq-server systemctl disable rabbitmq-server
Since the rabbit is part of the Koha standard installation I hesitate to permanently disable ist. For now I let it live. What I actually did and what seems to have helped I blocked all the bots I could find in "plack.log" (ahrefs|Amazonbot|bingbot|ClaudeBot|DotBot|Googlebot|GPTBot|meta-externalagent) using mod_rewrite. This stopped all the annoying bot searches immediately, thus also reduced the memory usage, and at least for now Koha seems to work all right again. Many thanks fpr your explanations, hints and inputs! Best wishes: Michael -- Geschäftsführer · Diplombibliothekar BBS, Informatiker eidg. Fachausweis Admin Kuhn GmbH · Pappelstrasse 20 · 4123 Allschwil · Schweiz T 0041 (0)61 261 55 61 · E mik@adminkuhn.ch · W www.adminkuhn.ch
On Mon, Mar 10, 2025 at 10:27 AM Michael Kuhn via Koha-devel <koha- devel@lists.koha-community.org <mailto:koha-devel@lists.koha- community.org>> wrote:
Hi
Our host "bib" owns 4 virtual CPU, 8 GB RAM and 18 GB swap space. It runs on Debian GNU/Linux 12 with Koha 24.05.01 and around 78'000 bibliographic records.
Since some time Koha sporadically just stops (today already twice), in such cases log file "/var/log/syslog" contains messages as attached at the end of this e-mail (the "oom-killer" is not always invoked by memcached). The messages say the host is out of memory so the Koha process was killed... I have already increased the swap space from 2 GB to 18 GB but to no avail.
How can we find out what is consuming so much memory causing Koha to get killed? How can we avoid this?
Best wishes: Michael -- Geschäftsführer · Diplombibliothekar BBS, Informatiker eidg. Fachausweis Admin Kuhn GmbH · Pappelstrasse 20 · 4123 Allschwil · Schweiz T 0041 (0)61 261 55 61 · E mik@adminkuhn.ch <mailto:mik@adminkuhn.ch> · W www.adminkuhn.ch <http://www.adminkuhn.ch>
2025-03-10T12:48:00.668764+01:00 bib kernel: [769596.762201] memcached invoked oom-killer: gfp_mask=0x140cca(GFP_HIGHUSER_MOVABLE|__GFP_COMP), order=0, oom_score_adj=0 2025-03-10T12:48:00.670036+01:00 bib kernel: [769596.762885] CPU: 3 PID: 2332685 Comm: memcached Not tainted 6.1.0-31-amd64 #1 Debian 6.1.128-1 2025-03-10T12:48:00.670038+01:00 bib kernel: [769596.763487] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.14.0-2 04/01/2014 2025-03-10T12:48:00.670039+01:00 bib kernel: [769596.764019] Call Trace: 2025-03-10T12:48:00.670039+01:00 bib kernel: [769596.764528] <TASK> 2025-03-10T12:48:00.670040+01:00 bib kernel: [769596.765027] dump_stack_lvl+0x44/0x5c 2025-03-10T12:48:00.670040+01:00 bib kernel: [769596.765539] dump_header+0x4a/0x211 2025-03-10T12:48:00.670041+01:00 bib kernel: [769596.766045] oom_kill_process.cold+0xb/0x10 2025-03-10T12:48:00.670041+01:00 bib kernel: [769596.766535] out_of_memory+0x1fd/0x4c0 2025-03-10T12:48:00.670042+01:00 bib kernel: [769596.767046] __alloc_pages_slowpath.constprop.0+0xc83/0xe40 2025-03-10T12:48:00.670042+01:00 bib kernel: [769596.767537] __alloc_pages+0x305/0x330 2025-03-10T12:48:00.670043+01:00 bib kernel: [769596.768014] folio_alloc+0x17/0x50 2025-03-10T12:48:00.670043+01:00 bib kernel: [769596.768499] __filemap_get_folio+0x155/0x340 2025-03-10T12:48:00.670044+01:00 bib kernel: [769596.768967] filemap_fault+0x139/0x910 2025-03-10T12:48:00.670044+01:00 bib kernel: [769596.769395] ? filemap_map_pages+0x153/0x700 2025-03-10T12:48:00.670044+01:00 bib kernel: [769596.769820] __do_fault+0x33/0x110 2025-03-10T12:48:00.670045+01:00 bib kernel: [769596.770303] do_fault+0x1b9/0x410 2025-03-10T12:48:00.670157+01:00 bib kernel: [769596.770734] __handle_mm_fault+0x660/0xfa0 2025-03-10T12:48:00.670298+01:00 bib kernel: [769596.771189] handle_mm_fault+0xdb/0x2d0 2025-03-10T12:48:00.670299+01:00 bib kernel: [769596.771594] do_user_addr_fault+0x191/0x550 2025-03-10T12:48:00.670300+01:00 bib kernel: [769596.771982] exc_page_fault+0x70/0x170 2025-03-10T12:48:00.670300+01:00 bib kernel: [769596.772411] asm_exc_page_fault+0x22/0x30 2025-03-10T12:48:00.670301+01:00 bib kernel: [769596.772829] RIP: 0033:0x557b12827140 2025-03-10T12:48:00.670302+01:00 bib kernel: [769596.773207] Code: Unable to access opcode bytes at 0x557b12827116. 2025-03-10T12:48:00.670302+01:00 bib kernel: [769596.773589] RSP: 002b:00007ffc7f74a9c8 EFLAGS: 00010246 2025-03-10T12:48:00.670303+01:00 bib kernel: [769596.773991] RAX: 00007fc1802bd440 RBX: 0000557b44749ac0 RCX: 0000000000000669 2025-03-10T12:48:00.670303+01:00 bib kernel: [769596.774387] RDX: 0000000000000000 RSI: 0000000000000001 RDI: 00000000ffffffff 2025-03-10T12:48:00.670303+01:00 bib kernel: [769596.774723] RBP: 0000000000000001 R08: 0000557b12827140 R09: 00007fc1802dd000 2025-03-10T12:48:00.670304+01:00 bib kernel: [769596.775111] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001 2025-03-10T12:48:00.670305+01:00 bib kernel: [769596.775506] R13: 0000000000000000 R14: 000000007fffffff R15: 0000557b1285cb80 2025-03-10T12:48:00.670305+01:00 bib kernel: [769596.775831] </TASK> 2025-03-10T12:48:00.670305+01:00 bib kernel: [769596.776226] Mem-Info: 2025-03-10T12:48:00.670365+01:00 bib kernel: [769596.776592] active_anon:550829 inactive_anon:1391840 isolated_anon:0 2025-03-10T12:48:00.670366+01:00 bib kernel: [769596.776592] active_file:0 inactive_file:94 isolated_file:0 2025-03-10T12:48:00.670366+01:00 bib kernel: [769596.776592] unevictable:0 dirty:0 writeback:0 2025-03-10T12:48:00.670367+01:00 bib kernel: [769596.776592] slab_reclaimable:9935 slab_unreclaimable:13188 2025-03-10T12:48:00.670367+01:00 bib kernel: [769596.776592] mapped:1134 shmem:5697 pagetables:5740 2025-03-10T12:48:00.670367+01:00 bib kernel: [769596.776592] sec_pagetables:0 bounce:0 2025-03-10T12:48:00.670368+01:00 bib kernel: [769596.776592] kernel_misc_reclaimable:0 2025-03-10T12:48:00.670368+01:00 bib kernel: [769596.776592] free:25298 free_pcp:0 free_cma:0 2025-03-10T12:48:00.670368+01:00 bib kernel: [769596.789186] Node 0 active_anon:2203316kB inactive_anon:5567360kB active_file:80kB inactive_file:156kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:4536kB dirty:0kB writeback:0kB shmem:22788kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 876544kB writeback_tmp:0kB kernel_stack:9056kB pagetables:22960kB sec_pagetables:0kB all_unreclaimable? no 2025-03-10T12:48:00.670369+01:00 bib kernel: [769596.790069] Node 0 DMA free:14336kB boost:0kB min:128kB low:160kB high:192kB reserved_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15360kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 2025-03-10T12:48:00.670370+01:00 bib kernel: [769596.790924] lowmem_reserve[]: 0 2899 7843 7843 7843 2025-03-10T12:48:00.670370+01:00 bib kernel: [769596.791252] Node 0 DMA32 free:44376kB boost:0kB min:24936kB low:31168kB high:37400kB reserved_highatomic:0KB active_anon:842432kB inactive_anon:2119316kB active_file:0kB inactive_file:84kB unevictable:0kB writepending:0kB present:3129196kB managed:3018408kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 2025-03-10T12:48:00.670370+01:00 bib kernel: [769596.792175] lowmem_reserve[]: 0 0 4943 4943 4943 2025-03-10T12:48:00.670371+01:00 bib kernel: [769596.792455] Node 0 Normal free:42480kB boost:0kB min:42516kB low:53144kB high:63772kB reserved_highatomic:0KB active_anon:1360884kB inactive_anon:3447664kB active_file:120kB inactive_file:0kB unevictable:0kB writepending:0kB present:5242880kB managed:5062604kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 2025-03-10T12:48:00.670371+01:00 bib kernel: [769596.793398] lowmem_reserve[]: 0 0 0 0 0 2025-03-10T12:48:00.670372+01:00 bib kernel: [769596.793716] Node 0 DMA: 0*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 1*2048kB (M) 3*4096kB (M) = 14336kB 2025-03-10T12:48:00.670372+01:00 bib kernel: [769596.794404] Node 0 DMA32: 115*4kB (UME) 68*8kB (UME) 110*16kB (UME) 94*32kB (UME) 78*64kB (UME) 56*128kB (UE) 40*256kB (UME) 15*512kB (E) 3*1024kB (UE) 3*2048kB (E) 0*4096kB = 45068kB 2025-03-10T12:48:00.670373+01:00 bib kernel: [769596.795118] Node 0 Normal: 412*4kB (UME) 307*8kB (UME) 166*16kB (UME) 167*32kB (UME) 83*64kB (UME) 50*128kB (UME) 23*256kB (E) 13*512kB (ME) 7*1024kB (ME) 0*2048kB 0*4096kB = 43528kB 2025-03-10T12:48:00.670373+01:00 bib kernel: [769596.795916] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB 2025-03-10T12:48:00.670373+01:00 bib kernel: [769596.796271] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB 2025-03-10T12:48:00.670374+01:00 bib kernel: [769596.796713] 155111 total pagecache pages 2025-03-10T12:48:00.670374+01:00 bib kernel: [769596.797122] 149255 pages in swap cache 2025-03-10T12:48:00.670374+01:00 bib kernel: [769596.797463] Free swap = 0kB 2025-03-10T12:48:00.670375+01:00 bib kernel: [769596.797848] Total swap = 1998844kB 2025-03-10T12:48:00.670922+01:00 bib kernel: [769596.798238] 2097017 pages RAM 2025-03-10T12:48:00.670926+01:00 bib kernel: [769596.798577] 0 pages HighMem/MovableOnly 2025-03-10T12:48:00.670926+01:00 bib kernel: [769596.798954] 72924 pages reserved 2025-03-10T12:48:00.671386+01:00 bib kernel: [769596.799356] 0 pages hwpoisoned 2025-03-10T12:48:00.671388+01:00 bib kernel: [769596.799693] Tasks state (memory values in pages): 2025-03-10T12:48:00.671388+01:00 bib kernel: [769596.800070] [ pid ] uid tgid total_vm rss pgtables_bytes swapents oom_score_adj name 2025-03-10T12:48:00.671389+01:00 bib kernel: [769596.800463] [ 274] 0 274 30075 22 241664 274 -250 systemd-journal 2025-03-10T12:48:00.671389+01:00 bib kernel: [769596.800839] [ 295] 0 295 6770 278 86016 221 -1000 systemd-udevd 2025-03-10T12:48:00.671390+01:00 bib kernel: [769596.801224] [ 524] 997 524 22521 154 77824 82 0 systemd- timesyn 2025-03-10T12:48:00.671390+01:00 bib kernel: [769596.801603] [ 609] 0 609 2372 35 53248 28 0 cron 2025-03-10T12:48:00.671390+01:00 bib kernel: [769596.801997] [ 610] 100 610 2011 143 61440 8 -900 dbus-daemon 2025-03-10T12:48:00.671391+01:00 bib kernel: [769596.802387] [ 612] 0 612 55447 184 81920 116 0 rsyslogd 2025-03-10T12:48:00.671391+01:00 bib kernel: [769596.802749] [ 613] 0 613 4185 203 73728 73 0 systemd-logind 2025-03-10T12:48:00.671391+01:00 bib kernel: [769596.803147] [ 629] 0 629 895 40 49152 3 0 atd 2025-03-10T12:48:00.671392+01:00 bib kernel: [769596.803558] [ 666] 0 666 1499 202 53248 45 0 dhclient 2025-03-10T12:48:00.671392+01:00 bib kernel: [769596.803913] [ 715] 0 715 1435 100 49152 105 0 dhclient 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.804313] [ 747] 104 747 2208 550 61440 34 0 epmd 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.804716] [ 753] 0 753 173229 3280 430080 880 0 fail2ban-server 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.805078] [ 774] 106 774 920414 28673 1294336 23431 -500 beam.smp 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.805494] [ 797] 0 797 2188 20 53248 2 0 agetty 2025-03-10T12:48:00.671394+01:00 bib kernel: [769596.806006] [ 812] 0 812 3859 213 65536 120 -1000 sshd 2025-03-10T12:48:00.671394+01:00 bib kernel: [769596.806567] [ 841] 106 841 616 19 53248 6 -500 erl_child_setup 2025-03-10T12:48:00.671395+01:00 bib kernel: [769596.807045] [ 1774] 0 1774 10665 108 69632 53 0 master 2025-03-10T12:48:00.671395+01:00 bib kernel: [769596.807442] [ 1779] 102 1779 10700 127 81920 48 0 qmgr 2025-03-10T12:48:00.671396+01:00 bib kernel: [769596.807848] [ 2023] 106 2023 848 11 45056 14 -500 inet_gethost 2025-03-10T12:48:00.671396+01:00 bib kernel: [769596.808192] [ 2026] 106 2026 848 24 45056 8 -500 inet_gethost 2025-03-10T12:48:00.671397+01:00 bib kernel: [769596.808560] [ 2034] 106 2034 644 14 40960 14 -500 sh 2025-03-10T12:48:00.671397+01:00 bib kernel: [769596.808953] [ 3262] 103 3262 2058793 518769 7716864 392357 0 mariadbd 2025-03-10T12:48:00.671397+01:00 bib kernel: [769596.809287] [ 392666] 102 392666 12109 128 90112 225 0 tlsmgr 2025-03-10T12:48:00.671398+01:00 bib kernel: [769596.809647] [2332677] 0 2332677 3456 434 61440 303 0 apache2 2025-03-10T12:48:00.671398+01:00 bib kernel: [769596.810031] [2332685] 105 2332685 107470 2677 159744 2787 0 memcached 2025-03-10T12:48:00.671399+01:00 bib kernel: [769596.810358] [2332735] 1003 2332735 2128 21 49152 15 0 daemon 2025-03-10T12:48:00.671399+01:00 bib kernel: [769596.810703] [2332737] 1003 2332737 14826 161 110592 256 0 zebrasrv 2025-03-10T12:48:00.671399+01:00 bib kernel: [769596.811075] [2332802] 1003 2332802 6211 2612 94208 287 0 starman master 2025-03-10T12:48:00.671400+01:00 bib kernel: [769596.811400] [2332846] 1003 2332846 2128 37 49152 0 0 daemon 2025-03-10T12:48:00.671400+01:00 bib kernel: [769596.811734] [2332847] 1003 2332847 29751 13047 221184 414 0 background_jobs 2025-03-10T12:48:00.671401+01:00 bib kernel: [769596.812076] [2332875] 1003 2332875 2128 21 45056 14 0 daemon 2025-03-10T12:48:00.671401+01:00 bib kernel: [769596.812396] [2332877] 1003 2332877 41320 19112 323584 4526 0 background_jobs 2025-03-10T12:48:00.671401+01:00 bib kernel: [769596.812718] [2332902] 1003 2332902 2128 13 49152 22 0 daemon 2025-03-10T12:48:00.671402+01:00 bib kernel: [769596.813044] [2332904] 1003 2332904 73759 36200 540672 6622 0 rebuild_zebra.p 2025-03-10T12:48:00.671402+01:00 bib kernel: [769596.813369] [1011996] 102 1011996 10671 154 73728 0 0 pickup 2025-03-10T12:48:00.671402+01:00 bib kernel: [769596.813651] [1014020] 33 1014020 3517 422 61440 316 0 apache2 2025-03-10T12:48:00.671403+01:00 bib kernel: [769596.813976] [1015250] 33 1015250 3517 426 61440 311 0 apache2 2025-03-10T12:48:00.671403+01:00 bib kernel: [769596.814307] [1018044] 33 1018044 3517 472 61440 265 0 apache2 2025-03-10T12:48:00.671403+01:00 bib kernel: [769596.814583] [1018109] 33 1018109 3517 465 61440 272 0 apache2 2025-03-10T12:48:00.671404+01:00 bib kernel: [769596.814882] [1018113] 33 1018113 3517 473 61440 265 0 apache2 2025-03-10T12:48:00.671404+01:00 bib kernel: [769596.815171] [1020113] 33 1020113 3517 473 61440 264 0 apache2 2025-03-10T12:48:00.671404+01:00 bib kernel: [769596.815506] [1024635] 33 1024635 3517 474 61440 264 0 apache2 2025-03-10T12:48:00.671405+01:00 bib kernel: [769596.815796] [1026139] 33 1026139 3517 474 61440 264 0 apache2 2025-03-10T12:48:00.671405+01:00 bib kernel: [769596.816089] [1026170] 33 1026170 3517 473 61440 264 0 apache2 2025-03-10T12:48:00.671405+01:00 bib kernel: [769596.816378] [1026641] 1003 1026641 1185289 1122584 9445376 29621 0 /usr/share/koha 2025-03-10T12:48:00.671406+01:00 bib kernel: [769596.816688] [1026652] 33 1026652 3517 473 61440 264 0 apache2 2025-03-10T12:48:00.671406+01:00 bib kernel: [769596.816972] [1027075] 1003 1027075 99496 34733 749568 33424 0 /usr/share/koha 2025-03-10T12:48:00.671407+01:00 bib kernel: [769596.817289] [1027426] 1003 1027426 3594 624 65536 241 0 apache2 2025-03-10T12:48:00.671416+01:00 bib kernel: [769596.817615] [1027453] 1003 1027453 3592 669 61440 240 0 apache2 2025-03-10T12:48:00.671416+01:00 bib kernel: [769596.817890] [1027749] 1003 1027749 16877 179 114688 2268 0 zebrasrv 2025-03-10T12:48:00.671416+01:00 bib kernel: [769596.818218] [1027761] 1003 1027761 3538 563 61440 244 0 apache2 2025-03-10T12:48:00.671417+01:00 bib kernel: [769596.818501] [1027769] 1003 1027769 16966 2354 114688 229 0 zebrasrv 2025-03-10T12:48:00.671417+01:00 bib kernel: [769596.818812] [1027770] 1003 1027770 3523 559 61440 241 0 apache2 2025-03-10T12:48:00.671417+01:00 bib kernel: [769596.819085] oom- kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/system.slice/koha-common.service,task=/usr/share/koha,pid=1026641,uid=1003 2025-03-10T12:48:00.671418+01:00 bib kernel: [769596.819717] Out of memory: Killed process 1026641 (/usr/share/koha) total-vm:4741156kB, anon-rss:4490332kB, file-rss:4kB, shmem-rss:0kB, UID:1003 pgtables:9224kB oom_score_adj:0 2025-03-10T12:48:00.721396+01:00 bib systemd[1]: koha-common.service: A process of this unit has been killed by the OOM killer. 2025-03-10T12:48:03.702481+01:00 bib koha-common[1027819]: Stopping Plack daemon for bib:. 2025-03-10T12:48:03.755927+01:00 bib koha-common[1027861]: Stopping Koha worker daemon for bib (default):. 2025-03-10T12:48:03.789372+01:00 bib koha-common[1027886]: Stopping Koha worker daemon for bib (long_tasks):. 2025-03-10T12:48:03.825612+01:00 bib koha-common[1027911]: Stopping Koha indexing daemon for bib:. 2025-03-10T12:48:05.057975+01:00 bib systemd[1]: koha-common.service: Failed with result 'oom-kill'. 2025-03-10T12:48:05.058217+01:00 bib systemd[1]: koha-common.service: Consumed 2d 22h 25min 610ms CPU time. _______________________________________________ Koha-devel mailing list Koha-devel@lists.koha-community.org <mailto:Koha-devel@lists.koha- community.org> https://lists.koha-community.org/cgi-bin/mailman/listinfo/koha-devel <https://lists.koha-community.org/cgi-bin/mailman/listinfo/koha-devel> website : https://www.koha-community.org/ <https://www.koha- community.org/> git : https://git.koha-community.org/ <https://git.koha-community.org/> bugs : https://bugs.koha-community.org/ <https://bugs.koha- community.org/>
-- Michael Hafen Washington County School District Technology Department Systems & Security Analyst
I just had a Koha OOM killed on a small server the other day, so I feel your pain. When you startup Starman, it won't be using very much memory, but the memory usage will grow with the more requests it serves. Part of that has to do with the loading of Perl modules needed by those new requests, but I suspect that there are memory leaks as well. Koha/Perl can't deallocate memory once it's been allocated, but it can re-use memory if the data has been "deleted" within Koha/Perl. So since it's just growing and growing with each request, it's a bit suspicious. I actually just discovered a bug with /cgi-bin/koha/patroncards/create-pdf.pl which I'll be working on fixing today which could cause resource exhaustion. I had some Starman workers using obscene amounts of memory and CPU, and it's because they got trapped in infinite loops trying to create labels/cards. Fun times... But in your case... I'm guessing it's probably due to bots. I've noticed Starman instances that get a lot of bot hits balloon in memory usage. You might want to look at your "plack_max_requests" in koha-conf.xml. Once the Starman worker reaches its max requests, it'll be killed off, and the memory released. But then there's some CPU overhead to starting up a new Starman worker process. So there's a cost/benefit to do there. It can be tough troubleshooting these things after the fact, so I'd suggest putting in some monitoring, which alerts you once your memory usage starts getting high. That way you can troubleshoot it more in real time. That said, troubleshooting memory use can be tricky... David Cook Senior Software Engineer Prosentient Systems Suite 7.03 6a Glen St Milsons Point NSW 2061 Australia Office: 02 9212 0899 -----Original Message----- From: Koha-devel <koha-devel-bounces@lists.koha-community.org> On Behalf Of Michael Kuhn via Koha-devel Sent: Tuesday, 11 March 2025 3:27 AM To: Koha-devel <koha-devel@lists.koha-community.org> Cc: Hallmann, Maximilian <Hallmann@landesarchiv.berlin.de>; Erdmann, Dominique <Erdmann@landesarchiv.berlin.de> Subject: [Koha-devel] oom-killer / Out of memory: Killed process 1026641 (/usr/share/koha) Hi Our host "bib" owns 4 virtual CPU, 8 GB RAM and 18 GB swap space. It runs on Debian GNU/Linux 12 with Koha 24.05.01 and around 78'000 bibliographic records. Since some time Koha sporadically just stops (today already twice), in such cases log file "/var/log/syslog" contains messages as attached at the end of this e-mail (the "oom-killer" is not always invoked by memcached). The messages say the host is out of memory so the Koha process was killed... I have already increased the swap space from 2 GB to 18 GB but to no avail. How can we find out what is consuming so much memory causing Koha to get killed? How can we avoid this? Best wishes: Michael -- Geschäftsführer · Diplombibliothekar BBS, Informatiker eidg. Fachausweis Admin Kuhn GmbH · Pappelstrasse 20 · 4123 Allschwil · Schweiz T 0041 (0)61 261 55 61 · E mik@adminkuhn.ch · W www.adminkuhn.ch 2025-03-10T12:48:00.668764+01:00 bib kernel: [769596.762201] memcached invoked oom-killer: gfp_mask=0x140cca(GFP_HIGHUSER_MOVABLE|__GFP_COMP), order=0, oom_score_adj=0 2025-03-10T12:48:00.670036+01:00 bib kernel: [769596.762885] CPU: 3 PID: 2332685 Comm: memcached Not tainted 6.1.0-31-amd64 #1 Debian 6.1.128-1 2025-03-10T12:48:00.670038+01:00 bib kernel: [769596.763487] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.14.0-2 04/01/2014 2025-03-10T12:48:00.670039+01:00 bib kernel: [769596.764019] Call Trace: 2025-03-10T12:48:00.670039+01:00 bib kernel: [769596.764528] <TASK> 2025-03-10T12:48:00.670040+01:00 bib kernel: [769596.765027] dump_stack_lvl+0x44/0x5c 2025-03-10T12:48:00.670040+01:00 bib kernel: [769596.765539] dump_header+0x4a/0x211 2025-03-10T12:48:00.670041+01:00 bib kernel: [769596.766045] oom_kill_process.cold+0xb/0x10 2025-03-10T12:48:00.670041+01:00 bib kernel: [769596.766535] out_of_memory+0x1fd/0x4c0 2025-03-10T12:48:00.670042+01:00 bib kernel: [769596.767046] __alloc_pages_slowpath.constprop.0+0xc83/0xe40 2025-03-10T12:48:00.670042+01:00 bib kernel: [769596.767537] __alloc_pages+0x305/0x330 2025-03-10T12:48:00.670043+01:00 bib kernel: [769596.768014] folio_alloc+0x17/0x50 2025-03-10T12:48:00.670043+01:00 bib kernel: [769596.768499] __filemap_get_folio+0x155/0x340 2025-03-10T12:48:00.670044+01:00 bib kernel: [769596.768967] filemap_fault+0x139/0x910 2025-03-10T12:48:00.670044+01:00 bib kernel: [769596.769395] ? filemap_map_pages+0x153/0x700 2025-03-10T12:48:00.670044+01:00 bib kernel: [769596.769820] __do_fault+0x33/0x110 2025-03-10T12:48:00.670045+01:00 bib kernel: [769596.770303] do_fault+0x1b9/0x410 2025-03-10T12:48:00.670157+01:00 bib kernel: [769596.770734] __handle_mm_fault+0x660/0xfa0 2025-03-10T12:48:00.670298+01:00 bib kernel: [769596.771189] handle_mm_fault+0xdb/0x2d0 2025-03-10T12:48:00.670299+01:00 bib kernel: [769596.771594] do_user_addr_fault+0x191/0x550 2025-03-10T12:48:00.670300+01:00 bib kernel: [769596.771982] exc_page_fault+0x70/0x170 2025-03-10T12:48:00.670300+01:00 bib kernel: [769596.772411] asm_exc_page_fault+0x22/0x30 2025-03-10T12:48:00.670301+01:00 bib kernel: [769596.772829] RIP: 0033:0x557b12827140 2025-03-10T12:48:00.670302+01:00 bib kernel: [769596.773207] Code: Unable to access opcode bytes at 0x557b12827116. 2025-03-10T12:48:00.670302+01:00 bib kernel: [769596.773589] RSP: 002b:00007ffc7f74a9c8 EFLAGS: 00010246 2025-03-10T12:48:00.670303+01:00 bib kernel: [769596.773991] RAX: 00007fc1802bd440 RBX: 0000557b44749ac0 RCX: 0000000000000669 2025-03-10T12:48:00.670303+01:00 bib kernel: [769596.774387] RDX: 0000000000000000 RSI: 0000000000000001 RDI: 00000000ffffffff 2025-03-10T12:48:00.670303+01:00 bib kernel: [769596.774723] RBP: 0000000000000001 R08: 0000557b12827140 R09: 00007fc1802dd000 2025-03-10T12:48:00.670304+01:00 bib kernel: [769596.775111] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001 2025-03-10T12:48:00.670305+01:00 bib kernel: [769596.775506] R13: 0000000000000000 R14: 000000007fffffff R15: 0000557b1285cb80 2025-03-10T12:48:00.670305+01:00 bib kernel: [769596.775831] </TASK> 2025-03-10T12:48:00.670305+01:00 bib kernel: [769596.776226] Mem-Info: 2025-03-10T12:48:00.670365+01:00 bib kernel: [769596.776592] active_anon:550829 inactive_anon:1391840 isolated_anon:0 2025-03-10T12:48:00.670366+01:00 bib kernel: [769596.776592] active_file:0 inactive_file:94 isolated_file:0 2025-03-10T12:48:00.670366+01:00 bib kernel: [769596.776592] unevictable:0 dirty:0 writeback:0 2025-03-10T12:48:00.670367+01:00 bib kernel: [769596.776592] slab_reclaimable:9935 slab_unreclaimable:13188 2025-03-10T12:48:00.670367+01:00 bib kernel: [769596.776592] mapped:1134 shmem:5697 pagetables:5740 2025-03-10T12:48:00.670367+01:00 bib kernel: [769596.776592] sec_pagetables:0 bounce:0 2025-03-10T12:48:00.670368+01:00 bib kernel: [769596.776592] kernel_misc_reclaimable:0 2025-03-10T12:48:00.670368+01:00 bib kernel: [769596.776592] free:25298 free_pcp:0 free_cma:0 2025-03-10T12:48:00.670368+01:00 bib kernel: [769596.789186] Node 0 active_anon:2203316kB inactive_anon:5567360kB active_file:80kB inactive_file:156kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:4536kB dirty:0kB writeback:0kB shmem:22788kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 876544kB writeback_tmp:0kB kernel_stack:9056kB pagetables:22960kB sec_pagetables:0kB all_unreclaimable? no 2025-03-10T12:48:00.670369+01:00 bib kernel: [769596.790069] Node 0 DMA free:14336kB boost:0kB min:128kB low:160kB high:192kB reserved_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15360kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 2025-03-10T12:48:00.670370+01:00 bib kernel: [769596.790924] lowmem_reserve[]: 0 2899 7843 7843 7843 2025-03-10T12:48:00.670370+01:00 bib kernel: [769596.791252] Node 0 DMA32 free:44376kB boost:0kB min:24936kB low:31168kB high:37400kB reserved_highatomic:0KB active_anon:842432kB inactive_anon:2119316kB active_file:0kB inactive_file:84kB unevictable:0kB writepending:0kB present:3129196kB managed:3018408kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 2025-03-10T12:48:00.670370+01:00 bib kernel: [769596.792175] lowmem_reserve[]: 0 0 4943 4943 4943 2025-03-10T12:48:00.670371+01:00 bib kernel: [769596.792455] Node 0 Normal free:42480kB boost:0kB min:42516kB low:53144kB high:63772kB reserved_highatomic:0KB active_anon:1360884kB inactive_anon:3447664kB active_file:120kB inactive_file:0kB unevictable:0kB writepending:0kB present:5242880kB managed:5062604kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 2025-03-10T12:48:00.670371+01:00 bib kernel: [769596.793398] lowmem_reserve[]: 0 0 0 0 0 2025-03-10T12:48:00.670372+01:00 bib kernel: [769596.793716] Node 0 DMA: 0*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 1*2048kB (M) 3*4096kB (M) = 14336kB 2025-03-10T12:48:00.670372+01:00 bib kernel: [769596.794404] Node 0 DMA32: 115*4kB (UME) 68*8kB (UME) 110*16kB (UME) 94*32kB (UME) 78*64kB (UME) 56*128kB (UE) 40*256kB (UME) 15*512kB (E) 3*1024kB (UE) 3*2048kB (E) 0*4096kB = 45068kB 2025-03-10T12:48:00.670373+01:00 bib kernel: [769596.795118] Node 0 Normal: 412*4kB (UME) 307*8kB (UME) 166*16kB (UME) 167*32kB (UME) 83*64kB (UME) 50*128kB (UME) 23*256kB (E) 13*512kB (ME) 7*1024kB (ME) 0*2048kB 0*4096kB = 43528kB 2025-03-10T12:48:00.670373+01:00 bib kernel: [769596.795916] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB 2025-03-10T12:48:00.670373+01:00 bib kernel: [769596.796271] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB 2025-03-10T12:48:00.670374+01:00 bib kernel: [769596.796713] 155111 total pagecache pages 2025-03-10T12:48:00.670374+01:00 bib kernel: [769596.797122] 149255 pages in swap cache 2025-03-10T12:48:00.670374+01:00 bib kernel: [769596.797463] Free swap = 0kB 2025-03-10T12:48:00.670375+01:00 bib kernel: [769596.797848] Total swap = 1998844kB 2025-03-10T12:48:00.670922+01:00 bib kernel: [769596.798238] 2097017 pages RAM 2025-03-10T12:48:00.670926+01:00 bib kernel: [769596.798577] 0 pages HighMem/MovableOnly 2025-03-10T12:48:00.670926+01:00 bib kernel: [769596.798954] 72924 pages reserved 2025-03-10T12:48:00.671386+01:00 bib kernel: [769596.799356] 0 pages hwpoisoned 2025-03-10T12:48:00.671388+01:00 bib kernel: [769596.799693] Tasks state (memory values in pages): 2025-03-10T12:48:00.671388+01:00 bib kernel: [769596.800070] [ pid ] uid tgid total_vm rss pgtables_bytes swapents oom_score_adj name 2025-03-10T12:48:00.671389+01:00 bib kernel: [769596.800463] [ 274] 0 274 30075 22 241664 274 -250 systemd-journal 2025-03-10T12:48:00.671389+01:00 bib kernel: [769596.800839] [ 295] 0 295 6770 278 86016 221 -1000 systemd-udevd 2025-03-10T12:48:00.671390+01:00 bib kernel: [769596.801224] [ 524] 997 524 22521 154 77824 82 0 systemd-timesyn 2025-03-10T12:48:00.671390+01:00 bib kernel: [769596.801603] [ 609] 0 609 2372 35 53248 28 0 cron 2025-03-10T12:48:00.671390+01:00 bib kernel: [769596.801997] [ 610] 100 610 2011 143 61440 8 -900 dbus-daemon 2025-03-10T12:48:00.671391+01:00 bib kernel: [769596.802387] [ 612] 0 612 55447 184 81920 116 0 rsyslogd 2025-03-10T12:48:00.671391+01:00 bib kernel: [769596.802749] [ 613] 0 613 4185 203 73728 73 0 systemd-logind 2025-03-10T12:48:00.671391+01:00 bib kernel: [769596.803147] [ 629] 0 629 895 40 49152 3 0 atd 2025-03-10T12:48:00.671392+01:00 bib kernel: [769596.803558] [ 666] 0 666 1499 202 53248 45 0 dhclient 2025-03-10T12:48:00.671392+01:00 bib kernel: [769596.803913] [ 715] 0 715 1435 100 49152 105 0 dhclient 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.804313] [ 747] 104 747 2208 550 61440 34 0 epmd 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.804716] [ 753] 0 753 173229 3280 430080 880 0 fail2ban-server 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.805078] [ 774] 106 774 920414 28673 1294336 23431 -500 beam.smp 2025-03-10T12:48:00.671393+01:00 bib kernel: [769596.805494] [ 797] 0 797 2188 20 53248 2 0 agetty 2025-03-10T12:48:00.671394+01:00 bib kernel: [769596.806006] [ 812] 0 812 3859 213 65536 120 -1000 sshd 2025-03-10T12:48:00.671394+01:00 bib kernel: [769596.806567] [ 841] 106 841 616 19 53248 6 -500 erl_child_setup 2025-03-10T12:48:00.671395+01:00 bib kernel: [769596.807045] [ 1774] 0 1774 10665 108 69632 53 0 master 2025-03-10T12:48:00.671395+01:00 bib kernel: [769596.807442] [ 1779] 102 1779 10700 127 81920 48 0 qmgr 2025-03-10T12:48:00.671396+01:00 bib kernel: [769596.807848] [ 2023] 106 2023 848 11 45056 14 -500 inet_gethost 2025-03-10T12:48:00.671396+01:00 bib kernel: [769596.808192] [ 2026] 106 2026 848 24 45056 8 -500 inet_gethost 2025-03-10T12:48:00.671397+01:00 bib kernel: [769596.808560] [ 2034] 106 2034 644 14 40960 14 -500 sh 2025-03-10T12:48:00.671397+01:00 bib kernel: [769596.808953] [ 3262] 103 3262 2058793 518769 7716864 392357 0 mariadbd 2025-03-10T12:48:00.671397+01:00 bib kernel: [769596.809287] [ 392666] 102 392666 12109 128 90112 225 0 tlsmgr 2025-03-10T12:48:00.671398+01:00 bib kernel: [769596.809647] [2332677] 0 2332677 3456 434 61440 303 0 apache2 2025-03-10T12:48:00.671398+01:00 bib kernel: [769596.810031] [2332685] 105 2332685 107470 2677 159744 2787 0 memcached 2025-03-10T12:48:00.671399+01:00 bib kernel: [769596.810358] [2332735] 1003 2332735 2128 21 49152 15 0 daemon 2025-03-10T12:48:00.671399+01:00 bib kernel: [769596.810703] [2332737] 1003 2332737 14826 161 110592 256 0 zebrasrv 2025-03-10T12:48:00.671399+01:00 bib kernel: [769596.811075] [2332802] 1003 2332802 6211 2612 94208 287 0 starman master 2025-03-10T12:48:00.671400+01:00 bib kernel: [769596.811400] [2332846] 1003 2332846 2128 37 49152 0 0 daemon 2025-03-10T12:48:00.671400+01:00 bib kernel: [769596.811734] [2332847] 1003 2332847 29751 13047 221184 414 0 background_jobs 2025-03-10T12:48:00.671401+01:00 bib kernel: [769596.812076] [2332875] 1003 2332875 2128 21 45056 14 0 daemon 2025-03-10T12:48:00.671401+01:00 bib kernel: [769596.812396] [2332877] 1003 2332877 41320 19112 323584 4526 0 background_jobs 2025-03-10T12:48:00.671401+01:00 bib kernel: [769596.812718] [2332902] 1003 2332902 2128 13 49152 22 0 daemon 2025-03-10T12:48:00.671402+01:00 bib kernel: [769596.813044] [2332904] 1003 2332904 73759 36200 540672 6622 0 rebuild_zebra.p 2025-03-10T12:48:00.671402+01:00 bib kernel: [769596.813369] [1011996] 102 1011996 10671 154 73728 0 0 pickup 2025-03-10T12:48:00.671402+01:00 bib kernel: [769596.813651] [1014020] 33 1014020 3517 422 61440 316 0 apache2 2025-03-10T12:48:00.671403+01:00 bib kernel: [769596.813976] [1015250] 33 1015250 3517 426 61440 311 0 apache2 2025-03-10T12:48:00.671403+01:00 bib kernel: [769596.814307] [1018044] 33 1018044 3517 472 61440 265 0 apache2 2025-03-10T12:48:00.671403+01:00 bib kernel: [769596.814583] [1018109] 33 1018109 3517 465 61440 272 0 apache2 2025-03-10T12:48:00.671404+01:00 bib kernel: [769596.814882] [1018113] 33 1018113 3517 473 61440 265 0 apache2 2025-03-10T12:48:00.671404+01:00 bib kernel: [769596.815171] [1020113] 33 1020113 3517 473 61440 264 0 apache2 2025-03-10T12:48:00.671404+01:00 bib kernel: [769596.815506] [1024635] 33 1024635 3517 474 61440 264 0 apache2 2025-03-10T12:48:00.671405+01:00 bib kernel: [769596.815796] [1026139] 33 1026139 3517 474 61440 264 0 apache2 2025-03-10T12:48:00.671405+01:00 bib kernel: [769596.816089] [1026170] 33 1026170 3517 473 61440 264 0 apache2 2025-03-10T12:48:00.671405+01:00 bib kernel: [769596.816378] [1026641] 1003 1026641 1185289 1122584 9445376 29621 0 /usr/share/koha 2025-03-10T12:48:00.671406+01:00 bib kernel: [769596.816688] [1026652] 33 1026652 3517 473 61440 264 0 apache2 2025-03-10T12:48:00.671406+01:00 bib kernel: [769596.816972] [1027075] 1003 1027075 99496 34733 749568 33424 0 /usr/share/koha 2025-03-10T12:48:00.671407+01:00 bib kernel: [769596.817289] [1027426] 1003 1027426 3594 624 65536 241 0 apache2 2025-03-10T12:48:00.671416+01:00 bib kernel: [769596.817615] [1027453] 1003 1027453 3592 669 61440 240 0 apache2 2025-03-10T12:48:00.671416+01:00 bib kernel: [769596.817890] [1027749] 1003 1027749 16877 179 114688 2268 0 zebrasrv 2025-03-10T12:48:00.671416+01:00 bib kernel: [769596.818218] [1027761] 1003 1027761 3538 563 61440 244 0 apache2 2025-03-10T12:48:00.671417+01:00 bib kernel: [769596.818501] [1027769] 1003 1027769 16966 2354 114688 229 0 zebrasrv 2025-03-10T12:48:00.671417+01:00 bib kernel: [769596.818812] [1027770] 1003 1027770 3523 559 61440 241 0 apache2 2025-03-10T12:48:00.671417+01:00 bib kernel: [769596.819085] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/system.slice/koha-common.service,task=/usr/share/koha,pid=1026641,uid=1003 2025-03-10T12:48:00.671418+01:00 bib kernel: [769596.819717] Out of memory: Killed process 1026641 (/usr/share/koha) total-vm:4741156kB, anon-rss:4490332kB, file-rss:4kB, shmem-rss:0kB, UID:1003 pgtables:9224kB oom_score_adj:0 2025-03-10T12:48:00.721396+01:00 bib systemd[1]: koha-common.service: A process of this unit has been killed by the OOM killer. 2025-03-10T12:48:03.702481+01:00 bib koha-common[1027819]: Stopping Plack daemon for bib:. 2025-03-10T12:48:03.755927+01:00 bib koha-common[1027861]: Stopping Koha worker daemon for bib (default):. 2025-03-10T12:48:03.789372+01:00 bib koha-common[1027886]: Stopping Koha worker daemon for bib (long_tasks):. 2025-03-10T12:48:03.825612+01:00 bib koha-common[1027911]: Stopping Koha indexing daemon for bib:. 2025-03-10T12:48:05.057975+01:00 bib systemd[1]: koha-common.service: Failed with result 'oom-kill'. 2025-03-10T12:48:05.058217+01:00 bib systemd[1]: koha-common.service: Consumed 2d 22h 25min 610ms CPU time. _______________________________________________ Koha-devel mailing list Koha-devel@lists.koha-community.org https://lists.koha-community.org/cgi-bin/mailman/listinfo/koha-devel website : https://www.koha-community.org/ git : https://git.koha-community.org/ bugs : https://bugs.koha-community.org/
Hi David Today you wrote:
I actually just discovered a bug with /cgi-bin/koha/patroncards/ create-pdf.pl which I'll be working on fixing today which could cause resource exhaustion. I had some Starman workers using obscene amounts of memory and CPU, and it's because they got trapped in infinite loops trying to create labels/cards. Fun times...
It's not exactly the same but regarding infinite loops I sometimes find queries like the following in "plack.log" - they look very strange to me and I don't know what they are trying to do: 18.211.148.239 - - [11/Dec/2024:18:52:38 +0100] "GET /opac/opac-search.pl?count=20&limit=su-to:Verwaltung&q=ccl%3Dti,phr:(%22Agenda%22)%20and%20su-to:Berlin%20and%20su-to:Lokale%20Agenda%2021%20and%20itype:BUCH%20and%20((%20(allrecords,AlwaysMatches%3D%27%27)%20and%20(not-onloan-count,st-numeric%20%3E%3D%201)%20and%20(lost,st-numeric%3D0)%20))%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20itype:BUCH%20and%20itype:BUCH%20and%20su-to:Lokale%20Agenda%2021%20and%20((%20(allrecords,AlwaysMatches%3D%27%27)%20and%20(not-onloan-count,st-numeric%20%3E%3D%201)%20and%20(lost,st-numeric%3D0)%20))%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021&sort_by=relevance HTTP/1.1" 302 0 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_1) AppleWebKit/600.2.5 (KHTML, like Gecko) Version/8.0.2 Safari/600.2.5 (Amazonbot/0.1; +https://developer.amazon.com/support/amazonbot)"
But in your case... I'm guessing it's probably due to bots. I've noticed Starman instances that get a lot of bot hits balloon in memory usage. You might want to look at your "plack_max_requests" in koha- conf.xml. Once the Starman worker reaches its max requests, it'll be killed off, and the memory released. But then there's some CPU overhead to starting up a new Starman worker process. So there's a cost/benefit to do there.
That's the path I followed! plack_workers and plack_max_requests both showed the default value, I have now increased the value of tag plack_workers from 2 to 4 (the CPU core count) even if it doesn't seem to have boosted the page load. Sadly, "robots.txt" doesn't really seem to impress most bot behavior. What really helped was when I blocked all the bots I could find in "plack.log" (ahrefs|Amazonbot|bingbot|ClaudeBot|DotBot|Googlebot|GPTBot|meta-externalagent) using mod_rewrite. This stopped all the bot queries immediately, thus also reduced the memory usage, and at least for now Koha seems to work all right again.
It can be tough troubleshooting these things after the fact, so I'd suggest putting in some monitoring, which alerts you once your memory usage starts getting high. That way you can troubleshoot it more in real time. That said, troubleshooting memory use can be tricky...
As an addition I have written a small script which will send me an e-mail if file "/var/log/syslog" contains a new message regarding "Out of memory". Many thanks for your suggestions! Best wishes: Michael -- Geschäftsführer · Diplombibliothekar BBS, Informatiker eidg. Fachausweis Admin Kuhn GmbH · Pappelstrasse 20 · 4123 Allschwil · Schweiz T 0041 (0)61 261 55 61 · E mik@adminkuhn.ch · W www.adminkuhn.ch
HI Michael, That opac-search.pl log looks like a bot that is really stuck. That looks like it would yield an ever growing search query. Yeah, most bots don't honour robots.txt anymore it seems. Blocking bots that self-identify with user agent strings is certainly useful, but it wouldn't block all the bots. Lyrasis has put together some good info on AI harvesting bots for instance: https://wiki.lyrasis.org/display/cmtygp/Aggressive+AI+Harvesting+of+Digital+... David Cook Senior Software Engineer Prosentient Systems Suite 7.03 6a Glen St Milsons Point NSW 2061 Australia Office: 02 9212 0899 -----Original Message----- From: Michael Kuhn <mik@adminkuhn.ch> Sent: Wednesday, 12 March 2025 8:08 AM To: David Cook <dcook@prosentient.com.au>; 'Koha-devel' <koha-devel@lists.koha-community.org> Subject: Re: [Koha-devel] oom-killer / Out of memory: Killed process 1026641 (/usr/share/koha) Hi David Today you wrote:
I actually just discovered a bug with /cgi-bin/koha/patroncards/ > create-pdf.pl which I'll be working on fixing today which could cause > resource exhaustion. I had some Starman workers using obscene amounts > of memory and CPU, and it's because they got trapped in infinite loops > trying to create labels/cards. Fun times...
It's not exactly the same but regarding infinite loops I sometimes find queries like the following in "plack.log" - they look very strange to me and I don't know what they are trying to do: 18.211.148.239 - - [11/Dec/2024:18:52:38 +0100] "GET /opac/opac-search.pl?count=20&limit=su-to:Verwaltung&q=ccl%3Dti,phr:(%22Agenda%22)%20and%20su-to:Berlin%20and%20su-to:Lokale%20Agenda%2021%20and%20itype:BUCH%20and%20((%20(allrecords,AlwaysMatches%3D%27%27)%20and%20(not-onloan-count,st-numeric%20%3E%3D%201)%20and%20(lost,st-numeric%3D0)%20))%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20itype:BUCH%20and%20itype:BUCH%20and%20su-to:Lokale%20Agenda%2021%20and%20((%20(allrecords,AlwaysMatches%3D%27%27)%20and%20(not-onloan-count,st-numeric%20%3E%3D%201)%20and%20(lost,st-numeric%3D0)%20))%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021&sort_by=relevance HTTP/1.1" 302 0 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_1) AppleWebKit/600.2.5 (KHTML, like Gecko) Version/8.0.2 Safari/600.2.5 (Amazonbot/0.1; +https://developer.amazon.com/support/amazonbot)"
But in your case... I'm guessing it's probably due to bots. I've > noticed Starman instances that get a lot of bot hits balloon in memory > usage. You might want to look at your "plack_max_requests" in koha- > conf.xml. Once the Starman worker reaches its max requests, it'll be > killed off, and the memory released. But then there's some CPU > overhead to starting up a new Starman worker process. So there's a > cost/benefit to do there.
That's the path I followed! plack_workers and plack_max_requests both showed the default value, I have now increased the value of tag plack_workers from 2 to 4 (the CPU core count) even if it doesn't seem to have boosted the page load. Sadly, "robots.txt" doesn't really seem to impress most bot behavior. What really helped was when I blocked all the bots I could find in "plack.log" (ahrefs|Amazonbot|bingbot|ClaudeBot|DotBot|Googlebot|GPTBot|meta-externalagent) using mod_rewrite. This stopped all the bot queries immediately, thus also reduced the memory usage, and at least for now Koha seems to work all right again.
It can be tough troubleshooting these things after the fact, so I'd > suggest putting in some monitoring, which alerts you once your memory > usage starts getting high. That way you can troubleshoot it more in > real time. That said, troubleshooting memory use can be tricky...
As an addition I have written a small script which will send me an e-mail if file "/var/log/syslog" contains a new message regarding "Out of memory". Many thanks for your suggestions! Best wishes: Michael -- Geschäftsführer · Diplombibliothekar BBS, Informatiker eidg. Fachausweis Admin Kuhn GmbH · Pappelstrasse 20 · 4123 Allschwil · Schweiz T 0041 (0)61 261 55 61 · E mik@adminkuhn.ch · W www.adminkuhn.ch
Hi David On 11 March you wrote:
That opac-search.pl log looks like a bot that is really stuck. That looks like it would yield an ever growing search query.
Yeah, most bots don't honour robots.txt anymore it seems.
Blocking bots that self-identify with user agent strings is certainly useful, but it wouldn't block all the bots. Lyrasis has put together some good info on AI harvesting bots for instance: * https://wiki.lyrasis.org/display/cmtygp/Aggressive+AI+Harvesting+of+Digital+...
Many thanks for this link which gives me some better insight since many of these these bots get even more annoying tahn they already were. Best wishes: Michael -- Geschäftsführer · Diplombibliothekar BBS, Informatiker eidg. Fachausweis Admin Kuhn GmbH · Pappelstrasse 20 · 4123 Allschwil · Schweiz T 0041 (0)61 261 55 61 · E mik@adminkuhn.ch · W www.adminkuhn.ch
-----Original Message----- From: Michael Kuhn <mik@adminkuhn.ch> Sent: Wednesday, 12 March 2025 8:08 AM To: David Cook <dcook@prosentient.com.au>; 'Koha-devel' <koha-devel@lists.koha-community.org> Subject: Re: [Koha-devel] oom-killer / Out of memory: Killed process 1026641 (/usr/share/koha)
Hi David
Today you wrote:
I actually just discovered a bug with /cgi-bin/koha/patroncards/ > create-pdf.pl which I'll be working on fixing today which could cause > resource exhaustion. I had some Starman workers using obscene amounts > of memory and CPU, and it's because they got trapped in infinite loops > trying to create labels/cards. Fun times...
It's not exactly the same but regarding infinite loops I sometimes find queries like the following in "plack.log" - they look very strange to me and I don't know what they are trying to do:
18.211.148.239 - - [11/Dec/2024:18:52:38 +0100] "GET /opac/opac-search.pl?count=20&limit=su-to:Verwaltung&q=ccl%3Dti,phr:(%22Agenda%22)%20and%20su-to:Berlin%20and%20su-to:Lokale%20Agenda%2021%20and%20itype:BUCH%20and%20((%20(allrecords,AlwaysMatches%3D%27%27)%20and%20(not-onloan-count,st-numeric%20%3E%3D%201)%20and%20(lost,st-numeric%3D0)%20))%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021%20and%20itype:BUCH%20and%20itype:BUCH%20and%20su-to:Lokale%20Agenda%2021%20and%20((%20(allrecords,AlwaysMatches%3D%27%27)%20and%20(not-onloan-count,st-numeric%20%3E%3D%201)%20and%20(lost,st-numeric%3D0)%20))%20and%20su-to:Lokale%20Agenda%2021%20and%20su-to:Lokale%20Agenda%2021&sort_by=relevance HTTP/1.1" 302 0 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_1) AppleWebKit/600.2.5 (KHTML, like Gecko) Version/8.0.2 Safari/600.2.5 (Amazonbot/0.1; +https://developer.amazon.com/support/amazonbot)"
But in your case... I'm guessing it's probably due to bots. I've > noticed Starman instances that get a lot of bot hits balloon in memory > usage. You might want to look at your "plack_max_requests" in koha- > conf.xml. Once the Starman worker reaches its max requests, it'll be > killed off, and the memory released. But then there's some CPU > overhead to starting up a new Starman worker process. So there's a > cost/benefit to do there.
That's the path I followed! plack_workers and plack_max_requests both showed the default value, I have now increased the value of tag plack_workers from 2 to 4 (the CPU core count) even if it doesn't seem to have boosted the page load.
Sadly, "robots.txt" doesn't really seem to impress most bot behavior.
What really helped was when I blocked all the bots I could find in "plack.log" (ahrefs|Amazonbot|bingbot|ClaudeBot|DotBot|Googlebot|GPTBot|meta-externalagent) using mod_rewrite. This stopped all the bot queries immediately, thus also reduced the memory usage, and at least for now Koha seems to work all right again.
It can be tough troubleshooting these things after the fact, so I'd > suggest putting in some monitoring, which alerts you once your memory > usage starts getting high. That way you can troubleshoot it more in > real time. That said, troubleshooting memory use can be tricky...
As an addition I have written a small script which will send me an e-mail if file "/var/log/syslog" contains a new message regarding "Out of memory".
Many thanks for your suggestions!
Best wishes: Michael -- Geschäftsführer · Diplombibliothekar BBS, Informatiker eidg. Fachausweis Admin Kuhn GmbH · Pappelstrasse 20 · 4123 Allschwil · Schweiz T 0041 (0)61 261 55 61 · E mik@adminkuhn.ch · W www.adminkuhn.ch
participants (3)
-
David Cook -
Michael Hafen -
Michael Kuhn