[Vibrant Android Development] Genesis3:
Yikes - those files are very messy (e.g. no line separators in them!) but I think I found something that matches what I expected.

I had to "tr" the file to be able to read it and there's no CRs in there either (from what platform did you pull these logcats?!) but there's a number of interesting things in here.

Among them:

0)E/RIL
149): requestDialEmergencyCall
)E/RIL
149): requestDialEmergencyCall
): address[911/], clir[0]E/RIL
149): TxCall_ExecOriginate
)E/RIL
149): TxCall_ExecOriginate
) number[911], number_len=3E/RIL
149): get_msg_sequence
)E/RIL
149): ipc_debug_send_ipc: timestamp 1320507653306009E/RIL
149): IPC_send_singleIPC: fd 17 sendto 99 bytesE/RIL
149): TX: Time: 1952693434 / 2597205E/RIL
149): TX:
M)IPC_CALL_CMD
S)IPC_CALL_OUTGOING
T)IPC_CMD_EXEC len:63 mseq:f1 aseq:0E/RIL
149): TX: ---- DATA BEGIN ----E/RIL
149): TX: 00 07 00 03 21 39 31 31 00 00 00 00 00 00 00 00 E/RIL
149): TX: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 E/RIL
149): TX: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 E/RIL
149): TX: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 E/RIL
149): TX: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 E/RIL
149): TX: 00 00 00 00 00 00 00 00 00 00 00 00 E/RIL
149): TX: ---- DATA END ----E/RIL
149): IPC_send_singleIPC: 99 bytes sent.E/RIL
149): WaitForExpectedCmd
): cur_time: 2597205, cur_req->timeout: 2657205, ph->near_timeout: 2602202E/RIL

149): ipc_debug_send_ipc: timestamp 1320507653326114E/RIL
149): [EVT]:Req
2), RX
1)E/RIL
149): RX: Time: 1952693454 / 2597225E/RIL
149): RX:
M)IPC_GEN_CMD
149): RX: ---- DATA BEGIN ----E/RIL
149): RX: 09 02 03 00 80 E/RIL
149): RX: ---- DATA END ----E/RIL
[b] 149): requestSetMute
)E/RIL [/b]
149): GR err: 0x8000E/RIL
149): COMPLETE - STATE[1] < E/RIL
149): RIL_onRequestComplete: tok
0x1b4b0)E/RIL
149): [RM REQ]: req
0x1b4c8), tok
0x1b4b0)E/RIL
149): [EVT]:Req
1), RX
0)E/RIL
149): [EVT]:Req
1), RX
0)D/RILJ
421): Serial: 1004D/RILJ
421): Error: 0D/RILJ
[b] 421): [1004]< SET_MUTE E/RIL[/b]

There's the audio-channel mute.

The problem appears to start here:

S)IPC_CALL_STATUS
T)IPC_CMD_NOTI len:d mseq:ff aseq:f1E/RIL
149): RX: ---- DATA BEGIN ----E/RIL
149): RX: 00 07 01 01 00 00 E/RIL
149): RX: ---- DATA END ----E/RIL
149): ipc_recv_call
)E/RIL
149): RxCall_CallStatusE/RIL
149): prv_get_release_cause
0x0,0x0)E/RIL
149): RIL_onMultiClientUnsolicitedResponse:E/RIL
149): unsupported multiclient unsolicited response code 1001W/RILJ
421): [1005]< <unknown request> exception, possible invalid RIL responseW/RILJ

421): java.lang.RuntimeException: Unrecognized solicited response: 10016W/RILJ

421): at com.android.internal.telephony.SamsungRIL.processSolicited
SamsungRIL.java:240)W/RILJ
421): at com.android.internal.telephony.RIL.processResponse
RIL.java:2112)W/RILJ
421): at com.android.internal.telephony.RIL.access$300
RIL.java:208)W/RILJ
421): at com.android.internal.telephony.RIL$RILReceiver.run
RIL.java:583)W/RILJ
421): at java.lang.Thread.run
Thread.java:1019)D/RILJ
421): [UNSL]< UNSOL_RESPONSE_CALL_STATE_CHANGEDE/RIL
149): [EVT]:Req
0), RX
1)E/RIL
149): RIL_onMultiClientUnsolicitedResponse:E/RIL
149): unsupported multiclient unsolicited response code 1009D/RILJ
421): [1006]> GET_CURRENT_CALLSE/RIL
149): onRequest: GET_CURRENT_CALLSE/RIL
149): CreateRequest
): req
0x1b718), id
9), tok
0x1b700) - FUNC
0x8001861d)E/RIL

That exception is a problem; I've got nothing in the 10000s in the RILConstants.java file which strongly implies that this is one of those fancy-schmancy Samsung proprietary deals. If I had to guess that upcall is used in the stock code to provide an upbound notification that an emergency call is in process (perhaps to lock the phone to the call screen and prohibit exit until the calls ends, for example.) The Samsung RIL override file has unsolicited upcalls in the 11000s and a solicited 10016 that is related to emergency dialing.... hmmmm......

This logcat output is radically different than what I get - what code version are you running? I'm on the release version (not the nightlies); it looks like the CM7 folks cranked the debugging data wide open in an attempt to find this, as I've got IPC-packet level trace data in the radio log you posted that isn't in my logs.

Incidentally, contrast your log with a "working" ordinary call off the stable build. The 11003 exception is still here but it's the only one, and it is handled cleanly without tossing anything upstream.

D/GSM ( 285): Poll ServiceState done: oldSS=[0 home T-Mobile T-Mobile 310260 UMTS CSS not supported -1 -1RoamInd: -1DefRoamInd: -1EmergOnly: false] newSS=[0 home T-Mobile T-Mobile 310260 UMTS CSS not supported -1 -1RoamInd: -1DefRoamInd: -1EmergOnly: false] oldGprs=0 newGprs=0 oldType=UMTS newType=UMTS
D/GSM ( 285): isTwoDigitShortCode
D/GSM ( 285): dialing w/ mmi 'null'...
D/GSM ( 285): [GSMConn] acquireWakeLock
D/RILJ ( 285): [6919]> SET_MUTE false
D/RILJ ( 285): [6920]> DIAL
D/RILJ ( 285): Serial: 6919
D/RILJ ( 285): Error: 0
D/RILJ ( 285): [6919]< SET_MUTE
E/RILJ ( 285): Exception processing unsol response: 11003Exception:java.lang.RuntimeException: Unrecognized unsol response: 11003
D/RILJ ( 285): Serial: 6920
D/RILJ ( 285): Error: 0
D/RILJ ( 285): [6920]< DIAL
D/RILJ ( 285): [UNSL]< UNSOL_RESPONSE_CALL_STATE_CHANGED
D/RILJ ( 285): [UNSL]< <unknown reponse>
D/PHONE ( 285): VM: PhoneSubInfo.getVoiceMailNUmber:
D/RILJ ( 285): [6921]> GET_CURRENT_CALLS
D/RILJ ( 285): [6922]> GET_CURRENT_CALLS
D/RILJ ( 285): Serial: 6921
D/RILJ ( 285): Error: 0
D/RILJ ( 285): Parcel size = 96
D/RILJ ( 285): Parcel pos = 12
D/RILJ ( 285): Parcel dataAvail = 84
D/RILJ ( 285): num = 1
D/RILJ ( 285): state = DIALING
D/RILJ ( 285): index = 1
D/RILJ ( 285): state = 129
D/RILJ ( 285): isMpty = false
D/RILJ ( 285): isMT = false
D/RILJ ( 285): als = 0
D/RILJ ( 285): isVoice = true
D/RILJ ( 285): Samsung magic = 0
D/RILJ ( 285): number = 850xxxxxxx
D/RILJ ( 285): np = 0
D/RILJ ( 285): name = null
D/RILJ ( 285): namePresentation = 0
D/RILJ ( 285): uusInfoPresent = 0
V/RILJ ( 285): Incoming UUS : NOT present!
D/RILJ ( 285): InCall VoicePrivacy is disabled
D/RILJ ( 285): [6921]< GET_CURRENT_CALLS [id=1,DIALING,toa=129,norm,mo,0,voc,noevp,,cli=1,,0]
D/RILJ ( 285): Serial: 6922
D/RILJ ( 285): Error: 0

Note that we got the 11003, but we also set the MUTE; (I blanked the nxx numbers); the call processes and then we get....

V/RILJ ( 285): Incoming UUS : NOT present!
D/RILJ ( 285): InCall VoicePrivacy is disabled
D/RILJ ( 285): [6922]< GET_CURRENT_CALLS [id=1,DIALING,toa=129,norm,mo,0,voc,noevp,,cli=1,,0]
D/RILJ ( 285): [6923]> OPERATOR
D/RILJ ( 285): [6924]> GPRS_REGISTRATION_STATE
D/RILJ ( 285): [6925]> REGISTRATION_STATE
D/RILJ ( 285): Serial: 6923
D/RILJ ( 285): Error: 0
D/RILJ ( 285): [6923]< OPERATOR {T-Mobile , T-Mobile , 310260}
D/RILJ ( 285): Serial: 6924
D/RILJ ( 285): Error: 0
D/RILJ ( 285): [6924]< GPRS_REGISTRATION_STATE {1, 865d, 045d21d5, 3}
D/RILJ ( 285): [6926]> QUERY_NETWORK_SELECTION_MODE
D/RILJ ( 285): Serial: 6925
D/RILJ ( 285): Error: 0
D/RILJ ( 285): [6925]< REGISTRATION_STATE {1, 865d, 045d21d5}
D/RILJ ( 285): Serial: 6926
D/RILJ ( 285): Error: 0
D/RILJ ( 285): [6926]< QUERY_NETWORK_SELECTION_MODE {0}
D/RILJ ( 285): [6927]> SET_MUTE false
D/RILJ ( 285): Serial: 6927
D/RILJ ( 285): Error: 0
D/RILJ ( 285): [6927]< SET_MUTE
D/RILJ ( 285): [6928]> SET_MUTE false

There it is - mute is TURNED OFF.

First blush it looks to me like the blowup in the call state is killing it.

The code attempts to un-mute and manage that state exactly as it does for a normal call. There's a ****ton of debugging trace data in your logs that aren't present in mine looking at an ordinary call setup. I don't see anything obvious there; the "zero" error returns are present.

My money is on the exception being thrown right at the top being responsible for the problem, but this is an educated guess at present.

Now let's see what we got in that Samsung RIL file for 10016...

static final int RIL_REQUEST_DIAL_EMERGENCY = 10016;

.....

if (PhoneNumberUtils.isEmergencyNumber(address)) {
Log.v(LOG_TAG, "Emergency dial: " + address);
rr = RILRequest.obtain(RIL_REQUEST_DIAL_EMERGENCY, result);
rr.mp.writeString(address + "/");
}

Aha. So we send up a 911 request with that code but what do we do if we get a response back with the same index?

Upstream in the code a bit we have this:

case RIL_REQUEST_REPORT_SMS_MEMORY_STATUS: ret = responseVoid(p); break;
case RIL_REQUEST_REPORT_STK_SERVICE_IS_RUNNING: ret = responseVoid(p); break;
default:
throw new RuntimeException("Unrecognized solicited response: " + rr.mRequest);
//break;

Uh huh. See that nice last default case? Bad news; that's the blowup in your log. I betcha we stick this in there right above it and the problem goes away:

case RIL_REQUEST_DIAL_EMERGENCY: ret = responseVoid(p); break;

I haven't grabbed the entire build set yet for the Vibrant so I'm working off my other local copy (which I build the Triumph from) so this is somewhat of a guess right now; my Linux VM is too small to grab another full tree and one of this weekend's jobs is to resize it onto another disk so I can work on the Vibrant code.

I'll try to get this done over the weekend and build up a KANG for you to try; if the official CM7 folks see this it's a literal one-liner to see if it solves the problem, but since they don't have a Vibrant to test on it's a ***** for them to check it.

Unless I'm reading the radio logcat wrong the routing and unmute is just fine - the problem is that the phone code got blown up by the unhandled exception during call setup and thus there's nothing to route from and to any more!

Thou shalt not send a request that can generate a response and not handle the response!