[clug] server crash

Wed Jul 20 06:51:47 GMT 2005

When you say "crashed", do you in fact mean just Apache or the entire
machine?
Because it's fairly clear from your log dump that Apache was using way
too much memory.  I'd hazard a guess that cgiirc was doing weird things
(Perl scripts shouldn't be able to fail to free memory, but it does
happen).  Or there were too many people using it...  which would be
inline with your filehandles maxing out for the apache2 process if
you're using mod_perl (and possibly even if you're not).
Keep in mind that your iptables rule won't stop people using cgiirc from
reaching your irc server.

Apart from that I can't suggest anything based on the log, as the kernel
deciding it needed to commit suicide to free up pages is extremely
unlikely (Make sure no one has an infinite improbability drive anywhere
nearby).

On Tue, 2005-07-19 at 22:56 +1000, chris wrote:
> Hi all:
> 
> It all happened last nigth, one of our debian servers crashed, quite 
> possibly, it was even hacked.
> The following output was obtained from
> 
> "tail -9000 /var/log/message|grep 'Jul 19'
> "tail -9000 /var/log/kern.log|grep 'Jul 19'
> 
> Jul 19 00:58:02 postal -- MARK --
> Jul 19 01:18:02 postal -- MARK --
> Jul 19 01:38:04 postal -- MARK --
> Jul 19 01:39:34 postal kernel: oom-killer: gfp_mask=0x1d2
> Jul 19 01:39:34 postal kernel: DMA per-cpu:
> Jul 19 01:39:34 postal kernel: cpu 0 hot: low 2, high 6, batch 1
> Jul 19 01:39:34 postal kernel: cpu 0 cold: low 0, high 2, batch 1
> Jul 19 01:39:34 postal kernel: Normal per-cpu:
> Jul 19 01:39:34 postal kernel: cpu 0 hot: low 32, high 96, batch 16
> Jul 19 01:39:34 postal kernel: cpu 0 cold: low 0, high 32, batch 16
> Jul 19 01:39:34 postal kernel: HighMem per-cpu: empty
> Jul 19 01:39:34 postal kernel:
> Jul 19 01:39:34 postal kernel: Free pages:        2360kB (0kB HighMem)
> Jul 19 01:39:34 postal kernel: Active:1329 inactive:68195 dirty:0 
> writeback:0 unstable:0 free:590 slab:21734 mapped:71502 pagetables:693
> Jul 19 01:39:34 postal kernel: DMA free:1208kB min:24kB low:48kB 
> high:72kB active:5060kB inactive:0kB present:16384kB
> Jul 19 01:39:34 postal kernel: protections[]: 12 310 310
> Jul 19 01:39:34 postal kernel: Normal free:1152kB min:596kB low:1192kB 
> high:1788kB active:256kB inactive:272780kB present:376820kB
> Jul 19 01:39:34 postal kernel: protections[]: 0 298 298
> Jul 19 01:39:34 postal kernel: HighMem free:0kB min:128kB low:256kB 
> high:384kB active:0kB inactive:0kB present:0kB
> Jul 19 01:39:34 postal kernel: protections[]: 0 0 0
> Jul 19 01:39:34 postal kernel: DMA: 0*4kB 1*8kB 9*16kB 5*32kB 2*64kB 
> 2*128kB 0*256kB 1*512kB 0*1024kB 0*2048kB 0*4096kB = 1208kB
> Jul 19 01:39:34 postal kernel: Normal: 0*4kB 0*8kB 0*16kB 4*32kB 2*64kB 
> 1*128kB 1*256kB 1*512kB 0*1024kB 0*2048kB 0*4096kB = 1152kB
> Jul 19 01:39:34 postal kernel: HighMem: empty
> Jul 19 01:39:34 postal kernel: Swap cache: add 26810, delete 26810, find 
> 2688/3937, race 0+0
> Jul 19 01:39:34 postal kernel: oom-killer: gfp_mask=0x1d2
> Jul 19 01:39:34 postal kernel: DMA per-cpu:
> Jul 19 01:39:34 postal kernel: cpu 0 hot: low 2, high 6, batch 1
> Jul 19 01:39:34 postal kernel: cpu 0 cold: low 0, high 2, batch 1
> Jul 19 01:39:34 postal kernel: Normal per-cpu:
> Jul 19 01:39:34 postal kernel: cpu 0 hot: low 32, high 96, batch 16
> Jul 19 01:39:34 postal kernel: cpu 0 cold: low 0, high 32, batch 16
> Jul 19 01:39:34 postal kernel: HighMem per-cpu: empty
> Jul 19 01:39:34 postal kernel:
> Jul 19 01:39:34 postal kernel: Free pages:        2544kB (0kB HighMem)
> Jul 19 01:39:34 postal kernel: Active:24638 inactive:44611 dirty:0 
> writeback:0 unstable:0 free:636 slab:21693 mapped:71494 pagetables:693
> Jul 19 01:39:34 postal kernel: DMA free:1208kB min:24kB low:48kB 
> high:72kB active:5060kB inactive:0kB present:16384kB
> Jul 19 01:39:34 postal kernel: protections[]: 12 310 310
> Jul 19 01:39:34 postal kernel: Normal free:1336kB min:596kB low:1192kB 
> high:1788kB active:93492kB inactive:178444kB present:376820kB
> 
> ..........
> 
> Jul 19 02:59:08 postal -- MARK --
> Jul 19 03:11:46 postal kernel: VFS: file-max limit 37652 reached
> Jul 19 03:11:46 postal last message repeated 111 times
> Jul 19 03:11:46 postal kernel: VFS: file-max limit 37 file-max limit 
> 37652 reached
> Jul 19 03:11:46 postal kernel: VFS: file-max limit 37652 reached
> Jul 19 03:11:46 postal last message repeated 1065 times
> Jul 19 03:11:47 postal kernel:  file-max limit 37652 reached
> Jul 19 03:11:47 postal kernel: VFS: file-max limit 37652 reached
> Jul 19 03:11:47 postal last message repeated 441 times
> Jul 19 03:11:47 postal kernel:  file-max limit 37652 reached
> Jul 19 03:11:47 postal kernel: VFS: file-max limit 37652 reached
> Jul 19 03:11:47 postal last message repeated 108 times
> 
> -----these messages repeated until I restarted the server--------
> 
> After I restarted the server, the system appears to be running fairly 
> stable, however, the damn messages came up again after 12 hours' uptime. 
> (even now, the system is still running fairly stable)
> 
> Jul 19 22:02:13 postal kernel: oom-killer: gfp_mask=0x1d2
> Jul 19 22:02:14 postal kernel: DMA per-cpu:
> Jul 19 22:02:14 postal kernel: cpu 0 hot: low 2, high 6, batch 1
> Jul 19 22:02:14 postal kernel: cpu 0 cold: low 0, high 2, batch 1
> Jul 19 22:02:14 postal kernel: Normal per-cpu:
> Jul 19 22:02:14 postal kernel: cpu 0 hot: low 32, high 96, batch 16
> Jul 19 22:02:14 postal kernel: cpu 0 cold: low 0, high 32, batch 16
> Jul 19 22:02:14 postal kernel: HighMem per-cpu: empty
> Jul 19 22:02:14 postal kernel:
> Jul 19 22:02:14 postal kernel: Free pages:        2384kB (0kB HighMem)
> Jul 19 22:02:14 postal kernel: Active:68178 inactive:16354 dirty:0 
> writeback:0 unstable:0 free:596 slab:4166 mapped:88299 pagetables:880
> Jul 19 22:02:14 postal kernel: DMA free:1240kB min:24kB low:48kB 
> high:72kB active:8480kB inactive:3380kB present:16384kB
> Jul 19 22:02:14 postal kernel: protections[]: 12 310 310
> Jul 19 22:02:14 postal kernel: Normal free:1144kB min:596kB low:1192kB 
> high:1788kB active:264232kB inactive:62036kB present:376820kB
> Jul 19 22:02:14 postal kernel: protections[]: 0 298 298
> Jul 19 22:02:14 postal kernel: HighMem free:0kB min:128kB low:256kB 
> high:384kB active:0kB inactive:0kB present:0kB
> Jul 19 22:02:14 postal kernel: protections[]: 0 0 0
> Jul 19 22:02:14 postal kernel: DMA: 2*4kB 0*8kB 1*16kB 0*32kB 1*64kB 
> 1*128kB 0*256kB 0*512kB 1*1024kB 0*2048kB 0*4096kB = 1240kB
> Jul 19 22:02:14 postal kernel: Normal: 0*4kB 1*8kB 1*16kB 1*32kB 1*64kB 
> 0*128kB 0*256kB 0*512kB 1*1024kB 0*2048kB 0*4096kB = 1144kB
> Jul 19 22:02:14 postal kernel: HighMem: empty
> Jul 19 22:02:14 postal kernel: Swap cache: add 19870, delete 19870, find 
> 1085/1511, race 0+0
> Jul 19 22:02:14 postal kernel: Out of Memory: Killed process 3583 
> (apache2).
> Jul 19 22:02:14 postal kernel: gh 32, batch 16
> Jul 19 22:02:14 postal kernel: HighMem per-cpu: empty
> Jul 19 22:02:14 postal kernel:
> Jul 19 22:02:14 postal kernel: Free pages:        2376kB (0kB HighMem)
> Jul 19 22:02:14 postal kernel: Active:64444 inactive:21982 dirty:0 
> writeback:0 unstable:0 free:594 slab:4132 mapped:88298 pagetables:880
> 
> I recently added an IRC server(ircu-ircd) on the machine, also a 
> web-based front end(cgiirc) along with it, I had both from apt-get, the 
> server is running Sarge, packags were up-to-date prior to the crash.
> 
> To prevent people accessing the IRC from off campus, I had
> iptables -A INPUT -p tcp -s ! 150.203.0.0/16 --dport 6666 -j DROP
> 
> If you need additional info, I can get them to you. Does anyone has a 
> clue what exactly happened? and what do I need to do to prevent another 
> crash?
> 
> Thank
> 
> Chris
> 
> 