Here is some info I found on ShoreTels website a while go that breaks down the TMSNCC log file and how to read it. I am putting here so that I can have easy access to it when I am out in the field and i see something that I don't recognize and i need some reference. There is a lot of data in this log that can give you info as to what is happening on a call. I am not covering all of it just part of it as there is just too much info to cover. Again most of this info was taken from a ShoreTel document that I got on their website.
Parameters:
C-CE: Call Create Event- To initiate a call
L-CE: Leg Create Event- Follows a C-CE for every call setup. For internal transfers (blind transfers) C-CE: may be skipped
L-IE: Leg Info Event- Follows a C-CE, L-CE typically. Leg Info provides information on the other parties in the call (peer as well as controller)
C-SE: Call State Event- When call is in progress updates either parties on the state of the call (RingBack, Offering, Established etc)
L-SE: Leg State Event- Typically follows a C-SE to inform the leg state changes
L-DE: Leg Destroy Event- When call is teared down leg is destroyed
C-DE: Call Destroy Event- Call destroyed after user/system hang up
G-MST: Media State Event- For the terminated leg in a call. Every RTP stream (every leg) has media stats
40000001 = Trunk call leg to PSTN
20000023 = Internal call leg
00020000-1aae-4f05-9cce-0010491e1b95 = Call GUID (different for every call)
ncc_media_ctl = PBX system responding to the caller
Example of a Call:
1555-555-5555 Calls in ---> Hunt Group Ext 2110 ---> HG Forward Always ---> Voicemail ---> User Hung Up
07:24:59.656 ( 7616: 4908) C-CE: 40000001 "00020000-1aae-4f05-9cce-0010491e1b95" ("+15555555555","WIRELESS CALLER",0xC) 00000000,SDP:N,ipCDS:0x00000002,flgs:0x00000000,cd:0x00000000,"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:0x00000002,flgs:0x00000001,cd:0x00000000,"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,("+15555555555","WIRELESS CALLER",0xC(NameNumber)),C("","WIRELESS CALLER",0x4(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("+15555555555","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:0x00000002,flgs:0x00000000,cd:0x00000000,"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,("+15555555555","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("+15555555555","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 (0x20000005, StopOnDTMF, "0123456789*#", id=0x000000B8, "00020000-1aae-4f05-9cce-0010491e1b95")
07:24:59.718 ( 7616: 6716) ncc_answer_call (0x20000005, 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 (0x20000005, 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 (0x20000005, 00020000-1aae-4f05-9cce-0010491e1b95,calldata=0x00000001,calldatamask=0x00000001, id=0x000000BB)
07:25:01.109 ( 7616: 4944) C-DAE: 20000005 "00020000-1aae-4f05-9cce-0010491e1b95" 0x00000001 "sip:2104@10.168.98.5:5441"
07:25:01.109 ( 7616: 6716) ncc_media_ctl2 (0x20000005, StartPlay, id=0x000000BC, "00020000-1aae-4f05-9cce-0010491e1b95")
07:25:01.125 ( 7616: 4908) C-DAE: 40000001 "00020000-1aae-4f05-9cce-0010491e1b95" 0x00000001 "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("+15555555555","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("+15555555555","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:0x00000000 "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"
Here is some other useful information that is found in the logs:
The time of the call this shows up in 24 hour time format
07:25:08.687 ( 7616: 4944) L-DE: 20000005 "00020000-1aae-4f05-9cce-0010491e1b95" 010000CC,rsn:4(HangUp),C("+15555555555","WIRELESS CALLER",0xC) TrGp=1 "sip:2104@10.168.98.5:5441"
This call came in on Trunk Group 1 port 1
07:24:59.656 ( 7616: 4908) C-CE: 40000001 "00020000-1aae-4f05-9cce-0010491e1b95" ("+15555555555","WIRELESS CALLER",0xC) 00000000,SDP:N,ipCDS:0x00000002,flgs:0x00000000,cd:0x00000000,"7722,TGrp_1,p1,"(704) 940-7722"" "sip:TGrp_1,p1@10.168.98.6:5441"
One of the last lines in the call gives you the G-MST which is the Global Mean Statistics for the call and shows you packets sent (s:), packets recieved (r:), packets lost (l:), jutter (j:), under-runs (u:) and over-runs (o:)
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:0x00000000 "sip:TGrp_1,p1@10.168.98.6:5441",vpn:0
This line does not only show the calling party's phone caller ID but the phone number also includes the number of digits that are being sent to ShoreTel. This is important as sometimes the carrier makes mistakes and sends to many or not enough digits and the call does not get routed properly. This is where you could look for that info if needed. In this example the carrier is sending us all 11 digits.
07:24:59.656 ( 7616: 4908) C-CE: 40000001 "00020000-1aae-4f05-9cce-0010491e1b95" ("+15555555555","WIRELESS CALLER",0xC) 00000000,SDP:N,ipCDS:0x00000002,flgs:0x00000000,cd:0x00000000,"7722,TGrp_1,p1,"(704) 940-7722"" "sip:TGrp_1,p1@10.168.98.6:5441
This line in the call log shows that the server started to play a greeting, either a voice mail greeting or an auto attendant greeting. This is seen by the StartPlay and then once the caller has recorded their message you will see a StopRecord on the line. There is not one in the example that I can show you.
07:25:01.109 ( 7616: 6716) ncc_media_ctl2 (0x20000005, StartPlay, id=0x000000BC, "00020000-1aae-4f05-9cce-0010491e1b95")
