Annotated trace file showing an incoming call via SCCP. Also shows audio playback, digit collection and call dropping.

 

06/19/2007 09:22:32.927 |28120,Default Switch-1-001,,MiuSkinny,12,Receive StationSelectSoftKeysMessage (20 bytes) instance=1 reference=26623404 softKeySetIndex=3 validKeyMask=4294901759|

06/19/2007 09:22:32.974 |28120,Default Switch-1-001,,MiuSkinny,12,Ignore StationSelectSoftKeysMessage|

 

************************************************************** new call, observe the SCCP message StationCallStateMessage, TsRingIn. All incoming SCCP messages are logged as below.

06/19/2007 09:22:32.974 |28120,Default Switch-1-001,,MiuSkinny,12,Receive StationCallStateMessage (28 bytes) callState=4=TsRingIn lineInstance=1 callReference=26623404 privacy=0 precedence=[precedenceLv=4 precedenceDm=0]|

06/19/2007 09:22:32.974 |28120,Default Switch-1-001,,MiuSkinny,12,Processing StationCallStateMessage|

06/19/2007 09:22:32.989 |28120,Default Switch-1-001,,MiuSkinny,12,CAvSkinnyCallStatus::SetCallReference - Setting m_dwOriginalCall=26623404=0x01963dac|

************************************************************** If message is consumed, it can move the state machine. Sometimes it takes 2 messages to move the state. A good way to follow the call from the SCCP point of view is to watch how the states advance. See EDCS-494253 for SCCP state machine.

06/19/2007 09:22:33.020 |28120,Default Switch-1-001,,MiuSkinny,12,CAvSkinnyCallStatus::AdvanceCurrentState - Old CallState=<Idle> New CallState=<Wait For Answer Requested>|

06/19/2007 09:22:33.020 |28120,Default Switch-1-001,,MiuSkinny,24,CAvSkinnyCallStatus::SetState New=<Wait For Answer Requested> Old=<Idle> PreviousOld=<Wait For Close Call>)|

06/19/2007 09:22:33.085 |28120,Default Switch-1-001,,MiuSkinny,23,CMiuSkinnyLine::RecvNewCall()|

06/19/2007 09:22:33.086 |28120,Default Switch-1-001,,MiuSkinny,24,CMiuSkinnyCall::ClearCallInfo:|

06/19/2007 09:22:33.086 |28120,Default Switch-1-001,,MiuSkinny,24,CMiuSkinnyLine::NewCall|

************************************************************** Configuration data is refreshed on each new call from the database cache. All data from the db is logged here.

06/19/2007 09:22:33.145 |28120,Default Switch-1-

001,,MiuSkinny,24,PortConfiguration=[PortDisplayName='Default Switch-1-001' RecordingTermWarningTimeMs=0 RecordingTermWarningMinRecordingLengthMs=30000 LiveRecordBeepInterval=15000 PortGroupDisplayName='Default Switch-1' OutgoingPreDialDelayMs=0 OutgoingPostDialDelayMs=0 DTMFDialInterDigitDelayMs=300 OutgoingGuardTimeMs=2500 RecordBeepDurationMs=0 AGCTargetDB=-26 AGCMinimumThreshold=-45 AGCGainThreshold=5 AGCSampleSize=8000 AGCUseCompression=1 EnableAGC=1 TrimDisconnectTonesOnRecordings=0 DelayBeforeOpeningMs=0 CallLoopSupervisedTransferDetect=0 CallLoopForwardNotificationDetect=0 CallLoopDTMF=A CallLoopGuardTimeMs=2500 DefaultWaveFormatObjectId=8961a48d-085d-4023-a4b4-6f682f8a8578 Identity=0xb6cc23e0]|

06/19/2007 09:22:33.146 |28120,Default Switch-1-001,,MiuSkinny,24,CMiuSkinnyCall::NewCall|

06/19/2007 09:22:33.208 |28132,Default Switch-1-001,,MiuGeneral,16,End wait for new call -> threadsWaiting=1|

06/19/2007 09:22:33.214 |28120,Default Switch-1-001,,MiuSkinny,24,CMiuSkinnyLine::NewCall: New call accepted|

06/19/2007 09:22:33.214 |28120,Default Switch-1-001,,MiuSkinny,12,Receive StationSelectSoftKeysMessage (20 bytes) instance=1 reference=26623404 softKeySetIndex=3 validKeyMask=4294901759|

************************************************************** Here is an example of a message that gets ignored

06/19/2007 09:22:33.214 |28120,Default Switch-1-001,,MiuSkinny,12,Ignore StationSelectSoftKeysMessage|

06/19/2007 09:22:33.214 |28120,Default Switch-1-001,,MiuSkinny,12,Receive StationDisplayPromptStatusMessage (48 bytes) timeOutValue=0 promptStatus="From 1000" lineInstance=1 callReference=26623404|

06/19/2007 09:22:33.214 |28120,Default Switch-1-001,,MiuSkinny,12,Ignore StationDisplayPromptStatusMessage|

06/19/2007 09:22:33.237 |28120,Default Switch-1-001,,MiuSkinny,12,Receive StationDisplayPriNotifyMessage (44 bytes) timeOutValue=10 priority=5 notify="From 1000"|

06/19/2007 09:22:33.237 |28120,Default Switch-1-001,,MiuSkinny,12,Ignore StationDisplayPriNotifyMessage|

06/19/2007 09:22:33.252 |28120,Default Switch-1-001,,MiuSkinny,12,Receive StationCallInfoMessage (388 bytes) callingPartyName="" callingParty="1000" calledPartyName="VoiceMail" calledParty="55000" lineInstance=1 callReference=26623404 callType=1=TsInBoundCall originalCalledPartyName="VoiceMail" originalCalledParty="55000" lastRedirectingPartyName="" lastRedirectingParty="55000" originalCdpnRedirectReason=0=RfrNoReason lastRedirectingReason=0=RfrNoReason cgpnVoiceMailbox="" cdpnVoiceMailbox="" originalCdpnVoiceMailbox="" lastRedirectingVoiceMailbox="" callInstance=1 callSecurityStatus=0=CallSecurityStatusUnknown partyPIRestrictionBits=0|

06/19/2007 09:22:33.252 |28120,Default Switch-1-001,,MiuSkinny,12,Processing StationCallInfoMessage|

************************************************************** StationCallInfoMessage contains call integration information used to route the call to appropriate conversation. Here, we log the caller information.

06/19/2007 09:22:33.252 |28120,Default Switch-1-001,,MiuSkinny,12,StationCallInfoMessage: Extracted CallerID='1000' CalledID='55000' RedirectReason=0=RfrNoReason LastRedirectingID='55000' LastRedirectReason=0=RfrNoReason|

06/19/2007 09:22:33.252 |28120,Default Switch-1-001,,MiuSkinny,24,MiuSkinnyLine active: original call|

06/19/2007 09:22:33.253 |28120,Default Switch-1-001,,MiuSkinny,24,CMiuSkinnyCall::RecvCallInfo()|

06/19/2007 09:22:33.253 |28120,Default Switch-1-001,,MiuSkinny,24,CMiuSkinnyCall::RecvCallInfo: Storing CallInfo as reason=0x00000001=Direct lastReason=0x00000400=Unknown callerID='1000' calledID='55000' lastRedirectID=''|

06/19/2007 09:22:33.253 |28120,Default Switch-1-001,,MiuSkinny,12,Receive StationSetLampMessage (16 bytes) stimulus=9=SsLine stimulusInstance=1 lampMode=5=StationLampBlink|

06/19/2007 09:22:33.253 |28120,Default Switch-1-001,,MiuSkinny,12,Processing StationSetLampMessage|

06/19/2007 09:22:33.253 |28120,Default Switch-1-001,,MiuSkinny,12,Receive StationSetLampMessage (16 bytes) stimulus=9=SsLine stimulusInstance=1 lampMode=5=StationLampBlink|

06/19/2007 09:22:33.253 |28120,Default Switch-1-001,,MiuSkinny,12,Processing StationSetLampMessage|

06/19/2007 09:22:33.253 |28120,Default Switch-1-001,,MiuSkinny,12,Receive StationSetRingerMessage (20 bytes) ringMode=2=StationInsideRing ringDuration=1=StationNormalRing lineInstance=1 callReference=26623404|

06/19/2007 09:22:33.253 |28120,Default Switch-1-001,,MiuSkinny,12,Ignore StationSetRingerMessage|

************************************************************** The call on port “Default Switch-1-001” gets associated with a Call GUID which can be used to follow the call throughout the system. It’s also logged to the trace file on all logs (if it’s known) CAF44A94B97E4CDF972EFC2532C1AFB1

06/19/2007 09:22:33.263 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,12,Enter CAvMiuCall::CallInit |

06/19/2007 09:22:33.263 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Enter CMiuSkinnyLine::CallInit|

06/19/2007 09:22:33.264 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Enter CMiuSkinnyLine::RetrieveCallInfo|

06/19/2007 09:22:33.264 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CMiuSkinnyLine::RetrieveCallInfo, (to MiuCall object), CallReason=Direct, LastCallReason=Unknown, CallerID=1000, CalledID=55000, RedirectingID=<Empty>, LastRedirectingID=<Empty>|

06/19/2007 09:22:33.264 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Exit CMiuSkinnyLine::RetrieveCallInfo=0x00000000=S_OK|

06/19/2007 09:22:33.264 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Exit CMiuSkinnyLine::CallInit=0x00000000=S_OK|

06/19/2007 09:22:33.264 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,12,Exit CAvMiuCall::CallInit=0x00000000=S_OK|

06/19/2007 09:22:33.264 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,12,Exit CAvMiu::GetCall=0x00045B33=S_MIU_CONNECTED|

06/19/2007 09:22:33.353 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,Arbiter,-1,Incoming Call: Caller=1000, Called=55000, Redirect=, Reason=1, Port=Default Switch-1-001, PortsInUse=1, AnsPortsFree=1, CallGuid=CAF44A94B97E4CDF972EFC2532C1AFB1|

06/19/2007 09:22:34.474 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,12,Enter CAvMiuCall::IsCallValid |

06/19/2007 09:22:34.474 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Enter CMiuSkinnyLine::IsCallValid|

06/19/2007 09:22:34.474 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Exit CMiuSkinnyLine::IsCallValid=0x00000000=S_OK|

06/19/2007 09:22:34.474 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,12,Exit CAvMiuCall::IsCallValid=0x00000000=S_OK|

06/19/2007 09:22:34.600 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,12,Enter CAvMiuCall::Answer |

06/19/2007 09:22:34.600 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Enter CMiuSkinnyLine::Answer|

06/19/2007 09:22:34.600 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,Clearing cached channel statistics|

06/19/2007 09:22:34.600 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Enter CMiuSkinnyLine::RequestAnswer|

06/19/2007 09:22:34.600 |28132,Default Switch-1-************************************************************** Here we’re attempting to answer the call. We won’t consider ourselves connected until we get an CallState/Connected and StartMediaTranmission

001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CMiuSkinnyCall::Answer:|

06/19/2007 09:22:34.614 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CAvSkinnyCallStatus::RequestStateTransition CurrentState=<Wait For Answer Requested> RequestedState=<Answer Requested>|

06/19/2007 09:22:34.614 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,CAvSkinnyCallStatus::AdvanceCurrentState - Old CallState=<Wait For Answer Requested> New CallState=<Answer Requested>|

06/19/2007 09:22:34.614 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CAvSkinnyCallStatus::SetState New=<Answer Requested> Old=<Wait For Answer Requested> PreviousOld=<Idle>)|

06/19/2007 09:22:34.614 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,13,Send StationOffHookMessage (4 bytes) no data|

06/19/2007 09:22:34.614 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CAvSkinnyCallStatus::RequestStateTransition CurrentState=<Answer Requested> RequestedState=<Wait For Connect>|

06/19/2007 09:22:34.615 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,CAvSkinnyCallStatus::AdvanceCurrentState - Old CallState=<Answer Requested> New CallState=<Wait For Connect>|

06/19/2007 09:22:34.615 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CAvSkinnyCallStatus::SetState New=<Wait For Connect> Old=<Answer Requested> PreviousOld=<Wait For Answer Requested>)|

06/19/2007 09:22:34.615 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Exit CMiuSkinnyLine::RequestAnswer=0x00000000=S_OK|

06/19/2007 09:22:34.615 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationSetRingerMessage (20 bytes) ringMode=1=StationRingOff ringDuration=1=StationNormalRing lineInstance=0 callReference=0|

06/19/2007 09:22:34.615 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Ignore StationSetRingerMessage|

06/19/2007 09:22:34.615 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationSetSpeakerModeMessage (8 bytes) speakerMode=1=StationSpeakerOn|

06/19/2007 09:22:34.615 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Ignore StationSetSpeakerModeMessage|

06/19/2007 09:22:34.640 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationSetLampMessage (16 bytes) stimulus=9=SsLine stimulusInstance=1 lampMode=2=StationLampOn|

06/19/2007 09:22:34.640 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationSetLampMessage|

06/19/2007 09:22:34.640 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationCallStateMessage (28 bytes) callState=1=TsOffHook lineInstance=1 callReference=26623404 privacy=0 precedence=[precedenceLv=4 precedenceDm=0]|

06/19/2007 09:22:34.640 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationCallStateMessage|

06/19/2007 09:22:34.641 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationActivateCallPlaneMessage (8 bytes) lineInstance=1|

06/19/2007 09:22:34.641 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Ignore StationActivateCallPlaneMessage|

06/19/2007 09:22:34.648 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationSetRingerMessage (20 bytes) ringMode=1=StationRingOff ringDuration=1=StationNormalRing lineInstance=1 callReference=26623404|

06/19/2007 09:22:34.648 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Ignore StationSetRingerMessage|

06/19/2007 09:22:35.112 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationStopToneMessage (12 bytes) lineInstance=1 callReference=26623404|

06/19/2007 09:22:35.112 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationStopToneMessage|

06/19/2007 09:22:35.112 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,MiuSkinnyLine active: original call|

06/19/2007 09:22:35.113 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationOpenReceiveChannelMessage (96 bytes) conferenceID=26623404 passThruPartyID=16777228 millisecondPacketSize=20 compressionType=4=Media_Payload_G711Ulaw64k qualifierIn=[ecValue=0=Media_EchoCancellation_Off g723BitRate=0] callReference=26623404 mRxMediaEncryptionKeyInfo.algorithmID=0=NO_ENCRYPTION mRxMediaEncryptionKeyInfo.keylen=0 mRxMediaEncryptionKeyInfo.saltlen=0 keyData=<not shown> mRxMediaEncryptionKeyInfo.isMKIPresent=0 mRxMediaEncryptionKeyInfo.keyDerivationRate=0 streamPassThroughID=0 associatedStreamID=0 RFC2833PayloadType=0 <4 bytes not parsed>|

06/19/2007 09:22:35.113 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationOpenReceiveChannelMessage|

06/19/2007 09:22:35.113 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,MediaOpenCallReference=26623404=0x01963dac|

06/19/2007 09:22:35.148 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::StartReceive |

06/19/2007 09:22:35.165 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::OpenChannel fPrimaryStream=1|

************************************************************** Communication with CuMixer (audio driver) is message-driven. Messages are sent to the Mixer and block until a response comes back. In this message exchange, we’re opening an audio channel and getting back the receive RTP port. This will be sent to UCM to tell remote ep where to send RTP. In this case, it’s port 20524.

06/19/2007 09:22:35.203 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_OPEN_CHN-32 len=544 msgID=32 confID=0 chnID=0 seqNo=242206 remoteIP=0.0.0.0  remoteRTPPort=0 remoteRTCPPort=0 eDTMFPayloadType=0 eInitMute=0 vad=1=GY_ON eStream.codecType=0 eStream.frameSize=0 eStream.bitRate=0 eStream.payloadType=0 precedenceTOS=0 ttl=0 localIP=0.0.0.0  localRTPPort=0 localRTCPPort=0 inDTMFPayloadType=0 dtmf=0 inInitMute=0 noCodecs=0 enableSrtp=0 inStreamKey(key)= <not shown> inStreamKey(salt)= <not shown> sessionID=0|

06/19/2007 09:22:35.340 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_OPEN_CHN_RES-288 len=544 msgID=288 confID=0 chnID=119 seqNo=242206 remoteIP=0.0.0.0  remoteRTPPort=0 remoteRTCPPort=0 eDTMFPayloadType=101 eInitMute=0 vad=1=GY_ON eStream.codecType=0 eStream.frameSize=0 eStream.bitRate=0 eStream.payloadType=0 precedenceTOS=0 ttl=0 localIP=10.93.225.29  localRTPPort=20524 localRTCPPort=20525 inDTMFPayloadType=101 dtmf=0 inInitMute=0 noCodecs=5 inStream[i].codecType=1=GY_G711u inStream[i].frameSize=10 inStream[i].bitRate=64000 inStream[i].payloadType=0 inStream[i].codecType=2=GY_G711a inStream[i].frameSize=10 inStream[i].bitRate=64000 inStream[i].payloadType=8 inStream[i].codecType=3=GY_G729a inStream[i].frameSize=10 inStream[i].bitRate=8000 inStream[i].payloadType=18 inStream[i].codecType=4=GY_G726 inStream[i].frameSize=10 inStream[i].bitRate=32000 inStream[i].payloadType=120 inStream[i].codecType=5=GY_PCM inStream[i].frameSize=10 inStream[i].bitRate=62464 inStream[i].payloadType=127 enableSrtp=0 inStreamKey(key)= <not shown> inStreamKey(salt)= <not shown> sessionID=6|

06/19/2007 09:22:35.349 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_OPEN_CHN_RES-288|

06/19/2007 09:22:35.349 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::OpenChannel=0x00000000=S_OK|

06/19/2007 09:22:35.349 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Stream State: OldState=STREAM_CLOSED, NewState=STREAM_RECEIVE|

06/19/2007 09:22:35.358 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Start Receive lRemoteIP=0.0.0.0:0 iAudioSendPacketSize=0 iSendDTMFPayload=0 iWaveFormat=0 lLocalIP=10.93.225.29:20524 iReceiveDTMFPayload=101,fEnableRFC2833=0|

06/19/2007 09:22:35.358 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::StartReceive=0x00000000=S_OK|

06/19/2007 09:22:35.358 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,13,Send ************************************************************** Tell UCM (and remote ep) to send RTP to port 20524.

StationOpenReceiveChannelAckMessage (20 bytes) orcStatus=0=orcOk ipAddr=10.93.225.29 portNumber=20524 passThruPartyID=16777228|

06/19/2007 09:22:35.358 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationStopToneMessage (12 bytes) lineInstance=1 callReference=26623404|

06/19/2007 09:22:35.358 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationStopToneMessage|

06/19/2007 09:22:35.358 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,MiuSkinnyLine active: original call|

06/19/2007 09:22:35.358 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationCallStateMessage (28 bytes) callState=5=TsConnected lineInstance=1 callReference=26623404 privacy=0 precedence=[precedenceLv=4 precedenceDm=0]|

06/19/2007 09:22:35.359 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationCallStateMessage|

06/19/2007 09:22:35.359 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationSelectSoftKeysMessage (20 bytes) instance=1 reference=26623404 softKeySetIndex=1 validKeyMask=4294901759|

06/19/2007 09:22:35.359 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Ignore StationSelectSoftKeysMessage|

06/19/2007 09:22:35.359 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationDisplayPromptStatusMessage (48 bytes) timeOutValue=0 promptStatus="Connected" lineInstance=1 callReference=26623404|

06/19/2007 09:22:35.359 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Ignore StationDisplayPromptStatusMessage|

06/19/2007 09:22:35.359 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationCallInfoMessage (388 bytes) callingPartyName="" callingParty="1000" calledPartyName="VoiceMail" calledParty="55000" lineInstance=1 callReference=26623404 callType=1=TsInBoundCall originalCalledPartyName="VoiceMail" originalCalledParty="55000" lastRedirectingPartyName="VoiceMail" lastRedirectingParty="55000" originalCdpnRedirectReason=0=RfrNoReason lastRedirectingReason=0=RfrNoReason cgpnVoiceMailbox="" cdpnVoiceMailbox="" originalCdpnVoiceMailbox="" lastRedirectingVoiceMailbox="" callInstance=1 callSecurityStatus=1=CallSecurityStatusNotAuthenticated partyPIRestrictionBits=0|

06/19/2007 09:22:35.359 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationCallInfoMessage|

06/19/2007 09:22:35.359 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,StationCallInfoMessage: Extracted CallerID='1000' CalledID='55000' RedirectReason=0=RfrNoReason LastRedirectingID='55000' LastRedirectReason=0=RfrNoReason|

06/19/2007 09:22:35.360 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,MiuSkinnyLine active: original call|

06/19/2007 09:22:35.360 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CMiuSkinnyCall::RecvCallInfo()|

06/19/2007 09:22:35.360 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CMiuSkinnyCall::RecvCallInfo: Storing CallInfo as reason=0x00000001=Direct lastReason=0x00000400=Unknown callerID='1000' calledID='55000' lastRedirectID=''|

************************************************************** StationStartMediaTransmissionMessage tells UC where to send its RTP, in this case, its 10.93.225.164 port 25346 and G711Ulaw64k.

06/19/2007 09:22:35.360 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationStartMediaTransmissionMessage (112 bytes) conferenceID=26623404 passThruPartyID=16777228 remoteIpAddr=10.93.225.164 remotePortNumber=25346 millisecondPacketSize=20 compressionType=4=Media_Payload_G711Ulaw64k qualifierOut=[precedenceValue=184 ssValue=0=Media_SilenceSuppression_Off maxFramesPerPacket=0 g723BitRate=0] callReference=26623404 mTxMediaEncryptionKeyInfo.algorithmID=0=NO_ENCRYPTION mTxMediaEncryptionKeyInfo.keylen=0 mTxMediaEncryptionKeyInfo.saltlen=0 keyData=<not shown> mTxMediaEncryptionKeyInfo.isMKIPresent=0 mTxMediaEncryptionKeyInfo.keyDerivationRate=0 streamPassThroughID=0 associatedStreamID=0 RFC2833PayloadType=0 <4 bytes not parsed>|

06/19/2007 09:22:35.360 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationStartMediaTransmissionMessage|

06/19/2007 09:22:35.360 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,CAvSkinnyCallStatus::AdvanceCurrentState - Old CallState=<Wait For Connect> New CallState=<Connected>|

06/19/2007 09:22:35.360 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CAvSkinnyCallStatus::SetState New=<Connected> Old=<Wait For Connect> PreviousOld=<Answer Requested>)|

06/19/2007 09:22:35.375 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::StartTransmit |

06/19/2007 09:22:35.375 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::UpdateChannel fPrimaryStream=1|

06/19/2007 09:22:35.391 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Using QoS-0xb8(EF DSCP (101110))|

************************************************************** Tell CuMixer where to send the RTP. Again, we send a message and block waiting for a response.

06/19/2007 09:22:35.391 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_UPDATE_CHN-33 len=272 msgID=33 confID=0 chnID=119 seqNo=242207 cmd=1=GY_UPDATE_REMOTE_PARAM enableSrtp=0 p.rs.IP=10.93.225.164  p.rs.RTPPort=25346 p.rs.RTCPPort=25347 p.rs.dtmf=0 p.rs.inDTMFPayloadType=0 p.rs.eDTMFPayloadType=0 p.rs.eInitMute=0 p.rs.vad=1=GY_ON p.rs.eStream.codecType=1=GY_G711u p.rs.eStream.frameSize=20 p.rs.eStream.bitRate=0 p.rs.eStream.payloadType=0 p.rs.eStreamKey(key)= <not shown> p.rs.eStreamKey(salt)= <not shown> p.rs.precedenceTOS=184 p.rs.ttl=0|

06/19/2007 09:22:35.428 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_UPDATE_CHN_RES-289 len=272 msgID=289 confID=0 chnID=119 seqNo=242207 cmd=1=GY_UPDATE_REMOTE_PARAM enableSrtp=0 p.rs.IP=10.93.225.164  p.rs.RTPPort=25346 p.rs.RTCPPort=25347 p.rs.dtmf=0 p.rs.inDTMFPayloadType=0 p.rs.eDTMFPayloadType=101 p.rs.eInitMute=0 p.rs.vad=1=GY_ON p.rs.eStream.codecType=1=GY_G711u p.rs.eStream.frameSize=20 p.rs.eStream.bitRate=0 p.rs.eStream.payloadType=0 p.rs.eStreamKey(key)= <not shown> p.rs.eStreamKey(salt)= <not shown> p.rs.precedenceTOS=184 p.rs.ttl=0|

06/19/2007 09:22:35.428 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_UPDATE_CHN_RES-289|

06/19/2007 09:22:35.428 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::UpdateChannel=0x00000000=S_OK|

06/19/2007 09:22:35.429 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Stream State: OldState=STREAM_RECEIVE, NewState=STREAM_TRANSMIT_RECEIVE|

06/19/2007 09:22:35.429 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Start Transmit lRemoteIP=10.93.225.164:25346 iAudioSendPacketSize=20 iSendDTMFPayload=101 iWaveFormat=0 lLocalIP=10.93.225.29:20524 iReceiveDTMFPayload=101,fEnableRFC2833=0|

06/19/2007 09:22:35.429 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::StartTransmit=0x00000000=S_OK|

06/19/2007 09:22:35.429 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,MiuSkinnyLine active: original call|

06/19/2007 09:22:35.429 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,MiuSkinnyLine active: original call|

06/19/2007 09:22:35.429 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CMiuSkinnyCall::RecvConnected()|

06/19/2007 09:22:35.429 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,MiuSkinnyLine set active call = original call|

************************************************************** The Answer request finally returns to the caller.

06/19/2007 09:22:35.429 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Exit CMiuSkinnyLine::Answer=0x00045b33=S_MIU_CONNECTED|

06/19/2007 09:22:35.439 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationCallInfoMessage (388 bytes) callingPartyName="" callingParty="1000" calledPartyName="VoiceMail" calledParty="55000" lineInstance=1 callReference=26623404 callType=1=TsInBoundCall originalCalledPartyName="VoiceMail" originalCalledParty="55000" lastRedirectingPartyName="VoiceMail" lastRedirectingParty="55000" originalCdpnRedirectReason=0=RfrNoReason lastRedirectingReason=0=RfrNoReason cgpnVoiceMailbox="" cdpnVoiceMailbox="" originalCdpnVoiceMailbox="" lastRedirectingVoiceMailbox="" callInstance=1 callSecurityStatus=1=CallSecurityStatusNotAuthenticated partyPIRestrictionBits=0|

06/19/2007 09:22:35.439 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationCallInfoMessage|

06/19/2007 09:22:35.440 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,StationCallInfoMessage: Extracted CallerID='1000' CalledID='55000' RedirectReason=0=RfrNoReason LastRedirectingID='55000' LastRedirectReason=0=RfrNoReason|

06/19/2007 09:22:35.440 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,MiuSkinnyLine active: original call|

06/19/2007 09:22:35.440 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CMiuSkinnyCall::RecvCallInfo()|

06/19/2007 09:22:35.440 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CMiuSkinnyCall::RecvCallInfo: Storing CallInfo as reason=0x00000001=Direct lastReason=0x00000400=Unknown callerID='1000' calledID='55000' lastRedirectID=''|

06/19/2007 09:22:35.449 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,12,Exit CAvMiuCall::Answer=0x00045B33=S_MIU_CONNECTED|

06/19/2007 09:22:37.153 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,11,[Port Default Switch-1-001] MiuCall Play begin|

06/19/2007 09:22:37.153 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Enter CMiuSkinnyLine::Play|

06/19/2007 09:22:37.164 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::Play Start Position in streams-0|

06/19/2007 09:22:37.233 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,GetLength success, file-/opt/cisco/connection/share/prompts/ENU/PCM/SubSignIn/AvSubSignInENU002.wav length-2408 ms|

06/19/2007 09:22:37.243 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Vol=50 Speed=100 StartPos=0ms|

************************************************************** Time to play a prompt. Observe the file to be played below. Also observe how long it is, above. While we typically receive a list of files, will only send one wav file down to CuMixer at a time.

06/19/2007 09:22:37.244 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,File Name to play-/opt/cisco/connection/share/prompts/ENU/PCM/SubSignIn/AvSubSignInENU002.wav|

06/19/2007 09:22:37.244 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_PLAY_FILE_START-64 len=325 msgID=64 confID=0 chnID=119 seqNo=242208 startTimeInFile=0 maxPlayTime=0 isRepeat=0 extraParam=0 language="" speed=0=GY_SPEED_NORMAL enableGC=0 targetGCLevel=0 validateFileHdrFmt=1 fileType[0]=0=GY_AUDIO_WAVE_FORMAT_FILE_TYPE nFiles=1|

06/19/2007 09:22:37.298 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_PLAY_FILE_RES-320 len=325 msgID=320 confID=0 chnID=119 seqNo=242208|

06/19/2007 09:22:37.298 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_PLAY_FILE_RES-320|

06/19/2007 09:22:37.298 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Media State: OldState=STATE_IDLE, NewState=STATE_PLAY|

06/19/2007 09:22:37.298 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Play-Waiting for Playback to complete|

06/19/2007 09:22:37.458 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_PLAY_FILE_EVT_RES-324 len=32 msgID=324 confID=65535 chnID=119 seqNo=242208 sessionID=6 event=7=GY_PR_CUR_PLAY_FILE p.fileIndex=0 p.elapseTime=0 p.voiceDuration=0|

06/19/2007 09:22:39.858 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_PLAY_FILE_EVT_RES-324 len=32 msgID=324 confID=65535 chnID=119 seqNo=242208 sessionID=6 event=8=GY_PR_NO_DATA_PLAYING p.fileIndex=0 p.elapseTime=0 p.voiceDuration=0|

06/19/2007 09:22:39.858 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_PLAY_FILE_EVT_RES-324|

06/19/2007 09:22:39.858 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::MediaEventHandler |

06/19/2007 09:22:39.858 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::MediaEventHandler-Mixer Play Event|

06/19/2007 09:22:39.858 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Media State: OldState=STATE_PLAY, NewState=STATE_CLOSING|

06/19/2007 09:22:39.858 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::MediaEventHandler=0x00000000=S_OK|

06/19/2007 09:22:39.858 |28132,Default Switch-1-

001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Play-Playback completed successfully|

06/19/2007 09:22:39.859 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::ClosePlayFile |

06/19/2007 09:22:39.859 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_CLOSE_PLAY_FILE-66 len=20 msgID=66 confID=0 chnID=119 seqNo=242209 bytes_played_in_ms=0 startPosition=0|

06/19/2007 09:22:39.878 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_CLOSE_PLAY_FILE_RES-322 len=20 msgID=322 confID=0 chnID=119 seqNo=242209 bytes_played_in_ms=2408 startPosition=0|

06/19/2007 09:22:39.878 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_CLOSE_PLAY_FILE_RES-322|

06/19/2007 09:22:39.878 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::ClosePlayFile=0x00000000=S_OK|

06/19/2007 09:22:39.878 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Play waiting for final play event|

06/19/2007 09:22:39.918 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_PLAY_FILE_EVT_RES-324 len=32 msgID=324 confID=65535 chnID=119 seqNo=242209 sessionID=6 event=11=GY_PR_DONE p.fileIndex=0 p.elapseTime=0 p.voiceDuration=0|

06/19/2007 09:22:39.918 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_PLAY_FILE_EVT_RES-324|

06/19/2007 09:22:39.918 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Play-Wait for Final Play Event completed successfully|

06/19/2007 09:22:39.918 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Media State: OldState=STATE_CLOSING, NewState=STATE_IDLE|

06/19/2007 09:22:39.918 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::Play=0x00000000=S_OK|

06/19/2007 09:22:39.918 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Exit CMiuSkinnyLine::Play=0x00000000=S_OK|

************************************************************** Play request finishes. We get a message back from the Mixer indicating its done and how much audio was played, in this case 2408ms.

06/19/2007 09:22:39.918 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,11,[Port Default Switch-1-001] MiuCall Play complete beginPositionMs=0 endPositionMs=2408 playTimeMsMs=2408|

06/19/2007 09:22:39.919 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,12,Enter CAvMiuCall::GatherDigits digits='' numDigitsRequested=24 options=1|

06/19/2007 09:22:39.919 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Enter CMiuSkinnyLine::GatherDigits|

06/19/2007 09:22:39.919 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::Gather LeadingTimeout=5000 InterDigitTimeout=3000 NumberDigits=24 Options=1|

06/19/2007 09:22:39.919 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Media State: OldState=STATE_IDLE, NewState=STATE_GATHERING|

06/19/2007 09:22:39.919 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Waiting for Digits|

************************************************************** Digits come in in the form of a SCCP message. In this case, the digits make up a PIN, which is masked by default.

06/19/2007 09:22:41.187 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationKeypadButtonMessage - contents MASKED|

06/19/2007 09:22:41.187 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationKeypadButtonMessage|

06/19/2007 09:22:41.187 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::MediaEventHandler |

06/19/2007 09:22:41.187 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::MediaEventHandler-Digit (X)|

06/19/2007 09:22:41.188 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::MediaEventHandler=0x00000000=S_OK|

06/19/2007 09:22:41.188 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Wait for Digits completed successfully|

06/19/2007 09:22:41.188 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Waiting for Digits|

06/19/2007 09:22:41.407 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationKeypadButtonMessage - contents MASKED|

06/19/2007 09:22:41.407 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationKeypadButtonMessage|

06/19/2007 09:22:41.407 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::MediaEventHandler |

06/19/2007 09:22:41.407 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::MediaEventHandler-Digit (X)|

06/19/2007 09:22:41.407 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::MediaEventHandler=0x00000000=S_OK|

06/19/2007 09:22:41.407 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Wait for Digits completed successfully|

06/19/2007 09:22:41.407 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Waiting for Digits|

06/19/2007 09:22:41.567 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationKeypadButtonMessage - contents MASKED|

06/19/2007 09:22:41.567 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationKeypadButtonMessage|

06/19/2007 09:22:41.567 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::MediaEventHandler |

06/19/2007 09:22:41.567 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::MediaEventHandler-Digit (X)|

06/19/2007 09:22:41.567 |28120,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::MediaEventHandler=0x00000000=S_OK|

06/19/2007 09:22:41.567 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Wait for Digits completed successfully|

06/19/2007 09:22:41.567 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Waiting for Digits|

06/19/2007 09:22:41.966 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationKeypadButtonMessage - contents MASKED|

06/19/2007 09:22:41.966 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationKeypadButtonMessage|

06/19/2007 09:22:41.967 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::MediaEventHandler |

06/19/2007 09:22:41.967 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::MediaEventHandler-Digit (X)|

06/19/2007 09:22:41.967 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::MediaEventHandler=0x00000000=S_OK|

06/19/2007 09:22:41.967 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Wait for Digits completed successfully|

06/19/2007 09:22:41.967 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Waiting for Digits|

06/19/2007 09:22:42.147 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationKeypadButtonMessage - contents MASKED|

06/19/2007 09:22:42.147 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationKeypadButtonMessage|

06/19/2007 09:22:42.147 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::MediaEventHandler |

06/19/2007 09:22:42.147 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::MediaEventHandler-Digit (X)|

06/19/2007 09:22:42.147 |31655,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::MediaEventHandler=0x00000000=S_OK|

06/19/2007 09:22:42.147 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Wait for Digits completed successfully|

06/19/2007 09:22:42.147 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Waiting for Digits|

06/19/2007 09:22:42.347 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationKeypadButtonMessage - contents MASKED|

06/19/2007 09:22:42.347 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationKeypadButtonMessage|

06/19/2007 09:22:42.347 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::MediaEventHandler |

06/19/2007 09:22:42.347 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::MediaEventHandler-Digit (X)|

06/19/2007 09:22:42.347 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::MediaEventHandler=0x00000000=S_OK|

06/19/2007 09:22:42.347 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Wait for Digits completed successfully|

06/19/2007 09:22:42.347 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Waiting for Digits|

06/19/2007 09:22:42.547 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationKeypadButtonMessage - contents MASKED|

06/19/2007 09:22:42.547 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationKeypadButtonMessage|

06/19/2007 09:22:42.547 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::MediaEventHandler |

06/19/2007 09:22:42.547 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::MediaEventHandler-Digit (X)|

06/19/2007 09:22:42.547 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::MediaEventHandler=0x00000000=S_OK|

06/19/2007 09:22:42.547 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Wait for Digits completed successfully|

06/19/2007 09:22:42.547 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Media State: OldState=STATE_GATHERING, NewState=STATE_IDLE|

06/19/2007 09:22:42.547 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Gather-Returing Digits <MASKED>|

06/19/2007 09:22:42.547 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::Gather=0x00045B31=S_MIU_TERM_DIGIT|

06/19/2007 09:22:42.547 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Exit CMiuSkinnyLine::GatherDigits=0x00045b31=S_MIU_TERM_DIGIT|

06/19/2007 09:22:42.560 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuGeneral,14,[Port Default Switch-1-001] GatherDigits succeeded result=0x00045b31 digitsRequested=24 mode=GATHER digitsGathered=7 digitString='<MASKED>'|

06/19/2007 09:22:42.560 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,12,Exit CAvMiuCall::GatherDigits=0x00045B31=S_MIU_TERM_DIGIT|

06/19/2007 09:22:42.660 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,CDL,11,CCsCdlSubscriber::Authenticate: Cannot authenticate user: ABelle IMS Result Code: 1

 on line 1693 of file src/CsCdlSubscriber.cpp: Error: 0x80046505 Description: E_CDL_SP_EXEC_FAILURE|

06/19/2007 09:22:42.661 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,-1,-1,An invalid password entered when trying to log into a subscriber mailbox. Details - ABelle [1000].|

06/19/2007 09:22:42.704 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,12,Enter CAvMiuCall::GatherDigits digits='' numDigitsRequested=-1 options=2|

06/19/2007 09:22:42.704 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::MediaEventPeekorFlush lDigitsRequested=-1 bFlush=1|

06/19/2007 09:22:42.704 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::MediaEventPeekorFlush=0x00000000=S_OK|

06/19/2007 09:22:42.704 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuGeneral,14,[Port Default Switch-1-001] GatherDigits succeeded result=0x00000000 digitsRequested=ALL mode=FLUSH digitsGathered=0 digitString=''|

06/19/2007 09:22:42.704 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,12,Exit CAvMiuCall::GatherDigits=0x00000000=S_OK|

06/19/2007 09:22:42.704 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,11,[Port Default Switch-1-001] MiuCall Play begin|

06/19/2007 09:22:42.704 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Enter CMiuSkinnyLine::Play|

06/19/2007 09:22:42.704 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::Play Start Position in streams-0|

06/19/2007 09:22:42.738 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,GetLength success, file-/opt/cisco/connection/share/prompts/ENU/PCM/SubSignIn/AvSubSignInENU004.wav length-1309 ms|

06/19/2007 09:22:42.738 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Vol=50 Speed=100 StartPos=0ms|

06/19/2007 09:22:42.738 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,File Name to play-/opt/cisco/connection/share/prompts/ENU/PCM/SubSignIn/AvSubSignInENU004.wav|

06/19/2007 09:22:42.738 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_PLAY_FILE_START-64 len=325 msgID=64 confID=0 chnID=119 seqNo=242210 startTimeInFile=0 maxPlayTime=0 isRepeat=0 extraParam=0 language="" speed=0=GY_SPEED_NORMAL enableGC=0 targetGCLevel=0 validateFileHdrFmt=1 fileType[0]=0=GY_AUDIO_WAVE_FORMAT_FILE_TYPE nFiles=1|

06/19/2007 09:22:42.808 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_PLAY_FILE_RES-320 len=325 msgID=320 confID=0 chnID=119 seqNo=242210|

06/19/2007 09:22:42.808 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_PLAY_FILE_RES-320|

06/19/2007 09:22:42.808 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Media State: OldState=STATE_IDLE, NewState=STATE_PLAY|

06/19/2007 09:22:42.808 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Play-Waiting for Playback to complete|

06/19/2007 09:22:42.928 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_PLAY_FILE_EVT_RES-324 len=32 msgID=324 confID=65535 chnID=119 seqNo=242210 sessionID=6 event=7=GY_PR_CUR_PLAY_FILE p.fileIndex=0 p.elapseTime=0 p.voiceDuration=0|

06/19/2007 09:22:44.228 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_PLAY_FILE_EVT_RES-324 len=32 msgID=324 confID=65535 chnID=119 seqNo=242210 sessionID=6 event=8=GY_PR_NO_DATA_PLAYING p.fileIndex=0 p.elapseTime=0 p.voiceDuration=0|

06/19/2007 09:22:44.228 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_PLAY_FILE_EVT_RES-324|

06/19/2007 09:22:44.228 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::MediaEventHandler |

06/19/2007 09:22:44.228 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::MediaEventHandler-Mixer Play Event|

06/19/2007 09:22:44.228 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Media State: OldState=STATE_PLAY, NewState=STATE_CLOSING|

06/19/2007 09:22:44.228 |28117,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::MediaEventHandler=0x00000000=S_OK|

06/19/2007 09:22:44.228 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Play-Playback completed successfully|

06/19/2007 09:22:44.228 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::ClosePlayFile |

06/19/2007 09:22:44.228 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_CLOSE_PLAY_FILE-66 len=20 msgID=66 confID=0 chnID=119 seqNo=242211 bytes_played_in_ms=0 startPosition=0|

06/19/2007 09:22:44.248 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_CLOSE_PLAY_FILE_RES-322 len=20 msgID=322 confID=0 chnID=119 seqNo=242211 bytes_played_in_ms=1309 startPosition=0|

06/19/2007 09:22:44.248 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_CLOSE_PLAY_FILE_RES-322|

06/19/2007 09:22:44.248 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::ClosePlayFile=0x00000000=S_OK|

06/19/2007 09:22:44.248 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Play waiting for final play event|

06/19/2007 09:22:44.288 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_PLAY_FILE_EVT_RES-324 len=32 msgID=324 confID=65535 chnID=119 seqNo=242211 sessionID=6 event=11=GY_PR_DONE p.fileIndex=0 p.elapseTime=0 p.voiceDuration=0|

06/19/2007 09:22:44.288 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_PLAY_FILE_EVT_RES-324|

06/19/2007 09:22:44.288 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Play-Wait for Final Play Event completed successfully|

06/19/2007 09:22:44.288 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Media State: OldState=STATE_CLOSING, NewState=STATE_IDLE|

06/19/2007 09:22:44.288 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::Play=0x00000000=S_OK|

06/19/2007 09:22:44.288 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Exit CMiuSkinnyLine::Play=0x00000000=S_OK|

06/19/2007 09:22:44.288 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,11,[Port Default Switch-1-001] MiuCall Play complete beginPositionMs=0 endPositionMs=1309 playTimeMsMs=1309|

06/19/2007 09:22:44.289 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,11,[Port Default Switch-1-001] MiuCall Play begin|

06/19/2007 09:22:44.289 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Enter CMiuSkinnyLine::Play|

06/19/2007 09:22:44.289 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::Play Start Position in streams-0|

06/19/2007 09:22:44.289 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,GetLength success, file-/opt/cisco/connection/share/prompts/ENU/PCM/SubSignIn/AvSubSignInENU002.wav length-2408 ms|

06/19/2007 09:22:44.289 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Vol=50 Speed=100 StartPos=0ms|

06/19/2007 09:22:44.289 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,File Name to play-/opt/cisco/connection/share/prompts/ENU/PCM/SubSignIn/AvSubSignInENU002.wav|

06/19/2007 09:22:44.289 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_PLAY_FILE_START-64 len=325 msgID=64 confID=0 chnID=119 seqNo=242212 startTimeInFile=0 maxPlayTime=0 isRepeat=0 extraParam=0 language="" speed=0=GY_SPEED_NORMAL enableGC=0 targetGCLevel=0 validateFileHdrFmt=1 fileType[0]=0=GY_AUDIO_WAVE_FORMAT_FILE_TYPE nFiles=1|

06/19/2007 09:22:44.328 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_PLAY_FILE_RES-320 len=325 msgID=320 confID=0 chnID=119 seqNo=242212|

06/19/2007 09:22:44.328 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_PLAY_FILE_RES-320|

06/19/2007 09:22:44.328 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Media State: OldState=STATE_IDLE, NewState=STATE_PLAY|

06/19/2007 09:22:44.328 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Play-Waiting for Playback to complete|

06/19/2007 09:22:44.388 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_PLAY_FILE_EVT_RES-324 len=32 msgID=324 confID=65535 chnID=119 seqNo=242212 sessionID=6 event=7=GY_PR_CUR_PLAY_FILE p.fileIndex=0 p.elapseTime=0 p.voiceDuration=0|

************************************************************** Remote user hangs up which starts with a SCCP message to close the ingress RTP stream.

06/19/2007 09:22:45.130 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationCloseReceiveChannelMessage (20 bytes) conferenceID=26623404 passThruPartyID=16777228 callReference=26623404|

06/19/2007 09:22:45.130 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationCloseReceiveChannelMessage|

06/19/2007 09:22:45.130 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::StopReceive |

06/19/2007 09:22:45.138 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::Mute fPrimaryStream=0|

06/19/2007 09:22:45.160 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_CTL_CHN-43 len=24 msgID=43 confID=0 chnID=119 seqNo=242213 cmd=1=GY_AUDIO_MUTE m.streamID=1=INGRESS_M|

06/19/2007 09:22:45.168 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_CTL_CHN_RES-299 len=24 msgID=299 confID=0 chnID=119 seqNo=242213 cmd=1=GY_AUDIO_MUTE m.streamID=1=INGRESS_M|

06/19/2007 09:22:45.168 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_CTL_CHN_RES-299|

06/19/2007 09:22:45.168 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::Mute=0x00000000=S_OK|

06/19/2007 09:22:45.168 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Stream State: OldState=STREAM_TRANSMIT_RECEIVE, NewState=STREAM_TRANSMIT|

06/19/2007 09:22:45.168 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::StopReceive=0x00000000=S_OK|

06/19/2007 09:22:45.168 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::GetChannelStatistics fPrimaryStream=true|

06/19/2007 09:22:45.169 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_GET_CHN_STAT-49 len=96 msgID=49 confID=0 chnID=119 seqNo=242214|

06/19/2007 09:22:45.188 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_GET_CHN_STAT_RES-305 len=96 msgID=305 confID=0 chnID=119 seqNo=242214|

06/19/2007 09:22:45.188 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_GET_CHN_STAT_RES-305|

************************************************************** When shutting down the RTP stream, we always log the channel statistics from CuMixer. This can be useful to see observe potential audio quality issues from the UC point of view.

06/19/2007 09:22:45.188 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Channel Statistics startTime=1182270155 elapseTime=10 totalPacketRecv=479 totalPacketSent=252 totalPacketDrop=0 packetSize=160 maxObservedJitter=4 minObservedJitter=0 avgPacketJitter=3 curPacketDelay=0 flushRate=0 insertRate=0 silentPktRate=0 totalDigitsRecvd=0 totalDigitsSent=0 maxPlayDelay=170 playDelay=50 maxRecordDelay=0 recordDelay=0 |

06/19/2007 09:22:45.188 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::GetChannelStatistics=0x00000000=S_OK|

06/19/2007 09:22:45.188 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,Save channel stats callReference=26623404 [startTime=1182270155 elapseTime=10 totalPacketRecv=479 totalPacketSent=252 totalPacketDrop=0 packetSize=160 maxObservedJitter=4 minObservedJitter=0 avgPacketJitter=3 curPacketDelay=0 flushRate=0 insertRate=0 silentPktRate=0 totalDigitsRecvd=0 totalDigitsSent=0 maxPlayDelay=170 playDelay=50 maxRecordDelay=0 recordDelay=0 ]|

06/19/2007 09:22:45.188 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationStopMediaTransmissionMessage (20 bytes) conferenceID=26623404 passThruPartyID=16777228 callReference=26623404|

06/19/2007 09:22:45.188 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationStopMediaTransmissionMessage|

06/19/2007 09:22:45.213 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::StopTransmit |

06/19/2007 09:22:45.213 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::Mute fPrimaryStream=1|

06/19/2007 09:22:45.213 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_CTL_CHN-43 len=24 msgID=43 confID=0 chnID=119 seqNo=242215 cmd=1=GY_AUDIO_MUTE m.streamID=2=EGRESS_M|

06/19/2007 09:22:45.248 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_CTL_CHN_RES-299 len=24 msgID=299 confID=0 chnID=119 seqNo=242215 cmd=1=GY_AUDIO_MUTE m.streamID=2=EGRESS_M|

06/19/2007 09:22:45.248 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_CTL_CHN_RES-299|

06/19/2007 09:22:45.248 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::Mute=0x00000000=S_OK|

06/19/2007 09:22:45.248 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Stream State: OldState=STREAM_TRANSMIT, NewState=STREAM_IDLE|

06/19/2007 09:22:45.248 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::StopTransmit=0x00000000=S_OK|

06/19/2007 09:22:45.248 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationStopToneMessage (12 bytes) lineInstance=1 callReference=26623404|

06/19/2007 09:22:45.248 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationStopToneMessage|

06/19/2007 09:22:45.248 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,MiuSkinnyLine active: original call|

06/19/2007 09:22:45.248 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationSetLampMessage (16 bytes) stimulus=9=SsLine stimulusInstance=1 lampMode=1=StationLampOff|

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationSetLampMessage|

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationClearPromptStatusMessage (12 bytes) lineInstance=1 callReference=26623404|

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Ignore StationClearPromptStatusMessage|

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationCallStateMessage (28 bytes) callState=2=TsOnHook lineInstance=1 callReference=26623404 privacy=0 precedence=[precedenceLv=4 precedenceDm=0]|

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Processing StationCallStateMessage|

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,CAvSkinnyCallStatus::AdvanceCurrentState - Old CallState=<Connected> New CallState=<Wait For Close Call>|

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CAvSkinnyCallStatus::SetState New=<Wait For Close Call> Old=<Connected> PreviousOld=<Wait For Connect>)|

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,MiuSkinnyLine active: original call|

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,CMiuSkinnyCall::RecvHangUp() - (original call)|

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::MediaEventHandler |

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::MediaEventHandler-Disconnected|

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Media State: OldState=STATE_PLAY, NewState=STATE_STOPPING|

06/19/2007 09:22:45.249 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::MediaEventHandler=0x00000000=S_OK|

06/19/2007 09:22:45.249 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Play-Stop the Playback|

06/19/2007 09:22:45.249 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::StopPlayFile |

06/19/2007 09:22:45.249 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_STOP_PLAY_FILE-65 len=20 msgID=65 confID=0 chnID=119 seqNo=242216 bytes_played_in_ms=0 startPosition=0|

06/19/2007 09:22:45.268 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_STOP_PLAY_FILE_RES-321 len=20 msgID=321 confID=0 chnID=119 seqNo=242216 bytes_played_in_ms=930 startPosition=0|

06/19/2007 09:22:45.268 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_STOP_PLAY_FILE_RES-321|

06/19/2007 09:22:45.268 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::StopPlayFile=0x00000000=S_OK|

06/19/2007 09:22:45.268 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Media State: OldState=STATE_STOPPING, NewState=STATE_CLOSING|

06/19/2007 09:22:45.268 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::ClosePlayFile |

06/19/2007 09:22:45.268 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_CLOSE_PLAY_FILE-66 len=20 msgID=66 confID=0 chnID=119 seqNo=242217 bytes_played_in_ms=0 startPosition=0|

06/19/2007 09:22:45.268 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,24,Initiated Drop successfully|

06/19/2007 09:22:45.268 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,CAvSkinnyCallStatus::ClearCallReference - Clearing m_dwOriginalCall=26623404=0x01963dac|

06/19/2007 09:22:45.268 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationSelectSoftKeysMessage (20 bytes) instance=0 reference=0 softKeySetIndex=0 validKeyMask=4294967295|

06/19/2007 09:22:45.268 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Ignore StationSelectSoftKeysMessage|

06/19/2007 09:22:45.269 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationDefineTimeDate (40 bytes) timeDataInfo=[2007-06-19 16:22:45 wMilliseconds=0 wDayOfWeek=2] systemTime=1182270165|

06/19/2007 09:22:45.269 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Ignore StationDefineTimeDate|

06/19/2007 09:22:45.269 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationSetSpeakerModeMessage (8 bytes) speakerMode=2=StationSpeakerOff|

06/19/2007 09:22:45.269 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Ignore StationSetSpeakerModeMessage|

06/19/2007 09:22:45.269 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Receive StationSetRingerMessage (20 bytes) ringMode=1=StationRingOff ringDuration=1=StationNormalRing lineInstance=0 callReference=0|

06/19/2007 09:22:45.269 |8380,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuSkinny,12,Ignore StationSetRingerMessage|

06/19/2007 09:22:45.281 |28121,Default Switch-1-001,Default Switch-1-001,MiuSkinny,24,CMiuSkinnyLineMgr::DropCall, Attempt to drop call|

06/19/2007 09:22:45.288 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_CLOSE_PLAY_FILE_RES-322 len=20 msgID=322 confID=0 chnID=119 seqNo=242217 bytes_played_in_ms=940 startPosition=0|

06/19/2007 09:22:45.288 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_CLOSE_PLAY_FILE_RES-322|

06/19/2007 09:22:45.288 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::ClosePlayFile=0x00000000=S_OK|

06/19/2007 09:22:45.288 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Play waiting for final play event|

06/19/2007 09:22:45.328 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_PLAY_FILE_EVT_RES-324 len=32 msgID=324 confID=65535 chnID=119 seqNo=242217 sessionID=6 event=11=GY_PR_DONE p.fileIndex=0 p.elapseTime=0 p.voiceDuration=0|

06/19/2007 09:22:45.328 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_PLAY_FILE_EVT_RES-324|

06/19/2007 09:22:45.328 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,CMiuMedia::Play-Wait for Final Play Event completed successfully|

06/19/2007 09:22:45.328 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Media State: OldState=STATE_CLOSING, NewState=STATE_IDLE|

06/19/2007 09:22:45.328 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::CloseStream |

06/19/2007 09:22:45.328 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::GetChannelStatistics fPrimaryStream=true|

06/19/2007 09:22:45.329 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_GET_CHN_STAT-49 len=96 msgID=49 confID=0 chnID=119 seqNo=242218|

06/19/2007 09:22:45.348 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_GET_CHN_STAT_RES-305 len=96 msgID=305 confID=0 chnID=119 seqNo=242218|

06/19/2007 09:22:45.348 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_GET_CHN_STAT_RES-305|

06/19/2007 09:22:45.348 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Channel Statistics startTime=1182270155 elapseTime=10 totalPacketRecv=479 totalPacketSent=255 totalPacketDrop=33 packetSize=160 maxObservedJitter=4 minObservedJitter=0 avgPacketJitter=3 curPacketDelay=0 flushRate=0 insertRate=6 silentPktRate=0 totalDigitsRecvd=0 totalDigitsSent=0 maxPlayDelay=170 playDelay=50 maxRecordDelay=0 recordDelay=0 |

06/19/2007 09:22:45.348 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::GetChannelStatistics=0x00000000=S_OK|

06/19/2007 09:22:45.348 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,13,Stream State: OldState=STREAM_IDLE, NewState=STREAM_CLOSED|

06/19/2007 09:22:45.348 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::CloseChannel fPrimaryStream=1|

06/19/2007 09:22:45.348 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Mixer Message send: GY_MSG_CLOSE_CHN-34 len=12 msgID=34 confID=0 chnID=119 seqNo=242219|

06/19/2007 09:22:45.388 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,12,Enter CAvMiuCall::Drop callData=''|

06/19/2007 09:22:45.388 |28119,,,MiuIO,12,Mixer Message received: GY_MSG_CLOSE_CHN_RES-290 len=12 msgID=290 confID=0 chnID=119 seqNo=242219|

06/19/2007 09:22:45.388 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,17,Enter CMiuSkinnyLine::Drop|

06/19/2007 09:22:45.388 |28119,,,MiuIO,12,CMiuMedia::MiuMediaCallback: Processing Mixer message GY_MSG_CLOSE_CHN_RES-290|

06/19/2007 09:22:45.388 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::CloseChannel=0x00000000=S_OK|

06/19/2007 09:22:45.388 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::CloseStream|

06/19/2007 09:22:45.388 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Enter CMiuMedia::MediaEventPeekorFlush lDigitsRequested=0 bFlush=1|

06/19/2007 09:22:45.388 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,17,Enter CMiuSkinnyLine::InitiateDropConsult|

06/19/2007 09:22:45.389 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::MediaEventPeekorFlush=0x00000000=S_OK|

06/19/2007 09:22:45.389 |28121,Default Switch-1-001,Default Switch-1-001,MiuSkinny,24,CMiuSkinnyLine::InitiateDropConsult-Attempted Drop, bad call state [Wait For Close Call]!!|

06/19/2007 09:22:45.389 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,17,Enter CMiuSkinnyLine::CleanupCall|

06/19/2007 09:22:45.389 |28121,Default Switch-1-001,Default Switch-1-001,MiuSkinny,24,Cleanup consult call|

06/19/2007 09:22:45.389 |28121,Default Switch-1-001,Default Switch-1-001,MiuSkinny,24,CMiuSkinnyLine::CloseCall(ConsultCall)|

06/19/2007 09:22:45.389 |28121,Default Switch-1-001,Default Switch-1-001,MiuSkinny,24,MiuSkinnyLine set active call = original call|

06/19/2007 09:22:45.389 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,17,Exit CMiuSkinnyLine::CleanupCall=0x00000000=S_OK|

06/19/2007 09:22:45.409 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,17,Exit CMiuSkinnyLine::InitiateDropConsult=0x80045b02=E_MIU_DISCONNECTED|

06/19/2007 09:22:45.409 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,17,Enter CMiuSkinnyLine::InitiateDrop|

06/19/2007 09:22:45.409 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,17,Enter CMiuSkinnyLine::CleanupCall|

06/19/2007 09:22:45.409 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuIO,12,Exit CMiuMedia::Play=0x80045B00=E_MIU_TERM_DISCONNECT|

06/19/2007 09:22:45.409 |28121,Default Switch-1-001,Default Switch-1-001,MiuSkinny,24,Cleanup primary call|

06/19/2007 09:22:45.409 |28132,Default Switch-1-001,CAF44A94B97E4CDF972EFC2532C1AFB1,MiuMethods,17,Exit CMiuSkinnyLine::Play=0x80045b00=E_MIU_TERM_DISCONNECT|

06/19/2007 09:22:45.409 |28121,Default Switch-1-001,Default Switch-1-001,MiuIO,12,Enter CMiuMedia::CloseStream |

06/19/2007 09:22:45.409 |28121,Default Switch-1-001,Default Switch-1-001,MiuIO,12,CMiuMedia::CloseStream-Already closed|

06/19/2007 09:22:45.409 |28121,Default Switch-1-001,Default Switch-1-001,MiuIO,12,Exit CMiuMedia::CloseStream|

06/19/2007 09:22:45.409 |28121,Default Switch-1-001,Default Switch-1-001,MiuIO,12,Enter CMiuMedia::MediaEventPeekorFlush lDigitsRequested=0 bFlush=1|

06/19/2007 09:22:45.410 |28121,Default Switch-1-001,Default Switch-1-001,MiuIO,12,Exit CMiuMedia::MediaEventPeekorFlush=0x00000000=S_OK|

06/19/2007 09:22:45.410 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,12,Enter CAvMiuCall::DisconnectCall digitQueue=''|

06/19/2007 09:22:45.410 |28121,Default Switch-1-001,Default Switch-1-001,MiuGeneral,16,[Port Default Switch-1-001] Signalling CallDroppedEvent method=CAvMiuCall::DisconnectCall|

06/19/2007 09:22:45.410 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,12,Exit CAvMiuCall::DisconnectCall=0x00000000=S_OK|

06/19/2007 09:22:45.410 |28121,Default Switch-1-001,Default Switch-1-001,MiuSkinny,24,CMiuSkinnyLine::CloseCall(PrimaryCall)|

06/19/2007 09:22:45.410 |28121,Default Switch-1-001,Default Switch-1-************************************************************** Call goes idle.

001,MiuSkinny,24,CAvSkinnyCallStatus::RequestStateTransition CurrentState=<Wait For Close Call> RequestedState=<Idle>|

06/19/2007 09:22:45.410 |28121,Default Switch-1-001,Default Switch-1-001,MiuSkinny,12,CAvSkinnyCallStatus::AdvanceCurrentState - Old CallState=<Wait For Close Call> New CallState=<Idle>|

06/19/2007 09:22:45.410 |28121,Default Switch-1-001,Default Switch-1-001,MiuSkinny,24,CAvSkinnyCallStatus::SetState New=<Idle> Old=<Wait For Close Call> PreviousOld=<Connected>)|

06/19/2007 09:22:45.410 |28121,Default Switch-1-001,Default Switch-1-001,MiuSkinny,24,MiuSkinnyLine set active call = original call|

06/19/2007 09:22:45.410 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,17,Exit CMiuSkinnyLine::CleanupCall=0x00000000=S_OK|

06/19/2007 09:22:45.411 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,17,Exit CMiuSkinnyLine::InitiateDrop=0x00000000=S_OK|

06/19/2007 09:22:45.411 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,17,Exit CMiuSkinnyLine::Drop=0x00000000=S_OK|

06/19/2007 09:22:45.411 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,12,Enter CAvMiuCall::CallDisassociate |

06/19/2007 09:22:45.411 |28121,Default Switch-1-001,Default Switch-1-001,MiuGeneral,16,[Port Default Switch-1-001] Wait for CallDroppedEvent method=CAvMiuCall::CallDisassociate|

06/19/2007 09:22:45.411 |28121,Default Switch-1-001,Default Switch-1-001,MiuGeneral,16,[Port Default Switch-1-001] Wait for CallDroppedEvent method=CAvMiuCall::CallDisassociate result=succeeded|

06/19/2007 09:22:45.411 |28121,Default Switch-1-001,Default Switch-1-001,MiuIO,11,ASR-ReleaseMrcpSession|

06/19/2007 09:22:45.411 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,12,Exit CAvMiuCall::CallDisassociate=0x00000000=S_OK|

06/19/2007 09:22:45.411 |28121,Default Switch-1-001,Default Switch-1-001,MiuMethods,12,Exit CAvMiuCall::Drop=0x00000000=S_OK|

06/19/2007 09:22:45.439 |28132,Default Switch-1-001,,MiuMethods,12,Enter CAvMiuCall::GatherDigits digits='' numDigitsRequested=-1 options=2|

06/19/2007 09:22:45.450 |28132,Default Switch-1-001,,MiuGeneral,14,[Port Default Switch-1-001] GatherDigits FAILED result=0x80045b02 digitsRequested=ALL mode=FLUSH digitsGathered=0 digitString=''|

06/19/2007 09:22:45.450 |28132,Default Switch-1-001,,MiuMethods,12,Exit CAvMiuCall::GatherDigits=0x80045B02=E_MIU_DISCONNECTED|

06/19/2007 09:22:45.450 |28132,Default Switch-1-001,,MiuIO,11,[Port Default Switch-1-001] MiuCall Play begin|

06/19/2007 09:22:45.478 |28132,Default Switch-1-001,,MiuMethods,12,Enter CAvMiuCall::IsCallValid |

06/19/2007 09:22:45.478 |28132,Default Switch-1-001,,MiuMethods,12,Exit CAvMiuCall::IsCallValid=0x80004005=E_FAIL|

06/19/2007 09:22:45.478 |28132,Default Switch-1-001,,MiuMethods,12,Enter CAvMiuCall::Drop callData=''|

06/19/2007 09:22:45.478 |28132,Default Switch-1-001,,MiuMethods,12,Exit CAvMiuCall::Drop=0x00000000=S_OK|

06/19/2007 09:22:45.649 |28132,Default Switch-1-001,,MiuIO,11,ASR-ReleaseMrcpSession|

************************************************************** Ready for a new call.

06/19/2007 09:22:45.672 |28132,Default Switch-1-001,,MiuMethods,12,Enter CAvMiu::GetCall |

06/19/2007 09:22:45.672 |28132,Default Switch-1-001,,MiuGeneral,16,Begin wait for new call -> threadsWaiting=2|