[asterisk-bugs] [Asterisk 0013909]: Recordings with Mixmonitor still ou of sync
Asterisk Bug Tracker
noreply at bugs.digium.com
Sat Dec 20 16:27:05 CST 2008
A NOTE has been added to this issue.
======================================================================
http://bugs.digium.com/view.php?id=13909
======================================================================
Reported By: edugs15
Assigned To:
======================================================================
Project: Asterisk
Issue ID: 13909
Category: Applications/app_mixmonitor
Reproducibility: always
Severity: major
Priority: normal
Status: feedback
Asterisk Version: 1.4.23
SVN Branch (only for SVN checkouts, not tarball releases): N/A
SVN Revision (number only!):
Disclaimer on File?: N/A
Request Review:
======================================================================
Date Submitted: 2008-11-17 06:34 CST
Last Modified: 2008-12-20 16:27 CST
======================================================================
Summary: Recordings with Mixmonitor still ou of sync
Description:
Recordings wirh Mixmonitor are still out of sync, with Asterisk 1.4.22 or
Asterisk 1.4.23-rc1.
This problem is always happening, no matter incoming or outgoing calls, no
matter short or long calls, no matter using chanspy or no.
One leg of the call is delayed.
======================================================================
----------------------------------------------------------------------
(0096752) edugs15 (reporter) - 2008-12-20 16:27
http://bugs.digium.com/view.php?id=13909#c96752
----------------------------------------------------------------------
Hello file,
for the call bellow (and for all calls), the out of syncness in call
recording is gradually introduced, starting about 45 seconds after call
being established (it happens for listenings via chanspy as well).
This is the dialplan :
exten =>
_0[7-9]xxxxxxx,1,Set(MIXMONITOR_FILENAME=/gravacoes/saidas/${CALLERID(num)}-${CALLERID(dnid)}-${STRFTIME(${EPOCH},,%d%m%Y-%H%M%S)})
exten => _0[7-9]xxxxxxx,2,MixMonitor(${MIXMONITOR_FILENAME}.gsm,b)
exten => _0[7-9]xxxxxxx,3,Dial(Dgv/g1/${EXTEN:1},60,tT)
exten => _0[7-9]xxxxxxx,4,Hangup()
This is the complete console output :
Core debug is at least 2
[Dec 20 11:51:49] DEBUG[2618]: chan_sip.c:4602 sip_alloc: Allocating new
SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 11:51:49] DEBUG[2618]: chan_sip.c:2216 __sip_ack: Stopping
retransmission on '01a9942545db4dad646fbe8516a4898c at 192.168.100.240' of
Request 102: Match Found
[Dec 20 11:52:33] DEBUG[2618]: chan_sip.c:2781 do_setnat: Setting NAT on
RTP to Off
[Dec 20 11:52:33] DEBUG[2618]: chan_sip.c:4602 sip_alloc: Allocating new
SIP dialog for MjgwNTgzYTliNWU2ZTEzMTFmY2E3NWRkMWQxYzE4YTI. - INVITE (With
RTP)
[Dec 20 11:52:33] DEBUG[2618]: chan_sip.c:2781 do_setnat: Setting NAT on
RTP to Off
[Dec 20 11:52:33] DEBUG[2618]: chan_sip.c:2216 __sip_ack: Stopping
retransmission on 'MjgwNTgzYTliNWU2ZTEzMTFmY2E3NWRkMWQxYzE4YTI.' of
Response 1: Match Found
[Dec 20 11:52:33] DEBUG[2618]: chan_sip.c:2781 do_setnat: Setting NAT on
RTP to Off
[Dec 20 11:52:33] DEBUG[2618]: chan_sip.c:5630 process_sdp: We're settling
with these formats: 0x8 (alaw)
[Dec 20 11:52:33] DEBUG[2618]: chan_sip.c:14424 handle_request_invite:
Checking SIP call limits for device 3710
[Dec 20 11:52:33] DEBUG[2618]: chan_sip.c:3319 update_call_counter: Call
from peer '3710' is 1 out of 1
[Dec 20 11:52:33] DEBUG[2618]: chan_sip.c:8477 build_route: build_route:
Contact hop: <sip:3710 at 192.168.100.243:59154>
[Dec 20 11:52:33] DEBUG[2618]: chan_sip.c:14507 handle_request_invite:
SIP/3710-09e3e688: New call is still down.... Trying...
[Dec 20 11:52:33] DEBUG[23082]: pbx.c:1691
pbx_substitute_variables_helper_full: Function result is '3710'
[Dec 20 11:52:33] DEBUG[23082]: pbx.c:1691
pbx_substitute_variables_helper_full: Function result is '082240105'
[Dec 20 11:52:33] DEBUG[23082]: pbx.c:1691
pbx_substitute_variables_helper_full: Function result is '20122008-115233'
[Dec 20 11:52:33] DEBUG[23082]: pbx.c:1842 pbx_extension_helper: Launching
'Set'
-- Executing [082240105 at superv-dafra:1] Set("SIP/3710-09e3e688",
"MIXMONITOR_FILENAME=/gravacoes/saidas/3710-082240105-20122008-115233") in
new stack
[Dec 20 11:52:33] DEBUG[23082]: pbx.c:1842 pbx_extension_helper: Launching
'MixMonitor'
-- Executing [082240105 at superv-dafra:2]
MixMonitor("SIP/3710-09e3e688",
"/gravacoes/saidas/3710-082240105-20122008-115233.gsm|b") in new stack
[Dec 20 11:52:33] DEBUG[23082]: pbx.c:1842 pbx_extension_helper: Launching
'Dial'
== Begin MixMonitor Recording SIP/3710-09e3e688
-- Executing [082240105 at superv-dafra:3] Dial("SIP/3710-09e3e688",
"Dgv/g1/82240105|60|tT") in new stack
[Dec 20 11:52:33] NOTICE[23082]: chan_dgv.c:10676 dgv_request: Asked to
get a channel Dgv/g1/82240105 using format AST_FORMAT_ALAW:ffWaveALaw
[Dec 20 11:52:33] NOTICE[23082]: chan_dgv.c:10692 dgv_request: Group g1
[Dec 20 11:52:33] DEBUG[23082]: rtp.c:1586 ast_rtp_make_compatible:
Channel 'DGV/1' has no RTP, not doing anything
[Dec 20 11:52:33] DEBUG[23082]: channel.c:3351
ast_channel_inherit_variables: Not copying variable DIALEDTIME.
[Dec 20 11:52:33] DEBUG[23082]: channel.c:3351
ast_channel_inherit_variables: Not copying variable ANSWEREDTIME.
[Dec 20 11:52:34] DEBUG[23082]: channel.c:3351
ast_channel_inherit_variables: Not copying variable DIALEDPEERNAME.
[Dec 20 11:52:34] DEBUG[23082]: channel.c:3351
ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER.
[Dec 20 11:52:34] DEBUG[23082]: channel.c:3351
ast_channel_inherit_variables: Not copying variable DIALSTATUS.
[Dec 20 11:52:34] DEBUG[23082]: channel.c:3351
ast_channel_inherit_variables: Not copying variable MIXMONITOR_FILENAME.
[Dec 20 11:52:34] DEBUG[23082]: channel.c:3351
ast_channel_inherit_variables: Not copying variable SIPCALLID.
[Dec 20 11:52:34] DEBUG[23082]: channel.c:3351
ast_channel_inherit_variables: Not copying variable SIPUSERAGENT.
[Dec 20 11:52:34] DEBUG[23082]: channel.c:3351
ast_channel_inherit_variables: Not copying variable SIPDOMAIN.
[Dec 20 11:52:34] DEBUG[23082]: channel.c:3351
ast_channel_inherit_variables: Not copying variable SIPURI.
-- Called g1/82240105
[Dec 20 11:52:34] DEBUG[23082]: channel.c:2843 set_format: Set channel
DGV/1 to read format alaw
[Dec 20 11:52:34] DEBUG[23082]: channel.c:2843 set_format: Set channel
DGV/1 to write format alaw
[Dec 20 11:52:34] DEBUG[23082]: chan_sip.c:6835
transmit_response_with_sdp: Setting framing from config on incoming call
[Dec 20 11:52:34] DEBUG[23082]: chan_sip.c:6599 add_sdp: ** Our
capability: 0x8 (alaw) Video flag: True
[Dec 20 11:52:34] DEBUG[23082]: chan_sip.c:6600 add_sdp: ** Our prefcodec:
0x0 (nothing)
[Dec 20 11:52:34] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:34] DEBUG[23082]: rtp.c:2775 ast_rtp_write: Ooh, format
changed from unknown to alaw
[Dec 20 11:52:34] DEBUG[23082]: rtp.c:2792 ast_rtp_write: Created
smoother: format: 8 ms: 20 len: 160
[Dec 20 11:52:34] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 132 bytes
[Dec 20 11:52:34] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:37] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
-- DGV/1 is ringing
[Dec 20 11:52:40] DEBUG[23083]: audiohook.c:249 audiohook_read_frame_both:
Failed to get 160 samples from read factory 0x9e15068
[Dec 20 11:52:40] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:52:43] NOTICE[2802]: chan_dgv.c:8102 event_handler:
dialplan_echo_thread Created(4) - port 1
-- DGV/1 answered SIP/3710-09e3e688
[Dec 20 11:52:43] DEBUG[23082]: chan_sip.c:3716 sip_answer: SIP answering
channel: SIP/3710-09e3e688
[Dec 20 11:52:43] DEBUG[23082]: chan_sip.c:6835
transmit_response_with_sdp: Setting framing from config on incoming call
[Dec 20 11:52:43] DEBUG[23082]: chan_sip.c:6599 add_sdp: ** Our
capability: 0x8 (alaw) Video flag: True
[Dec 20 11:52:43] DEBUG[23082]: chan_sip.c:6600 add_sdp: ** Our prefcodec:
0x0 (nothing)
[Dec 20 11:52:43] DEBUG[23082]: channel.c:2137 __ast_read: Dropping
duplicate answer!
[Dec 20 11:52:43] DEBUG[23082]: rtp.c:2792 ast_rtp_write: Created
smoother: format: 8 ms: 20 len: 160
[Dec 20 11:52:43] DEBUG[2618]: chan_sip.c:2216 __sip_ack: Stopping
retransmission on 'MjgwNTgzYTliNWU2ZTEzMTFmY2E3NWRkMWQxYzE4YTI.' of
Response 2: Match Found
[Dec 20 11:52:44] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:52:47] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:52:49] DEBUG[2618]: chan_sip.c:4602 sip_alloc: Allocating new
SIP dialog for NDA1MDRlYjliNjQ1ZmVlNjk4ZDA5ODRjMzJhMGEyYWI. - REGISTER (No
RTP)
[Dec 20 11:52:49] DEBUG[7958]: manager.c:2165 process_message: Manager
received command 'Command'
[Dec 20 11:52:49] DEBUG[2618]: chan_sip.c:4602 sip_alloc: Allocating new
SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 11:52:49] DEBUG[2618]: chan_sip.c:2216 __sip_ack: Stopping
retransmission on '5f399495705598b541b208583ddf9602 at 192.168.100.240' of
Request 102: Match Found
[Dec 20 11:52:51] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:52:54] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:52:57] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:01] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:04] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:08] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:11] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:15] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:18] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:21] DEBUG[2618]: chan_sip.c:2119 __sip_autodestruct: Auto
destroying SIP dialog 'NDA1MDRlYjliNjQ1ZmVlNjk4ZDA5ODRjMzJhMGEyYWI.'
[Dec 20 11:53:21] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:25] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:28] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:32] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:35] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:39] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:42] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:45] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:49] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:49] DEBUG[2618]: chan_sip.c:4602 sip_alloc: Allocating new
SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 11:53:49] DEBUG[2618]: chan_sip.c:2216 __sip_ack: Stopping
retransmission on '11c7c4834b9a9e016185a4431067c51c at 192.168.100.240' of
Request 102: Match Found
[Dec 20 11:53:52] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:56] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:53:59] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:03] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:06] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:09] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:13] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:16] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:20] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:23] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:26] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:30] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:33] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:37] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:40] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:44] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:47] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:49] DEBUG[2618]: chan_sip.c:4602 sip_alloc: Allocating new
SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 11:54:49] DEBUG[2618]: chan_sip.c:2216 __sip_ack: Stopping
retransmission on '77ac7cb710e281ad228495442710c1bd at 192.168.100.240' of
Request 102: Match Found
[Dec 20 11:54:50] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:54] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:54:57] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:01] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:04] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:08] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:11] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:14] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:18] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:21] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:25] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:28] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:31] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:35] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:38] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:42] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:45] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:49] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:49] DEBUG[2618]: chan_sip.c:4602 sip_alloc: Allocating new
SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 11:55:49] DEBUG[2618]: chan_sip.c:2216 __sip_ack: Stopping
retransmission on '7f09547c00b2e8a1468e364e2afdf4d4 at 192.168.100.240' of
Request 102: Match Found
[Dec 20 11:55:52] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:55] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:55:59] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:02] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:06] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:09] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:13] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:16] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:19] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:23] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:26] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:30] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:33] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:36] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:40] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:43] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:47] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:49] DEBUG[2618]: chan_sip.c:4602 sip_alloc: Allocating new
SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 11:56:49] DEBUG[2618]: chan_sip.c:2216 __sip_ack: Stopping
retransmission on '4ee082213762f16f4ef86855331f7ade at 192.168.100.240' of
Request 102: Match Found
[Dec 20 11:56:50] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:54] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:56:57] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:00] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:04] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:07] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:11] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:14] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:18] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:21] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:24] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:28] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:31] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:35] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:38] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:42] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:45] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:48] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:49] DEBUG[2618]: chan_sip.c:4602 sip_alloc: Allocating new
SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 11:57:49] DEBUG[2618]: chan_sip.c:2216 __sip_ack: Stopping
retransmission on '39a40c105cd4b0fb7d4991f20dc140c5 at 192.168.100.240' of
Request 102: Match Found
[Dec 20 11:57:52] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:55] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:57:59] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:58:02] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:58:05] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:58:09] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:58:12] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:58:16] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:58:19] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:58:23] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:58:26] DEBUG[23082]: rtp.c:879 ast_rtcp_read: Got RTCP report
of 176 bytes
[Dec 20 11:58:27] DEBUG[2618]: chan_sip.c:4602 sip_alloc: Allocating new
SIP dialog for 1e0969cb-af746161 at 192.168.100.24 - REGISTER (No RTP)
[Dec 20 11:58:27] DEBUG[7958]: manager.c:2165 process_message: Manager
received command 'Command'
[Dec 20 11:58:27] DEBUG[23082]: channel.c:3839 ast_generic_bridge: Didn't
get a frame from channel: DGV/1
[Dec 20 11:58:27] DEBUG[23082]: channel.c:4182 ast_channel_bridge: Bridge
stops bridging channels SIP/3710-09e3e688 and DGV/1
[Dec 20 11:58:27] DEBUG[23082]: channel.c:1505 ast_hangup: Hanging up
channel 'DGV/1'
[Dec 20 11:58:27] NOTICE[23082]: chan_dgv.c:12205 dgv_hangup: Calling
dg_HangUp on port 1
[Dec 20 11:58:27] DEBUG[23082]: rtp.c:1511 ast_rtp_early_bridge: Channel
'<unspecified>' has no RTP, not doing anything
[Dec 20 11:58:27] DEBUG[23082]: app_dial.c:1846 dial_exec_full: Exiting
with DIALSTATUS=ANSWER.
[Dec 20 11:58:27] DEBUG[23082]: pbx.c:2425 __ast_pbx_run: Spawn extension
(superv-dafra,082240105,3) exited non-zero on 'SIP/3710-09e3e688'
== Spawn extension (superv-dafra, 082240105, 3) exited non-zero on
'SIP/3710-09e3e688'
[Dec 20 11:58:27] DEBUG[23082]: channel.c:1412 ast_softhangup_nolock:
Soft-Hanging up channel 'SIP/3710-09e3e688'
== End MixMonitor Recording SIP/3710-09e3e688
[Dec 20 11:58:27] DEBUG[23082]: channel.c:1505 ast_hangup: Hanging up
channel 'SIP/3710-09e3e688'
[Dec 20 11:58:27] DEBUG[23082]: chan_sip.c:3555 sip_hangup: Hangup call
SIP/3710-09e3e688, SIP callid
MjgwNTgzYTliNWU2ZTEzMTFmY2E3NWRkMWQxYzE4YTI.)
[Dec 20 11:58:27] DEBUG[23082]: chan_sip.c:3293 update_call_counter: Call
from peer '3710' removed from call limit 1
[Dec 20 11:58:28] DEBUG[2618]: chan_sip.c:2216 __sip_ack: Stopping
retransmission on 'MjgwNTgzYTliNWU2ZTEzMTFmY2E3NWRkMWQxYzE4YTI.' of Request
102: Match Found
[Dec 20 11:58:47] DEBUG[2618]: chan_sip.c:4602 sip_alloc: Allocating new
SIP dialog for 148792282822828QnJh at 192.168.100.241 - REGISTER (No RTP)
[Dec 20 11:58:47] DEBUG[7958]: manager.c:2165 process_message: Manager
received command 'Command'
[Dec 20 11:58:49] DEBUG[2618]: chan_sip.c:4602 sip_alloc: Allocating new
SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 11:58:49] DEBUG[2618]: chan_sip.c:2216 __sip_ack: Stopping
retransmission on '6fbc74970184391a4d1ed71b2ea47b5e at 192.168.100.240' of
Request 102: Match Found
asterisk*CLI>
Issue History
Date Modified Username Field Change
======================================================================
2008-12-20 16:27 edugs15 Note Added: 0096752
======================================================================
More information about the asterisk-bugs
mailing list