Hi Yulian :
following are server log from 2 calls : the first call offer Telephone-event format 97 ; the second call offer Telephone-event format 101.
Media server could not detect dtmf in the first call, but the second call is work well.
Thanks & Regards,
Anake
======================================================
## the first call log ##
======================================================
v=0
o=HuaweiSoftX3000 54025524 54025524 IN IP4 172.31.69.218
s=Sip Call
c=IN IP4 172.31.69.218
t=0 0
m=audio 21458 RTP/AVP 8 0 18 97
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=rtpmap:97 telephone-event/8000
a=fmtp:97 0-15
a=fmtp:18 annexb=no
08/10/2014 17:11:57,521 DEBUG [MgcpProvider] (Thread-47) Dispatching message
08/10/2014 17:11:57,621 INFO [MGCP] (Thread-47) tx=147483653 Started, message= CRCX
mobius/bridge/$@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:11:57,625 DEBUG [EndpointQueue] (Thread-63) Endpoint mobius/bridge/1 taken
08/10/2014 17:11:57,625 DEBUG [EndpointQueue] (Thread-63) Free endpoints 29
08/10/2014 17:11:57,630 DEBUG [ResourcesPool] (Thread-63) Allocated new rtp connection,pool size:30,free:29
08/10/2014 17:11:57,642 INFO [RtpConnectionImpl] (Thread-63) FormatsRTPFormats{8 AudioFormat[PCMA,8000,8,mono],0 AudioFormat[PCMU,8000,8,mono],18 AudioFormat[G729,8000,mono],97 AudioFormat[telephone-event,8000,16,mono]}
08/10/2014 17:11:57,653 INFO [MGCP] (Thread-71) tx=147483653 was executed normaly
08/10/2014 17:11:57,896 INFO [JitterBuffer] (Thread-127) Format has been changed: 8 AudioFormat[PCMA,8000,8,mono]
08/10/2014 17:11:58,055 DEBUG [MgcpProvider] (Thread-74) Receive message 139 bytes length
08/10/2014 17:11:58,056 DEBUG [MgcpProvider] (Thread-74) Parsing message: CRCX 147483654
mobius/ivr/$@192.168.169.2:2427 MGCP 1.0
C:1
M:inactive
N:msco...@192.168.169.1:2727Z2:mobius/bridge/
1...@192.168.169.2:242708/10/2014 17:11:58,057 DEBUG [MgcpProvider] (Thread-74) Dispatching message
08/10/2014 17:11:58,058 INFO [MGCP] (Thread-74) tx=147483654 Started, message= CRCX
mobius/ivr/$@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:11:58,060 DEBUG [EndpointQueue] (Thread-89) Endpoint mobius/ivr/1 taken
08/10/2014 17:11:58,061 DEBUG [EndpointQueue] (Thread-89) Free endpoints 29
08/10/2014 17:11:58,062 DEBUG [ResourcesPool] (Thread-89) Allocated new local connection,pool size:30,free:29
08/10/2014 17:11:58,065 DEBUG [ResourcesPool] (Thread-89) Allocated new dtmf detector,pool size:30,free:29
08/10/2014 17:11:58,067 DEBUG [ResourcesPool] (Thread-89) Allocated new local connection,pool size:30,free:28
08/10/2014 17:11:58,070 INFO [MGCP] (Thread-11) tx=147483654 was executed normaly
08/10/2014 17:11:58,095 DEBUG [MgcpProvider] (Thread-63) Receive message 76 bytes length
08/10/2014 17:11:58,095 DEBUG [MgcpProvider] (Thread-63) Parsing message: MDCX 147483655
mobius/ivr/1...@192.168.169.2:2427 MGCP 1.0
C:1
I:1f
M:sendrecv
08/10/2014 17:11:58,096 DEBUG [MgcpProvider] (Thread-63) Dispatching message
08/10/2014 17:11:58,097 INFO [MGCP] (Thread-63) tx=147483655 Started, message= MDCX
mobius/ivr/1...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:11:58,097 DEBUG [MgcpProvider] (Thread-63) Receive message 80 bytes length
08/10/2014 17:11:58,098 DEBUG [MgcpProvider] (Thread-63) Parsing message: MDCX 147483656
mobius/bridge/1...@192.168.169.2:2427 MGCP 1.0
C:1
I:22d
M:sendrecv
08/10/2014 17:11:58,098 DEBUG [MgcpProvider] (Thread-63) Dispatching message
08/10/2014 17:11:58,099 INFO [MGCP] (Thread-63) tx=147483656 Started, message= MDCX
mobius/bridge/1...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:11:58,102 INFO [MGCP] (Thread-33) tx=147483655 was executed normaly
08/10/2014 17:11:58,102 INFO [MGCP] (Thread-14) tx=147483656 was executed normaly
08/10/2014 17:11:58,195 DEBUG [MgcpProvider] (Thread-99) Receive message 231 bytes length
08/10/2014 17:11:58,195 DEBUG [MgcpProvider] (Thread-99) Parsing message: RQNT 147483657
mobius/ivr/1...@192.168.169.2:2427 MGCP 1.0
N:msco...@192.168.169.1:2727X:1
S:AU/pc(mn=1 ip=file:///usr/mobicents/sipme4.0.2/target_default/mms-server-4.0.2-SNAPSHOT/audio/audio/dtmf_welcome.wav)
R:AU/oc(N),AU/of(N)
08/10/2014 17:11:58,196 DEBUG [MgcpProvider] (Thread-99) Dispatching message
08/10/2014 17:11:58,197 INFO [MGCP] (Thread-99) tx=147483657 Started, message= RQNT
mobius/ivr/1...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:11:58,237 INFO [PlayCollect] (Thread-9) (mobius/ivr/1) Prepare digit collect phase
08/10/2014 17:11:58,240 INFO [PlayCollect] (Thread-9) (mobius/ivr/1) Start prompt phase
08/10/2014 17:11:58,241 DEBUG [ResourcesPool] (Thread-9) Allocated new player,pool size:30,free:29
08/10/2014 17:11:58,247 INFO [MGCP] (Thread-9) tx=147483657 was executed normaly
08/10/2014 17:11:58,252 INFO [DtmfBuffer] (Thread-68) (detector) Flush, buffer size: 0
08/10/2014 17:11:58,648 INFO [JitterBuffer] (Thread-125) Clearing and increasing jitter buffer size to 240
08/10/2014 17:11:58,652 INFO [JitterBuffer] (Thread-125) Clearing and increasing jitter buffer size to 320
08/10/2014 17:12:05,176 INFO [AudioPlayerImpl] (Thread-108) (mobius/ivr/1) End of file reached
08/10/2014 17:12:05,179 INFO [PlayCollect] (Thread-13) (mobius/ivr/1) Prompt phase terminated, start collect phase
08/10/2014 17:12:45,000 DEBUG [ResourcesPool] (Thread-84) Released rtp connection,pool size:30,free:30
08/10/2014 17:12:45,002 INFO [MGCP] (Thread-84) tx=2 Started, message= DLCX
mobius/bridge/1...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:12:45,004 INFO [MGCP] (Thread-68) tx=2 was executed normaly
=====================================================
## the second call log ###
====================================================
v=0
o=HuaweiSoftX3000 54014049 54014049 IN IP4 172.31.69.218
s=Sip Call
c=IN IP4 172.31.69.218
t=0 0
m=audio 21460 RTP/AVP 8 18 101
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=fmtp:18 annexb=yes
08/10/2014 17:13:07,020 DEBUG [MgcpProvider] (Thread-87) Dispatching message
08/10/2014 17:13:07,021 INFO [MGCP] (Thread-87) tx=147483659 Started, message= CRCX
mobius/bridge/$@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:07,022 DEBUG [EndpointQueue] (Thread-126) Endpoint mobius/bridge/2 taken
08/10/2014 17:13:07,022 DEBUG [EndpointQueue] (Thread-126) Free endpoints 28
08/10/2014 17:13:07,023 DEBUG [ResourcesPool] (Thread-126) Allocated new rtp connection,pool size:30,free:29
08/10/2014 17:13:07,026 INFO [RtpConnectionImpl] (Thread-126) FormatsRTPFormats{8 AudioFormat[PCMA,8000,8,mono],18 AudioFormat[G729,8000,mono],101 AudioFormat[telephone-event,8000,mono]}
08/10/2014 17:13:07,032 INFO [MGCP] (Thread-25) tx=147483659 was executed normaly
08/10/2014 17:13:10,717 INFO [JitterBuffer] (Thread-129) Format has been changed: 8 AudioFormat[PCMA,8000,8,mono]
08/10/2014 17:13:10,798 DEBUG [MgcpProvider] (Thread-118) Receive message 139 bytes length
08/10/2014 17:13:10,800 DEBUG [MgcpProvider] (Thread-118) Parsing message: CRCX 147483660
mobius/ivr/$@192.168.169.2:2427 MGCP 1.0
C:2
M:inactive
N:msco...@192.168.169.1:2727Z2:mobius/bridge/
2...@192.168.169.2:242708/10/2014 17:13:10,800 DEBUG [MgcpProvider] (Thread-118) Dispatching message
08/10/2014 17:13:10,801 INFO [MGCP] (Thread-118) tx=147483660 Started, message= CRCX
mobius/ivr/$@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:10,802 DEBUG [EndpointQueue] (Thread-45) Endpoint mobius/ivr/2 taken
08/10/2014 17:13:10,802 DEBUG [EndpointQueue] (Thread-45) Free endpoints 28
08/10/2014 17:13:10,803 DEBUG [ResourcesPool] (Thread-45) Allocated new local connection,pool size:30,free:27
08/10/2014 17:13:10,804 DEBUG [ResourcesPool] (Thread-45) Allocated new dtmf detector,pool size:30,free:28
08/10/2014 17:13:10,804 DEBUG [ResourcesPool] (Thread-45) Allocated new local connection,pool size:30,free:26
08/10/2014 17:13:10,805 INFO [MGCP] (Thread-13) tx=147483660 was executed normaly
08/10/2014 17:13:10,817 DEBUG [MgcpProvider] (Thread-123) Receive message 76 bytes length
08/10/2014 17:13:10,818 DEBUG [MgcpProvider] (Thread-123) Parsing message: MDCX 147483661
mobius/ivr/2...@192.168.169.2:2427 MGCP 1.0
C:2
I:2e
M:sendrecv
08/10/2014 17:13:10,819 DEBUG [MgcpProvider] (Thread-123) Dispatching message
08/10/2014 17:13:10,819 INFO [MGCP] (Thread-123) tx=147483661 Started, message= MDCX
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:10,820 DEBUG [MgcpProvider] (Thread-123) Receive message 80 bytes length
08/10/2014 17:13:10,820 DEBUG [MgcpProvider] (Thread-123) Parsing message: MDCX 147483662
mobius/bridge/2...@192.168.169.2:2427 MGCP 1.0
C:2
I:23c
M:sendrecv
08/10/2014 17:13:10,821 DEBUG [MgcpProvider] (Thread-123) Dispatching message
08/10/2014 17:13:10,822 INFO [MGCP] (Thread-123) tx=147483662 Started, message= MDCX
mobius/bridge/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:10,823 INFO [MGCP] (Thread-75) tx=147483661 was executed normaly
08/10/2014 17:13:10,823 INFO [MGCP] (Thread-55) tx=147483662 was executed normaly
08/10/2014 17:13:10,838 DEBUG [MgcpProvider] (Thread-106) Receive message 231 bytes length
08/10/2014 17:13:10,838 DEBUG [MgcpProvider] (Thread-106) Parsing message: RQNT 147483663
mobius/ivr/2...@192.168.169.2:2427 MGCP 1.0
N:msco...@192.168.169.1:2727X:2
S:AU/pc(mn=1 ip=file:///usr/mobicents/sipme4.0.2/target_default/mms-server-4.0.2-SNAPSHOT/audio/audio/dtmf_welcome.wav)
R:AU/oc(N),AU/of(N)
08/10/2014 17:13:10,839 DEBUG [MgcpProvider] (Thread-106) Dispatching message
08/10/2014 17:13:10,840 INFO [MGCP] (Thread-106) tx=147483663 Started, message= RQNT
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:10,857 INFO [PlayCollect] (Thread-28) (mobius/ivr/2) Prepare digit collect phase
08/10/2014 17:13:10,858 INFO [PlayCollect] (Thread-28) (mobius/ivr/2) Start prompt phase
08/10/2014 17:13:10,858 DEBUG [ResourcesPool] (Thread-28) Allocated new player,pool size:30,free:28
08/10/2014 17:13:10,860 INFO [MGCP] (Thread-28) tx=147483663 was executed normaly
08/10/2014 17:13:10,863 INFO [DtmfBuffer] (Thread-5) (detector) Flush, buffer size: 0
08/10/2014 17:13:17,818 INFO [AudioPlayerImpl] (Thread-112) (mobius/ivr/2) End of file reached
08/10/2014 17:13:17,821 INFO [PlayCollect] (Thread-68) (mobius/ivr/2) Prompt phase terminated, start collect phase
08/10/2014 17:13:18,961 INFO [EventBuffer] (Thread-39) Receive 2 tone
08/10/2014 17:13:18,962 INFO [PlayCollect] (Thread-39) (mobius/ivr/2) Tone '2' has been detected
08/10/2014 17:13:18,963 INFO [PlayCollect] (Thread-39) (mobius/ivr/2) Tone '2' has been detected: collected
08/10/2014 17:13:18,964 INFO [PlayCollect] (Thread-39) (mobius/ivr/2) Collect phase: max number of digits has been detected
08/10/2014 17:13:18,967 INFO [MGCP] (Thread-39) tx=3 Started, message= NTFY
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:18,968 INFO [DetectorImpl] (Thread-39) (mobius/ivr/2) (detector) Delivered '2' tone
08/10/2014 17:13:18,969 INFO [MGCP] (Thread-83) tx=3 was executed normaly
08/10/2014 17:13:19,018 DEBUG [MgcpProvider] (Thread-27) Receive message 224 bytes length
08/10/2014 17:13:19,019 DEBUG [MgcpProvider] (Thread-27) Parsing message: RQNT 147483665
mobius/ivr/2...@192.168.169.2:2427 MGCP 1.0
N:msco...@192.168.169.1:2727X:3
S:AU/pc(mn=1 ip=file:///usr/mobicents/sipme4.0.2/target_default/mms-server-4.0.2-SNAPSHOT/audio/audio/dtmf2.wav)
R:AU/oc(N),AU/of(N)
08/10/2014 17:13:19,020 DEBUG [MgcpProvider] (Thread-27) Dispatching message
08/10/2014 17:13:19,020 INFO [MGCP] (Thread-27) tx=147483665 Started, message= RQNT
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:19,021 DEBUG [MgcpProvider] (Thread-27) Receive message 55 bytes length
08/10/2014 17:13:19,021 DEBUG [MgcpProvider] (Thread-27) Parsing message: 200 3 The requested transaction was executed normally.
08/10/2014 17:13:19,022 DEBUG [MgcpProvider] (Thread-27) Dispatching message
08/10/2014 17:13:19,038 INFO [PlayCollect] (Thread-99) (mobius/ivr/2) Prepare digit collect phase
08/10/2014 17:13:19,038 INFO [PlayCollect] (Thread-99) (mobius/ivr/2) Start prompt phase
08/10/2014 17:13:19,041 INFO [MGCP] (Thread-99) tx=147483665 was executed normaly
08/10/2014 17:13:19,043 INFO [DtmfBuffer] (Thread-3) (detector) Flush, buffer size: 0
08/10/2014 17:13:20,719 INFO [AudioPlayerImpl] (Thread-98) (mobius/ivr/2) End of file reached
08/10/2014 17:13:20,720 INFO [PlayCollect] (Thread-39) (mobius/ivr/2) Prompt phase terminated, start collect phase
08/10/2014 17:13:21,558 INFO [EventBuffer] (Thread-104) Receive 1 tone
08/10/2014 17:13:21,560 INFO [PlayCollect] (Thread-104) (mobius/ivr/2) Tone '1' has been detected
08/10/2014 17:13:21,561 INFO [PlayCollect] (Thread-104) (mobius/ivr/2) Tone '1' has been detected: collected
08/10/2014 17:13:21,561 INFO [PlayCollect] (Thread-104) (mobius/ivr/2) Collect phase: max number of digits has been detected
08/10/2014 17:13:21,564 INFO [MGCP] (Thread-104) tx=4 Started, message= NTFY
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:21,564 INFO [DetectorImpl] (Thread-104) (mobius/ivr/2) (detector) Delivered '1' tone
08/10/2014 17:13:21,566 INFO [MGCP] (Thread-57) tx=4 was executed normaly
08/10/2014 17:13:21,598 DEBUG [MgcpProvider] (Thread-100) Receive message 224 bytes length
08/10/2014 17:13:21,599 DEBUG [MgcpProvider] (Thread-100) Parsing message: RQNT 147483667
mobius/ivr/2...@192.168.169.2:2427 MGCP 1.0
N:msco...@192.168.169.1:2727X:4
S:AU/pc(mn=1 ip=file:///usr/mobicents/sipme4.0.2/target_default/mms-server-4.0.2-SNAPSHOT/audio/audio/dtmf1.wav)
R:AU/oc(N),AU/of(N)
08/10/2014 17:13:21,600 DEBUG [MgcpProvider] (Thread-100) Dispatching message
08/10/2014 17:13:21,600 INFO [MGCP] (Thread-100) tx=147483667 Started, message= RQNT
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:21,601 DEBUG [MgcpProvider] (Thread-100) Receive message 55 bytes length
08/10/2014 17:13:21,601 DEBUG [MgcpProvider] (Thread-100) Parsing message: 200 4 The requested transaction was executed normally.
08/10/2014 17:13:21,602 DEBUG [MgcpProvider] (Thread-100) Dispatching message
08/10/2014 17:13:21,617 INFO [PlayCollect] (Thread-5) (mobius/ivr/2) Prepare digit collect phase
08/10/2014 17:13:21,618 INFO [PlayCollect] (Thread-5) (mobius/ivr/2) Start prompt phase
08/10/2014 17:13:21,620 INFO [MGCP] (Thread-5) tx=147483667 was executed normaly
08/10/2014 17:13:21,622 INFO [DtmfBuffer] (Thread-72) (detector) Flush, buffer size: 0
08/10/2014 17:13:23,199 INFO [AudioPlayerImpl] (Thread-34) (mobius/ivr/2) End of file reached
08/10/2014 17:13:23,200 INFO [PlayCollect] (Thread-37) (mobius/ivr/2) Prompt phase terminated, start collect phase
08/10/2014 17:13:24,098 INFO [EventBuffer] (Thread-36) Receive 6 tone
08/10/2014 17:13:24,099 INFO [PlayCollect] (Thread-36) (mobius/ivr/2) Tone '6' has been detected
08/10/2014 17:13:24,100 INFO [PlayCollect] (Thread-36) (mobius/ivr/2) Tone '6' has been detected: collected
08/10/2014 17:13:24,101 INFO [PlayCollect] (Thread-36) (mobius/ivr/2) Collect phase: max number of digits has been detected
08/10/2014 17:13:24,103 INFO [MGCP] (Thread-36) tx=5 Started, message= NTFY
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:24,104 INFO [DetectorImpl] (Thread-36) (mobius/ivr/2) (detector) Delivered '6' tone
08/10/2014 17:13:24,105 INFO [MGCP] (Thread-9) tx=5 was executed normaly
08/10/2014 17:13:24,138 DEBUG [MgcpProvider] (Thread-119) Receive message 224 bytes length
08/10/2014 17:13:24,139 DEBUG [MgcpProvider] (Thread-119) Parsing message: RQNT 147483669
mobius/ivr/2...@192.168.169.2:2427 MGCP 1.0
N:msco...@192.168.169.1:2727X:5
S:AU/pc(mn=1 ip=file:///usr/mobicents/sipme4.0.2/target_default/mms-server-4.0.2-SNAPSHOT/audio/audio/dtmf6.wav)
R:AU/oc(N),AU/of(N)
08/10/2014 17:13:24,140 DEBUG [MgcpProvider] (Thread-119) Dispatching message
08/10/2014 17:13:24,140 INFO [MGCP] (Thread-119) tx=147483669 Started, message= RQNT
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:24,141 DEBUG [MgcpProvider] (Thread-119) Receive message 55 bytes length
08/10/2014 17:13:24,141 DEBUG [MgcpProvider] (Thread-119) Parsing message: 200 5 The requested transaction was executed normally.
08/10/2014 17:13:24,142 DEBUG [MgcpProvider] (Thread-119) Dispatching message
08/10/2014 17:13:24,157 INFO [PlayCollect] (Thread-38) (mobius/ivr/2) Prepare digit collect phase
08/10/2014 17:13:24,158 INFO [PlayCollect] (Thread-38) (mobius/ivr/2) Start prompt phase
08/10/2014 17:13:24,160 INFO [MGCP] (Thread-38) tx=147483669 was executed normaly
08/10/2014 17:13:24,163 INFO [DtmfBuffer] (Thread-28) (detector) Flush, buffer size: 0
08/10/2014 17:13:25,978 INFO [AudioPlayerImpl] (Thread-66) (mobius/ivr/2) End of file reached
08/10/2014 17:13:25,980 INFO [PlayCollect] (Thread-4) (mobius/ivr/2) Prompt phase terminated, start collect phase
08/10/2014 17:13:26,918 INFO [EventBuffer] (Thread-67) Receive 7 tone
08/10/2014 17:13:26,919 INFO [PlayCollect] (Thread-67) (mobius/ivr/2) Tone '7' has been detected
08/10/2014 17:13:26,920 INFO [PlayCollect] (Thread-67) (mobius/ivr/2) Tone '7' has been detected: collected
08/10/2014 17:13:26,921 INFO [PlayCollect] (Thread-67) (mobius/ivr/2) Collect phase: max number of digits has been detected
08/10/2014 17:13:26,923 INFO [MGCP] (Thread-67) tx=6 Started, message= NTFY
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:26,924 INFO [DetectorImpl] (Thread-67) (mobius/ivr/2) (detector) Delivered '7' tone
08/10/2014 17:13:26,925 INFO [MGCP] (Thread-6) tx=6 was executed normaly
08/10/2014 17:13:26,959 DEBUG [MgcpProvider] (Thread-58) Receive message 224 bytes length
08/10/2014 17:13:26,959 DEBUG [MgcpProvider] (Thread-58) Parsing message: RQNT 147483671
mobius/ivr/2...@192.168.169.2:2427 MGCP 1.0
N:msco...@192.168.169.1:2727X:6
S:AU/pc(mn=1 ip=file:///usr/mobicents/sipme4.0.2/target_default/mms-server-4.0.2-SNAPSHOT/audio/audio/dtmf7.wav)
R:AU/oc(N),AU/of(N)
08/10/2014 17:13:26,960 DEBUG [MgcpProvider] (Thread-58) Dispatching message
08/10/2014 17:13:26,960 INFO [MGCP] (Thread-58) tx=147483671 Started, message= RQNT
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:26,961 DEBUG [MgcpProvider] (Thread-58) Receive message 55 bytes length
08/10/2014 17:13:26,962 DEBUG [MgcpProvider] (Thread-58) Parsing message: 200 6 The requested transaction was executed normally.
08/10/2014 17:13:26,962 DEBUG [MgcpProvider] (Thread-58) Dispatching message
08/10/2014 17:13:26,977 INFO [PlayCollect] (Thread-111) (mobius/ivr/2) Prepare digit collect phase
08/10/2014 17:13:26,978 INFO [PlayCollect] (Thread-111) (mobius/ivr/2) Start prompt phase
08/10/2014 17:13:26,980 INFO [MGCP] (Thread-111) tx=147483671 was executed normaly
08/10/2014 17:13:26,985 INFO [DtmfBuffer] (Thread-114) (detector) Flush, buffer size: 0
08/10/2014 17:13:28,719 INFO [AudioPlayerImpl] (Thread-77) (mobius/ivr/2) End of file reached
08/10/2014 17:13:28,720 INFO [PlayCollect] (Thread-38) (mobius/ivr/2) Prompt phase terminated, start collect phase
08/10/2014 17:13:31,738 INFO [EventBuffer] (Thread-86) Receive 3 tone
08/10/2014 17:13:31,740 INFO [PlayCollect] (Thread-86) (mobius/ivr/2) Tone '3' has been detected
08/10/2014 17:13:31,740 INFO [PlayCollect] (Thread-86) (mobius/ivr/2) Tone '3' has been detected: collected
08/10/2014 17:13:31,741 INFO [PlayCollect] (Thread-86) (mobius/ivr/2) Collect phase: max number of digits has been detected
08/10/2014 17:13:31,743 INFO [MGCP] (Thread-86) tx=7 Started, message= NTFY
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:31,744 INFO [DetectorImpl] (Thread-86) (mobius/ivr/2) (detector) Delivered '3' tone
08/10/2014 17:13:31,745 INFO [MGCP] (Thread-70) tx=7 was executed normaly
08/10/2014 17:13:31,778 DEBUG [MgcpProvider] (Thread-114) Receive message 224 bytes length
08/10/2014 17:13:31,779 DEBUG [MgcpProvider] (Thread-114) Parsing message: RQNT 147483673
mobius/ivr/2...@192.168.169.2:2427 MGCP 1.0
N:msco...@192.168.169.1:2727X:7
S:AU/pc(mn=1 ip=file:///usr/mobicents/sipme4.0.2/target_default/mms-server-4.0.2-SNAPSHOT/audio/audio/dtmf3.wav)
R:AU/oc(N),AU/of(N)
08/10/2014 17:13:31,780 DEBUG [MgcpProvider] (Thread-114) Dispatching message
08/10/2014 17:13:31,780 INFO [MGCP] (Thread-114) tx=147483673 Started, message= RQNT
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:31,781 DEBUG [MgcpProvider] (Thread-114) Receive message 55 bytes length
08/10/2014 17:13:31,781 DEBUG [MgcpProvider] (Thread-114) Parsing message: 200 7 The requested transaction was executed normally.
08/10/2014 17:13:31,782 DEBUG [MgcpProvider] (Thread-114) Dispatching message
08/10/2014 17:13:31,798 INFO [PlayCollect] (Thread-48) (mobius/ivr/2) Prepare digit collect phase
08/10/2014 17:13:31,799 INFO [PlayCollect] (Thread-48) (mobius/ivr/2) Start prompt phase
08/10/2014 17:13:31,801 INFO [MGCP] (Thread-48) tx=147483673 was executed normaly
08/10/2014 17:13:31,804 INFO [DtmfBuffer] (Thread-123) (detector) Flush, buffer size: 0
08/10/2014 17:13:33,439 INFO [AudioPlayerImpl] (Thread-94) (mobius/ivr/2) End of file reached
08/10/2014 17:13:33,440 INFO [PlayCollect] (Thread-117) (mobius/ivr/2) Prompt phase terminated, start collect phase
08/10/2014 17:13:34,539 DEBUG [MgcpProvider] (Thread-71) Receive message 65 bytes length
08/10/2014 17:13:34,540 DEBUG [MgcpProvider] (Thread-71) Parsing message: DLCX 147483674
mobius/ivr/2...@192.168.169.2:2427 MGCP 1.0
C:2
I:2e
08/10/2014 17:13:34,541 DEBUG [MgcpProvider] (Thread-71) Dispatching message
08/10/2014 17:13:34,542 INFO [MGCP] (Thread-71) tx=147483674 Started, message= DLCX
mobius/ivr/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:34,542 DEBUG [MgcpProvider] (Thread-71) Receive message 69 bytes length
08/10/2014 17:13:34,543 DEBUG [MgcpProvider] (Thread-71) Parsing message: DLCX 147483675
mobius/bridge/2...@192.168.169.2:2427 MGCP 1.0
C:2
I:23c
08/10/2014 17:13:34,543 DEBUG [MgcpProvider] (Thread-71) Dispatching message
08/10/2014 17:13:34,544 INFO [MGCP] (Thread-71) tx=147483675 Started, message= DLCX
mobius/bridge/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:34,546 DEBUG [ResourcesPool] (Thread-42) Released local connection,pool size:30,free:28
08/10/2014 17:13:34,546 DEBUG [ResourcesPool] (Thread-21) Released local connection,pool size:30,free:28
08/10/2014 17:13:34,547 DEBUG [ResourcesPool] (Thread-21) Released player,pool size:30,free:29
08/10/2014 17:13:34,548 DEBUG [ResourcesPool] (Thread-21) Released dtmf detector,pool size:30,free:29
08/10/2014 17:13:34,549 DEBUG [EndpointQueue] (Thread-21) Endpoint mobius/ivr/2 released
08/10/2014 17:13:34,550 DEBUG [EndpointQueue] (Thread-21) Free endpoints 29
08/10/2014 17:13:34,551 INFO [MGCP] (Thread-73) tx=147483674 was executed normaly
08/10/2014 17:13:34,552 INFO [MGCP] (Thread-2) tx=147483675 was executed normaly
08/10/2014 17:13:35,159 DEBUG [MgcpProvider] (Thread-26) Receive message 69 bytes length
08/10/2014 17:13:35,160 DEBUG [MgcpProvider] (Thread-26) Parsing message: DLCX 147483676
mobius/bridge/2...@192.168.169.2:2427 MGCP 1.0
C:2
I:23b
08/10/2014 17:13:35,161 DEBUG [MgcpProvider] (Thread-26) Dispatching message
08/10/2014 17:13:35,162 INFO [MGCP] (Thread-26) tx=147483676 Started, message= DLCX
mobius/bridge/2...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:35,163 DEBUG [ResourcesPool] (Thread-23) Released rtp connection,pool size:30,free:30
08/10/2014 17:13:35,164 DEBUG [EndpointQueue] (Thread-23) Endpoint mobius/bridge/2 released
08/10/2014 17:13:35,164 DEBUG [EndpointQueue] (Thread-23) Free endpoints 29
08/10/2014 17:13:35,168 INFO [MGCP] (Thread-108) tx=147483676 was executed normaly
08/10/2014 17:13:43,720 DEBUG [MgcpProvider] (Thread-81) Receive message 65 bytes length
08/10/2014 17:13:43,721 DEBUG [MgcpProvider] (Thread-81) Parsing message: DLCX 147483677
mobius/ivr/1...@192.168.169.2:2427 MGCP 1.0
C:1
I:1f
08/10/2014 17:13:43,722 DEBUG [MgcpProvider] (Thread-81) Dispatching message
08/10/2014 17:13:43,722 INFO [MGCP] (Thread-81) tx=147483677 Started, message= DLCX
mobius/ivr/1...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:43,723 DEBUG [MgcpProvider] (Thread-81) Receive message 69 bytes length
08/10/2014 17:13:43,723 DEBUG [MgcpProvider] (Thread-81) Parsing message: DLCX 147483678
mobius/bridge/1...@192.168.169.2:2427 MGCP 1.0
C:1
I:22d
08/10/2014 17:13:43,724 DEBUG [MgcpProvider] (Thread-81) Dispatching message
08/10/2014 17:13:43,725 INFO [MGCP] (Thread-81) tx=147483678 Started, message= DLCX
mobius/bridge/1...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:43,725 DEBUG [ResourcesPool] (Thread-59) Released local connection,pool size:30,free:30
08/10/2014 17:13:43,725 DEBUG [ResourcesPool] (Thread-82) Released local connection,pool size:30,free:30
08/10/2014 17:13:43,726 DEBUG [ResourcesPool] (Thread-59) Released player,pool size:30,free:30
08/10/2014 17:13:43,726 DEBUG [EndpointQueue] (Thread-82) Endpoint mobius/bridge/1 released
08/10/2014 17:13:43,727 DEBUG [ResourcesPool] (Thread-59) Released dtmf detector,pool size:30,free:30
08/10/2014 17:13:43,727 DEBUG [EndpointQueue] (Thread-82) Free endpoints 30
08/10/2014 17:13:43,728 DEBUG [EndpointQueue] (Thread-59) Endpoint mobius/ivr/1 released
08/10/2014 17:13:43,729 DEBUG [EndpointQueue] (Thread-59) Free endpoints 30
08/10/2014 17:13:43,730 INFO [MGCP] (Thread-43) tx=147483677 was executed normaly
08/10/2014 17:13:43,730 INFO [MGCP] (Thread-10) tx=147483678 was executed normaly
08/10/2014 17:13:44,319 DEBUG [MgcpProvider] (Thread-117) Receive message 69 bytes length
08/10/2014 17:13:44,320 DEBUG [MgcpProvider] (Thread-117) Parsing message: DLCX 147483679
mobius/bridge/1...@192.168.169.2:2427 MGCP 1.0
C:1
I:22c
08/10/2014 17:13:44,321 DEBUG [MgcpProvider] (Thread-117) Dispatching message
08/10/2014 17:13:44,321 INFO [MGCP] (Thread-117) tx=147483679 Started, message= DLCX
mobius/bridge/1...@192.168.169.2:2427, call agent = vasvmsserver11/
192.168.169.1:272708/10/2014 17:13:44,326 ERROR [MGCP] (Thread-122) tx=147483679 Failed
ua.mobius.media.server.mgcp.tx.cmd.MgcpCommandException
at ua.mobius.media.server.mgcp.tx.cmd.DeleteConnectionCmd$Delete.perform(DeleteConnectionCmd.java:163)
at ua.mobius.media.server.scheduler.Task.run(Task.java:127)
at ua.mobius.media.server.scheduler.Scheduler$WorkerThread.run(Scheduler.java:425)
08/10/2014 17:13:44,331 INFO [MGCP] (Thread-4) tx=147483679 Rolled back
======================================