Login at Kodi Home

**.:B:.** · 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 Smile

.

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:
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)

52:16 T:3026577280 M:149917696   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules

52:16 T:3026577280 M:149917696   DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules

52:16 T:3026577280 M:149917696   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtv

52:16 T:3026577280 M:149917696   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/myth/rtmp/mms/udp

52:16 T:3026577280 M:149917696   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout

52:16 T:3026577280 M:149917696   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp

52:16 T:3026577280 M:149917696   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams

52:16 T:3026577280 M:149917696   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd

52:16 T:3026577280 M:149917696   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdfile

52:16 T:3026577280 M:149917696   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage

52:16 T:3026577280 M:149917696   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf

52:16 T:3026577280 M:149917696   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv

52:16 T:3026577280 M:149917696   DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players

52:16 T:3026577280 M:149950464   DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)

52:16 T:3026577280 M:149950464   DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0

52:16 T:3026577280 M:149950464   DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1

52:16 T:3026577280 M:149950464   DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)

52:16 T:3026577280 M:149950464   DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players

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

52:16 T:3026577280 M:148660224 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED

52:16 T:2803768176 M:148660224   DEBUG: thread start, auto delete: 0

52:16 T:2803768176 M:148660224  NOTICE: Creating InputStream

52:16 T:2803768176 M:148688896    INFO: CDVDFactorySubtitle::GetSubtitles, searching subtitles

52:16 T:2803768176 M:148688896   DEBUG: CacheSubtitles: START

52:16 T:2803768176 M:148688896   DEBUG: CacheSubtitles: Checking for common subdirs...

52:16 T:2803768176 M:148688896   DEBUG: CacheSubtitles: Done (time: 9 ms)

52:16 T:2803768176 M:148688896   DEBUG: CacheSubtitles: Searching for subtitles...

52:16 T:2803768176 M:148623360   DEBUG: CacheSubtitles: Done (time: 25 ms)

52:16 T:2803768176 M:148623360   DEBUG: CacheSubtitles: END (total time: 38 ms)

52:16 T:2803768176 M:148623360    INFO: CDVDFactorySubtitle::GetSubtitles, searching subtitles done

52:16 T:2803768176 M:148623360  NOTICE: Creating Demuxer

52:16 T:2803768176 M:148623360   DEBUG: SECTION:LoadDLL(special://xbmcbin/system/players/dvdplayer/avformat-52-i486-linux.so)

52:16 T:2803768176 M:148623360   DEBUG: Loading: /usr/lib/xbmc/system/players/dvdplayer/avformat-52-i486-linux.so

52:16 T:2803768176 M:148070400   DEBUG: Open - probing detected format [matroska]

52:16 T:2803768176 M:148070400   DEBUG: Open - av_find_stream_info starting

52:16 T:3026577280 M:148070400   DEBUG: ------ Window Init (DialogBusy.xml) ------

52:16 T:3026577280 M:148070400   DEBUG: Alloc resources: 0.01ms (0.01 ms skin load)

52:17 T:2803768176 M:147578880   DEBUG: Open - av_find_stream_info finished

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':

52:17 T:2803768176 M:147578880    INFO: ffmpeg[A71E1B70]:   Duration: 00:40:52.06, start: 0.000000, bitrate: 3826 kb/s

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

52:17 T:2803768176 M:147578880    INFO: ffmpeg[A71E1B70]:     Stream #0.1: Audio: ac3, 48000 Hz, 5.1, s16, 448 kb/s

52:17 T:2803768176 M:147578880  NOTICE: Opening video stream: 0 source: 256

52:17 T:2803768176 M:147578880  NOTICE: Creating video codec with codec id: 28

52:17 T:2803768176 M:147578880   DEBUG: CDVDFactoryCodec: compiled in hardware support: CrystalHD:yes OpenMax:no VDPAU:no VAAPI:no

52:17 T:2803768176 M:147578880    INFO: Trying Broadcom Crystal HD Decoder...

52:17 T:2803768176 M:147578880   DEBUG: FactoryCodec - Video:  - Opening

52:18 T:2803768176 M: 82358272   DEBUG: CrystalHD: device open failed , returning(0x6)

52:18 T:2803768176 M: 82358272   ERROR: DVDVideoCodecCrystalHD: Failed to open Broadcom Crystal HD Codec

52:18 T:2803768176 M: 82358272   DEBUG: FactoryCodec - Video: chd-h264 - Failed

52:18 T:2803768176 M: 82096128   DEBUG: FactoryCodec - Video:  - Opening

52:18 T:2803768176 M: 82165760  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10

52:18 T:2803768176 M: 82165760   DEBUG: FactoryCodec - Video: ff-h264 - Opened

Full log

davilla · 2010-09-23, 01:05

Grrrr. Will check into this when I get back home. I'm assuming that you are on hardy using the 3.6.0 driver/lib from crystalhd-for-osx. Did you self build r34014 ?

**.:B:.** · (This post was last modified: 2010-09-23, 02:32 by .:B:..)

Yes, I built it myself. I am running Arch Linux, and yes I'm running the 3.6.0 driver/lib. Reverting to r33910 'solves' the issue. Running the 2.6.32 LTS kernel. This is on an AppleTV btw, maybe the amount of RAM has something to do with it (although I am using swap as well).

davilla · (This post was last modified: 2010-09-23, 04:17 by davilla.)

.:B:. Wrote:Yes, I built it myself. I am running Arch Linux, and yes I'm running the 3.6.0 driver/lib. Reverting to r33910 'solves' the issue. Running the 2.6.32 LTS kernel. This is on an AppleTV btw, maybe the amount of RAM has something to do with it (although I am using swap as well).

You could revert back to 8 DMA buffers, change to something like this http://code.google.com/p/crystalhd-for-o...tail?r=151 on bc_dts_glob_lnx.h

From the feedback that I'm getting 16 might be too much under the AppleTV with only 256MBs of RAM. Still closing the lib/driver should have released those buffers.

EDIT: "65279 pages RAM" humm, why so little ? I'd like to see dmesg and top output from a fresh boot before crystalhd is opened by xbmc.

**.:B:.** · (This post was last modified: 2010-09-23, 13:58 by .:B:..)

I'll get back to you with that. I thought the driver only used 8 DMA buffers anymore on the AppleTV, or am I mistaken? I thought you added some conditionals a while back exactly because the AppleTV was tight on RAM.

Dmesg output, on a fresh boot with r34014 (forum software complained post was too long, so I put it on pastebin).

Top output:

Code:

[stijn@mnemosyne ~]$ modinfo crystalhd

filename:       /lib/modules/2.6.32-lts/kernel/drivers/video/broadcom/crystalhd.ko

alias:          crystalhd

license:        GPL

description:    Broadcom Crystal HD Decoder Driver

author:         Prasad Bolisetty <[email protected]>

author:         Naren Sankar <[email protected]>

alias:          pci:v000014E4d00001615sv*sd*bc*sc*i*

alias:          pci:v000014E4d00001612sv*sd*bc*sc*i*

depends:        

vermagic:       2.6.32-lts SMP mod_unload 686 

[stijn@mnemosyne ~]$ pacman -Qo /lib/modules/2.6.32-lts/kernel/drivers/video/broadcom/crystalhd.ko

/lib/modules/2.6.32-lts/kernel/drivers/video/broadcom/crystalhd.ko is owned by crystalhd-lts 3.6.0-1

[stijn@mnemosyne ~]

davilla · 2010-09-24, 01:26

8 DMA buffers for OSX aimed at helping the atv(osx). Linux remained at 16.

**.:B:.** · (This post was last modified: 2010-09-24, 13:46 by .:B:..)

Okay, I must have misread that. I'll do as you suggested and report back. Does the data in my previous post help you any, btw?

Edit: just to be clear, the above dmesg output was from a clean boot, and Xbmc seems to open/close the CrystalHD card automatically when it starts up. Short of not starting Xbmc (launches automatically) there's nothing I can do about that. If you want to see that, let me know and I'll adapt the startup routine and post again.

**.:B:.** · 2010-09-24, 15:43

I recompiled with 8 instead of 16 buffers and performance is visibly better. However, I notice e.g. when pulling up the diagnostic overlay or the info panel during playback will still make playback become choppy (and lose sync). RAM usage during playback for a 720p file is ~ 230 MB, with ~ 100 MB swap used. This is the second video I'm playing btw, so the driver unloaded and loaded successfully. Funnily enough RAM usage drops to 200-ish MB when I play a third 720p file (still with crystalhd loading/unloading successfully), so I don't know if RAM usage is any indicator here.

When playback is stopped it drops back to ~145 MB RAM.

**Jimmer** · 2010-12-06, 19:19

Scott,

Hate to bump up an old thread, but I'm seeing something very similar with 1080p content on my ATV with the following setup:

OS: Karmic minimal install with 2.6.31-22-generic kernel
XBMC VER: Dharma RC2 using xbmc-live package from apt
CrystalHD VER: r174 (include file edited to give 8 DMA limit under linux)

dmesg:
http://pastebin.com/Ln9tsp9s

xbmc.log:
http://pastebin.com/aE7J1yid

Media info for 1080p files that have caused this to happen (note files may play correctly several times without issue - sometimes system is up for a day or two without issue):

media info:
http://pastebin.com/L4WFmESu
http://pastebin.com/F7QQH6yv
http://pastebin.com/E3gWEBiF

This was not a problem under Hardy, so I'm wondering if it's something in the newer Kernels we are running that the card is finding funky? Also I have a 1 Gig Swap partition, which is hardly being used before the card craps out with memory complaints:

Code:
total       used       free     shared    buffers     cached

Mem:        247052     243136       3916          0       4400      96748

-/+ buffers/cache:     141988     105064

Swap:       984116      57416     926700

I was wondering if it is a change in the default 'swappiness'? Think for Karmic it's set to 60 by default, but can't remember what was default for Hardy.... do you think it worth having a tinker with my settings, see if it makes a difference?

Also I would like to add that I had this problem all the time before changing to 8 DMA buffers. Then I thought I had it licked after limiting it to 8. But now my attached USB drive I usually use for Movies is failing so I've moved my Movies to my timecapsule. Since serving 1080p over SMB I am again seeing this error. However, this may be a coincidence - I will report back when I've put my content back on a replacement USB drive.

If you need any more info - or have specific instructions about things to try, let me know...

Jim

davilla · 2010-12-06, 20:23

I don't recommend anything other than Hardy for usage under the atv(linux)

andybz · (This post was last modified: 2010-12-24, 22:29 by andybz.)

I just stumbled on this thread, after googling for the same error.

I'm running Lucid on my AppleTV with the BCM70012, and when it opens the CrystalHD card, I get the same errors:

Code:
==> /var/log/messages <==

Dec 24 19:48:59 appletv kernel: [   73.843067] crystalhd 0000:02:00.0: Opening new user[0] handle

==> /home/xbmc/.xbmc/temp/xbmc.log <==

19:48:59 T:2918902640 M: 13180928   ERROR: DVDVideoCodecCrystalHD: Failed to open Broadcom Crystal HD Codec

==> /var/log/messages <==

Dec 24 19:48:59 appletv kernel: [   74.600136] xbmc.bin: page allocation failure. order:3, mode:0x8020

I've been using some deb packages providing v3.6, but I've been seeing the same thing when I complied it from source too.

*EDIT*: Switching to 8 Max Rx DMA Rings helps a lot.