RIL Proxy Logging --- The Most Important Debugging Tool for Investigating Radio and RIL Issues

----------------------------------------
RIL proxy logging in Magneto AKU2:
 
Starting with Magneto AKU2, RIL proxy logging feature is componentized into a separate, optional DLL, rillog.dll. The purpose of this change is to reduce ROM footprint of RIL proxy component (ril.dll) as well as to improve its memory usage. To enable RIL Proxy logging, set the environment variable SYSGEN_RILPROXY_LOG before building an image.  Alternately, the DLL can be sysgen’d manually by running "sysgen -p cellcore rillog". Rillog.dll is automatically loaded by ril.dll at boot time provided that both of the following criteria are met:
1) The value of "RILProxyLogNormal" under [HKEY_LOCAL_MACHINE\Software\Microsoft\RIL] is set to dword:1
2) Rillog.dll is either in ROM under the \Windows directory or in Platform Builder release directory (for KITL images).
----------------------------------------

The Radio Interface Layer (RIL) provides an interface that handles the communication between the CellCore system software and the radio hardware. The RIL provides an abstraction layer that enables you to create a single driver that can be implemented on different radios. This single driver then allows all of the radios to work under a single set of CellCore components.

 

RIL consists of two modules: the RIL proxy and the RIL driver. The proxy layer is a Windows CE-based dynamic-link library (DLL) that manages callback notifications and inter-process function calls into the driver layer. CellCore modules use the RIL application programming interface (API) by linking to this proxy DLL.

 

The RIL driver layer is implemented as a Windows CE device driver that is managed by the Device Manager (Device.exe). The RIL driver services system requests for radio functionality including voice, data, Short Message Service (SMS), and other functionality, and notifies the system of changes in the radio state, such as coverage, signal strength, and incoming calls.

 

The RIL proxy is provided by Microsoft. You have to write a customized RIL driver to work with your radio hardware. Microsoft provides a sample implementation of a RIL driver that works with several Global System for Mobile communication (GSM) radios.

 

Different OEMs provide different RIL drivers which might have different or no RIL driver logs. To help investigate issues related to radio and RIL, Microsoft provides RIL proxy log. RIL proxy log is the most popular debugging tools for investigating RIL and radio issues. It is in RIL proxy level and provides the same log format for different OEM radios.

 

The following is the instruction for enabling RIL Proxy Log.

RilProxyLog is inside Windows Mobile 5.0 and later releases (both debug and retail builds). You just need to enable it. There are several ways to get RIL Proxy Log.

 

If Platform Build is attached, you can use any one of the following to get RIL Proxy Log.

- If you have all the symbols, you can go to Target->CE Debug Zones in PB, select ril.dll and enable RILProxyLog and RILProxyLogDebug. The logs will immediately show up in debug output window.

- Or choose menu Tools->Remote Registry Editor, set RILProxyLogNormal = 1 and RILProxyLogDetail = 1 under HKLM\Software\Microsoft\RIL\, then warm reboot the device.

- If you create your private Magneto build, before compiling CellCore code or running blddemo –c after setting RILPROXYALL=1. The RilProxyLog will be automatically enabled in the build. Once PB is attached, the log will show up in PB output window.

 

If Platform Build is not attached, you can use PerfMan tool to preserve RIL Proxy Log on device by using the following steps:
1. Contact your Technical Account Manager at Microsoft to get this Microsoft internal tool - PerfMan if you don’t have it. Basically, it is a signed version of file perf.cab.pkg. Copy Perf.cab.pkg to "\windows\Start Menu" on the device, launch the Perf package installation from the Programs menu, and follow the instructions on the device. Also, make sure you get readlog.exe and rd.bat on your desktop machine, these files are for reading the PerfMan output file.
2. Use PB Remote Registry Editor or RegEdit tool provided by OEM or other similar tool to open device registry, and add DWORD RILProxyLogNormal = 1 and RILProxyLogDetail = 1 under HKLM\Software\Microsoft\RIL\. (Note: it might take more than one minute to get the registry value change flashed into device after the values are changed in the tools.)
3. Warm reboot your device. (Check the registry value and make sure they are there.)
4. Run perfman.exe on the device. On Pocket PC, it can be found at "Start->Programs"; while on SmartPhone, it is at "Start->More->...".
5. In PerfMan, select Celog/Profiler, set Buffer to 1 MB, set AutoFlush to “Every 10 seconds”, choose menu & select “set zones”, uncheck all zones, check zone for 0x00800000 only, press Done, and then press Start to start logging.
6. Run your RIL related tests.
7. Go to PerfMan and press Stop to stop logging.
8. Use ActiveSync or other way to copy the PerfMan output log file to desktop machine.
9. On desktop machine, put readlog.exe, rd.bat, PerfMan log (perfman.clg) under the same folder. Run rd.bat.
          Rd.bat runs following
          readlog .\perfman.clg .\perfman.txt
10. The generated file (perfman.txt) contains RIL proxy log.

 

The general format of the output is:

 

“<time> <proc> <thread>  RILProxy: <type> : <information>”

 

Where “<time> <proc> <thread>” is the time, process, and thread information we all know and love from Platform Builder.

 

<type> is:

  C – Normal mode command data

  c – Debug mode command data

  R – Normal mode response data

  r – Debug mode response data

  N – Normal mode notification data

  n – Debug mode notification data

 

<information> is specific to the type and RIL operation that is providing the information as follows:

 

Information Format for Normal Mode Command Data

 

“<function> - [ID: <command id>][, ][<params>]”

“<function> [- [ (Return) ]<params>]”

 

<function> is the RIL interface function being called, stripped of the “RIL_” at the beginning of the name (e.g. “RIL_Initialize” would be presented as “Initialize”).  Note that this will be all caps for functions which call into the RIL Driver, and capitalized for calls which do not.

<command id> is the Command Id as generated by a call to the RIL Driver.  This is only valid for commands which call into the RIL Driver.

<params> are the parameters that are passed to the function.  This may not include all parameters that are passed in, but may be limited to those parameters of interest to a “Normal” audience.

 

There may be multiple lines containing “<function> [- <params>]” data.  For functions that return values to the caller immediately, these will be on a separate line from the input parameters and the parameters are preceded by the string “(Return)”.

 

<params> consists of “{<enum param>|<bitfield param>|<value param>}[, ...]”

<enum param> is an enumeration constants, stripped of the “RIL_XXX_” at the beginning of the name (e.g. “RIL_CAPSTYPE_SIMTOOLKITNOTIFICATIONS” would be presented as “SIMTOOLKITNOTIFICATIONS”).

<bitfield param> is a parameter that contains several discrete bits.  It consists of “<param name> = [<bitn>][|...]”

<param name> is a user friendly representation of the parameter variable name.

<bitn> is the enumeration constant for a bit stripped of the “RIL_XXX_” at the beginning of the name.  <bitn> is only presented if the bit is true.

<value param> consists of “<param name> = <param value>”

<param value> is the value of the parameter in units that make sense for that parameter.

 

In the case where a parameter is structure, structure elements will (recursively) be treated as individual parameters.  For structures that contain member validity bits, those bits will not be presented, but will be used to filter the parameters that are being presented.

 

Examples:

  10830 PID:c3d6bc7a TID:c3dc991a RILProxy : C : INITIALIZE - RIL: 1, Notification Registration = CALLCTRL | MISC | NETWORK | RADIOSTATE | SUPSERVICE

  63339 PID:5b3783a TID:a571dc5e RILProxy : C : GETDEVCAPS - ID: 13, CALLPROGRESSNOTIFICATION

 

Information Format for Debug  Mode Command Data

 

“<function> - From <module name>”

“<function> [- <params>]”

“<function> [- ][[ (Return) ]<params>][, ][Function Result = <return value>]”

 

<module name> is the name of the calling module as reported by GetModuleName.  This is useful to track processes for command results and notifications.

<params> are parameters that are passed to the function that are not of interest to a “Normal” audience, but may be of use while debugging.  Examples of this are the callback function pointers and user defines parameters associated with a call to RIL_Initialize.

 

Again, there may be multiple lines containing “<function> [- <params>]” data.

 

<return value> is the value returned to the caller of the RIL function.  Usually this is of type HRESULT, but in cases where a command is passed asynchronously to the RIL, this will contain the Command ID on a successful return.

 

Examples:

  19860 PID:47ded77a TID:47e0840a RILProxy : c : From \Windows\device.exe

  19860 PID:47ded77a TID:47e0840a RILProxy : c : Initialize - Result Callback = 0x01a7fe00, Notify Callback = 0x01a82160, Param = 0x00000000

  19860 PID:47ded77a TID:47e0840a RILProxy : c : Initialize – (Return) Handle = 0x00042f50, Thread = 0x87bc26da, Function Result = 0x00000000

  61160 PID:67656c8a TID:876abeae RILProxy : c : GETDEVCAPS – FunctionResult = 0x00000006

 

Information Format for Normal Mode Response Data

 

“<function> - [ID: <command id>][, ][<params>]”

<function> is the RIL interface function for which the response notification is being sent, stripped of the “RIL_” at the beginning of the name (e.g. “RIL_GetDevCaps” would be presented as “GETDEVCAPS”).

<command id> is the Command Id as generated by a call to the RIL Driver.  This is only valid for commands which call into the RIL Driver.

<params> are the parameters that are passed through the callback function.  This may not include all parameters that are passed in, but may be limited to those parameters of interest to a “Normal” audience.

 

There may be multiple lines containing “<function> - [ID: <command id>][, ][<params>]” data.

 

Examples:

  56110 PID:5592d62 TID:4582d33e RILProxy : R : GETDEVCAPS - ID: 11, Result: OK

  56113 PID:5592d62 TID:4582d33e RILProxy : R : GETDEVCAPS - (SIMSUPPORT) SIM functionality = CAPS_SIM_BASIC

805098 PID:5b3783a TID:5970902 RILProxy : R : GETCALLLIST - ID: 84, Result: OK

805113 PID:5b3783a TID:5970902 RILProxy : R : GETCALLLIST - Call 1: CALLDIR_INCOMING, CALLSTAT_ACTIVE, CALLTYPE_PTT, ADDRESS: ADDRTYPE_UNKNOWN, NUMPLAN_TELEPHONE, "14252081262",

805121 PID:5b3783a TID:5970902 RILProxy : R : GETCALLLIST - Call 2: CALLDIR_INCOMING, CALLSTAT_WAITING, CALLTYPE_VOICE, ADDRESS: ADDRTYPE_UNKNOWN, NUMPLAN_TELEPHONE, "14254428198",

 

Information Format for Debug  Mode Response Data

 

“<function> - To <module name>[- <params>]”

<module name> is the name of the calling module that initiated the command.

<params> are parameters that are passed through the callback function that are not of interest to a “Normal” audience, but may be of use while debugging.  Examples of this are the callback data pointer and user defines parameters associated with the instantiating call to RIL_Initialize.

 

Again, there may be multiple lines containing <params> data.

 

Example:

  61160 PID:67656c8a TID:876abeae RILProxy : r : GETDEVCAPS – To \Windows\device.exe - Info Pointer = 0x0e09f8d8, Param = 0x00040940

 

Information Format for Normal Mode Notification Data

 

“<notification> [- <params>]”

<notification> is the RIL notification constant for which the notification is being sent, stripped of the “RIL_NOTIFY_” at the beginning of the name (e.g. “RIL_ NOTIFY_RADIOEQUIPMENTCHANGED” would be presented as “RADIOEQUIPMENTCHANGED”).

 

<params> are the parameters that are passed through the callback function.  This may not include all parameters that are passed in, but may be limited to those parameters of interest to a “Normal” audience.

 

There may be multiple lines containing “<notification> [- <params>]” data.

 

Examples:

  60551 PID:a7d26802 TID:a7c49fce RILProxy : N : RADIOEQUIPMENTSTATECHANGED - Ready State = INITIALIZED | SIM | SIM_PB | SMS | UNLOCKED

  29180 PID:c3d6bc7a TID:a3896fa2 RILProxy : N : SIGNALQUALITY - SignalStrength = -113, MinSS = -113, MaxSS = -51, BitErrorRate = 14, LowSS = -110, HighSS = -60

 

Information Format for Debug  Mode Notification Data

 

“<notification> - To <module name>[ -<params>][<cr><lf>…]”

<params> are parameters that are passed through the callback function that are not of interest to a “Normal” audience, but may be of use while debugging.  Examples of this are the callback data pointer and user defines parameters associated with the instantiating call to RIL_Initialize.

 

Again, there may be multiple lines containing <params> data.

 

Example:

  60551 PID:a7d26802 TID:a7c49fce RILProxy : n : RADIOEQUIPMENTSTATECHANGED - To \Windows\device.exe - Info Pointer = 0x0812faf4, Param = 0x00000000

  73546 PID:a7d26802 TID:e7913fca RILProxy : n : SIGNALQUALITY - To \Windows\device.exe - Info Pointer = 0x0848faf4, Param = 0x00368610

 

 

 

Author: [Yibin Tai]