ASTERISK-14637: After update from 1.4.26 to 1.6.1.4 outgoing call and h323 trace does not work ...

[Home]

Summary: ASTERISK-14637: After update from 1.4.26 to 1.6.1.4 outgoing call and h323 trace does not work ...

Reporter: Badalian Vyacheslav (slavon) Labels:

Date Opened: 2009-08-12 02:57:00 Date Closed: 2011-06-07 14:00:50

Priority: Major Regression? No

Status: Closed/Complete Components: Channels/chan_h323

Versions: Frequency of
Occurrence

Related
Issues:

Environment: Attachments:

Description: Hello.

After update from 1.4.26 to 1.6.1.4:
1. outgoing call does not work. Incomming work
2. h323 trace does not work
3. version of h323 does not show

****** ADDITIONAL INFORMATION ******

In 1.4.26:
asterisk-lip*CLI> core set verbose 3
Verbosity was 0 and is now 3
asterisk-lip*CLI> core set debug 1
Core debug was 0 and is now 1
asterisk-lip*CLI> h323 show version
[Aug 12 11:46:42] H.323 version: 1.18.0
asterisk-lip*CLI> h323 set trace 3
H.323 trace set to level trace
asterisk-lip*CLI> h323 set debug
H.323 debug enabled

Call:

[Aug 12 11:47:25] DEBUG[19634]: chan_sip.c:14819 handle_request_invite: Checking SIP call limits for device office_4201
[Aug 12 11:47:25] DEBUG[19651]: pbx.c:1843 pbx_extension_helper: Launching 'Dial'
[Aug 12 11:47:25] -- Executing [989167932333@office:1] Dial("SIP/office_4201-008ea7d0", "H323/89167932333@85.90.108.3") in new stack
[Aug 12 11:47:25] DEBUG[19651]: chan_h323.c:1686 oh323_request: type=H323, format=4, data=89167932333@85.90.108.3.
[Aug 12 11:47:25] DEBUG[19651]: chan_h323.c:1722 oh323_request: Extension: 89167932333 Host: 85.90.108.3
[Aug 12 11:47:25] DEBUG[19651]: chan_h323.c:1598 find_peer: Could not find peer by name 85.90.108.3 or address <NONE>
[Aug 12 11:47:25] DEBUG[19651]: channel.c:3688 ast_channel_inherit_variables: Not copying variable DIALEDTIME.
[Aug 12 11:47:25] DEBUG[19651]: channel.c:3688 ast_channel_inherit_variables: Not copying variable ANSWEREDTIME.
[Aug 12 11:47:25] DEBUG[19651]: channel.c:3688 ast_channel_inherit_variables: Not copying variable DIALEDPEERNAME.
[Aug 12 11:47:25] DEBUG[19651]: channel.c:3688 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER.
[Aug 12 11:47:25] DEBUG[19651]: channel.c:3688 ast_channel_inherit_variables: Not copying variable DIALSTATUS.
[Aug 12 11:47:25] DEBUG[19651]: channel.c:3688 ast_channel_inherit_variables: Not copying variable SIPCALLID.
[Aug 12 11:47:25] DEBUG[19651]: channel.c:3688 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT.
[Aug 12 11:47:25] DEBUG[19651]: channel.c:3688 ast_channel_inherit_variables: Not copying variable SIPDOMAIN.
[Aug 12 11:47:25] DEBUG[19651]: channel.c:3688 ast_channel_inherit_variables: Not copying variable SIPURI.
[Aug 12 11:47:25] DEBUG[19651]: chan_h323.c:594 oh323_call: Calling to 89167932333@85.90.108.3 on H323/85.90.108.3-1
[Aug 12 11:47:25] -- Requested transfer capability: 0x00 - SPEECH
[Aug 12 11:47:25] DEBUG[19651]: chan_h323.c:654 oh323_call: Placing outgoing call to 89167932333@85.90.108.3:1720, 101
[Aug 12 11:47:25] -- Making call to 89167932333@85.90.108.3:1720 without gatekeeper.
[Aug 12 11:47:25] == New H.323 Connection created.
[Aug 12 11:47:25] -- root is calling host 89167932333@85.90.108.3:1720
[Aug 12 11:47:25] -- Call token is ip$localhost/16494
[Aug 12 11:47:25] -- Call reference is 16494
[Aug 12 11:47:25] -- DTMF Payload is 101
[Aug 12 11:47:25] -- Called 89167932333@85.90.108.3
[Aug 12 11:47:26] DEBUG[19634]: chan_sip.c:4689 sip_alloc: Allocating new SIP dialog for 4270e9fb448d94433cad30385b2b1454@91.207.142.18 - OPTIONS (No RTP)
[Aug 12 11:47:26] DEBUG[19634]: chan_sip.c:16507 sipsock_read: SIP message could not be handled, bad request: 4270e9fb448d94433cad30385b2b1454@91.207.142.18
[Aug 12 11:47:28] DEBUG[19652]: chan_h323.c:2436 set_local_capabilities: Setting capabilities for connection ip$localhost/16494
[Aug 12 11:47:28] Setting capabilities to 0xc (ulaw|alaw)
[Aug 12 11:47:28] Capabilities in preference order is (ulaw|alaw)
[Aug 12 11:47:28] Allowed Codecs:
[Aug 12 11:47:28] Table:
[Aug 12 11:47:28] G.711-uLaw-64k <1>
[Aug 12 11:47:28] G.711-ALaw-64k <2>
[Aug 12 11:47:28] UserInput/hookflash <3>
[Aug 12 11:47:28] UserInput/RFC2833 <4>
[Aug 12 11:47:28] UserInput/dtmf <5>
[Aug 12 11:47:28] Set:
[Aug 12 11:47:28] 0:
[Aug 12 11:47:28] 0:
[Aug 12 11:47:28] G.711-uLaw-64k <1>
[Aug 12 11:47:28] G.711-ALaw-64k <2>
[Aug 12 11:47:28] 1:
[Aug 12 11:47:28] UserInput/hookflash <3>
[Aug 12 11:47:28] 2:
[Aug 12 11:47:28] UserInput/RFC2833 <4>
[Aug 12 11:47:28] UserInput/dtmf <5>
[Aug 12 11:47:28]
[Aug 12 11:47:28] DEBUG[19652]: chan_h323.c:2453 set_local_capabilities: local prefs[0]=ulaw:20
[Aug 12 11:47:28] DEBUG[19652]: chan_h323.c:2453 set_local_capabilities: local prefs[1]=alaw:20
[Aug 12 11:47:28] DEBUG[19652]: chan_h323.c:2455 set_local_capabilities: Capabilities for connection ip$localhost/16494 is set
[Aug 12 11:47:28] DEBUG[19652]: chan_h323.c:974 __oh323_rtp_create: Created RTP channel
[Aug 12 11:47:28] DEBUG[19652]: chan_h323.c:979 __oh323_rtp_create: Setting NAT on RTP to 0
[Aug 12 11:47:28] DEBUG[19652]: chan_h323.c:1880 external_rtp_create: Sending RTP 'US' 194.0.69.3:17006
[Aug 12 11:47:28] DEBUG[19652]: chan_h323.c:1880 external_rtp_create: Sending RTP 'US' 194.0.69.3:17006
[Aug 12 11:47:28] DEBUG[19652]: chan_h323.c:1880 external_rtp_create: Sending RTP 'US' 194.0.69.3:17006
[Aug 12 11:47:28] DEBUG[19652]: chan_h323.c:1880 external_rtp_create: Sending RTP 'US' 194.0.69.3:17006
[Aug 12 11:47:28] -- Sending SETUP message
[Aug 12 11:47:28] -- Transmitting RFC2833 on payload 101
[Aug 12 11:47:29] -- Started logical channel: sending G.711-ALaw-64k
[Aug 12 11:47:29] -- channelsOpen = 1
[Aug 12 11:47:29] External RTP Session Starting
[Aug 12 11:47:29] RTP channel id 1 parameters:
[Aug 12 11:47:29] -- remoteIpAddress: 85.90.108.3
[Aug 12 11:47:29] -- remotePort: 28814
[Aug 12 11:47:29] -- ExternalIpAddress: 194.0.69.3
[Aug 12 11:47:29] -- ExternalPort: 17006
[Aug 12 11:47:29] DEBUG[19652]: chan_h323.c:1906 setup_rtp_connection: Setting up RTP connection for ip$localhost/16494
[Aug 12 11:47:29] DEBUG[19652]: chan_h323.c:1946 setup_rtp_connection: Native format is set to 8 from 4 by RTP payload type 8
[Aug 12 11:47:29] DEBUG[19652]: chan_h323.c:1960 setup_rtp_connection: Native format changed to 8 from 4, read format is 4, write format is 4
[Aug 12 11:47:29] DEBUG[19652]: channel.c:3085 set_format: Set channel H323/85.90.108.3-1 to read format ulaw
[Aug 12 11:47:29] DEBUG[19652]: channel.c:3085 set_format: Set channel H323/85.90.108.3-1 to write format ulaw
[Aug 12 11:47:29] DEBUG[19652]: chan_h323.c:1993 setup_rtp_connection: [Aug 12 11:47:29] -- H323/85.90.108.3-1 is making progress passing it to SIP/office_4201-008ea7d0
RTP connection prepared for ip$localhost/16494
[Aug 12 11:47:29] DEBUG[19651]: chan_sip.c:7002 transmit_response_with_sdp: Setting framing from config on incoming call
[Aug 12 11:47:29] -- Started logical channel: receiving G.711-ALaw-64k
[Aug 12 11:47:29] -- channelsOpen = 2
[Aug 12 11:47:29] External RTP Session Starting
[Aug 12 11:47:29] RTP channel id 1 parameters:
[Aug 12 11:47:29] -- remoteIpAddress: 85.90.108.3
[Aug 12 11:47:29] -- remotePort: 28814
[Aug 12 11:47:29] -- ExternalIpAddress: 194.0.69.3
[Aug 12 11:47:29] -- ExternalPort: 17006
[Aug 12 11:47:29] DEBUG[19652]: chan_h323.c:1906 setup_rtp_connection: Setting up RTP connection for ip$localhost/16494
[Aug 12 11:47:29] DEBUG[19652]: chan_h323.c:1946 setup_rtp_connection: Native format is set to 8 from 8 by RTP payload type 8
[Aug 12 11:47:29] DEBUG[19652]: chan_h323.c:1993 setup_rtp_connection: [Aug 12 11:47:29] -- H323/85.90.108.3-1 is making progress passing it to SIP/office_4201-008ea7d0
RTP connection prepared for ip$localhost/16494
[Aug 12 11:47:29] ExternalRTPChannel Destroyed
[Aug 12 11:47:29] ExternalRTPChannel Destroyed
[Aug 12 11:47:29] Received non-standard Cisco extension data 51 octets {
[Aug 12 11:47:29] 60 01 01 00 01 1e 2c 1e 02 81 81 1c 26 9e 81 00 `.....,.....&...
[Aug 12 11:47:29] 03 67 74 64 00 00 00 1b 43 50 47 2c 0d 0a 50 52 .gtd....CPG,..PR
[Aug 12 11:47:29] 4e 2c 69 73 64 6e 2a 2c 2c 4e 45 54 35 2a 2c 0d N,isdn*,,NET5*,.
[Aug 12 11:47:29] 0a 0d 0a ...
[Aug 12 11:47:29] }
[Aug 12 11:47:29] H323_UU_NonStdInfo = {
[Aug 12 11:47:29] }
[Aug 12 11:47:29] Information elements collected:{
[Aug 12 11:47:29] protocolDiscriminator = 8
[Aug 12 11:47:29] callReference = 0
[Aug 12 11:47:29] from = originator
[Aug 12 11:47:29] messageType = Escape
[Aug 12 11:47:29] IE: Facility = {
[Aug 12 11:47:29] 9e 81 00 03 67 74 64 00 00 00 1b 43 50 47 2c 0d ....gtd....CPG,.
[Aug 12 11:47:29] 0a 50 52 4e 2c 69 73 64 6e 2a 2c 2c 4e 45 54 35 .PRN,isdn*,,NET5
[Aug 12 11:47:29] 2a 2c 0d 0a 0d 0a *,....
[Aug 12 11:47:29] }
[Aug 12 11:47:29] IE: Progress-Indicator = {
[Aug 12 11:47:29] 81 81 ..
[Aug 12 11:47:29] }
[Aug 12 11:47:29] }
[Aug 12 11:47:29] =-= In OnAlerting for call 16494: sessionId=0
[Aug 12 11:47:29] -- Ringing phone for "89167932333"
[Aug 12 11:47:29] - Progress Indicator: 8
[Aug 12 11:47:29] DEBUG[19652]: chan_h323.c:2034 progress: Received ALERT/PROGRESS message for inband tones
[Aug 12 11:47:29] DEBUG[19652]: chan_h323.c:2273 chan_ringing: Ringing on ip$localhost/16494
[Aug 12 11:47:29] DEBUG[19632]: channel.c:1130 channel_find_locked: Avoiding initial deadlock for channel '0x8d8830'
[Aug 12 11:47:29] -- H323/85.90.108.3-1 is making progress passing it to SIP/office_4201-008ea7d0
[Aug 12 11:47:29] -- H323/85.90.108.3-1 is ringing
[Aug 12 11:47:29] DEBUG[19651]: rtp.c:2885 ast_rtp_write: Ooh, format changed from unknown to alaw
[Aug 12 11:47:29] DEBUG[19651]: rtp.c:2902 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160
[Aug 12 11:47:29] DEBUG[19651]: rtp.c:2885 ast_rtp_write: Ooh, format changed from unknown to ulaw
[Aug 12 11:47:29] DEBUG[19651]: rtp.c:2902 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160
[Aug 12 11:47:30] DEBUG[19651]: rtp.c:923 ast_rtcp_read: Got RTCP report of 132 bytes
[Aug 12 11:47:34] DEBUG[19651]: rtp.c:923 ast_rtcp_read: Got RTCP report of 132 bytes
[Aug 12 11:47:34] Received non-standard Cisco extension data 51 octets {
[Aug 12 11:47:34] 60 01 01 00 01 1e 2c 1e 02 82 88 1c 26 9e 81 00 `.....,.....&...
[Aug 12 11:47:34] 03 67 74 64 00 00 00 1b 43 50 47 2c 0d 0a 50 52 .gtd....CPG,..PR
[Aug 12 11:47:34] 4e 2c 69 73 64 6e 2a 2c 2c 4e 45 54 35 2a 2c 0d N,isdn*,,NET5*,.
[Aug 12 11:47:34] 0a 0d 0a ...
[Aug 12 11:47:34] }
[Aug 12 11:47:34] H323_UU_NonStdInfo = {
[Aug 12 11:47:34] }
[Aug 12 11:47:34] Information elements collected:{
[Aug 12 11:47:34] protocolDiscriminator = 8
[Aug 12 11:47:34] callReference = 0
[Aug 12 11:47:34] from = originator
[Aug 12 11:47:34] messageType = Escape
[Aug 12 11:47:34] IE: Facility = {
[Aug 12 11:47:34] 9e 81 00 03 67 74 64 00 00 00 1b 43 50 47 2c 0d ....gtd....CPG,.
[Aug 12 11:47:34] 0a 50 52 4e 2c 69 73 64 6e 2a 2c 2c 4e 45 54 35 .PRN,isdn*,,NET5
[Aug 12 11:47:34] 2a 2c 0d 0a 0d 0a *,....
[Aug 12 11:47:34] }
[Aug 12 11:47:34] IE: Progress-Indicator = {
[Aug 12 11:47:34] 82 88 ..
[Aug 12 11:47:34] }
[Aug 12 11:47:34] }
[Aug 12 11:47:34] - Progress Indicator: 8
[Aug 12 11:47:34] DEBUG[19652]: chan_h323.c:2034 progress: Received ALERT/PROGRESS message for inband tones
[Aug 12 11:47:34] -- H323/85.90.108.3-1 is making progress passing it to SIP/office_4201-008ea7d0
[Aug 12 11:47:36] NOTICE[19651]: rtp.c:830 process_rfc3389: Comfort noise support incomplete in Asterisk (RFC 3389). Please turn off on client if possible. Client IP: 85.90.108.3
[Aug 12 11:47:38] DEBUG[19651]: rtp.c:923 ast_rtcp_read: Got RTCP report of 132 bytes
[Aug 12 11:47:43] DEBUG[19651]: rtp.c:923 ast_rtcp_read: Got RTCP report of 132 bytes
[Aug 12 11:47:48] DEBUG[19651]: rtp.c:923 ast_rtcp_read: Got RTCP report of 132 bytes
[Aug 12 11:47:53] Received non-standard Cisco extension data 11 octets {
[Aug 12 11:47:53] 60 01 10 00 01 1e 04 1e 02 81 88 `..........
[Aug 12 11:47:53] }
[Aug 12 11:47:53] H323_UU_NonStdInfo = {
[Aug 12 11:47:53] }
[Aug 12 11:47:53] Information elements collected:{
[Aug 12 11:47:53] protocolDiscriminator = 8
[Aug 12 11:47:53] callReference = 0
[Aug 12 11:47:53] from = originator
[Aug 12 11:47:53] messageType = Escape
[Aug 12 11:47:53] IE: Progress-Indicator = {
[Aug 12 11:47:53] 81 88 ..
[Aug 12 11:47:53] }
[Aug 12 11:47:53] }
[Aug 12 11:47:53] - Progress Indicator: 8
[Aug 12 11:47:53] DEBUG[19652]: chan_h323.c:2034 progress: Received ALERT/PROGRESS message for inband tones
[Aug 12 11:47:53] -- H323/85.90.108.3-1 is making progress passing it to SIP/office_4201-008ea7d0
[Aug 12 11:47:53] DEBUG[19634]: chan_sip.c:4689 sip_alloc: Allocating new SIP dialog for 510231a03638852d2e25fa411c1e82f6@87.255.0.218 - OPTIONS (No RTP)
[Aug 12 11:47:53] DEBUG[19634]: chan_sip.c:16507 sipsock_read: SIP message could not be handled, bad request: 510231a03638852d2e25fa411c1e82f6@87.255.0.218
[Aug 12 11:47:55] DEBUG[19651]: rtp.c:923 ast_rtcp_read: Got RTCP report of 132 bytes
[Aug 12 11:47:57] DEBUG[19651]: rtp.c:1567 ast_rtp_early_bridge: Channel '<unspecified>' has no RTP, not doing anything
[Aug 12 11:47:57] DEBUG[19651]: channel.c:1546 ast_hangup: Hanging up channel 'H323/85.90.108.3-1'
[Aug 12 11:47:57] DEBUG[19651]: chan_h323.c:696 oh323_hangup: Hanging up and scheduling destroy of call H323/85.90.108.3-1
[Aug 12 11:47:57] -- Sending RELEASE COMPLETE
[Aug 12 11:47:57] -- ClearCall: Request to clear call with token ip$localhost/16494, cause 3
[Aug 12 11:47:57] channelsOpen = 1
[Aug 12 11:47:57] channelsOpen = 0
[Aug 12 11:47:57] DEBUG[19651]: app_dial.c:1825 dial_exec_full: Exiting with DIALSTATUS=CANCEL.
[Aug 12 11:47:57] ExternalRTPChannel Destroyed
[Aug 12 11:47:57] DEBUG[19651]: pbx.c:2392 __ast_pbx_run: Spawn extension (office,989167932333,1) exited non-zero on 'SIP/office_4201-008ea7d0'
[Aug 12 11:47:57] == Spawn extension (office, 989167932333, 1) exited non-zero on 'SIP/office_4201-008ea7d0'
[Aug 12 11:47:57] DEBUG[19651]: channel.c:1453 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/office_4201-008ea7d0'
[Aug 12 11:47:57] DEBUG[19651]: channel.c:1546 ast_hangup: [Aug 12 11:47:57] ExternalRTPChannel Destroyed
Hanging up channel 'SIP/office_4201-008ea7d0'
[Aug 12 11:47:57] DEBUG[19651]: chan_sip.c:3616 sip_hangup: Hangup call SIP/office_4201-008ea7d0, SIP callid 0009433c-deca0010-5daf6a73-59b9d5a8@10.50.2.102)
[Aug 12 11:47:57] -- ClearCall: Request to clear call with token ip$localhost/16494, cause 7
[Aug 12 11:47:57] -- 89167932333 has cleared the call
[Aug 12 11:47:57] DEBUG[19638]: chan_h323.c:2299 cleanup_connection: Cleaning connection to ip$localhost/16494
[Aug 12 11:47:57] DEBUG[19638]: chan_h323.c:2305 cleanup_connection: No connection for ip$localhost/16494
[Aug 12 11:47:57] == H.323 Connection deleted.
1.6.1.4:

asterisk-lip*CLI> core set verbose 3
Verbosity was 0 and is now 3
asterisk-lip*CLI> core set debug 2
Core debug was 0 and is now 2
asterisk-lip*CLI> h323 show version
asterisk-lip*CLI> h323 set trace 3
H.323 trace set to level trace
asterisk-lip*CLI> h323 set debug
H.323 debug enabled
asterisk-lip*CLI> h323 show version

Call:

[Aug 12 11:45:14] DEBUG[18697]: pbx.c:3179 pbx_extension_helper: Launching 'Dial'
[Aug 12 11:45:14] -- Executing [9222222@office:1] Dial("SIP/office_4201-b80f3570", "H323/222222@Mera") in new stack
[Aug 12 11:45:14] DEBUG[18697]: chan_h323.c:1727 oh323_request: type=H323, format=4, data=222222@Mera.
[Aug 12 11:45:14] DEBUG[18697]: chan_h323.c:1763 oh323_request: Extension: 222222 Host: Mera
[Aug 12 11:45:14] DEBUG[18697]: chan_h323.c:966 __oh323_rtp_create: Created RTP channel
[Aug 12 11:45:14] DEBUG[18697]: chan_h323.c:971 __oh323_rtp_create: Setting NAT on RTP to 0
[Aug 12 11:45:14] DEBUG[18697]: channel.c:3989 ast_channel_inherit_variables: Not copying variable DIALEDTIME.
[Aug 12 11:45:14] DEBUG[18697]: channel.c:3989 ast_channel_inherit_variables: Not copying variable ANSWEREDTIME.
[Aug 12 11:45:14] DEBUG[18697]: channel.c:3989 ast_channel_inherit_variables: Not copying variable DIALEDPEERNAME.
[Aug 12 11:45:14] DEBUG[18697]: channel.c:3989 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER.
[Aug 12 11:45:14] DEBUG[18697]: channel.c:3989 ast_channel_inherit_variables: Not copying variable DIALSTATUS.
[Aug 12 11:45:14] DEBUG[18697]: channel.c:3989 ast_channel_inherit_variables: Not copying variable SIPCALLID.
[Aug 12 11:45:14] DEBUG[18697]: channel.c:3989 ast_channel_inherit_variables: Not copying variable SIPDOMAIN.
[Aug 12 11:45:14] DEBUG[18697]: channel.c:3989 ast_channel_inherit_variables: Not copying variable SIPURI.
[Aug 12 11:45:14] DEBUG[18697]: chan_h323.c:584 oh323_call: Calling to 222222@Mera on H323/Mera-10
[Aug 12 11:45:14] -- Requested transfer capability: 0x00 - SPEECH
[Aug 12 11:45:14] DEBUG[18697]: chan_h323.c:643 oh323_call: Placing outgoing call to 222222@85.90.108.3:1720, 101/121
[Aug 12 11:45:14] -- Called 222222@Mera
[Aug 12 11:45:14] DEBUG[18698]: chan_h323.c:2476 set_local_capabilities: Setting capabilities for connection ip$localhost/21619
[Aug 12 11:45:14] DEBUG[18698]: chan_h323.c:2489 set_local_capabilities: Capabilities for connection ip$localhost/21619 is set
[Aug 12 11:45:14] DEBUG[18698]: chan_h323.c:1921 external_rtp_create: Sending RTP 'US' 194.0.69.3:27098
[Aug 12 11:45:14] DEBUG[18698]: chan_h323.c:1921 external_rtp_create: Sending RTP 'US' 194.0.69.3:27098
[Aug 12 11:45:14] DEBUG[18698]: chan_h323.c:1921 external_rtp_create: Sending RTP 'US' 194.0.69.3:27098
[Aug 12 11:45:14] DEBUG[18698]: chan_h323.c:1921 external_rtp_create: Sending RTP 'US' 194.0.69.3:27098
[Aug 12 11:45:14] DEBUG[18698]: chan_h323.c:2080 progress: Received ALERT/PROGRESS message for inband tones
[Aug 12 11:45:14] DEBUG[18698]: chan_h323.c:2319 chan_ringing: Ringing on ip$localhost/21619
[Aug 12 11:45:14] -- H323/Mera-10 is making progress passing it to SIP/office_4201-b80f3570
[Aug 12 11:45:14] DEBUG[18697]: chan_sip.c:9009 transmit_response_with_sdp: Setting framing from config on incoming call
[Aug 12 11:45:14] DEBUG[18697]: chan_sip.c:8677 add_sdp: ** Our capability: 0xc (ulaw|alaw) Video flag: True Text flag: True
[Aug 12 11:45:14] DEBUG[18697]: chan_sip.c:8678 add_sdp: ** Our prefcodec: 0x0 (nothing)
[Aug 12 11:45:14] DEBUG[18697]: chan_sip.c:2870 __sip_xmit: Trying to put 'SIP/2.0 18' onto UDP socket destined for 10.50.2.102:5060
[Aug 12 11:45:14] DEBUG[18699]: chan_h323.c:2446 set_peer_capabilities: Got remote capabilities from connection ip$localhost/21619
[Aug 12 11:45:14] DEBUG[18699]: chan_h323.c:2460 set_peer_capabilities: prefs[0]=g729:20
[Aug 12 11:45:14] DEBUG[18699]: chan_h323.c:2460 set_peer_capabilities: prefs[1]=g723:30
[Aug 12 11:45:14] DEBUG[18699]: chan_h323.c:2460 set_peer_capabilities: prefs[2]=ulaw:20
[Aug 12 11:45:14] DEBUG[18699]: chan_h323.c:2460 set_peer_capabilities: prefs[3]=alaw:20
[Aug 12 11:45:14] DEBUG[18377]: channel.c:1180 channel_find_locked: Avoiding initial deadlock for channel '0x903ed8'
[Aug 12 11:45:14] -- H323/Mera-10 is ringing
[Aug 12 11:45:14] DEBUG[18697]: chan_sip.c:2870 __sip_xmit: Trying to put 'SIP/2.0 18' onto UDP socket destined for 10.50.2.102:5060
[Aug 12 11:45:14] DEBUG[18699]: chan_h323.c:1921 external_rtp_create: Sending RTP 'US' 194.0.69.3:27098
[Aug 12 11:45:14] DEBUG[18699]: chan_h323.c:1948 setup_rtp_connection: Setting up RTP connection for ip$localhost/21619
[Aug 12 11:45:14] DEBUG[18699]: chan_h323.c:1992 setup_rtp_connection: Native format is set to 8 from 4 by RTP payload type 8
[Aug 12 11:45:14] DEBUG[18699]: chan_h323.c:2006 setup_rtp_connection: Native format changed to 8 from 4, read format is 4, write format is 4
[Aug 12 11:45:14] DEBUG[18699]: channel.c:3475 set_format: Set channel H323/Mera-10 to read format ulaw
[Aug 12 11:45:14] DEBUG[18699]: channel.c:3475 set_format: Set channel H323/Mera-10 to write format ulaw
[Aug 12 11:45:14] DEBUG[18699]: chan_h323.c:2039 setup_rtp_connection: RTP connection prepared for ip$localhost/21619
[Aug 12 11:45:14] DEBUG[18699]: chan_h323.c:1921 external_rtp_create: Sending RTP 'US' 194.0.69.3:27098
[Aug 12 11:45:14] -- H323/Mera-10 is making progress passing it to SIP/office_4201-b80f3570
[Aug 12 11:45:14] DEBUG[18697]: rtp.c:3726 ast_rtp_write: Ooh, format changed from unknown to alaw
[Aug 12 11:45:14] DEBUG[18697]: rtp.c:3742 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160
[Aug 12 11:45:18] DEBUG[18698]: chan_h323.c:2398 hangup_connection: Hanging up connection to ip$localhost/21619 with cause 41
[Aug 12 11:45:18] DEBUG[18697]: channel.c:1644 ast_hangup: Hanging up channel 'H323/Mera-10'
[Aug 12 11:45:18] DEBUG[18697]: chan_h323.c:685 oh323_hangup: Hanging up and scheduling destroy of call H323/Mera-10
[Aug 12 11:45:18] == Everyone is busy/congested at this time (1:0/0/1)
[Aug 12 11:45:18] DEBUG[18697]: rtp.c:2058 ast_rtp_early_bridge: Channel '<unspecified>' has no RTP, not doing anything
[Aug 12 11:45:18] DEBUG[18697]: app_dial.c:2024 dial_exec_full: Exiting with DIALSTATUS=CHANUNAVAIL.
[Aug 12 11:45:18] DEBUG[18697]: pbx.c:3179 pbx_extension_helper: Launching 'Busy'
[Aug 12 11:45:18] -- Executing [9222222@office:2] Busy("SIP/office_4201-b80f3570", "") in new stack
[Aug 12 11:45:18] DEBUG[18697]: chan_sip.c:2870 __sip_xmit: Trying to put 'SIP/2.0 48' onto UDP socket destined for 10.50.2.102:5060
[Aug 12 11:45:18] DEBUG[18697]: channel.c:1549 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/office_4201-b80f3570'
[Aug 12 11:45:18] DEBUG[18697]: pbx.c:3779 __ast_pbx_run: Spawn extension (office,9222222,2) exited non-zero on 'SIP/office_4201-b80f3570'
[Aug 12 11:45:18] == Spawn extension (office, 9222222, 2) exited non-zero on 'SIP/office_4201-b80f3570'
[Aug 12 11:45:18] DEBUG[18697]: channel.c:1549 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/office_4201-b80f3570'
[Aug 12 11:45:18] DEBUG[18697]: channel.c:1644 ast_hangup: Hanging up channel 'SIP/office_4201-b80f3570'
[Aug 12 11:45:18] DEBUG[18697]: chan_sip.c:5172 sip_hangup: Hangup call SIP/office_4201-b80f3570, SIP callid 0009433c-deca000f-55b4a49d-6c331953@10.50.2.102
[Aug 12 11:45:18] DEBUG[18376]: chan_sip.c:3367 __sip_ack: Stopping retransmission on '0009433c-deca000f-55b4a49d-6c331953@10.50.2.102' of Response 102: Match Found
[Aug 12 11:45:21] DEBUG[18383]: chan_h323.c:2345 cleanup_connection: Cleaning connection to ip$localhost/21619
[Aug 12 11:45:21] DEBUG[18383]: chan_h323.c:2351 cleanup_connection: No connection for ip$localhost/21619

Comments: By: Badalian Vyacheslav (slavon) 2009-08-12 03:05:54

[Mera]
type=friend
host=85.90.108.3
fastStart=no
prefix=4742
context=incoming
fastStart=yes

_9[12345679]XXXXX => {
Dial(H323/${EXTEN:1}@Mera);
Busy();
}

_989XXXXXXXXX => {
// Dial(H323/${EXTEN:1}@85.90.108.3);
Dial(H323/${EXTEN:1}@Mera);
Busy();
}