Kodi Community Forum

Full Version: CrystalHD failing to initialize after loading and playing content successfully
You're currently viewing a stripped down version of our content. View the full version with proper formatting.
Einkoro Wrote:Looks like the 480p h264 content is only working on the first video played in XBMC after launching. CrystalHD fails to open on the second and each attempt afterwards.
http://janpingel.com/misc/files/xbmc.old.log <-- Around line 17065 it fails where it worked the first time around 2163

I have to reboot the AppleTV to get it to work once more. Exiting XBMC and starting it up again doesn't work as the device fails to initialize at startup until a reboot.

http://janpingel.com/misc/files/xbmc.log <-- here it fails immediately after exiting XBMC and starting it up again without a reboot

bcm70012, CrystalHD for OS X 3.6.0, xbmc r33963

dmesg:

Quote:bash-2.05b# dmesg
EEPROM: 8129 10ec 8139 10ec 8139 4020 e510 1700
RTL8139::registerEEPROM: fbf2 60a0 8d10 f7c2 8801 03b9 60f4 071a
RTL8139::registerEEPROM: dfa3 9836 dfa3 9836 03b9 60f4 1a1a 1a1a
RTL8139::registerEEPROM: 0000 a09e 0000 0000 0000 0000 0000 2000
RTL8139::registerEEPROM: 0000 0000 0000 0000 0000 0000 0000 0000
RTL8139::registerEEPROM: 0000 0000 0000 0000 0000 0000 0000 0000
RTL8139::registerEEPROM: 0000 0000 0000 0000 0000 0000 0000 0000
RTL8139::registerEEPROM: 0000 0000 0000 0000 0000 0000 0000 0000
Jettisoning kernel linker.
Resetting IOCatalogue.
com_apple_driver_RTL8139: Ethernet address 00:17:f2:fb:a0:60
{ 10 41e1} RTL8139::phyReportLinkStatus - ethernet flow control not enabled.
netsmb_dev: loaded
BroadcomCrystalHD:Confusedtart
crystalhd_hw_open: setting up functions, device = Link
Starting Crystal HD Device
Opening HW. hw:0x1f20e04, hw->adp:0x1f52200
Stopping Crystal HD Device
BroadcomCrystalHD: Found HW and started driver SW.
IOAudioStream[0x1c58b00]::clipIfNecessary() - Error: attempting to clip to a position more than one buffer ahead of last clip position (3,2fe0)->(4,3c52).
IOAudioStream[0x1c58b00]::clipIfNecessary() - adjusting clipped position to (4,2fe0)
Opening new user[0] handle
crystalhd_hw_open: setting up functions, device = Link
Starting Crystal HD Device
Opening HW. hw:0x22fe204, hw->adp:0x1f52200
BroadcomCrystalHD opened
allocated 18 elem
Initializing Dio pool 10 1024 305c 0x1debec4
crystalhd_link_download_fw entered
Firmware Downloaded Successfully
crystalhd_link_do_fw_cmd entered
Closing user[0] handle
Capture Stop: 29 List0:Sts:0 List1:Sts:0
Releasing RX Pkt pool
Released dio pool 10
no element found
released 18 elem
Stopping Crystal HD Device
BroadcomCrystalHD closed
Opening new user[0] handle
crystalhd_hw_open: setting up functions, device = Link
Starting Crystal HD Device
Opening HW. hw:0x23b6804, hw->adp:0x1f52200
BroadcomCrystalHD opened
allocated 18 elem
Initializing Dio pool 10 1024 305c 0x1dd6264
crystalhd_link_download_fw entered
Firmware Downloaded Successfully
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
DelQAddr:4fed8 RelQAddr:4ffdc
start_capture: pause_th:12, resume_th:5
[FMT CH] PIB:0 ff 420 6 2d0 1e0 2d0 0 0 0
Invalid Line Number[80808080]
MISSING 3 PICTURES
list_index:1 rx[1] rxtot[20] Y:10 UV:10 Int:2800 YDnSz:0 UVDnSz:0
list_index:1 rx[2] rxtot[22] Y:10 UV:10 Int:2800 YDnSz:0 UVDnSz:0
list_index:1 rx[3] rxtot[24] Y:10 UV:10 Int:2800 YDnSz:0 UVDnSz:0
list_index:1 rx[4] rxtot[28] Y:10 UV:10 Int:2800 YDnSz:0 UVDnSz:0
list_index:1 rx[5] rxtot[30] Y:10 UV:10 Int:2800 YDnSz:0 UVDnSz:0
MISSING 5 PICTURES
MISSING 10 PICTURES
FETCH TIMEOUT
number of rx success 2750 and failure 5
Capture Stop: 29 List0:Sts:0 List1:Sts:0
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
Closing user[0] handle
Capture Stop: 29 List0:Sts:0 List1:Sts:0
Releasing RX Pkt pool
Released dio pool 10
no element found
released 18 elem
Stopping Crystal HD Device
BroadcomCrystalHD closed
Opening new user[0] handle
crystalhd_hw_open: setting up functions, device = Link
Starting Crystal HD Device
Opening HW. hw:0x20c2204, hw->adp:0x1f52200
BroadcomCrystalHD opened
allocated 18 elem
Initializing Dio pool 10 1024 305c 0x1dd6264
crystalhd_link_download_fw entered
Firmware Downloaded Successfully
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
DelQAddr:4fed8 RelQAddr:4ffdc
start_capture: pause_th:12, resume_th:5
[FMT CH] PIB:0 ff 420 6 2d0 1e0 2d0 0 0 0
Invalid Line Number[80808080]
MISSING 3 PICTURES
number of rx success 224106 and failure 0
Capture Stop: 29 List0:Sts:0 List1:Sts:0
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
Closing user[0] handle
Capture Stop: 29 List0:Sts:0 List1:Sts:0
Releasing RX Pkt pool
Released dio pool 10
no element found
released 18 elem
Stopping Crystal HD Device
BroadcomCrystalHD closed
Einkoro Wrote:bcm70012, CrystalHD for OS X 3.6.0, xbmc r33963

and dmesg ?
davilla Wrote:and dmesg ?

You sir are quick. Pasted in OP.
I'm not see what you say the logs indicate. Lets start simple, clean boot. Launch xbmc, play 480p h264 content for 5 mins, then stop. play it again for 5 mins, then stop. Quit XBMC, get xbmc.log, Launch xbmc again, play, stop, exit get log.

EDIT: cancel that. update to the new 3.6.0 driver//lib/firmware. You should be able to do this from Launcher is you have the plist added. There's a thread about that.

EDIT2: http://forum.xbmc.org/showthread.php?tid=69321
davilla Wrote:I'm not see what you say the logs indicate. Lets start simple, clean boot. Launch xbmc, play 480p h264 content for 5 mins, then stop. play it again for 5 mins, then stop. Quit XBMC, get xbmc.log, Launch xbmc again, play, stop, exit get log.

EDIT: cancel that. update to the new 3.6.0 driver//lib/firmware. You should be able to do this from Launcher is you have the plist added. There's a thread about that.

EDIT2: http://forum.xbmc.org/showthread.php?tid=69321

I'm only seeing the same r156 3.6.0 in launcher and the project site that I already have installed.


No luck reproducing it this time around:
http://janpingel.com/misc/files/xbmc.old2.log <-- first run
http://janpingel.com/misc/files/xbmc2.log <-- second run

The only thing really different with regular usage from that test run I can think of: screen blanking from inactivity overnight between episodes, watching the full episodes, and navigating around more menus. I suppose it could be something slightly more random and I've just happened to have the luck to run into it approximately every second episode (and second night) after a reboot.
Einkoro Wrote:I'm only seeing the same r156 3.6.0 in launcher and the project site that I already have installed.


No luck reproducing it this time around:
http://janpingel.com/misc/files/xbmc.old2.log <-- first run
http://janpingel.com/misc/files/xbmc2.log <-- second run

The only thing really different with regular usage from that test run I can think of: screen blanking from inactivity overnight between episodes, watching the full episodes, and navigating around more menus. I suppose it could be something slightly more random and I've just happened to have the luck to run into it approximately every second episode (and second night) after a reboot.

Keep an eye on top (PhysMem), if there is a leak, it will show up there.
Another eye on dmesg, if crystalhd driver fails to open, there will be messages there.
I've been away for awhile but I'm back and running into the issue a few times in the last two nights. Here is the log, physmem from top and dmesg where CrystalHD failed to open after a few shows played fine:

http://janpingel.com/misc/files/xbmc.log

PhysMem: 78.9M wired, 112M active, 57.9M inactive, 249M used, 6.75M free

Code:
FETCH TIMEOUT
list_index:0 rx[1] rxtot[75013] Y:2 UV:2 Int:28 YDnSz:0 UVDnSz:0
MISSING 88 PICTURES
number of rx success 220125 and failure 1
Capture Stop: 29 List0:Sts:0 List1:Sts:0
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
Closing user[0] handle
Capture Stop: 29 List0:Sts:0 List1:Sts:0
Releasing RX Pkt pool
Released dio pool 10
no element found
released 18 elem
Stopping Crystal HD Device
BroadcomCrystalHD closed
Opening new user[0] handle
crystalhd_hw_open: setting up functions, device = Link
Starting Crystal HD Device
Opening HW. hw:0x24c4604, hw->adp:0x1f5d400
BroadcomCrystalHD opened
allocated 18 elem
Initializing Dio pool 10 1024 305c 0x1ad3464
crystalhd_link_download_fw entered
Firmware Downloaded Successfully
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
DelQAddr:4fed8 RelQAddr:4ffdc
start_capture: pause_th:12, resume_th:5
[FMT CH] PIB:0 ff 420 6 2d0 1e0 2d0 0 0 0
Invalid Line Number[80808080]
MISSING 3 PICTURES
number of rx success 161085 and failure 0
Capture Stop: 29 List0:Sts:0 List1:Sts:0
crystalhd_link_do_fw_cmd entered
crystalhd_link_do_fw_cmd entered
Closing user[0] handle
Capture Stop: 29 List0:Sts:0 List1:Sts:0
Releasing RX Pkt pool
Released dio pool 10
no element found
released 18 elem
Stopping Crystal HD Device
BroadcomCrystalHD closed
Opening new user[0] handle
crystalhd_hw_open: setting up functions, device = Link
Starting Crystal HD Device
Opening HW. hw:0x24ec604, hw->adp:0x1f5d400
BroadcomCrystalHD opened
allocated 18 elem
Initializing Dio pool 10 1024 305c 0x1de0d44
pci_alloc_consistent:IOBufferMemoryDescriptor::inTaskWithOptions failed
Insufficient Memory For TX
Releasing RX Pkt pool
I am seeing the exact same issue, I have the Broadcom 15 card installed, Launcher 3.2.5, ATV 3.02, Darma Beta 2 release, Driver 3.6.0 for the Broadcom - no addons except BBC Iplayer that doesn't work. I get the the error:-

dmesg:
pci_alloc_consistent:IOBufferMemoryDescriptor::inTaskWithOptions failed

This comes when playing h264 DTS5.1 video, I was/am seeing 97/99%% CPU utilisation.

However if I reboot the ATV, launch launcher, start XBMC, start the same movie (AI), I get 70% CPU at most and no dropped frames.

The only difference is that when the memory failure occurs above, the XBMC has been running a while, when rebooted, it's smooth as silk and get the following good output:-


BroadcomCrystalHD opened
allocated 18 elem
Initializing Dio pool 10 1024 305c 0x209f644
[crystalhd_flea_download_fw]: Sz:864276
[crystalhd_flea_download_fw]: step 1. Enable scrubbing
[crystalhd_flea_download_fw]: step 2. Poll for SCRAM_KEY_DONE_INT
[crystalhd_flea_download_fw]: step 3. Write the BORCH and STARCH addresses. f6004:d2fff, f6008:d2fff
[crystalhd_flea_download_fw]: step 4. Write the firmware to DRAM. Sz:864256 Bytes
[crystalhd_flea_download_fw]: step 5. Write the signature to CMAC register.
[crystalhd_flea_download_fw]: step 6. Write the ARM run bit to 1.
[crystalhd_flea_download_fw]: step 7. Poll for Boot Verification done/failure interrupt.
[crystalhd_flea_download_fw]: step 7. Done RetVal:400019
[crystalhd_flea_download_fw]: ..... Complete.
crystalhd_flea_do_fw_cmd entered
crystalhd_flea_do_fw_cmd entered
Snooped ChOpen Cmd For ChNo:0 TxBuffAddr:d3300
crystalhd_flea_do_fw_cmd entered
crystalhd_flea_do_fw_cmd entered
crystalhd_flea_do_fw_cmd entered
Snooped ChOpen Cmd For ChNo:0 TxBuffAddr:d3300
crystalhd_flea_do_fw_cmd entered
crystalhd_flea_do_fw_cmd entered
crystalhd_flea_do_fw_cmd entered
Snooping CHAN_START_VIDEO command to get the Addr of Del/Rel Queue
DelQAddr:0 RelQAddr:0
start_capture: pause_th:6, resume_th:3
[FMT CH] DoneSz:0xa0, PIB:0 0 1 2020200 1 2d0 500 0 9 0
[FMT CH] DoneSz:0xa0, PIB:0 0 1 2020200 1 2d0 500 0 9 0
[FMT CH] DoneSz:0xa0, PIB:0 0 1 2020200 1 2d0 500 0 9 0
[FMT CH] DoneSz:0xa0, PIB:0 0 1 2020200 1 2d0 500 0 9 0
[FMT CH] DoneSz:0xa0, PIB:0 0 1 2020200 1 2d0 500 0 9 0