Often when working in a ShoreTel envoirment one must diagnose call issues using logs. All calls are registered in the Shoreware Call Detail Record file and the call is logged in the TMSNcc-YYMMDD.log file for the particular day. Log files are located on HQ or DVS servers in the \shoreline data\logs folder.
Call Code Parameters:
| C-CE | Call Creation Event | Call Initiation. |
| L-CE | Leg Create Event | Follows a C-CE for every call setup. Internal transfers (blind transfers). |
| L-IE | Leg Info Event | Follows a C-CE, L-CE. Leg Info; provides information on other parties in the call. |
| C-SE | Call State Event |
State of call in progress, all parties; RingBack, Offering, Established ,etc.
|
| L-SE | Leg State Event | Follows a C-SE to inform the leg state changes. |
| L-DE | Leg Destroy Event | Call tear down; Leg is destoryed. |
| C-DE | Call Destroy Event | Call Destoryed user or system hung up. |
| G-MST | Media State Event | Media states for the terminated call leg. Every RTP stream also has a media state. |
Call Example:
+1 (123)-456-7891 Calls in → Hunt Group Ext 2110 → Hunt Group Forward Always → Voicemail → User Hung Up
Key:
| Trunk Call Leg To PSTN | 40000001 |
| Internal Call Leg | 20000023 |
| Call GUID | 00020000-1aae-4f05-9cce-0010491e1b95 |
| PBX Responding to Party | ncc_media_ctl |
Packet Information:
(s:1, r:378, l:0),(j:0,u:0,o:0)
The above packet information lists sent and recieved packets, and jitter. This is very useful in understanding why calls fail. In many cases we will see issues with jitter readjustments during problem or dropped calls. The s:1 indicates 1 packet was sent, the r:378 indicates 378 packets were recieved. The second set of parentheses (j:0,u:0,o:0) describes the jitter buffer, and in this case was adjusted 0 times. This is more of an ideal scenario as problem calls will vary in their jitter and packet amounts.
Example tmsncc.log:
|
07:24:59.656 ( 7616: 4908) C-CE: 40000001 “00020000-1aae-4f05-9cce-0010491e1b95” (“+11234567891″,”WIRELESS
CALLER”,0xC) 00000000,SDP:N,ipCDS:0×00000002,flgs:0×00000000,cd:0×00000000,”7722,TGrp_1,p1,”(704) 940-7722″”
“sip:TGrp_1,p1@10.168.98.6:5441″
|
|
07:24:59.656 ( 7616: 4908) L-CE: 40000001 “00020000-1aae-4f05-9cce-0010491e1b95“
0100847C(00000000),Req:00000000,1,Flgs:00000000(Null) “sip:TGrp_1,p1@10.168.98.6:5441″
|
|
07:24:59.656 ( 7616: 4908) C-CE: 20000023 “00020000-1aae-4f05-9cce-0010491e1b95” (“2110″,”HQ Main Hunt”,0xC)
00000000,SDP:N,ipCDS:0×00000002,flgs:0×00000001,cd:0×00000000,”7722,TGrp_1,p1,”(704) 940-7722″”
“sip:2110@10.168.98.6:5441″
|
|
07:24:59.656 ( 7616: 4908) L-CE: 20000023 “00020000-1aae-4f05-9cce-0010491e1b95“
0100847E(00000000),Req:00000000,0,Flgs:00000000(Null) “sip:2110@10.168.98.6:5441″
|
|
07:24:59.671 ( 7616: 4908) L-IE: 20000023 “00020000-1aae-4f05-9cce-0010491e1b95“
0100847E,rsn:3(Called),1,(“+11234567891″,”WIRELESS CALLER”,0xC(NameNumber)),C(“”,”WIRELESS CALLER”,0×4(Name))
contact=sip:TGrp_1,p1@10.168.98.6:5441, “sip:2110@10.168.98.6:5441″
|
|
07:24:59.671 ( 7616: 4908) L-DE: 20000023 “00020000-1aae-4f05-9cce-0010491e1b95“
0100847E,rsn:13(ForwardAlways),C(“2110″,”HQ Main Hunt”,0xC) TrGp=-1 “sip:2110@10.168.98.6:5441″
|
|
07:24:59.671 ( 7616: 4908) C-DE: 20000023 “00020000-1aae-4f05-9cce-0010491e1b95″ 13,(ForwardAlways)
“sip:2110@10.168.98.6:5441″
|
|
07:24:59.671 ( 7616: 4908) L-IE: 40000001 “00020000-1aae-4f05-9cce-0010491e1b95“
0100847C,rsn:2(Originate),0,(“2110″,”HQ Main Hunt”,0xC(NameNumber)),C(“+11234567891″,”WIRELESS
CALLER”,0xC(NameNumber)) contact=, “sip:TGrp_1,p1@10.168.98.6:5441″
|
|
07:24:59.671 ( 7616: 4908) L-SE: 40000001 “00020000-1aae-4f05-9cce-0010491e1b95“
0100847C,5(Established),0,11:25:00.945 (UTC) “sip:TGrp_1,p1@10.168.98.6:5441″
|
|
07:24:59.671 ( 7616: 4944) C-CE: 20000005 “00020000-1aae-4f05-9cce-0010491e1b95” (“2104″,”VM-AutoAttendant”,0xC)
00000000,SDP:N,ipCDS:0×00000002,flgs:0×00000000,cd:0×00000000,”7722,TGrp_1,p1,”(704) 940-7722″”
“sip:2104@10.168.98.5:5441″
|
|
07:24:59.671 ( 7616: 4944) L-CE: 20000005 “00020000-1aae-4f05-9cce-0010491e1b95“
010000CC(00000000),Req:00000000,0,Flgs:00000000(Null) “sip:2104@10.168.98.5:5441″
|
|
07:24:59.671 ( 7616: 4944) L-IE: 20000005 “00020000-1aae-4f05-9cce-0010491e1b95“
010000CC,rsn:13(ForwardAlways),1,(“+11234567891″,”WIRELESS CALLER”,0xC(NameNumber)),C(“2110″,”HQ Main
Hunt”,0xC(NameNumber)) contact=, “sip:2104@10.168.98.5:5441″
|
|
07:24:59.671 ( 7616: 4944) L-SE: 20000005 “00020000-1aae-4f05-9cce-0010491e1b95“
010000CC,3(Ringback),0,11:24:59.672 (UTC) “sip:2104@10.168.98.5:5441″
|
|
07:24:59.671 ( 7616: 4908) L-IE: 40000001 “00020000-1aae-4f05-9cce-0010491e1b95“
0100847C,rsn:2(Originate),0,(“2104″,”VM-AutoAttendant”,0xC(NameNumber)),C(“+11234567891″,”WIRELESS
CALLER”,0xC(NameNumber)) contact=, “sip:TGrp_1,p1@10.168.98.6:5441
|
|
07:24:59.671 ( 7616: 4908) C-SE: 40000001 “00020000-1aae-4f05-9cce-0010491e1b95” 3(Ringback),sd:0,11:25:00.951 (UTC)
“sip:TGrp_1,p1@10.168.98.6:5441″
|
|
07:24:59.671 ( 7616: 4944) C-SE: 20000005 “00020000-1aae-4f05-9cce-0010491e1b95” 2(Offering),sd:0,11:24:59.672 (UTC)
“sip:2104@10.168.98.5:5441″
|
|
07:24:59.687 ( 7616: 6716) ncc_media_ctl (0×20000005, StopOnDTMF, “0123456789*#”, id=0x000000B8, “00020000-1aae-
4f05-9cce-0010491e1b95“)
|
|
07:24:59.718 ( 7616: 6716) ncc_answer_call (0×20000005, 00020000-1aae-4f05-9cce-0010491e1b95, mode=None,
id=0x000000B9)
|
|
07:24:59.718 ( 7616: 4944) C-SE: 20000005 “00020000-1aae-4f05-9cce-0010491e1b95” 5(Established),sd:0,11:24:59.719
(UTC) “sip:2104@10.168.98.5:5441″
|
|
07:24:59.718 ( 7616: 4944) L-SE: 20000005 “00020000-1aae-4f05-9cce-0010491e1b95“
010000CC,5(Established),0,11:24:59.719 (UTC) “sip:2104@10.168.98.5:5441
|
|
07:24:59.718 ( 7616: 6716) ncc_media_ctl2 (0×20000005, StopRecord, id=0x000000BA, “00020000-1aae-4f05-9cce-
0010491e1b95“)
|
|
07:24:59.718 ( 7616: 4908) C-SE: 40000001 “00020000-1aae-4f05-9cce-0010491e1b95” 5(Established),sd:0,11:25:01.003
(UTC) “sip:TGrp_1,p1@10.168.98.6:5441″
|
|
07:24:59.718 ( 7616: 4908) L-SE: 40000001 “00020000-1aae-4f05-9cce-0010491e1b95“
0100847C,5(Established),0,11:25:01.003 (UTC) “sip:TGrp_1,p1@10.168.98.6:5441
|
|
07:25:01.109 ( 7616: 6716) ncc_set_call_data (0×20000005, 00020000-1aae-4f05-9cce-
0010491e1b95,calldata=0×00000001,calldatamask=0×00000001, id=0x000000BB)
|
|
07:25:01.109 ( 7616: 4944) C-DAE: 20000005 “00020000-1aae-4f05-9cce-0010491e1b95” 0×00000001
“sip:2104@10.168.98.5:5441″
|
|
07:25:01.109 ( 7616: 6716) ncc_media_ctl2 (0×20000005, StartPlay, id=0x000000BC, “00020000-1aae-4f05-9cce-
0010491e1b95“)
|
|
07:25:01.125 ( 7616: 4908) C-DAE: 40000001 “00020000-1aae-4f05-9cce-0010491e1b95” 0×00000001
“sip:TGrp_1,p1@10.168.98.6:5441″
|
|
07:25:08.687 ( 7616: 4944) L-DE: 20000005 “00020000-1aae-4f05-9cce-0010491e1b95“
010000CC,rsn:4(HangUp),C(“+11234567891″,”WIRELESS CALLER”,0xC) TrGp=1 “sip:2104@10.168.98.5:5441
|
|
07:25:08.687 ( 7616: 4944) C-DE: 20000005 “00020000-1aae-4f05-9cce-0010491e1b95″ 4,(HangUp)
“sip:2104@10.168.98.5:5441″
|
|
07:25:08.687 ( 7616: 4908) L-DE: 40000001 “00020000-1aae-4f05-9cce-0010491e1b95“
0100847C,rsn:4(HangUp),C(“+11234567891″,”WIRELESS CALLER”,0xC) TrGp=-1 “sip:TGrp_1,p1@10.168.98.6:5441″
|
|
07:25:08.687 ( 7616: 4908) G-MST: 40000001 “00020000-1aae-4f05-9cce-0010491e1b95“
(“10.168.98.6″,”10.168.98.5″),2(ULaw),rsn:1,11:25:01.003 (UTC),pl:20,(s:1, r:378, l:0),(j:0,u:0,o:0) flgs:0×00000000
“sip:TGrp_1,p1@10.168.98.6:5441″,vpn:0
|
|
07:25:08.687 ( 7616: 4908) C-DE: 40000001 “00020000-1aae-4f05-9cce-0010491e1b95” 4,(HangUp)
“sip:TGrp_1,p1@10.168.98.6:5441″
|
As you can see there are many entries for each call leg, media states, and actions. Using the color code above you can break down each section of the call, and diagnose if a problem is occuring.
