Hi!
Currently we have a little bit of issues with wowza and java. Last weekend java crashed a couple of times, and i`m not sure what the cause exactly is. I hope you can help me out.
Problem: Wowza stopped working. Dmesg shows:
May 13 20:51:17 hostname kernel: [11700997.102428] java invoked oom-killer: gfp_mask=0x1201d2, order=0, oomkilladj=0
May 13 20:51:17 hostname kernel: [11700997.102436] Pid: 8744, comm: java Not tainted 2.6.26-2-amd64 #1
May 13 20:51:17 hostname kernel: [11700997.102437]
May 13 20:51:17 hostname kernel: [11700997.102438] Call Trace:
May 13 20:51:17 hostname kernel: [11700997.102531] [<ffffffff802738dc>] oom_kill_process+0x57/0x1dc
May 13 20:51:17 hostname kernel: [11700997.102539] [<ffffffff8023b4d1>] __capable+0x9/0x1c
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff80273c07>] badness+0x188/0x1c7
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff80273e3b>] out_of_memory+0x1f5/0x28e
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff80276b8c>] __alloc_pages_internal+0x31d/0x3bf
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff80278842>] __do_page_cache_readahead+0x79/0x183
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff802730f1>] filemap_fault+0x15d/0x33c
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff8027e670>] __do_fault+0x50/0x3e8
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff8024fb2f>] futex_wake+0x74/0xfa
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff80281a33>] handle_mm_fault+0x452/0x8de
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff80248b8a>] hrtimer_start+0x112/0x134
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff80229020>] hrtick_start_fair+0xfb/0x144
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff80221fbc>] do_page_fault+0x5d8/0x9c8
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff8042918f>] thread_return+0x6b/0xac
May 13 20:51:17 hostname kernel: [11700997.103887] [<ffffffff8042a889>] error_exit+0x0/0x60
May 13 20:51:17 hostname kernel: [11700997.103887]
May 13 20:51:17 hostname kernel: [11700997.103887] Mem-info:
May 13 20:51:17 hostname kernel: [11700997.103887] Node 0 DMA per-cpu:
May 13 20:51:17 hostname kernel: [11700997.103887] CPU 0: hi: 0, btch: 1 usd: 0
May 13 20:51:17 hostname kernel: [11700997.103887] CPU 1: hi: 0, btch: 1 usd: 0
May 13 20:51:17 hostname kernel: [11700997.103887] Node 0 DMA32 per-cpu:
May 13 20:51:17 hostname kernel: [11700997.103887] CPU 0: hi: 186, btch: 31 usd: 180
May 13 20:51:17 hostname kernel: [11700997.103887] CPU 1: hi: 186, btch: 31 usd: 178
May 13 20:51:17 hostname kernel: [11700997.103887] Node 0 Normal per-cpu:
May 13 20:51:17 hostname kernel: [11700997.103887] CPU 0: hi: 186, btch: 31 usd: 176
May 13 20:51:17 hostname kernel: [11700997.103887] CPU 1: hi: 186, btch: 31 usd: 182
May 13 20:51:17 hostname kernel: [11700997.103887] Active:966157 inactive:26396 dirty:0 writeback:0 unstable:0
May 13 20:51:17 hostname kernel: [11700997.103887] free:5919 slab:4164 mapped:2 pagetables:10479 bounce:0
May 13 20:51:17 hostname kernel: [11700997.103887] Node 0 DMA free:11704kB min:20kB low:24kB high:28kB active:0kB inactive:0kB present:10780kB pages_scanned:0 all_unreclaimable? yes
May 13 20:51:17 hostname kernel: [11700997.103887] lowmem_reserve[]: 0 3000 4010 4010
May 13 20:51:17 hostname kernel: [11700997.103887] Node 0 DMA32 free:10008kB min:6056kB low:7568kB high:9084kB active:2928072kB inactive:41940kB present:3072160kB pages_scanned:4700797 all_unreclaimable? yes
May 13 20:51:17 hostname kernel: [11700997.103887] lowmem_reserve[]: 0 0 1010 1010
May 13 20:51:17 hostname kernel: [11700997.103887] Node 0 Normal free:1964kB min:2036kB low:2544kB high:3052kB active:936556kB inactive:63516kB present:1034240kB pages_scanned:3837210 all_unreclaimable? yes
May 13 20:51:17 hostname kernel: [11700997.103887] lowmem_reserve[]: 0 0 0 0
May 13 20:51:17 hostname kernel: [11700997.103887] Node 0 DMA: 6*4kB 6*8kB 3*16kB 6*32kB 4*64kB 1*128kB 1*256kB 1*512kB 2*1024kB 0*2048kB 2*4096kB = 11704kB
May 13 20:51:17 hostname kernel: [11700997.103887] Node 0 DMA32: 1028*4kB 11*8kB 7*16kB 2*32kB 0*64kB 0*128kB 0*256kB 1*512kB 1*1024kB 0*2048kB 1*4096kB = 10008kB
May 13 20:51:17 hostname kernel: [11700997.103887] Node 0 Normal: 41*4kB 7*8kB 3*16kB 1*32kB 0*64kB 1*128kB 0*256kB 1*512kB 1*1024kB 0*2048kB 0*4096kB = 1964kB
May 13 20:51:17 hostname kernel: [11700997.103887] 67 total pagecache pages
May 13 20:51:17 hostname kernel: [11700997.103887] Swap cache: add 19471782, delete 19471782, find 6322006/8213143
May 13 20:51:17 hostname kernel: [11700997.103887] Free swap = 0kB
May 13 20:51:17 hostname kernel: [11700997.103887] Total swap = 979956kB
May 13 20:51:17 hostname kernel: [11700997.114997] 1048576 pages of RAM
May 13 20:51:17 hostname kernel: [11700997.114999] 32134 reserved pages
May 13 20:51:17 hostname kernel: [11700997.115000] 3437 pages shared
May 13 20:51:17 hostname kernel: [11700997.115001] 0 pages swap cached
May 13 20:51:17 hostname kernel: [11700997.115003] Out of memory: kill process 8738 (WowzaMediaServe) score 3365667 or a child
May 13 20:51:17 hostname kernel: [11700997.115130] Killed process 8739 (java)
Logs:
Wowza error log: none
Wowza access log, just before the crash (and a piece of logging that it’s beeing started again)
2011-05-15 19:30:17 CEST play stream INFO 200 first - _defaultVHost_ 10042 _definst_ 0.644 [any] 1935 rtmp://hostname:1935/10042 clientip93.42.217 rtmp http://www.host.nl/swf/flowplayer-3.2.5.swf?0.9216546089064822 WIN 10,0,42,34 1180811637 3572 3453 1 0 0 0 first - - - - - rtmp://hostname:1935/10042/first rtmp://hostname:1935/10042/first - rtmp://hostname:1935/10042 -
2011-05-15 19:31:05 CEST comment server INFO 200 - MediaStreamMediaCasterPlay: close - - - 5261.97 - - - - - - - -- - - - - - - - - - - - - - - - -
2011-05-15 19:31:05 CEST stop stream INFO 200 first - _defaultVHost_ 11231 _definst_ 284.924 [any] 1935 rtmp://hostname:1935/11231 clientip rtmp http://www.host.nl/swf/flowplayer-3.2.5.swf?0.34244836596281014 WIN 10,2,153,1 886600220 3688 19661789 1 287463 0 19564992 first - - - -- rtmp://hostname:1935/11231/first rtmp://hostname:1935/11231/first - rtmp://hostname:1935/11231 -
2011-05-15 19:31:08 CEST destroy stream INFO 200 first - _defaultVHost_ 11231 _definst_ 287.439 [any] 1935 rtmp://hostname:1935/11231 clientip rtmp http://www.host.nl/swf/flowplayer-3.2.5.swf?0.34244836596281014 WIN 10,2,153,1 886600220 3688 19661973 1 - 0 19564992 first - - - -- rtmp://hostname:1935/11231/first rtmp://hostname:1935/11231/first - rtmp://hostname:1935/11231 -
2011-05-15 19:31:08 CEST disconnect session INFO 200 886600220 - _defaultVHost_ 11231 _definst_ 287.59 [any] 1935 rtmp://hostname:1935/11231clientip rtmp http://www.host.nl/swf/flowplayer-3.2.5.swf?0.34244836596281014 WIN 10,2,153,1 886600220 3688 19661973 - - - - - - - -- - - - - rtmp://hostname:1935/11231 -
2011-05-15 19:31:08 CEST comment server INFO 200 - onDisconnect: CLIENT ID=886600220 USER-AGENT=WIN 10,2,153,1 _defaultVHost_ 11231 _definst_ 5264.489 - -- - - - - - - - - - - - - - - - - - - - - - -
2011-05-15 19:31:08 CEST connect-pending session INFO 100 clientip - _defaultVHost_ 11231 _definst_ 0.084 [any] 1935 rtmp://hostname:1935/11231clientip rtmp http://www.host.nl/swf/flowplayer-3.2.5.swf?0.34244836596281014 WIN 10,2,153,1 501117344 3443 3073 - - - - - - - - -- - - - rtmp://hostname:1935/11231 -
2011-05-15 19:31:08 CEST comment server INFO 200 - onConnect: CLIENT ID=501117344 USER-AGENT=WIN 10,2,153,1 _defaultVHost_ 11231 _definst_ 5264.563 - -- - - - - - - - - - - - - - - - - - - - - - -
2011-05-15 19:31:08 CEST comment server INFO 200 - sessionParms= _defaultVHost_ 11231 _definst_ 5264.564 - - - - - - - -- - - - - - - - - - - - - - - - -
2011-05-15 19:31:09 CEST connect-pending session INFO 100 clientip - _defaultVHost_ 11231 _definst_ 0.791 [any] 1935 rtmpt://hostname:1935/11231clientip rtmpt (HTTP-1.1) http://www.host.nl/swf/flowplayer-3.2.5.swf?0.34244836596281014 WIN 10,2,153,1 2147123495 3441 3085 - - - - - - -- - - - - - rtmpt://hostname:1935/11231 -
2011-05-15 19:31:09 CEST comment server INFO 200 - onConnect: CLIENT ID=2147123495 USER-AGENT=WIN 10,2,153,1 _defaultVHost_ 11231 _definst_ 5265.293 - -- - - - - - - - - - - - - - - - - - - - - - -
2011-05-15 19:31:09 CEST comment server INFO 200 - sessionParms=null _defaultVHost_ 11231 _definst_ 5265.293 - - - - - - -- - - - - - - - - - - - - - - - - -
2011-05-15 19:31:12 CEST comment server INFO 200 - This stream is PUBLIC _defaultVHost_ 11231 _definst_ 5268.808 - - - - - - -- - - - - - - - - - - - - - - - - -
2011-05-15 19:31:12 CEST connect session INFO 200 clientip - _defaultVHost_ 11231 _definst_ 4.311 [any] 1935 rtmpt://hostname:1935/11231 clientip rtmpt (HTTP-1.1) http://www.host.nl/swf/flowplayer-3.2.5.swf?0.34244836596281014 WIN 10,2,153,1 2147123495 3441 3085 - - - - - - -- - - - - - rtmpt://hostname:1935/11231 -
2011-05-15 19:31:12 CEST comment server INFO 200 - Connection ACCEPTED _defaultVHost_ 11231 _definst_ 5268.813 - - - - - - -- - - - - - - - - - - - - - - - - -
2011-05-15 19:31:13 CEST create stream INFO 200 - - _defaultVHost_ 11231 _definst_ 0.0010 [any] 1935 rtmpt://hostname:1935/11231 clientip rtmpt (HTTP-1.1) http://www.host.nl/swf/flowplayer-3.2.5.swf?0.34244836596281014 WIN 10,2,153,1 2147123495 3513 3425 1 0 0 0 - - - -0 0.0 rtmpt://hostname:1935/11231 rtmpt://hostname:1935/11231 - rtmpt://hostname:1935/11231 -
2011-05-15 19:31:13 CEST comment server INFO 200 - This stream is PUBLIC _defaultVHost_ 11231 _definst_ 5269.588 - - - - - - -- - - - - - - - - - - - - - - - - -
2011-05-15 19:31:13 CEST connect session INFO 200 clientip - _defaultVHost_ 11231 _definst_ 5.11 [any] 1935 rtmp://hostname:1935/11231 clientip rtmp http://www.host.nl/swf/flowplayer-3.2.5.swf?0.34244836596281014 WIN 10,2,153,1 501117344 3443 3073 - - - - - - - - - -- - - rtmp://hostname:1935/11231 -
2011-05-15 19:31:13 CEST comment server INFO 200 - Connection ACCEPTED _defaultVHost_ 11231 _definst_ 5269.589 - - - - - - -- - - - - - - - - - - - - - - - - -
2011-05-15 19:31:13 CEST disconnect session INFO 200 501117344 - _defaultVHost_ 11231 _definst_ 5.112 [any] 1935 rtmp://hostname:1935/11231clientip rtmp http://www.host.nl/swf/flowplayer-3.2.5.swf?0.34244836596281014 WIN 10,2,153,1 501117344 3443 3411 - - - - - - - - -- - - - rtmp://hostname:1935/11231 -
2011-05-15 19:31:13 CEST comment server INFO 200 - onDisconnect: CLIENT ID=501117344 USER-AGENT=WIN 10,2,153,1 _defaultVHost_ 11231 _definst_ 5269.591 - -- - - - - - - - - - - - - - - - - - - - - - -
2011-05-15 19:31:13 CEST comment server INFO 200 - MediaStreamMediaCasterPlay: startPlay - - - 5269.612 - - - - - - -- - - - - - - - - - - - - - - - - -
2011-05-15 19:31:13 CEST comment server INFO 200 - LivePlayer.play[11231/_definst_/2011-05-15-18-04-11]: Dynamic Stream Markers are on. - - - 5269.612 -- - - - - - - - - - - - - - - - - - - - - - - -
2011-05-15 19:31:13 CEST play stream INFO 200 first - _defaultVHost_ 11231 _definst_ 0.634 [any] 1935 rtmpt://hostname:1935/11231 clientip rtmpt (HTTP-1.1) http://www.host.nl/swf/flowplayer-3.2.5.swf?0.34244836596281014 WIN 10,2,153,1 2147123495 3571 3470 1 0 0 0 first - - -- - rtmpt://hostname:1935/11231/first rtmpt://hostname:1935/11231/first - rtmpt://hostname:1935/11231 -
#Version: 1.0
#Start-Date: 2011-05-15 19:36:36 CEST
#Software: Wowza Media Server 2.2.3 build26454
#Date: 2011-05-15
#Fields: date time tz x-event x-category x-severity x-status x-ctx x-comment x-vhost x-app x-appinst x-duration s-ip s-port s-uri c-ip c-proto c-referrer c-user-agent c-client-id cs-bytes sc-bytes x-stream-id x-spos cs-stream-bytes sc-stream-bytes x-sname x-sname-query x-file-name x-file-ext x-file-size x-file-length x-suri x-suri-stem x-suri-query cs-uri-stem cs-uri-query
2011-05-15 19:36:37 CEST server-start server INFO 200 Wowza Media Server 2 Subscription 2.2.3 build26454 - - - - 2.123 - - - - -- - - - - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Serial number: XXXXX-XXXXX-XXXXX-XXXXX-REMOVED - - - 2.162 - - - - - - -- - - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Maximum connections: Unlimited - - - 2.163 - - - - - - - - -- - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Hardware Available Processors: 2 - - - 2.163 - - - - - - - -- - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Hardware Physical Memory: 1921MB/3970MB - - - 2.164 - - - - - - - -- - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Hardware Swap Space: 1MB/956MB - - - 2.164 - - - - - - - - -- - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Max File Descriptor Count: 1024 - - - 2.166 - - - - - - - - -- - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Open File Descriptor Count: 46 - - - 2.166 - - - - - - - - -- - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - OS Name: Linux - - - 2.166 - - - - - - - - - - -- - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - OS Version: 2.6.26-2-amd64 - - - 2.167 - - - - - - - - -- - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - OS Architecture: amd64 - - - 2.167 - - - - - - - - - -- - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Name: Java HotSpot(TM) 64-Bit Server VM - - - 2.167 - - - - - - -- - - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Vendor: Sun Microsystems Inc. - - - 2.167 - - - - - - - -- - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Version: 1.6.0_22 - - - 2.168 - - - - - - - - - -- - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java VM Version: 17.1-b03 - - - 2.168 - - - - - - - - -- - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Spec Version: 1.6 - - - 2.168 - - - - - - - - - -- - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Home: /usr/lib/jvm/java-6-sun-1.6.0.22/jre - - - 2.169 - - - - - - -- - - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Max Heap Size: 2995MB - - - 2.169 - - - - - - - - -- - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Architecture: 64 - - - 2.169 - - - - - - - - - -- - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Encoding[file.encoding]: ANSI_X3.4-1968 - - - 2.17 - - - - - - -- - - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Args[0]: -Xmx3000M - - - 2.17 - - - - - - - - - -- - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Args[1]: -XX:+UseConcMarkSweepGC - - - 2.17 - - - - - - - -- - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Args[2]: -XX:+CMSIncrementalMode - - - 2.171 - - - - - - - -- - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Args[3]: -XX:+UseParNewGC - - - 2.171 - - - - - - - - -- - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Args[4]: -Dcom.sun.management.jmxremote=true - - - 2.171 - - - - - -- - - - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Args[5]: -Dcom.wowza.wms.AppHome=/usr/local/WowzaMediaServer - - - 2.171 - - - -- - - - - - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Args[6]: -Dcom.wowza.wms.ConfigURL= - - - 2.172 - - - - - - -- - - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java Args[7]: -Dcom.wowza.wms.ConfigHome=/usr/local/WowzaMediaServer - - - 2.172 - - - -- - - - - - - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java GC[0]: ParNew - - - 2.172 - - - - - - - - - -- - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Java GC[1]: ConcurrentMarkSweep - - - 2.173 - - - - - - - - -- - - - - - - - - - - - - - - -
2011-05-15 19:36:37 CEST comment server INFO 200 - Server threads[h/t]: 10/10 - - - 2.173 - - - - - - - - -- - - - - - - - - - - - - - - -
2011-05-15 19:36:38 CEST comment server INFO 200 - CMDInterface now listening: [any]:8083 - - - 3.812 - - - - - - - -- - - - - - - - - - - - - - - - -
2011-05-15 19:36:39 CEST vhost-start vhost INFO 200 _defaultVHost_ - - - - 4.599 - - - - - - - - - -- - - - - - - - - - - - - - -
2011-05-15 19:36:39 CEST comment server INFO 200 - _defaultVHost_ threads[h/t]:120/80 home:/usr/local/WowzaMediaServer - - - 4.738 - - - -- - - - - - - - - - - - - - - - - - - - -
2011-05-15 19:36:39 CEST comment vhost INFO 200 _defaultVHost_ Bind attempt ([any]:1935:4) - - - 4.755 - - - - - - - -- - - - - - - - - - - - - - - - -
2011-05-15 19:36:39 CEST comment vhost INFO 200 _defaultVHost_ Bind successful ([any]:1935) - - - 4.758 - - - - - - - -- - - - - - - - - - - - - - - - -
2011-05-15 19:36:39 CEST comment vhost INFO 200 _defaultVHost_ Bind attempt ([any]:8086:1) - - - 4.76 - - - - - - - -- - - - - - - - - - - - - - - - -
2011-05-15 19:36:39 CEST comment vhost INFO 200 _defaultVHost_ Bind successful ([any]:8086)
setenv.sh:
#!/bin/sh
_EXECJAVA=java
JAVA_OPTS="-Xmx3000M"
# Uncomment to run server environment (faster), Note: will only work if server VM install, comes with JDL
JAVA_OPTS="$JAVA_OPTS -server"
# Better garbage collection setting to avoid long pauses
#JAVA_OPTS="$JAVA_OPTS -XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode -XX:NewSize=1024m"
JAVA_OPTS="$JAVA_OPTS -XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode -XX:+UseParNewGC"
# Uncomment to fix multicast crosstalk problem when streams share multicast port
#JAVA_OPTS="$JAVA_OPTS -Djava.net.preferIPv4Stack=true"
WMSAPP_HOME=/usr/local/WowzaMediaServer
WMSCONFIG_HOME=/usr/local/WowzaMediaServer
WMSCONFIG_URL=
export WMSAPP_HOME WMSCONFIG_HOME JAVA_OPTS _EXECJAVA
System specs:
4GB RAM
dual core Xenon 2.66Ghz
Debian 2.6.26-2-amd64
Java Version: 1.6.0_22
Any clue how I can resolve this? We got, in total, about 10 publishing streams and a maximum of 100 viewers. The streams are about 700kbit/s.