[Einkoro]

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:

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

[davilla]

bcm70012, CrystalHD for OS X 3.6.0, xbmc r33963

and dmesg ?

[Einkoro]

and dmesg ?

You sir are quick. Pasted in OP.

[davilla]

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

[Einkoro]

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.

[davilla]

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.

[Einkoro]

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

[mattg42]

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