2010-09-22, 23:11
I am running Dharma r34014, and I noticed some code got introduced recently to unload the CrystalHD driver when there was no playback being done. I am experiencing something quirky though - a first h.264 file will play fine, and the diagnostic overlay will show the chd-h264 decoder being used, but the ones after that will be decoded with the ff-h264 one - needless to say my AppleTV barely copes .
Dmesg shows some ugly stack trace (I've included some of the lines of the previous succesful playback - albeit not without problems either, but that's just a crappy encode - to show it unloads cleanly the first time(s)):
Xbmc's log:
Full log
Dmesg shows some ugly stack trace (I've included some of the lines of the previous succesful playback - albeit not without problems either, but that's just a crappy encode - to show it unloads cleanly the first time(s)):
Code:
crystalhd 0000:02:00.0: number of rx success 1888 and failure 711
crystalhd 0000:02:00.0: Entering chd_dec_close
crystalhd 0000:02:00.0: Closing user[0] handle
no element found
crystalhd 0000:02:00.0: Entering chd_dec_open
crystalhd 0000:02:00.0: Opening new user[0] handle
xbmc: page allocation failure. order:3, mode:0x8020
Pid: 3058, comm: xbmc Tainted: P 2.6.32-lts #1
Call Trace:
[<c12ba46b>] ? printk+0x18/0x1d
[<c10b9c32>] __alloc_pages_nodemask+0x382/0x550
[<c1006300>] ? do_IRQ+0x50/0xc0
[<c1008412>] dma_generic_alloc_coherent+0x62/0xc0
[<c10083b0>] ? dma_generic_alloc_coherent+0x0/0xc0
[<d26a7f61>] bc_kern_dma_alloc+0xd1/0x110 [crystalhd]
[<d26ab0ff>] ? crystalhd_hw_setup_dma_rings+0xbf/0x230 [crystalhd]
[<d26ab129>] crystalhd_hw_setup_dma_rings+0xe9/0x230 [crystalhd]
[<d26a9012>] ? crystalhd_create_elem_pool+0x52/0xf0 [crystalhd]
[<d26a97b8>] bc_cproc_notify_mode+0xb8/0x160 [crystalhd]
[<d26a7857>] ? chd_dec_alloc_iodata+0x47/0x60 [crystalhd]
[<d26a7a80>] chd_dec_ioctl+0xa0/0x180 [crystalhd]
[<d26a9700>] ? bc_cproc_notify_mode+0x0/0x160 [crystalhd]
[<c10f846b>] vfs_ioctl+0x7b/0x90
[<c10f8aa6>] do_vfs_ioctl+0x66/0x580
[<c1179aa1>] ? rwsem_wake+0x51/0x130
[<c12bcdba>] ? call_rwsem_wake+0xa/0xc
[<c10607a3>] ? up_read+0x13/0x20
[<c1024ed4>] ? do_page_fault+0x154/0x300
[<c10f901f>] sys_ioctl+0x5f/0x80
[<c10038db>] sysenter_do_call+0x12/0x28
Mem-Info:
DMA per-cpu:
CPU 0: hi: 0, btch: 1 usd: 0
Normal per-cpu:
CPU 0: hi: 90, btch: 15 usd: 0
active_anon:13780 inactive_anon:13829 isolated_anon:0
active_file:8301 inactive_file:10911 isolated_file:0
unevictable:0 dirty:0 writeback:7 unstable:0
free:839 slab_reclaimable:1772 slab_unreclaimable:1164
mapped:4327 shmem:2 pagetables:271 bounce:0
DMA free:996kB min:124kB low:152kB high:184kB active_anon:7020kB inactive_anon:7164kB active_file:356kB inactive_file:248kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15848kB mlocked:0kB dirty:0kB writeback:0kB mapped:420kB shmem:0kB slab_reclaimable:36kB slab_unreclaimable:40kB kernel_stack:0kB pagetables:16kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
lowmem_reserve[]: 0 234 234 234
Normal free:2360kB min:1896kB low:2368kB high:2844kB active_anon:48100kB inactive_anon:48152kB active_file:32848kB inactive_file:43396kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:240192kB mlocked:0kB dirty:0kB writeback:28kB mapped:16888kB shmem:8kB slab_reclaimable:7052kB slab_unreclaimable:4616kB kernel_stack:1192kB pagetables:1068kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
lowmem_reserve[]: 0 0 0 0
DMA: 1*4kB 2*8kB 1*16kB 0*32kB 1*64kB 1*128kB 1*256kB 1*512kB 0*1024kB 0*2048kB 0*4096kB = 996kB
Normal: 230*4kB 136*8kB 16*16kB 3*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 2360kB
21592 total pagecache pages
2380 pages in swap cache
Swap cache stats: add 443299, delete 440919, find 97235/142131
Free swap = 179612kB
Total swap = 264184kB
65279 pages RAM
0 pages HighMem
2925 pages reserved
16927 pages shared
47220 pages non-shared
crystalhd 0000:02:00.0: Insufficient Memory For RX
Xbmc's log:
Code:
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerCoreFactory::GetPlayers(/home/user/server/series/House M.D./Season 07/House.S07E01.720p.HDTV.X264-DIMENSION.mkv)
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtv
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/myth/rtmp/mms/udp
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdfile
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
22:52:16 T:3026577280 M:149917696 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
22:52:16 T:3026577280 M:149950464 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)
22:52:16 T:3026577280 M:149950464 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0
22:52:16 T:3026577280 M:149950464 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
22:52:16 T:3026577280 M:149950464 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
22:52:16 T:3026577280 M:149950464 DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players
22:52:16 T:3026577280 M:148660224 NOTICE: DVDPlayer: Opening: /home/user/server/series/House M.D./Season 07/House.S07E01.720p.HDTV.X264-DIMENSION.mkv
22:52:16 T:3026577280 M:148660224 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
22:52:16 T:2803768176 M:148660224 DEBUG: thread start, auto delete: 0
22:52:16 T:2803768176 M:148660224 NOTICE: Creating InputStream
22:52:16 T:2803768176 M:148688896 INFO: CDVDFactorySubtitle::GetSubtitles, searching subtitles
22:52:16 T:2803768176 M:148688896 DEBUG: CacheSubtitles: START
22:52:16 T:2803768176 M:148688896 DEBUG: CacheSubtitles: Checking for common subdirs...
22:52:16 T:2803768176 M:148688896 DEBUG: CacheSubtitles: Done (time: 9 ms)
22:52:16 T:2803768176 M:148688896 DEBUG: CacheSubtitles: Searching for subtitles...
22:52:16 T:2803768176 M:148623360 DEBUG: CacheSubtitles: Done (time: 25 ms)
22:52:16 T:2803768176 M:148623360 DEBUG: CacheSubtitles: END (total time: 38 ms)
22:52:16 T:2803768176 M:148623360 INFO: CDVDFactorySubtitle::GetSubtitles, searching subtitles done
22:52:16 T:2803768176 M:148623360 NOTICE: Creating Demuxer
22:52:16 T:2803768176 M:148623360 DEBUG: SECTION:LoadDLL(special://xbmcbin/system/players/dvdplayer/avformat-52-i486-linux.so)
22:52:16 T:2803768176 M:148623360 DEBUG: Loading: /usr/lib/xbmc/system/players/dvdplayer/avformat-52-i486-linux.so
22:52:16 T:2803768176 M:148070400 DEBUG: Open - probing detected format [matroska]
22:52:16 T:2803768176 M:148070400 DEBUG: Open - av_find_stream_info starting
22:52:16 T:3026577280 M:148070400 DEBUG: ------ Window Init (DialogBusy.xml) ------
22:52:16 T:3026577280 M:148070400 DEBUG: Alloc resources: 0.01ms (0.01 ms skin load)
22:52:17 T:2803768176 M:147578880 DEBUG: Open - av_find_stream_info finished
22:52:17 T:2803768176 M:147578880 INFO: ffmpeg[A71E1B70]: Input #0, matroska, from '/home/user/server/series/House M.D./Season 07/House.S07E01.720p.HDTV.X264-DIMENSION.mkv':
22:52:17 T:2803768176 M:147578880 INFO: ffmpeg[A71E1B70]: Duration: 00:40:52.06, start: 0.000000, bitrate: 3826 kb/s
22:52:17 T:2803768176 M:147578880 INFO: ffmpeg[A71E1B70]: Stream #0.0(eng): Video: h264, yuv420p, 1280x720, PAR 1:1 DAR 16:9, 23.98 fps, 24 tbr, 1k tbn, 47.95 tbc
22:52:17 T:2803768176 M:147578880 INFO: ffmpeg[A71E1B70]: Stream #0.1: Audio: ac3, 48000 Hz, 5.1, s16, 448 kb/s
22:52:17 T:2803768176 M:147578880 NOTICE: Opening video stream: 0 source: 256
22:52:17 T:2803768176 M:147578880 NOTICE: Creating video codec with codec id: 28
22:52:17 T:2803768176 M:147578880 DEBUG: CDVDFactoryCodec: compiled in hardware support: CrystalHD:yes OpenMax:no VDPAU:no VAAPI:no
22:52:17 T:2803768176 M:147578880 INFO: Trying Broadcom Crystal HD Decoder...
22:52:17 T:2803768176 M:147578880 DEBUG: FactoryCodec - Video: - Opening
22:52:18 T:2803768176 M: 82358272 DEBUG: CrystalHD: device open failed , returning(0x6)
22:52:18 T:2803768176 M: 82358272 ERROR: DVDVideoCodecCrystalHD: Failed to open Broadcom Crystal HD Codec
22:52:18 T:2803768176 M: 82358272 DEBUG: FactoryCodec - Video: chd-h264 - Failed
22:52:18 T:2803768176 M: 82096128 DEBUG: FactoryCodec - Video: - Opening
22:52:18 T:2803768176 M: 82165760 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
22:52:18 T:2803768176 M: 82165760 DEBUG: FactoryCodec - Video: ff-h264 - Opened
Full log