Gentlemen,
I normally wouldn't bother you all with easy questions but this one is perplexing. Please help if you have run into this before. Thanks in advance. Any help is appreciated.
System Specs:
-Locale: US
-IPO release 8.1(69)
-VMPRO release 8.1.81
-System contains VCM32 Card.
-Trunks are on ATM16 External Module.
Issue:
Call comes in on analog trunk, caller presses digit to access conference menu and after recording of name (using Whisper Feature) right before call is transferred into the conference, the call is dropped.
Steps Performed:
1. This has been tested with analog trunks provided by Verizon as well as analog emulated lines provided by Broadview. Tests performed on the aforementioned trunks which are on two separate ATM16 Modules with same result.
2. Customer also has a PRI circuit that when tested using the same scenario, is transferred successfully.
3. If the Whisper portion of the transfer is removed from the process, the call is transferred successfully. (Customer requires the announcement portion of the entrance into conference otherwise I'd remove it)
4. Have tried checking the impedance of the analog trunks--no luck.
5. Thinking about testing several flash pulse times since this appears during the transfer but unsure if this will remedy the problem.
6. Here is a copy of monitor trace during the problem:
618297mS CMExtnRx: v=RAS, p1=0
CMFacility
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
Called[CLAIM] Type=ACD (103) Reason=CMDRdirect
618298mS CMLineTx: v=601
CMFacility
Line: type=AnalogueLine 601 Call: lid=601 id=4 in=1
Called[CLAIM] Type=ACD (103) Reason=CMDRdirect
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=ElmDairyAttendNight
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4) number=ElmDairyAttendNight
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceVoicemail type=0 number=0 channel=42 rx_gain=32 tx_gain=32 ep_callid=1029 ipaddr=192.168.1.250 apps=0
618308mS CD: CALL: 601.4.1 BState=Connected Cut=3 Music=0.0 Aend="Line 601" (13.3) Bend="ElmDairyAttendNight(ElmDairyAttendNight)" [VoiceMail] (21.42) CalledNum=ElmDairyAttendNight () CallingNum=95168221801 (HEANEY BRYAN ) Internal=0 Time=23981 ASt
te=Connecte
618317mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 1029->0 )
618318mS CMLineTx: v=601
CMFacility
Line: type=AnalogueLine 601 Call: lid=601 id=4 in=1
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
HoldNotific.Invoke.CodePageUnknown
invokeId 14627
618318mS CMExtnEvt: v=1011 State, new=Idle old=Connected,0,0,RAS
618319mS CMCallEvt: 0.1030.0 -1 BaseEP: NEW CMEndpoint f4720724 TOTAL NOW=3 CALL_LIST=1
618319mS CMCallEvt: CREATE CALL:10 (f470a89c)
618319mS CMCallEvt: 0.1031.0 -1 BaseEP: NEW CMEndpoint f5195064 TOTAL NOW=4 CALL_LIST=1
618320mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 0->1030 )
618321mS CMExtnRx: v=RAS, p1=0
CMSetup
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[95168221801] Type=Unknown Plan=Unknown Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=HEANEY BRYAN
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=HEANEY BRYAN
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceUnknown type=0 number=0 channel=0 rx_gain=32 tx_gain=32 ep_callid=1030 ipaddr=192.168.1.250 apps=0
IE CMIEMohSourceId (247) MOH Source = 1
Locale: enu
618321mS CMCallEvt: 0.1030.0 10 RAS.1: StateChange: END=A CMCSIdle->CMCSDialInitiated
618321mS CMExtnEvt: v=1011 State, new=Dialling old=Idle,0,0,RAS
618321mS CMTARGET: 0.1030.0 10 RAS.1: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=95168221801 dir=out complete=0 ses=0
618321mS CMTARGET: 0.1030.0 10 RAS.1: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
618322mS CMCallEvt: 0.1030.0 10 RAS.1: StateChange: END=A CMCSDialInitiated->CMCSDialling
618322mS CMExtnTx: v=RAS, p1=0
CMSetupAck
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BChan: slot=21 chan=42
618323mS CMExtnRx: v=RAS, p1=0
CMInformation
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
Called[55511] Type=Default (100) Reason=CMDRdirect SndComp
618324mS CMTARGET: 0.1030.0 10 RAS.1: LOOKUP CALL ROUTE: type=100 called_party=55511 sub= calling=95168221801 dir=out complete=1 ses=0
618324mS CMTARGET: 0.1030.0 10 RAS.1: ADD TARGET (N): number=55511 type=100 depth=1 nobar=1 setorig=1 ses=0
618324mS CMTARGET: 0.1030.0 10 RAS.1: SYS SC: 55511 5 sc=type=ConferenceRendezvous code=55511, num=55511 callinfop->sending_complete=1 secondary_dialtone=
618325mS CMMap: a=240.1 b=0.0 X
618325mS CMMap: PCG Conference create g C[34] (240.1)
618326mS CMCallEvt: 0.1032.0 -1 BaseEP: NEW CMEndpoint f4721f14 TOTAL NOW=5 CALL_LIST=2
618327mS CMTARGET: 0.1030.0 10 RAS.1: CancelTimer CMTCDialToneTimeout
618327mS CMTARGET: 0.1030.0 10 RAS.1: INITIAL TARGETING SUCCEEDED
618327mS CMTARGET: 0.1030.0 10 RAS.1: GetNoAnswerTimer:20
618328mS CMCallEvt: 0.1030.0 10 RAS.1: StateChange: END=A CMCSDialling->CMCSDialled
618328mS CMExtnEvt: v=1011 State, new=Proceeding old=Dialling,0,0,RAS
618328mS CMExtnTx: v=RAS, p1=0
CMProceeding
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BChan: slot=21 chan=42
618328mS CMCallEvt: 0.1031.0 10 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
618329mS CMCallEvt: 0.1032.0 10 Conf 55511.-1: StateChange: END=T CMCSIdle->CMCSOffering
618329mS CMCallEvt: 0.1032.0 10 Conf 55511.-1: StateChange: END=T CMCSOffering->CMCSConnReq
618329mS CMCallEvt: 0.1031.0 10 TargetingEP: RequestEnd 0.1032.0 10 Conf 55511.-1
618330mS CMTARGET: 0.1030.0 10 RAS.1: CancelTimer CMTCNoAnswerTimeout
618330mS CMCallEvt: 0.1030.0 10 RAS.1: StateChange: END=A CMCSDialled->CMCSOGConnReq
618330mS CMExtnEvt: v=1011 State, new=Connected old=Proceeding,0,0,RAS
618330mS CMExtnTx: v=RAS, p1=0
CMConnect
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Conf 55511
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:116 N:100 R:4) number=55511
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceConference type=2 number=55511 channel=1 rx_gain=32 tx_gain=32 ep_callid=1032 ipaddr=192.168.1.250 apps=10
618331mS CMExtnRx: v=RAS, p1=0
CMConnectAck
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
618331mS CMCallEvt: 0.1030.0 10 RAS.1: StateChange: END=A CMCSOGConnReq->CMCSConnected
618331mS CMTARGET: 0.1030.0 10 RAS.1: ~CMTargetHandler f518eae4 ep f4720724
618331mS CMCallEvt: 0.1032.0 10 Conf 55511.-1: StateChange: END=B CMCSConnReq->CMCSConnected
618332mS CMExtnRx: v=RAS, p1=0
CMConnectAck
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceVoicemail type=0 number=0 channel=42 rx_gain=32 tx_gain=32 ep_callid=1030 ipaddr=192.168.1.250 apps=0
618333mS CMExtnTx: v=RAS, p1=0
CMConnect
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Conf 55511
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:116 N:100 R:4) number=55511
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceConference type=2 number=55511 channel=1 rx_gain=32 tx_gain=32 ep_callid=1032 ipaddr=192.168.1.250 apps=10
618333mS CMExtnRx: v=RAS, p1=0
CMConnectAck
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
618333mS CMExtnRx: v=RAS, p1=0
CMConnectAck
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceVoicemail type=0 number=0 channel=42 rx_gain=32 tx_gain=32 ep_callid=1030 ipaddr=192.168.1.250 apps=0
618334mS CMExtnTx: v=RAS, p1=0
CMFacility
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BChan: slot=21 chan=42
618334mS CMCallEvt: 0.1031.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
618334mS CMCallEvt: 0.1031.0 -1 BaseEP: DELETE CMEndpoint f5195064 TOTAL NOW=4 CALL_LIST=2
618335mS CMMap: PCG::UnmapBChan pcp[205]b1r0 cp_b f51e56dc other_cp_b f5367b6c
618335mS CMMap: a=21.42 b=13.3 M02
618336mS CMMap: PCG::UnmapBChan pcp[54]b1r0 cp_b f5367b6c other_cp_b 0
618336mS CMMap: a=13.3 b=0.0 H1
618336mS CMMap: PCG::MapBChan pcp[54]b1r0 cp_b f5367b6c other_cp_b f47101c4 type CGTypeConference
618336mS CMMap: a=240.1 b=21.42 M11
618337mS CD: CALL: 601.4.1 BState=Connected Cut=1 Music=1.0 Aend="Line 601" (13.3) Bend="ElmDairyAttendNight(ElmDairyAttendNight)" [VoiceMail] (21.42) CalledNum=ElmDairyAttendNight () CallingNum=95168221801 (HEANEY BRYAN ) Internal=0 Time=24010 ASt
te=Connecte
618337mS CD: CALL: 0.1030.0 BState=Connected Cut=3 Music=0.0 Aend="VoiceMail" (21.42) Bend="" [Conf 1] (240.1) CalledNum=55511 () CallingNum=95168221801 (HEANEY BRYAN ) Internal=1 Time=18 AState=Connected
618338mS PRN: Config Write Wake Up
618477mS RES: Mon 4/11/2013 22:32:09 FreeMem=48983168 48722528(1) CachedMem=260640 CMMsg=7(8) Buff=5200 1406 1000 12407 5 Links=15214 BTree=0 CPU=11/23/3154/12660/13350/1
618477mS RES2: IP 500 V2 8.1(69) Tasks=53 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=92 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=54 TAPI=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
618478mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
618834mS CMMap: a=21.39 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 6, total 8
618835mS CMMap: a=21.39 b=1.255 T
618835mS CMMap: PCG::MapBChan g C[34] cp_b f47101c4 other_cp_b f536af5c type CGTypeDTMF
618835mS CMMap: a=21.39 b=240.1 M12
618835mS CMMap: DTMF:
layTones g T[35] E
618835mS CMMap: Started playing tones, C[34] (from g null)
618836mS CMMap: C[34] SetOperGroup from g null to g null not executed, playing tones in progress E
618839mS PRN: Updates IO list size 1 updated list size 1
618839mS PRN: Sending Updates out to f48d9984 started
618839mS PRN: Sending Updates out to f48d9984 finished
618839mS PRN: Config Write Completed
619000mS CMMap: PCG::UnmapBChan g C[34] cp_b f47101c4 other_cp_b f536af5c
619000mS CMMap: a=21.39 b=240.1 M02
619001mS CMMap: a=21.39 b=0.0 T0
619001mS CMMap: a=21.39 b=0.0 DTMF::~DTMF freed CMRTTonegen resource busy 5, total 8
620333mS PRN: VMAIL - VMSEQ Retransmission
624372mS CMCallEvt: CompleteTransferTo 'this' is consultation, 'tgep' is original
624372mS CMTARGET: TransferProposal: X_call: ID=10 Aend= -> 55511
624372mS CMTARGET: TransferProposal: Y_call: ID=9 Aend=95168221801 -> ElmDairyAttendNight
624373mS CMExtnRx: v=RAS, p1=0
CMReleaseComp
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
624373mS CMCallEvt: CompleteTransferTo 'this' is consultation, 'tgep' is original
624373mS CMTARGET: TransferProposal: X_call: ID=10 Aend= -> 55511
624373mS CMTARGET: TransferProposal: Y_call: ID=9 Aend=95168221801 -> ElmDairyAttendNight
624373mS CMCallEvt: 0.1030.0 10 RAS.1: StateChange: END=A CMCSConnected->CMCSCompleted
624374mS CMExtnEvt: v=1011 State, new=PortRecoverDelay old=Connected,0,0,RAS
624374mS CMLOGGING: CALL:2013/11/0422:32,00:00:06,000,95168221801,O,55511,55511,,,,1,,""n/a,0
624374mS CD: CALL: 0.1030.0 BState=Connected Cut=2 Music=0.0 Aend="VoiceMail" (21.42) Bend="" [Conf 1] (240.1) CalledNum=55511 () CallingNum=95168221801 (HEANEY BRYAN ) Internal=1 Time=6055 AState=Idle
624374mS CD: CALL: 0.1030.0 Deleted
624375mS CMExtnEvt: RAS: CALL LOST (CMCauseNormal)
624375mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 1030->0 )
624375mS CMCallEvt: 0.1030.0 -1 RAS.-1: StateChange: END=X CMCSCompleted->CMCSDelete
624375mS CMExtnEvt: v=1011 State, new=Idle old=PortRecoverDelay,0,0,RAS
624375mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 0->1029 )
624375mS CMLineTx: v=601
CMFacility
Line: type=AnalogueLine 601 Call: lid=601 id=4 in=1
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
RetrieveNotific.Invoke.CodePageUnknown
invokeId 14628
624376mS CMExtnEvt: v=1011 State, new=Connected old=Idle,0,0,RAS
624377mS PRN: ===> Conference destroyed in ~CMConferenceEndpoint
624378mS CMCallEvt: 0.1032.0 -1 CMConferenceEndpoint: StateChange: END=X CMCSConnected->CMCSDelete
624378mS CMCallEvt: 0.1032.0 -1 BaseEP: DELETE CMEndpoint f4721f14 TOTAL NOW=3 CALL_LIST=1
624378mS CMCallEvt: END CALL:10 (f470a89c)
624379mS CMCallEvt: 0.1030.0 -1 BaseEP: DELETE CMEndpoint f4720724 TOTAL NOW=2 CALL_LIST=1
624380mS CMMap: PCG::UnmapBChan pcp[54]b1r0 cp_b f5367b6c other_cp_b f47101c4
624380mS CMMap: a=240.1 b=21.42 M01
624380mS CMMap: PCG::MapBChan pcp[54]b1r0 cp_b f5367b6c other_cp_b 0 type CGTypeSimple
624380mS CMMap: a=13.3 b=0.0 H0
624381mS CMMap: PCG::MapBChan pcp[205]b1r0 cp_b f51e56dc other_cp_b f5367b6c type CGTypeSimple
624381mS CMMap: a=21.42 b=13.3 M12
624381mS CMMap: a=240.1 b=0.0 x
624382mS PRN: Config Write Wake Up
624385mS CD: CALL: 601.4.1 BState=Connected Cut=3 Music=0.0 Aend="Line 601" (13.3) Bend="ElmDairyAttendNight(ElmDairyAttendNight)" [VoiceMail] (21.42) CalledNum=ElmDairyAttendNight () CallingNum=95168221801 (HEANEY BRYAN ) Internal=0 Time=30058 ASt
te=Connecte
624480mS RES: Mon 4/11/2013 22:32:15 FreeMem=49001376 48722528(1) CachedMem=278848 CMMsg=7(8) Buff=5200 1405 1000 12423 5 Links=15228 BTree=0 CPU=7/14/3154/12868/13350/1
624480mS RES2: IP 500 V2 8.1(69) Tasks=54 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=89 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=54 TAPI=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
624480mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
624882mS PRN: Updates IO list size 1 updated list size 1
624883mS PRN: Sending Updates out to f48d9984 started
624883mS PRN: Sending Updates out to f48d9984 finished
624883mS PRN: Config Write Completed
625638mS CMExtnRx: v=RAS, p1=0
CMReleaseComp
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
625639mS CMCallEvt: 0.1029.0 9 RAS.0: StateChange: END=B CMCSConnected->CMCSCompleted
625639mS CMExtnEvt: v=1011 State, new=PortRecoverDelay old=Connected,0,0,RAS
625640mS CMLOGGING: CALL:2013/11/0422:31,00:00:31,000,95168221801,I,ElmDairyAttendNight,,HEANEYBRYAN,,,0,,""n/a,0
625640mS CD: CALL: 601.4.1 BState=Disconnecting Cut=1 Music=0.0 Aend="Line 601" (13.3) Bend="ElmDairyAttendNight(ElmDairyAttendNight)" [VoiceMail] (21.42) CalledNum=ElmDairyAttendNight () CallingNum=95168221801 (HEANEY BRYAN ) Internal=0 Time=31313
AState=Connecte
625640mS CD: CALL: 601.4.1 Deleted
625641mS CMCallEvt: 601.4.1 -1 Alog Trunk:601: StateChange: END=X CMCSConnected->CMCSDelete
625641mS CMCallEvt: 601.4.1 -1 BaseEP: DELETE CMEndpoint f470e85c TOTAL NOW=1 CALL_LIST=0
625642mS CMExtnEvt: RAS: CALL LOST (CMCauseNormal)
625642mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 1029->0 )
625642mS CMCallEvt: 0.1029.0 -1 RAS.-1: StateChange: END=X CMCSCompleted->CMCSDelete
625642mS CMExtnEvt: v=1011 State, new=Idle old=PortRecoverDelay,0,0,RAS
625642mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BChan: slot=21 chan=42
Cause=16, Normal call clearing
625643mS CMMap: a=21.42 b=0.0 T0
625644mS CMCallEvt: END CALL:9 (f519e2b4)
625645mS CMCallEvt: 0.1029.0 -1 BaseEP: DELETE CMEndpoint f519e7a4 TOTAL NOW=0 CALL_LIST=0
625646mS CMMap: PCG::UnmapBChan pcp[205]b1r0 cp_b f51e56dc other_cp_b f5367b6c
625646mS CMMap: a=21.42 b=13.3 M02
625647mS CMMap: PCG::UnmapBChan pcp[54]b1r0 cp_b f5367b6c other_cp_b 0
I normally wouldn't bother you all with easy questions but this one is perplexing. Please help if you have run into this before. Thanks in advance. Any help is appreciated.
System Specs:
-Locale: US
-IPO release 8.1(69)
-VMPRO release 8.1.81
-System contains VCM32 Card.
-Trunks are on ATM16 External Module.
Issue:
Call comes in on analog trunk, caller presses digit to access conference menu and after recording of name (using Whisper Feature) right before call is transferred into the conference, the call is dropped.
Steps Performed:
1. This has been tested with analog trunks provided by Verizon as well as analog emulated lines provided by Broadview. Tests performed on the aforementioned trunks which are on two separate ATM16 Modules with same result.
2. Customer also has a PRI circuit that when tested using the same scenario, is transferred successfully.
3. If the Whisper portion of the transfer is removed from the process, the call is transferred successfully. (Customer requires the announcement portion of the entrance into conference otherwise I'd remove it)
4. Have tried checking the impedance of the analog trunks--no luck.
5. Thinking about testing several flash pulse times since this appears during the transfer but unsure if this will remedy the problem.
6. Here is a copy of monitor trace during the problem:
618297mS CMExtnRx: v=RAS, p1=0
CMFacility
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
Called[CLAIM] Type=ACD (103) Reason=CMDRdirect
618298mS CMLineTx: v=601
CMFacility
Line: type=AnalogueLine 601 Call: lid=601 id=4 in=1
Called[CLAIM] Type=ACD (103) Reason=CMDRdirect
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=ElmDairyAttendNight
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4) number=ElmDairyAttendNight
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceVoicemail type=0 number=0 channel=42 rx_gain=32 tx_gain=32 ep_callid=1029 ipaddr=192.168.1.250 apps=0
618308mS CD: CALL: 601.4.1 BState=Connected Cut=3 Music=0.0 Aend="Line 601" (13.3) Bend="ElmDairyAttendNight(ElmDairyAttendNight)" [VoiceMail] (21.42) CalledNum=ElmDairyAttendNight () CallingNum=95168221801 (HEANEY BRYAN ) Internal=0 Time=23981 ASt
te=Connecte
618317mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 1029->0 )
618318mS CMLineTx: v=601
CMFacility
Line: type=AnalogueLine 601 Call: lid=601 id=4 in=1
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
HoldNotific.Invoke.CodePageUnknown
invokeId 14627
618318mS CMExtnEvt: v=1011 State, new=Idle old=Connected,0,0,RAS
618319mS CMCallEvt: 0.1030.0 -1 BaseEP: NEW CMEndpoint f4720724 TOTAL NOW=3 CALL_LIST=1
618319mS CMCallEvt: CREATE CALL:10 (f470a89c)
618319mS CMCallEvt: 0.1031.0 -1 BaseEP: NEW CMEndpoint f5195064 TOTAL NOW=4 CALL_LIST=1
618320mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 0->1030 )
618321mS CMExtnRx: v=RAS, p1=0
CMSetup
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[95168221801] Type=Unknown Plan=Unknown Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=HEANEY BRYAN
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=HEANEY BRYAN
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceUnknown type=0 number=0 channel=0 rx_gain=32 tx_gain=32 ep_callid=1030 ipaddr=192.168.1.250 apps=0
IE CMIEMohSourceId (247) MOH Source = 1
Locale: enu
618321mS CMCallEvt: 0.1030.0 10 RAS.1: StateChange: END=A CMCSIdle->CMCSDialInitiated
618321mS CMExtnEvt: v=1011 State, new=Dialling old=Idle,0,0,RAS
618321mS CMTARGET: 0.1030.0 10 RAS.1: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=95168221801 dir=out complete=0 ses=0
618321mS CMTARGET: 0.1030.0 10 RAS.1: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
618322mS CMCallEvt: 0.1030.0 10 RAS.1: StateChange: END=A CMCSDialInitiated->CMCSDialling
618322mS CMExtnTx: v=RAS, p1=0
CMSetupAck
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BChan: slot=21 chan=42
618323mS CMExtnRx: v=RAS, p1=0
CMInformation
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
Called[55511] Type=Default (100) Reason=CMDRdirect SndComp
618324mS CMTARGET: 0.1030.0 10 RAS.1: LOOKUP CALL ROUTE: type=100 called_party=55511 sub= calling=95168221801 dir=out complete=1 ses=0
618324mS CMTARGET: 0.1030.0 10 RAS.1: ADD TARGET (N): number=55511 type=100 depth=1 nobar=1 setorig=1 ses=0
618324mS CMTARGET: 0.1030.0 10 RAS.1: SYS SC: 55511 5 sc=type=ConferenceRendezvous code=55511, num=55511 callinfop->sending_complete=1 secondary_dialtone=
618325mS CMMap: a=240.1 b=0.0 X
618325mS CMMap: PCG Conference create g C[34] (240.1)
618326mS CMCallEvt: 0.1032.0 -1 BaseEP: NEW CMEndpoint f4721f14 TOTAL NOW=5 CALL_LIST=2
618327mS CMTARGET: 0.1030.0 10 RAS.1: CancelTimer CMTCDialToneTimeout
618327mS CMTARGET: 0.1030.0 10 RAS.1: INITIAL TARGETING SUCCEEDED
618327mS CMTARGET: 0.1030.0 10 RAS.1: GetNoAnswerTimer:20
618328mS CMCallEvt: 0.1030.0 10 RAS.1: StateChange: END=A CMCSDialling->CMCSDialled
618328mS CMExtnEvt: v=1011 State, new=Proceeding old=Dialling,0,0,RAS
618328mS CMExtnTx: v=RAS, p1=0
CMProceeding
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BChan: slot=21 chan=42
618328mS CMCallEvt: 0.1031.0 10 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
618329mS CMCallEvt: 0.1032.0 10 Conf 55511.-1: StateChange: END=T CMCSIdle->CMCSOffering
618329mS CMCallEvt: 0.1032.0 10 Conf 55511.-1: StateChange: END=T CMCSOffering->CMCSConnReq
618329mS CMCallEvt: 0.1031.0 10 TargetingEP: RequestEnd 0.1032.0 10 Conf 55511.-1
618330mS CMTARGET: 0.1030.0 10 RAS.1: CancelTimer CMTCNoAnswerTimeout
618330mS CMCallEvt: 0.1030.0 10 RAS.1: StateChange: END=A CMCSDialled->CMCSOGConnReq
618330mS CMExtnEvt: v=1011 State, new=Connected old=Proceeding,0,0,RAS
618330mS CMExtnTx: v=RAS, p1=0
CMConnect
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Conf 55511
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:116 N:100 R:4) number=55511
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceConference type=2 number=55511 channel=1 rx_gain=32 tx_gain=32 ep_callid=1032 ipaddr=192.168.1.250 apps=10
618331mS CMExtnRx: v=RAS, p1=0
CMConnectAck
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
618331mS CMCallEvt: 0.1030.0 10 RAS.1: StateChange: END=A CMCSOGConnReq->CMCSConnected
618331mS CMTARGET: 0.1030.0 10 RAS.1: ~CMTargetHandler f518eae4 ep f4720724
618331mS CMCallEvt: 0.1032.0 10 Conf 55511.-1: StateChange: END=B CMCSConnReq->CMCSConnected
618332mS CMExtnRx: v=RAS, p1=0
CMConnectAck
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceVoicemail type=0 number=0 channel=42 rx_gain=32 tx_gain=32 ep_callid=1030 ipaddr=192.168.1.250 apps=0
618333mS CMExtnTx: v=RAS, p1=0
CMConnect
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Conf 55511
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:116 N:100 R:4) number=55511
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceConference type=2 number=55511 channel=1 rx_gain=32 tx_gain=32 ep_callid=1032 ipaddr=192.168.1.250 apps=10
618333mS CMExtnRx: v=RAS, p1=0
CMConnectAck
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
618333mS CMExtnRx: v=RAS, p1=0
CMConnectAck
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceVoicemail type=0 number=0 channel=42 rx_gain=32 tx_gain=32 ep_callid=1030 ipaddr=192.168.1.250 apps=0
618334mS CMExtnTx: v=RAS, p1=0
CMFacility
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BChan: slot=21 chan=42
618334mS CMCallEvt: 0.1031.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
618334mS CMCallEvt: 0.1031.0 -1 BaseEP: DELETE CMEndpoint f5195064 TOTAL NOW=4 CALL_LIST=2
618335mS CMMap: PCG::UnmapBChan pcp[205]b1r0 cp_b f51e56dc other_cp_b f5367b6c
618335mS CMMap: a=21.42 b=13.3 M02
618336mS CMMap: PCG::UnmapBChan pcp[54]b1r0 cp_b f5367b6c other_cp_b 0
618336mS CMMap: a=13.3 b=0.0 H1
618336mS CMMap: PCG::MapBChan pcp[54]b1r0 cp_b f5367b6c other_cp_b f47101c4 type CGTypeConference
618336mS CMMap: a=240.1 b=21.42 M11
618337mS CD: CALL: 601.4.1 BState=Connected Cut=1 Music=1.0 Aend="Line 601" (13.3) Bend="ElmDairyAttendNight(ElmDairyAttendNight)" [VoiceMail] (21.42) CalledNum=ElmDairyAttendNight () CallingNum=95168221801 (HEANEY BRYAN ) Internal=0 Time=24010 ASt
te=Connecte
618337mS CD: CALL: 0.1030.0 BState=Connected Cut=3 Music=0.0 Aend="VoiceMail" (21.42) Bend="" [Conf 1] (240.1) CalledNum=55511 () CallingNum=95168221801 (HEANEY BRYAN ) Internal=1 Time=18 AState=Connected
618338mS PRN: Config Write Wake Up
618477mS RES: Mon 4/11/2013 22:32:09 FreeMem=48983168 48722528(1) CachedMem=260640 CMMsg=7(8) Buff=5200 1406 1000 12407 5 Links=15214 BTree=0 CPU=11/23/3154/12660/13350/1
618477mS RES2: IP 500 V2 8.1(69) Tasks=53 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=92 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=54 TAPI=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
618478mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
618834mS CMMap: a=21.39 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 6, total 8
618835mS CMMap: a=21.39 b=1.255 T
618835mS CMMap: PCG::MapBChan g C[34] cp_b f47101c4 other_cp_b f536af5c type CGTypeDTMF
618835mS CMMap: a=21.39 b=240.1 M12
618835mS CMMap: DTMF:
layTones g T[35] E618835mS CMMap: Started playing tones, C[34] (from g null)
618836mS CMMap: C[34] SetOperGroup from g null to g null not executed, playing tones in progress E
618839mS PRN: Updates IO list size 1 updated list size 1
618839mS PRN: Sending Updates out to f48d9984 started
618839mS PRN: Sending Updates out to f48d9984 finished
618839mS PRN: Config Write Completed
619000mS CMMap: PCG::UnmapBChan g C[34] cp_b f47101c4 other_cp_b f536af5c
619000mS CMMap: a=21.39 b=240.1 M02
619001mS CMMap: a=21.39 b=0.0 T0
619001mS CMMap: a=21.39 b=0.0 DTMF::~DTMF freed CMRTTonegen resource busy 5, total 8
620333mS PRN: VMAIL - VMSEQ Retransmission
624372mS CMCallEvt: CompleteTransferTo 'this' is consultation, 'tgep' is original
624372mS CMTARGET: TransferProposal: X_call: ID=10 Aend= -> 55511
624372mS CMTARGET: TransferProposal: Y_call: ID=9 Aend=95168221801 -> ElmDairyAttendNight
624373mS CMExtnRx: v=RAS, p1=0
CMReleaseComp
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
624373mS CMCallEvt: CompleteTransferTo 'this' is consultation, 'tgep' is original
624373mS CMTARGET: TransferProposal: X_call: ID=10 Aend= -> 55511
624373mS CMTARGET: TransferProposal: Y_call: ID=9 Aend=95168221801 -> ElmDairyAttendNight
624373mS CMCallEvt: 0.1030.0 10 RAS.1: StateChange: END=A CMCSConnected->CMCSCompleted
624374mS CMExtnEvt: v=1011 State, new=PortRecoverDelay old=Connected,0,0,RAS
624374mS CMLOGGING: CALL:2013/11/0422:32,00:00:06,000,95168221801,O,55511,55511,,,,1,,""n/a,0
624374mS CD: CALL: 0.1030.0 BState=Connected Cut=2 Music=0.0 Aend="VoiceMail" (21.42) Bend="" [Conf 1] (240.1) CalledNum=55511 () CallingNum=95168221801 (HEANEY BRYAN ) Internal=1 Time=6055 AState=Idle
624374mS CD: CALL: 0.1030.0 Deleted
624375mS CMExtnEvt: RAS: CALL LOST (CMCauseNormal)
624375mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 1030->0 )
624375mS CMCallEvt: 0.1030.0 -1 RAS.-1: StateChange: END=X CMCSCompleted->CMCSDelete
624375mS CMExtnEvt: v=1011 State, new=Idle old=PortRecoverDelay,0,0,RAS
624375mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 0->1029 )
624375mS CMLineTx: v=601
CMFacility
Line: type=AnalogueLine 601 Call: lid=601 id=4 in=1
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
RetrieveNotific.Invoke.CodePageUnknown
invokeId 14628
624376mS CMExtnEvt: v=1011 State, new=Connected old=Idle,0,0,RAS
624377mS PRN: ===> Conference destroyed in ~CMConferenceEndpoint
624378mS CMCallEvt: 0.1032.0 -1 CMConferenceEndpoint: StateChange: END=X CMCSConnected->CMCSDelete
624378mS CMCallEvt: 0.1032.0 -1 BaseEP: DELETE CMEndpoint f4721f14 TOTAL NOW=3 CALL_LIST=1
624378mS CMCallEvt: END CALL:10 (f470a89c)
624379mS CMCallEvt: 0.1030.0 -1 BaseEP: DELETE CMEndpoint f4720724 TOTAL NOW=2 CALL_LIST=1
624380mS CMMap: PCG::UnmapBChan pcp[54]b1r0 cp_b f5367b6c other_cp_b f47101c4
624380mS CMMap: a=240.1 b=21.42 M01
624380mS CMMap: PCG::MapBChan pcp[54]b1r0 cp_b f5367b6c other_cp_b 0 type CGTypeSimple
624380mS CMMap: a=13.3 b=0.0 H0
624381mS CMMap: PCG::MapBChan pcp[205]b1r0 cp_b f51e56dc other_cp_b f5367b6c type CGTypeSimple
624381mS CMMap: a=21.42 b=13.3 M12
624381mS CMMap: a=240.1 b=0.0 x
624382mS PRN: Config Write Wake Up
624385mS CD: CALL: 601.4.1 BState=Connected Cut=3 Music=0.0 Aend="Line 601" (13.3) Bend="ElmDairyAttendNight(ElmDairyAttendNight)" [VoiceMail] (21.42) CalledNum=ElmDairyAttendNight () CallingNum=95168221801 (HEANEY BRYAN ) Internal=0 Time=30058 ASt
te=Connecte
624480mS RES: Mon 4/11/2013 22:32:15 FreeMem=49001376 48722528(1) CachedMem=278848 CMMsg=7(8) Buff=5200 1405 1000 12423 5 Links=15228 BTree=0 CPU=7/14/3154/12868/13350/1
624480mS RES2: IP 500 V2 8.1(69) Tasks=54 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=89 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=54 TAPI=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
624480mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
624882mS PRN: Updates IO list size 1 updated list size 1
624883mS PRN: Sending Updates out to f48d9984 started
624883mS PRN: Sending Updates out to f48d9984 finished
624883mS PRN: Config Write Completed
625638mS CMExtnRx: v=RAS, p1=0
CMReleaseComp
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
625639mS CMCallEvt: 0.1029.0 9 RAS.0: StateChange: END=B CMCSConnected->CMCSCompleted
625639mS CMExtnEvt: v=1011 State, new=PortRecoverDelay old=Connected,0,0,RAS
625640mS CMLOGGING: CALL:2013/11/0422:31,00:00:31,000,95168221801,I,ElmDairyAttendNight,,HEANEYBRYAN,,,0,,""n/a,0
625640mS CD: CALL: 601.4.1 BState=Disconnecting Cut=1 Music=0.0 Aend="Line 601" (13.3) Bend="ElmDairyAttendNight(ElmDairyAttendNight)" [VoiceMail] (21.42) CalledNum=ElmDairyAttendNight () CallingNum=95168221801 (HEANEY BRYAN ) Internal=0 Time=31313
AState=Connecte
625640mS CD: CALL: 601.4.1 Deleted
625641mS CMCallEvt: 601.4.1 -1 Alog Trunk:601: StateChange: END=X CMCSConnected->CMCSDelete
625641mS CMCallEvt: 601.4.1 -1 BaseEP: DELETE CMEndpoint f470e85c TOTAL NOW=1 CALL_LIST=0
625642mS CMExtnEvt: RAS: CALL LOST (CMCauseNormal)
625642mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 1029->0 )
625642mS CMCallEvt: 0.1029.0 -1 RAS.-1: StateChange: END=X CMCSCompleted->CMCSDelete
625642mS CMExtnEvt: v=1011 State, new=Idle old=PortRecoverDelay,0,0,RAS
625642mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BChan: slot=21 chan=42
Cause=16, Normal call clearing
625643mS CMMap: a=21.42 b=0.0 T0
625644mS CMCallEvt: END CALL:9 (f519e2b4)
625645mS CMCallEvt: 0.1029.0 -1 BaseEP: DELETE CMEndpoint f519e7a4 TOTAL NOW=0 CALL_LIST=0
625646mS CMMap: PCG::UnmapBChan pcp[205]b1r0 cp_b f51e56dc other_cp_b f5367b6c
625646mS CMMap: a=21.42 b=13.3 M02
625647mS CMMap: PCG::UnmapBChan pcp[54]b1r0 cp_b f5367b6c other_cp_b 0