Interpreting a signaling process trace

Figure 1 is an extract of a signaling interface trace. This example shows a call being set up; it corresponds to the first part of the flow Successful outgoing call (common channel signaling).

Figure 1. Extract of a signaling interface trace

ID     ELAPSED_SEC     DELTA_MSEC   APPL    SYSCALL KERNEL  INTERRUPT
459   60.241133184      16.942208   SIGLIB: [39487] sl_send_request SL_PROC_USR1
                                            SL_CALL_SETUP_REQ
                                            SL_REQUEST_ST
                                            SLID_REQUEST_ST
                                            iseq_no 0 pidCHP 39487
                                            SL_CALL_SETUP_REQ
                                            SL_REQUEST_PARM_ST
                                            sizetLength 148 CallRef 0
                                            pause 0 ring_wait 10
                                            ring_time 120 iChannelNo -1
                                            iVpackNo -1 fd 555556
                                            Channel Groups [0]=0 unused
                                            0 0 0 1 0 0 0 0 0 0 0 0
                                            phone_num [01962815000]
459   60.243664256       2.531072   SIGLIB: [39487] sli_get_queue SL_PROC_USR1 create_it
 0
459   60.293464832      49.800576   SIGLIB: [39487] return sl_send_request
                                            code SLRC_OK errno 0
...
459   60.794861184       0.141184   SIGLIB: [24878] sl_receive_request
                                            sl_handle 20055008
                                            timeout 30 pslRequest 2FF7EFB8
459   60.797641216       2.780032   SIGLIB: [24878] sli_validate_handle
                                            sl_handle 20055008
                                            SL_SIGPROC_DATA_ST
                                            SLID_SIGPROC_DATA_ST
                                            vsc_fd 999999 vscdd_fd 666666
                                            registered 1
459   60.797759232       0.118016   SIGLIB: [24878] return sli_validate_handle
                                            code SLRC_OK errno 0
459   60.797878016       0.118784   SIGLIB: [24878] sli_get_queue SL_PROC_USR1 create_it
 0
459   60.804822528       6.944512   SIGLIB: [24878] sl_set_timeout timeout 30
459   60.807234304       2.411776   SIGLIB: [24878] sl_set_timeout timeout 0
459   60.809741696       2.507392   SIGLIB: [24878] return sli_msgrcv
                                            code SLRC_OK errno 0
...
ID     ELAPSED_SEC     DELTA_MSEC   APPL    SYSCALL KERNEL  INTERRUPT
459   60.946913024     137.171328   SIGLIB: [24878] received primitive
                                            SL_CALL_SETUP_REQ
                                            SL_REQUEST_ST
                                             SLID_REQUEST_ST
                                             iseq_no 5 pidCHP 39487
                                             SL_CALL_SETUP_REQ
                                            SL_REQUEST_PARM_ST
                                            sizetLength 148 CallRef 2
                                            pause 0 ring_wait 10
                                            ring_time 120 iChannelNo -1
                                            iVpackNo -1 fd 555556
                                            Channel Groups [0]=0 unused
                                            0 0 0 1 0 0 0 0 0 0 0 0
                                            phone_num [01962815000]
459   60.947030016       0.116992   SIGLIB: [24878] return sl_receive_request
                                            code SLRC_OK errno 0
...

The trace in Figure 1 was formatted using the Blueworx Voice Response print_trace command. The basic format of the trace is the same as a trace formatted using the AIX trcrpt command.

The first column (ID) is the trace event ID.
- Trace event IDs are explained in more detail in the section on defining trace events in AIX 4.1 Writing a Device Driver.
- Blueworx Voice Response uses seven event IDs depending on what is being traced. See the section on Blueworx Voice Response usage of AIX trace event ids in the Blueworx Voice Response for AIX: Problem Determinationguide.
- signaling interface trace uses event id 0X459. Once you know the event id, you can use AIX selective trace.
The second column (ELAPSED_SEC) is the elapsed time (in seconds) since the trace started.
The third column (DELTA_MSEC) is the number of milliseconds since the previous trace event.
The fourth column (APPL) is set to SIGLIB by Blueworx Voice Response to identify a line in the formatted trace report that is part of signaling interface tracing.
The fifth column contains the id of the process making the signaling interface subroutine call.
Note: The titles of the fifth column and the columns headed SYSCALL, KERNEL and INTERRUPT are not applicable to Blueworx Voice Response signaling interface traces and should be ignored.
The sixth column describes the trace entry:

sl _

Entry to a signaling interface subroutine. The first line contains the name of the subroutine (for example sl_receive_request) and the remaining lines list the parameters passed to the subroutine. In the example shown above, the trace for sl_receive_request includes the sl_proc_type and psignalingRequest parameters.
Structures are decoded member by member.

Note: You can see that two process ids appear in the trace, the sending CHP is 39487, and the signaling process is 24878. The process id of the CHP also appears in the pidCHP field in the SL_CALL_SETUP_REQUEST_ST.
You may find this useful when debugging problems.

return

Return from a signaling interface subroutine. code specifies the value of the return code from the subroutine, displayed as one of the values of the SL_RET_CODE enumeration from slcommon.h.
errno displays the value of the AIX global variable errno.

sli_

Entry to a internal subroutine within the signaling interface. You can ignore these, they are not intended for use by developers of signaling processes; they are included to assist IBM in problem determination.

received primitive

This traces a signaling interface primitive that has been received by the signaling process, before sl_receive_request() completes. This allows you to see the primitive received by your signaling process.

other

The trace may also contain other entries, you can ignore these they are not intended for use by developers of signaling processes; they are included to assist IBM in problem determination.