Author Topic: New Kenwood HU with OEM VM Phatbox - not working (Read 25329 times)

jheyerman · « **on:** July 14, 2008, 11:22:50 am »

I did a test install of my new Kenwood KDC-X692 yesterday, which works fine except for Phatbox, which does not work at all:

I used Phathack DMS Tools to install new firmware for Kenwood (13.01 hacked, with VOIT) using the reflash box with firmware option. I have a new KHD-5L1 cable. When I inserted the DMS, the regular green flashing started. I left it for 15 mins or so, came back and both LEDs were off. I hit the reset button on the deck, and turned it on. CD Changer did not show as a source. Then I used PH DMS Tools to do a full repair on the DMS, and tried it with PMM. PMM recognized and initialized the DMS; PMM options verified KW 13.01 firmware. I then tried again in the car, no luck.

Other stuff: when I turn on the deck, the PB LEDs do come on. The red is constant, and the green comes on for a few seconds, then blinks every 5 seconds or so with a 1/2 second duration. If I turn off the deck, after a few seconds the LEDs turn off. So it seems some communication is happening. I also tried pulling the bat neg cable with everything hooked up. When I do that, the CD changer source is shown as an option on the deck. If I switch to it, it says Aux Ext on the screen. However, nothing happens, and the LEDs are not on on the PB. If I then hit the Kenwood reset button, the behavior reverts to that descibed previously (ie LEDs on PB come on and flash, but not recognized by deck).

I tried flashing firmware again (same version, etc) but no change

I pulled the cable and determined the connectivity with a multimeter - then compared with what's published in the WIKI, and all connections match, so very likely not the cable.

The DMS is a 160GB, and the box was hacked in June 2007.

At this point I can only guess that the deck is not compatible (although Kenwood Canada told me the new decks should work fine since the changer protocol has not changed), or that the deck is defective, or that the PB broke during the switch somehow. Another debug option is to reflash to VW firmware, and try my old stock VW deck to confirm the PB isn't dead.

Any help/advice would be much appreciated!

Thanks.
Jeff

VorTechS · « **Reply #1 on:** July 14, 2008, 11:41:10 am »

Try disconnecting the box from the HU, leave a few seconds and then re-connecting it. I've seen the AUX EXT behaviour before and disconnecting the box and re-connecting usually solved it. Sometimes it took a few goes.

Firefox · « **Reply #2 on:** July 14, 2008, 03:39:26 pm »

Don't you need the modified linux for a 160GB drive? as per:

"I replaced the linux file on my phtsys partition with http://downloads.phathack.com/sbingner/linux-lba48.bz2

now working"

(Not sure if the PhatHack tools do that as a matter of course anyway...?). Might be worth a try?

VorTechS · « **Reply #3 on:** July 14, 2008, 05:59:52 pm »

The DMS tools puts the correct version of Linux on the DMS based on the disk size. You can also check the logs to this effect. (My Docs\PhatHack Media Manager\Logs)

jheyerman · « **Reply #4 on:** July 15, 2008, 01:20:01 am »

Well, no luck. I did verify the large LBA linux file is on the DMS - I tried reflashing the firware again. I watched it this time, and it seemed to flash correctly. I tried plugging and unplugging.

The problem is very consistent - I get no recognition of a CD changer at all, unless I pull the batter neg. Then it only shows as an option, but PB leds do not come on. They only come on if I turn the deck off then on again... then the LEDs come on, but no CD changer option in the sources.

Is it possible the new deck processors are fast enough that the PB can't say it's a disc changer in the time the deck is looking?

One strange thing is with the deck off and the PB empty, if I put the DMS in the PB, I don't get any LEDs - the deck has to be on for the PB to show LEDs - I don't remember this being the way it worked, but I may be misremembering. At this point I don't know what to do. I have a friend with a new Kenwood deck... he's going to bring it to work tomorrow, and I am going to trying hooking up the PB to that one...

Any other ideas - is there a log file I can look at or generate? Should I try to flash back to VW and make sure it still works? Is it possible the hacked box isn't working, since I did the hack in 2007?

Thanks.
Jeff

VorTechS · « **Reply #5 on:** July 15, 2008, 06:56:49 am »

Are you telling us everything? As in:

Have you tried using the tools to 'Create a new DMS' (do not choose the option 'Reflash box') and then immediately when the DMS is ready, tried putting it in the PhatBox to see if it works?

Key thing here is, if you tried copying over say an existing AAC plugin after the DMS is ready - you'll likely find that the PhatBox will fail to boot. But that's why we have the new AAC workaround that the tools installs.

If things still fail, try dropping on the Level 10 RC pairs and then get us a log file. It might show something up.

sbingner · « **Reply #6 on:** July 15, 2008, 10:28:16 am »

if it will flash your firmware the DMS is working fine (as in patched etc)

If you're sure you have the kenwood firmware -- are you sure you have music on the DMS?

Also, with kenwood you need to connect everything... and wait for the phatbox to boot up once and turn off, then turn on the head unit. When it works properly it should say "HDD EXT" instead of Aux

jheyerman · « **Reply #7 on:** July 15, 2008, 10:39:42 am »

VorTechS,

I am switching over from a VW stock PB - same DMS. I did not use the option "create new DMS", but did use "repair DMS full", with KW13.01 firmware. I did not do anything with the DMS after that except see if it was recognized by PMM 3.92.

I am currently doing what you suggest - using the create new DMS option, making sure reflash was not checked, but did check the VIOT box. The drive is currently formatting: I'll post my results in 30-45 mins.

sbinger,
Yes had the 13.01 firmware - after doing the repair DMS full, I initialized the DMS in PMM 3.92 - this put the start up sound "Welcome to..." on the DMS. But as I said earlier - I never see the CDChanger option on the deck, except if I diconnect car battery and reconnect. But when I see the option, there is no activity on the PB at all - no LEDs. Turning the deck on and off leads to activity on the PB, but then there is no CD changer option on the deck...

Thanks.
Jeff

jheyerman · « **Reply #8 on:** July 15, 2008, 10:58:07 am »

No change - exact same behavior after running the new DMS tool. I will try the Level 10 RC pairs (not sure how, but I remember seeing a post on how to do it - will search).

Thanks,
Jeff

jheyerman · « **Reply #9 on:** July 15, 2008, 11:11:58 am »

Put the DMS in with the RC10 pairs,and let the box run for 30s or so. Here is the contents of the logfile.txt

Code: [Select]

05.60:phatd:main      : Media Daemon (phatd) $Revision: 1.226 $
05.69:phatd:main      : Debug level = 10
Selected profile is: Default
05.90:phatd:main      : Using /dos/exec.ini for exec.ini
06.01:phatd:fork_if_in: Spawning /dos/51d
06.01:phatd:fork_if_in: Program started (/dos/51d), pid=13, childno=0
06.59:phatd:check_inst: Added PWid 1, value 0
06.59:phatd:main      : Entering Main loop
06.63:51d  :main      : 
--- 51d (Mar  3 2004 18:49:12) --- $Revision: 1.205 $

06.63:51d  :main      : Debug level = 10
06.64:phatd:main      : Socket 2 has MSG_ID 2
06.92:51d  :openserpor: /dev/ttyS1 open fd=11
06.92:51d  :main      : Old ISP timeout value set to 50000 uSec
06.93:51d  :main      : Rollins timeout value set to 100000 uSec
06.93:51d  :test_uC_ve: 		 f9 (249) ------------>
06.94:51d  :test_uC_ve: 				 <============ 53 (83)
06.94:51d  :test_uC_ve: Got 53 for invalid header, must have ProtoPhat 2
06.94:51d  :parse_pac : opening /dos/firmware.pac
06.94:51d  :parse_pac : PAC file summary
06.94:51d  :parse_pac : 	 firmware name h: 02
06.94:51d  :parse_pac : 	 firmware name l: ff
06.94:51d  :parse_pac : 	 firmware ver   : 0c
06.94:51d  :parse_pac : 	 firmware base h: 0f
06.94:51d  :parse_pac : 	 firmware base l: fd
06.94:51d  :parse_pac : 	 firmware size h: 26
06.94:51d  :parse_pac : 	 firmware size l: f0
06.95:51d  :send_arm_s: firmware_modification=20
07.05:phatd:check_inst: Added PWid 1, value 0
07.05:51d  :rw_packet : Buffering 10 at 0
07.05:51d  :rw_packet : ########################################################
07.05:51d  :rw_packet : 		 10 (16) ------------->
07.05:51d  :rw_packet : Expecting HACK
07.06:51d  :rw_packet : 				 <============ ac (172)
07.06:51d  :rw_packet : 		 0c (12) ------------->
07.06:51d  :rw_packet : Expecting BACK
07.07:51d  :rw_packet : 				 <============ bd (189)
07.07:51d  :rw_packet : 		 02 (2) ------------->
07.07:51d  :rw_packet : Expecting BACK
07.08:51d  :rw_packet : 				 <============ bd (189)
07.08:51d  :rw_packet : 		 ff (255) ------------->
07.08:51d  :rw_packet : Expecting BACK
07.09:51d  :rw_packet : 				 <============ bd (189)
07.09:51d  :rw_packet : 		 00 (0) ------------->
07.09:51d  :rw_packet : Expecting BACK
07.10:51d  :rw_packet : 				 <============ bd (189)
07.10:51d  :rw_packet : 		 14 (20) ------------->
07.10:51d  :rw_packet : Expecting BACK
07.11:51d  :rw_packet : 				 <============ bd (189)
07.11:51d  :rw_packet : 		 05 (5) ------------->
07.11:51d  :rw_packet : Expecting BACK
07.12:51d  :rw_packet : 				 <============ bd (189)
07.12:51d  :rw_packet : 		 ca (202) ------------->
07.12:51d  :rw_packet : Expecting PACK
07.13:51d  :rw_packet : 				 <============ ce (206)
07.13:51d  :rw_packet : 				 <============ 11 (17)
07.13:51d  :rw_packet : 				 <============ 00 (0)
07.13:51d  :rw_packet : 				 <============ 16 (22)
07.13:51d  :rw_packet : 				 <============ 31 (49)
07.13:51d  :rw_packet : 				 <============ 02 (2)
07.13:51d  :rw_packet : 				 <============ a6 (166)
07.13:51d  :rw_packet : 				 <============ 14 (20)
07.13:51d  :rw_packet : 				 <============ 02 (2)
07.13:51d  :rw_packet : 				 <============ ff (255)
07.13:51d  :rw_packet : 				 <============ 0c (12)
07.13:51d  :rw_packet : 				 <============ 00 (0)
07.13:51d  :rw_packet : 				 <============ 00 (0)
07.13:51d  :rw_packet : 				 <============ 02 (2)
07.14:51d  :rw_packet : 				 <============ dd (221)
07.14:51d  :rw_packet : ########################################################
07.14:51d  :rw_packet : 		 ce (206) ------------->
07.14:51d  :rw_packet : ********************************************************
07.14:51d  :processpac: Got Session: mode 0, run type 22, lot 31 02
07.14:phatd:log_bc    : CPUid info:
Unique ID: 0x7fec1b90
Random ID: 0x7fec1b90be10a981696f942929c0e590
CPU: EP73xx, ver 0x02
Lot Code: 0x3102
07.18:51d  :processpac: Initializing 1.2 DAC
07.18:51d  :processpac: SSA head unit
07.19:51d  :processpac: Extra help enabled
07.21:51d  :rw_packet : 		 ce (206) ------------->
07.21:51d  :rw_packet : ********************************************************
07.21:51d  :processpac: Got uC ID
07.48:phatd:check_inst: Added PWid 1, value 0
07.49:51d  :rw_packet : Buffering 15 at 0
07.49:51d  :rw_packet : ########################################################
07.49:51d  :rw_packet : 		 15 (21) ------------->
07.49:51d  :rw_packet : Expecting HACK
07.50:51d  :rw_packet : 				 <============ ac (172)
07.50:51d  :rw_packet : 		 01 (1) ------------->
07.50:51d  :rw_packet : Expecting BACK
07.51:51d  :rw_packet : 				 <============ bd (189)
07.51:51d  :rw_packet : 		 00 (0) ------------->
07.51:51d  :rw_packet : Expecting BACK
07.52:51d  :rw_packet : 				 <============ bd (189)
07.52:51d  :rw_packet : 		 ea (234) ------------->
07.52:51d  :rw_packet : Expecting PACK
07.53:51d  :rw_packet : 				 <============ ce (206)
07.53:51d  :rw_packet : 				 <============ 15 (21)
07.53:51d  :rw_packet : 				 <============ 01 (1)
07.53:51d  :rw_packet : 				 <============ 01 (1)
07.53:51d  :rw_packet : 				 <============ e9 (233)
07.53:51d  :rw_packet : ########################################################
07.53:51d  :rw_packet : 		 ce (206) ------------->
07.53:51d  :rw_packet : ********************************************************
07.53:phatd:enable_pha: Will activate PW 1
07.55:51d  :rw_packet : Buffering 13 at 0
07.55:51d  :rw_packet : ########################################################
07.55:51d  :rw_packet : 		 13 (19) ------------->
07.55:51d  :rw_packet : Expecting HACK
07.56:51d  :rw_packet : 				 <============ ac (172)
07.56:51d  :rw_packet : 		 19 (25) ------------->
07.56:51d  :rw_packet : Expecting BACK
07.57:51d  :rw_packet : 				 <============ bd (189)
07.57:51d  :rw_packet : 		 00 (0) ------------->
07.57:51d  :rw_packet : Expecting BACK
07.58:51d  :rw_packet : 				 <============ bd (189)
07.58:51d  :rw_packet : 		 00 (0) ------------->
07.58:51d  :rw_packet : Expecting BACK
07.59:51d  :rw_packet : 				 <============ bd (189)
07.59:51d  :rw_packet : 		 00 (0) ------------->
07.59:51d  :rw_packet : Expecting BACK
07.60:51d  :rw_packet : 				 <============ bd (189)
07.60:51d  :rw_packet : 		 d4 (212) ------------->
07.60:51d  :rw_packet : Expecting PACK
07.61:51d  :rw_packet : 				 <============ ce (206)
07.61:51d  :rw_packet : 				 <============ 11 (17)
07.61:51d  :rw_packet : 				 <============ 00 (0)
07.61:51d  :rw_packet : 				 <============ 16 (22)
07.61:51d  :rw_packet : 				 <============ 31 (49)
07.61:51d  :rw_packet : 				 <============ 02 (2)
07.61:51d  :rw_packet : 				 <============ a6 (166)
07.61:51d  :rw_packet : ########################################################
07.61:51d  :rw_packet : 		 ce (206) ------------->
07.61:51d  :rw_packet : ********************************************************
07.61:51d  :processpac: Got Session: mode 0, run type 22, lot 31 02
07.62:phatd:log_bc    : CPUid info:
Unique ID: 0x7fec1b90
Random ID: 0x7fec1b90be10a981696f942929c0e590
CPU: EP73xx, ver 0x02
Lot Code: 0x3102
07.62:51d  :processpac: Initializing 1.2 DAC
07.62:51d  :processpac: SSA head unit
07.62:51d  :processpac: Extra help enabled
07.68:51d  :rw_packet : ********************************************************
07.68:51d  :rw_packet : 				 <============ 21 (33)
07.68:51d  :rw_packet : 				 <============ df (223)
07.68:51d  :rw_packet : 		 ce (206) ------------->
07.68:51d  :rw_packet : ********************************************************
07.68:51d  :processpac: Got Query total disc
07.68:51d  :rw_packet : Buffering 7d at 0
07.68:51d  :rw_packet : ########################################################
07.68:51d  :rw_packet : 		 7d (125) ------------->
07.69:51d  :rw_packet : Expecting HACK
07.69:51d  :rw_packet : 				 <============ ac (172)
07.70:51d  :rw_packet : 		 00 (0) ------------->
07.70:51d  :rw_packet : Expecting BACK
07.71:51d  :rw_packet : 				 <============ bd (189)
07.71:51d  :rw_packet : 		 00 (0) ------------->
07.71:51d  :rw_packet : Expecting BACK
07.72:51d  :rw_packet : 				 <============ bd (189)
07.72:51d  :rw_packet : 		 83 (131) ------------->
07.72:51d  :rw_packet : Expecting PACK
07.73:51d  :rw_packet : 				 <============ ce (206)
07.73:51d  :rw_packet : 				 <============ 32 (50)
07.73:51d  :rw_packet : 				 <============ ce (206)
07.73:51d  :rw_packet : ########################################################
07.73:51d  :rw_packet : 		 ce (206) ------------->
07.73:51d  :rw_packet : ********************************************************
07.73:51d  :processpac: Got Stop
12.73:51d  :main      : Auto PONG
12.73:51d  :rw_packet : Buffering 70 at 0
12.73:51d  :rw_packet : ########################################################
12.73:51d  :rw_packet : 		 70 (112) ------------->
12.73:51d  :rw_packet : Expecting HACK
12.74:51d  :rw_packet : 				 <============ ac (172)
12.74:51d  :rw_packet : 		 90 (144) ------------->
12.74:51d  :rw_packet : Expecting PACK
12.75:51d  :rw_packet : 				 <============ ce (206)
12.75:51d  :rw_packet : ########################################################
17.75:51d  :main      : Auto PONG
17.75:51d  :rw_packet : Buffering 70 at 0
17.75:51d  :rw_packet : ########################################################
17.75:51d  :rw_packet : 		 70 (112) ------------->
17.75:51d  :rw_packet : Expecting HACK
17.76:51d  :rw_packet : 				 <============ ac (172)
17.76:51d  :rw_packet : 		 90 (144) ------------->
17.76:51d  :rw_packet : Expecting PACK
17.77:51d  :rw_packet : 				 <============ ce (206)
17.77:51d  :rw_packet : ########################################################
22.77:51d  :main      : Auto PONG
22.77:51d  :rw_packet : Buffering 70 at 0
22.77:51d  :rw_packet : ########################################################
22.77:51d  :rw_packet : 		 70 (112) ------------->
22.77:51d  :rw_packet : Expecting HACK
22.78:51d  :rw_packet : 				 <============ ac (172)
22.78:51d  :rw_packet : 		 90 (144) ------------->
22.78:51d  :rw_packet : Expecting PACK
22.79:51d  :rw_packet : 				 <============ ce (206)
22.79:51d  :rw_packet : ########################################################
27.79:51d  :main      : Auto PONG
27.79:51d  :rw_packet : Buffering 70 at 0
27.79:51d  :rw_packet : ########################################################
27.79:51d  :rw_packet : 		 70 (112) ------------->
27.79:51d  :rw_packet : Expecting HACK
27.80:51d  :rw_packet : 				 <============ ac (172)
27.80:51d  :rw_packet : 		 90 (144) ------------->
27.80:51d  :rw_packet : Expecting PACK
27.81:51d  :rw_packet : 				 <============ ce (206)
27.81:51d  :rw_packet : ########################################################
32.81:51d  :main      : Auto PONG
32.81:51d  :rw_packet : Buffering 70 at 0
32.81:51d  :rw_packet : ########################################################
32.81:51d  :rw_packet : 		 70 (112) ------------->
32.81:51d  :rw_packet : Expecting HACK
32.82:51d  :rw_packet : 				 <============ ac (172)
32.82:51d  :rw_packet : 		 90 (144) ------------->
32.82:51d  :rw_packet : Expecting PACK
32.83:51d  :rw_packet : 				 <============ ce (206)
32.83:51d  :rw_packet : ########################################################
37.83:51d  :main      : Auto PONG
37.83:51d  :rw_packet : Buffering 70 at 0
37.83:51d  :rw_packet : ########################################################
37.83:51d  :rw_packet : 		 70 (112) ------------->
37.83:51d  :rw_packet : Expecting HACK
37.84:51d  :rw_packet : 				 <============ ac (172)
37.84:51d  :rw_packet : 		 90 (144) ------------->
37.84:51d  :rw_packet : Expecting PACK
37.85:51d  :rw_packet : 				 <============ ce (206)
37.85:51d  :rw_packet : ########################################################
42.85:51d  :main      : Auto PONG
42.85:51d  :rw_packet : Buffering 70 at 0
42.85:51d  :rw_packet : ########################################################
42.85:51d  :rw_packet : 		 70 (112) ------------->
42.85:51d  :rw_packet : Expecting HACK
42.86:51d  :rw_packet : 				 <============ ac (172)
42.86:51d  :rw_packet : 		 90 (144) ------------->
42.86:51d  :rw_packet : Expecting PACK
42.87:51d  :rw_packet : 				 <============ ce (206)
42.87:51d  :rw_packet : ########################################################
47.87:51d  :main      : Auto PONG
47.87:51d  :rw_packet : Buffering 70 at 0
47.87:51d  :rw_packet : ########################################################
47.87:51d  :rw_packet : 		 70 (112) ------------->
47.87:51d  :rw_packet : Expecting HACK
47.88:51d  :rw_packet : 				 <============ ac (172)
47.88:51d  :rw_packet : 		 90 (144) ------------->
47.88:51d  :rw_packet : Expecting PACK
47.89:51d  :rw_packet : 				 <============ ce (206)
47.89:51d  :rw_packet : ########################################################
52.16:51d  :rw_packet : ********************************************************
52.16:51d  :rw_packet : 				 <============ 32 (50)
52.16:51d  :rw_packet : 				 <============ ce (206)
52.16:51d  :rw_packet : 		 ce (206) ------------->
52.16:51d  :rw_packet : ********************************************************
52.16:51d  :processpac: Got Stop
57.16:51d  :main      : Auto PONG
57.16:51d  :rw_packet : Buffering 70 at 0
57.16:51d  :rw_packet : ########################################################
57.16:51d  :rw_packet : 		 70 (112) ------------->
57.16:51d  :rw_packet : Expecting HACK
57.17:51d  :rw_packet : 				 <============ ac (172)
57.17:51d  :rw_packet : 		 90 (144) ------------->
57.17:51d  :rw_packet : Expecting PACK
57.27:51d  :main      : ACK timeout
57.27:51d  :rw_packet : 		 90 (144) ------------->
57.37:51d  :main      : ACK timeout
57.37:51d  :rw_packet : 		 90 (144) ------------->
57.47:51d  :main      : ACK timeout
57.47:51d  :rw_packet : 		 90 (144) ------------->
57.57:51d  :main      : ACK timeout
57.57:51d  :rw_packet : 		 90 (144) ------------->
57.67:51d  :main      : ACK timeout
57.67:51d  :rw_packet : 		 90 (144) ------------->
57.77:51d  :main      : ACK timeout
57.77:51d  :rw_packet : 		 90 (144) ------------->
57.87:51d  :main      : ACK timeout
57.87:51d  :rw_packet : Too many retries removing packet from send queue
60.13:51d  :rw_packet : ********************************************************
60.13:51d  :rw_packet : 				 <============ 61 (97)
60.13:51d  :rw_packet : 				 <============ 9f (159)
60.13:51d  :rw_packet : 		 ce (206) ------------->
60.13:51d  :rw_packet : ********************************************************
60.13:51d  :processpac: Got Shutdown

VorTechS · « **Reply #10 on:** July 15, 2008, 11:46:52 am »

Sbingner: From what I recall from our conversations in the past.... doesn't this mean 'No Discs'?

07.68:51d :processpac: Got Query total disc
07.68:51d :rw_packet : Buffering 7d at 0

jheyerman · « **Reply #11 on:** July 16, 2008, 12:38:08 am »

I tried with my friend's new deck - same behaviour exactly. His deck is also a new 2008 model (he has x592, I have x692). I am sure these are pretty much the same basic electronics.

So, I have eliminated that my deck is "bad". That leaves: cable (unlikely since I checked all connections), dead Phatbox, or 2008 Kenwood models do not work with PB, or?

I was wondering if the possible "No Discs" might be related to the lack of content, as I used "create new DMS" in the PhatHack DMS tools. I might drop the RC10 pairs in again, and get the logfile, since I put on some content.

After that I might try reverting to the VW setup, and see if it still works. Otherwise, I have no idea what to do - maybe call Kenwood again and ask them to verify the new decks work with Music Kegs?

Also, might it be that the hardware for the VW box is different then the Music Keg boxes. I know this isn't supposed to be the case, but maybe they modified them. I only bought my VW PB new from the dealer last year...

Thanks again,
Jeff

jheyerman · « **Reply #12 on:** July 16, 2008, 01:04:01 am »

Well, reran with the RC10 pairs and some content on the drive - looks like the same output:

Code: [Select]

05.60:phatd:main      : Media Daemon (phatd) $Revision: 1.226 $
05.69:phatd:main      : Debug level = 10
Selected profile is: Default
05.90:phatd:main      : Using /dos/exec.ini for exec.ini
06.01:phatd:fork_if_in: Spawning /dos/51d
06.01:phatd:fork_if_in: Program started (/dos/51d), pid=13, childno=0
06.59:51d  :main      : 
--- 51d (Mar  3 2004 18:49:12) --- $Revision: 1.205 $

06.59:51d  :main      : Debug level = 10
06.64:phatd:check_inst: Added PWid 1, value 0
06.64:phatd:main      : Entering Main loop
06.65:phatd:main      : Socket 2 has MSG_ID 2
06.93:51d  :openserpor: /dev/ttyS1 open fd=11
06.94:51d  :main      : Old ISP timeout value set to 50000 uSec
06.94:51d  :main      : Rollins timeout value set to 100000 uSec
06.94:51d  :test_uC_ve: 		 f9 (249) ------------>
06.95:51d  :test_uC_ve: 				 <============ 53 (83)
06.95:51d  :test_uC_ve: Got 53 for invalid header, must have ProtoPhat 2
06.95:51d  :parse_pac : opening /dos/firmware.pac
06.95:51d  :parse_pac : PAC file summary
06.95:51d  :parse_pac : 	 firmware name h: 02
06.95:51d  :parse_pac : 	 firmware name l: ff
06.95:51d  :parse_pac : 	 firmware ver   : 0c
06.95:51d  :parse_pac : 	 firmware base h: 0f
06.95:51d  :parse_pac : 	 firmware base l: fd
06.95:51d  :parse_pac : 	 firmware size h: 26
06.95:51d  :parse_pac : 	 firmware size l: f0
06.96:51d  :send_arm_s: firmware_modification=22
07.06:phatd:check_inst: Added PWid 1, value 0
07.06:51d  :rw_packet : Buffering 10 at 0
07.06:51d  :rw_packet : ########################################################
07.06:51d  :rw_packet : 		 10 (16) ------------->
07.07:51d  :rw_packet : Expecting HACK
07.07:51d  :rw_packet : 				 <============ ac (172)
07.07:51d  :rw_packet : 		 0c (12) ------------->
07.07:51d  :rw_packet : Expecting BACK
07.08:51d  :rw_packet : 				 <============ bd (189)
07.08:51d  :rw_packet : 		 02 (2) ------------->
07.08:51d  :rw_packet : Expecting BACK
07.09:51d  :rw_packet : 				 <============ bd (189)
07.09:51d  :rw_packet : 		 ff (255) ------------->
07.09:51d  :rw_packet : Expecting BACK
07.10:51d  :rw_packet : 				 <============ bd (189)
07.10:51d  :rw_packet : 		 00 (0) ------------->
07.10:51d  :rw_packet : Expecting BACK
07.11:51d  :rw_packet : 				 <============ bd (189)
07.11:51d  :rw_packet : 		 16 (22) ------------->
07.11:51d  :rw_packet : Expecting BACK
07.12:51d  :rw_packet : 				 <============ bd (189)
07.12:51d  :rw_packet : 		 05 (5) ------------->
07.12:51d  :rw_packet : Expecting BACK
07.13:51d  :rw_packet : 				 <============ bd (189)
07.13:51d  :rw_packet : 		 c8 (200) ------------->
07.13:51d  :rw_packet : Expecting PACK
07.14:51d  :rw_packet : 				 <============ ce (206)
07.14:51d  :rw_packet : 				 <============ 11 (17)
07.14:51d  :rw_packet : 				 <============ 00 (0)
07.14:51d  :rw_packet : 				 <============ 16 (22)
07.14:51d  :rw_packet : 				 <============ 31 (49)
07.14:51d  :rw_packet : 				 <============ 02 (2)
07.14:51d  :rw_packet : 				 <============ a6 (166)
07.14:51d  :rw_packet : 				 <============ 14 (20)
07.14:51d  :rw_packet : 				 <============ 02 (2)
07.14:51d  :rw_packet : 				 <============ ff (255)
07.14:51d  :rw_packet : 				 <============ 0c (12)
07.14:51d  :rw_packet : 				 <============ 00 (0)
07.14:51d  :rw_packet : 				 <============ 00 (0)
07.14:51d  :rw_packet : 				 <============ 02 (2)
07.15:51d  :rw_packet : 				 <============ dd (221)
07.15:51d  :rw_packet : ########################################################
07.15:51d  :rw_packet : 		 ce (206) ------------->
07.15:51d  :rw_packet : ********************************************************
07.15:51d  :processpac: Got Session: mode 0, run type 22, lot 31 02
07.15:phatd:log_bc    : CPUid info:
Unique ID: 0x7fec1b90
Random ID: 0x7fec1b90be10a981696f942929c0e590
CPU: EP73xx, ver 0x02
Lot Code: 0x3102
07.19:51d  :processpac: Initializing 1.2 DAC
07.19:51d  :processpac: SSA head unit
07.20:51d  :processpac: Extra help enabled
07.22:51d  :rw_packet : 		 ce (206) ------------->
07.22:51d  :rw_packet : ********************************************************
07.22:51d  :processpac: Got uC ID
07.50:phatd:check_inst: Added PWid 1, value 0
07.50:51d  :rw_packet : Buffering 15 at 0
07.50:51d  :rw_packet : ########################################################
07.50:51d  :rw_packet : 		 15 (21) ------------->
07.50:51d  :rw_packet : Expecting HACK
07.51:51d  :rw_packet : 				 <============ ac (172)
07.51:51d  :rw_packet : 		 01 (1) ------------->
07.51:51d  :rw_packet : Expecting BACK
07.52:51d  :rw_packet : 				 <============ bd (189)
07.52:51d  :rw_packet : 		 00 (0) ------------->
07.52:51d  :rw_packet : Expecting BACK
07.53:51d  :rw_packet : 				 <============ bd (189)
07.53:51d  :rw_packet : 		 ea (234) ------------->
07.53:51d  :rw_packet : Expecting PACK
07.54:51d  :rw_packet : 				 <============ ce (206)
07.54:51d  :rw_packet : 				 <============ 15 (21)
07.54:51d  :rw_packet : 				 <============ 01 (1)
07.54:51d  :rw_packet : 				 <============ 01 (1)
07.54:51d  :rw_packet : 				 <============ e9 (233)
07.54:51d  :rw_packet : ########################################################
07.54:51d  :rw_packet : 		 ce (206) ------------->
07.54:51d  :rw_packet : ********************************************************
07.54:phatd:enable_pha: Will activate PW 1
07.56:51d  :rw_packet : Buffering 13 at 0
07.56:51d  :rw_packet : ########################################################
07.56:51d  :rw_packet : 		 13 (19) ------------->
07.56:51d  :rw_packet : Expecting HACK
07.57:51d  :rw_packet : 				 <============ ac (172)
07.57:51d  :rw_packet : 		 19 (25) ------------->
07.57:51d  :rw_packet : Expecting BACK
07.58:51d  :rw_packet : 				 <============ bd (189)
07.58:51d  :rw_packet : 		 00 (0) ------------->
07.58:51d  :rw_packet : Expecting BACK
07.59:51d  :rw_packet : 				 <============ bd (189)
07.59:51d  :rw_packet : 		 00 (0) ------------->
07.59:51d  :rw_packet : Expecting BACK
07.60:51d  :rw_packet : 				 <============ bd (189)
07.60:51d  :rw_packet : 		 00 (0) ------------->
07.60:51d  :rw_packet : Expecting BACK
07.61:51d  :rw_packet : 				 <============ bd (189)
07.61:51d  :rw_packet : 		 d4 (212) ------------->
07.62:51d  :rw_packet : Expecting PACK
07.63:51d  :rw_packet : 				 <============ ce (206)
07.63:51d  :rw_packet : 				 <============ 11 (17)
07.63:51d  :rw_packet : 				 <============ 00 (0)
07.63:51d  :rw_packet : 				 <============ 16 (22)
07.63:51d  :rw_packet : 				 <============ 31 (49)
07.63:51d  :rw_packet : 				 <============ 02 (2)
07.63:51d  :rw_packet : 				 <============ a6 (166)
07.63:51d  :rw_packet : ########################################################
07.63:51d  :rw_packet : 		 ce (206) ------------->
07.63:51d  :rw_packet : ********************************************************
07.63:51d  :processpac: Got Session: mode 0, run type 22, lot 31 02
07.64:phatd:log_bc    : CPUid info:
Unique ID: 0x7fec1b90
Random ID: 0x7fec1b90be10a981696f942929c0e590
CPU: EP73xx, ver 0x02
Lot Code: 0x3102
07.64:51d  :processpac: Initializing 1.2 DAC
07.64:51d  :processpac: SSA head unit
07.64:51d  :processpac: Extra help enabled
07.69:51d  :rw_packet : ********************************************************
07.69:51d  :rw_packet : 				 <============ 21 (33)
07.69:51d  :rw_packet : 				 <============ df (223)
07.69:51d  :rw_packet : 		 ce (206) ------------->
07.69:51d  :rw_packet : ********************************************************
07.69:51d  :processpac: Got Query total disc
07.69:51d  :rw_packet : Buffering 7d at 0
07.69:51d  :rw_packet : ########################################################
07.69:51d  :rw_packet : 		 7d (125) ------------->
07.70:51d  :rw_packet : Expecting HACK
07.70:51d  :rw_packet : 				 <============ ac (172)
07.70:51d  :rw_packet : 		 00 (0) ------------->
07.70:51d  :rw_packet : Expecting BACK
07.71:51d  :rw_packet : 				 <============ bd (189)
07.71:51d  :rw_packet : 		 01 (1) ------------->
07.71:51d  :rw_packet : Expecting BACK
07.72:51d  :rw_packet : 				 <============ bd (189)
07.72:51d  :rw_packet : 		 82 (130) ------------->
07.72:51d  :rw_packet : Expecting PACK
07.73:51d  :rw_packet : 				 <============ ce (206)
07.73:51d  :rw_packet : ########################################################
12.73:51d  :main      : Auto PONG
12.73:51d  :rw_packet : Buffering 70 at 0
12.73:51d  :rw_packet : ########################################################
12.73:51d  :rw_packet : 		 70 (112) ------------->
12.73:51d  :rw_packet : Expecting HACK
12.74:51d  :rw_packet : 				 <============ ac (172)
12.74:51d  :rw_packet : 		 90 (144) ------------->
12.74:51d  :rw_packet : Expecting PACK
12.75:51d  :rw_packet : 				 <============ ce (206)
12.75:51d  :rw_packet : ########################################################
17.75:51d  :main      : Auto PONG
17.75:51d  :rw_packet : Buffering 70 at 0
17.75:51d  :rw_packet : ########################################################
17.75:51d  :rw_packet : 		 70 (112) ------------->
17.75:51d  :rw_packet : Expecting HACK
17.76:51d  :rw_packet : 				 <============ ac (172)
17.76:51d  :rw_packet : 		 90 (144) ------------->
17.76:51d  :rw_packet : Expecting PACK
17.77:51d  :rw_packet : 				 <============ ce (206)
17.77:51d  :rw_packet : ########################################################
22.77:51d  :main      : Auto PONG
22.77:51d  :rw_packet : Buffering 70 at 0
22.77:51d  :rw_packet : ########################################################
22.77:51d  :rw_packet : 		 70 (112) ------------->
22.77:51d  :rw_packet : Expecting HACK
22.78:51d  :rw_packet : 				 <============ ac (172)
22.78:51d  :rw_packet : 		 90 (144) ------------->
22.78:51d  :rw_packet : Expecting PACK
22.79:51d  :rw_packet : 				 <============ ce (206)
22.79:51d  :rw_packet : ########################################################
27.79:51d  :main      : Auto PONG
27.79:51d  :rw_packet : Buffering 70 at 0
27.79:51d  :rw_packet : ########################################################
27.79:51d  :rw_packet : 		 70 (112) ------------->
27.79:51d  :rw_packet : Expecting HACK
27.80:51d  :rw_packet : 				 <============ ac (172)
27.80:51d  :rw_packet : 		 90 (144) ------------->
27.80:51d  :rw_packet : Expecting PACK
27.81:51d  :rw_packet : 				 <============ ce (206)
27.81:51d  :rw_packet : ########################################################
32.81:51d  :main      : Auto PONG
32.81:51d  :rw_packet : Buffering 70 at 0
32.81:51d  :rw_packet : ########################################################
32.81:51d  :rw_packet : 		 70 (112) ------------->
32.81:51d  :rw_packet : Expecting HACK
32.82:51d  :rw_packet : 				 <============ ac (172)
32.82:51d  :rw_packet : 		 90 (144) ------------->
32.82:51d  :rw_packet : Expecting PACK
32.83:51d  :rw_packet : 				 <============ ce (206)
32.83:51d  :rw_packet : ########################################################
37.83:51d  :main      : Auto PONG
37.83:51d  :rw_packet : Buffering 70 at 0
37.83:51d  :rw_packet : ########################################################
37.83:51d  :rw_packet : 		 70 (112) ------------->
37.83:51d  :rw_packet : Expecting HACK
37.84:51d  :rw_packet : 				 <============ ac (172)
37.84:51d  :rw_packet : 		 90 (144) ------------->
37.84:51d  :rw_packet : Expecting PACK
37.85:51d  :rw_packet : 				 <============ ce (206)
37.85:51d  :rw_packet : ########################################################
42.85:51d  :main      : Auto PONG
42.85:51d  :rw_packet : Buffering 70 at 0
42.85:51d  :rw_packet : ########################################################
42.85:51d  :rw_packet : 		 70 (112) ------------->
42.85:51d  :rw_packet : Expecting HACK
42.86:51d  :rw_packet : 				 <============ ac (172)
42.86:51d  :rw_packet : 		 90 (144) ------------->
42.86:51d  :rw_packet : Expecting PACK
42.87:51d  :rw_packet : 				 <============ ce (206)
42.87:51d  :rw_packet : ########################################################
47.87:51d  :main      : Auto PONG
47.87:51d  :rw_packet : Buffering 70 at 0
47.87:51d  :rw_packet : ########################################################
47.87:51d  :rw_packet : 		 70 (112) ------------->
47.87:51d  :rw_packet : Expecting HACK
47.88:51d  :rw_packet : 				 <============ ac (172)
47.88:51d  :rw_packet : 		 90 (144) ------------->
47.88:51d  :rw_packet : Expecting PACK
47.89:51d  :rw_packet : 				 <============ ce (206)
47.89:51d  :rw_packet : ########################################################
52.89:51d  :main      : Auto PONG
52.89:51d  :rw_packet : Buffering 70 at 0
52.89:51d  :rw_packet : ########################################################
52.89:51d  :rw_packet : 		 70 (112) ------------->
52.89:51d  :rw_packet : Expecting HACK
52.90:51d  :rw_packet : 				 <============ ac (172)
52.90:51d  :rw_packet : 		 90 (144) ------------->
52.90:51d  :rw_packet : Expecting PACK
52.91:51d  :rw_packet : 				 <============ ce (206)
52.91:51d  :rw_packet : ########################################################
57.91:51d  :main      : Auto PONG
57.91:51d  :rw_packet : Buffering 70 at 0
57.91:51d  :rw_packet : ########################################################
57.91:51d  :rw_packet : 		 70 (112) ------------->
57.91:51d  :rw_packet : Expecting HACK
57.92:51d  :rw_packet : 				 <============ ac (172)
57.92:51d  :rw_packet : 		 90 (144) ------------->
57.92:51d  :rw_packet : Expecting PACK
57.93:51d  :rw_packet : 				 <============ ce (206)
57.93:51d  :rw_packet : ########################################################
62.93:51d  :main      : Auto PONG
62.93:51d  :rw_packet : Buffering 70 at 0
62.93:51d  :rw_packet : ########################################################
62.93:51d  :rw_packet : 		 70 (112) ------------->
62.93:51d  :rw_packet : Expecting HACK
62.94:51d  :rw_packet : 				 <============ ac (172)
62.94:51d  :rw_packet : 		 90 (144) ------------->
62.94:51d  :rw_packet : Expecting PACK
62.95:51d  :rw_packet : 				 <============ ce (206)
62.95:51d  :rw_packet : ########################################################
67.95:51d  :main      : Auto PONG
67.95:51d  :rw_packet : Buffering 70 at 0
67.95:51d  :rw_packet : ########################################################
67.95:51d  :rw_packet : 		 70 (112) ------------->
67.95:51d  :rw_packet : Expecting HACK
67.96:51d  :rw_packet : 				 <============ ac (172)
67.96:51d  :rw_packet : 		 90 (144) ------------->
67.96:51d  :rw_packet : Expecting PACK
67.97:51d  :rw_packet : 				 <============ ce (206)
67.97:51d  :rw_packet : ########################################################
72.00:51d  :rw_packet : ********************************************************
72.00:51d  :rw_packet : 				 <============ 32 (50)
72.00:51d  :rw_packet : 				 <============ ce (206)
72.00:51d  :rw_packet : 		 ce (206) ------------->
72.00:51d  :rw_packet : ********************************************************
72.00:51d  :processpac: Got Stop
77.00:51d  :main      : Auto PONG
77.00:51d  :rw_packet : Buffering 70 at 0
77.00:51d  :rw_packet : ########################################################
77.00:51d  :rw_packet : 		 70 (112) ------------->
77.00:51d  :rw_packet : Expecting HACK
77.01:51d  :rw_packet : 				 <============ ac (172)
77.01:51d  :rw_packet : 		 90 (144) ------------->
77.01:51d  :rw_packet : Expecting PACK
77.11:51d  :main      : ACK timeout
77.11:51d  :rw_packet : 		 90 (144) ------------->
77.21:51d  :main      : ACK timeout
77.21:51d  :rw_packet : 		 90 (144) ------------->
77.31:51d  :main      : ACK timeout
77.31:51d  :rw_packet : 		 90 (144) ------------->
77.41:51d  :main      : ACK timeout
77.41:51d  :rw_packet : 		 90 (144) ------------->
77.51:51d  :main      : ACK timeout
77.51:51d  :rw_packet : 		 90 (144) ------------->
77.61:51d  :main      : ACK timeout
77.61:51d  :rw_packet : 		 90 (144) ------------->
77.71:51d  :main      : ACK timeout
77.71:51d  :rw_packet : Too many retries removing packet from send queue
79.98:51d  :rw_packet : ********************************************************
79.98:51d  :rw_packet : 				 <============ 61 (97)
79.98:51d  :rw_packet : 				 <============ 9f (159)
79.98:51d  :rw_packet : 		 ce (206) ------------->
79.98:51d  :rw_packet : ********************************************************
79.98:51d  :processpac: Got Shutdown

Any thoughts? Will try to revert to VW to see what happens...

Thanks.
Jeff

jheyerman · « **Reply #13 on:** July 16, 2008, 01:33:32 am »

Reverted to VW system and works fine. My most logical guess is PB is incompatible with 2008 decks? What if I try an earlier version of firmware, or the non-hacked (even though my box is hacked) - I am curious what the difference is in those - is it for the VIOT or AAC workaround?

Very confused at this point...

Thanks.
Jeff

More update - switched from VW to KW firmware, but this time manually by downloading the files. Copied over the linux LBA file. Same behaviour again - not recognized by the KW deck.

markbowen · « **Reply #14 on:** July 16, 2008, 06:58:07 am »

Just to comment that it's highly unlikely that the PB is not compatible with 2008 models. The PB acts like a CD changer, and so should work with all Kenwood HUs that have CD changer compatibility. I have a 2007 model HU, and my PB works just fine. You can double check with Kenwood, but I don't think that's the issue.

jheyerman · « **Reply #15 on:** July 16, 2008, 12:28:24 pm »

Well, I did call KW before I purchased the deck, and they said it should be compatible. I will verify. One thing is when I was putting in the new cable, I did stress the connector a little since the VW supplied mounts do push the cable off to the side - does the log file suggest a possible hardware/connection error? If so I will take it apart and check the solder connections.

Thanks.
Jeff

sbingner · « **Reply #16 on:** July 17, 2008, 02:03:00 am »

Log file says it booted up then never got any command to start playing -- it was just waiting for your head unit to say "play something"

jheyerman · « **Reply #17 on:** July 17, 2008, 05:15:55 am »

That makes sense based on LED activity - it is the same as when connected as a VW and working (but not playing).

Took the PB apart before getting Sbingner's post - did a continuity check from KW end of cable to solder pads on the board - all ok. Now left with nothing to try except older firmware.

I did call KW US (last time I called KW Canada), and they say it should work - but I would still like to get a 2007 or earlier model and try it out...

Thanks,
Jeff

markbowen · « **Reply #18 on:** July 17, 2008, 01:34:35 pm »

Also to try: With everything connected, reset the Kenwood HU. Somewhere on the faceplate should be a tiny recessed button, which can only be pressed with a paper clip or pen tip. It's been a while since I did my install, but I believe the reset was recommended either in an install sheet or in the Music Keg instructions. I know for sure that it didn't work the first time until I reset the HU.

jheyerman · « **Reply #19 on:** July 17, 2008, 06:32:44 pm »

OFFICIAL:

***2008+ model year Kenwood decks are not compatibile with PBs/music keg***

I spoke to Dean at second level support, Kenwood USA, and he was immediate in his reply. The lower level technical support I spoke to earlier in US and Canada just didn't know.

This should prob go in the Wiki/Faq?

I appreciate the help everybody gave - I have about 25 hrs invested in the debugging - now to get a 2007 deck; hope it goes smoother!

News:

Author Topic: New Kenwood HU with OEM VM Phatbox - not working (Read 25329 times)