Problems with audio

tourmark · April 30, 2007, 10:38am

Hi all,
this is my forst post. Since 2 weeks I try to setup my asterisk on my gentoo linux box.

I CAN MAKE CALL FROM VOIP TELEFONE, BUT ON ANSWER CAN’T HEAR NOTHING. I CAN’T MAKE CALL TO MY VOIP TELEPHONE FROM OUTSIDE

Note: I’m on MAN network with no public address on eth0 (my outside interface), and I use eth1 with private ip’s to local net

I use Eutelia (Italian SIP provider) and this is my configurations:

** is replaced by my

sip.conf:
[general]
account SIP da attivare
realm=voip.eutelia.it ; Dominio del servizio VoIP SIP
port=5060 ; Porta UDP per la segnalazione SIP
srvlookup=yes ; Abilita il DNS SRV per chiamate uscenti
defaultexpirey=330 ; timer di registrazione degli account SIP
useragent=Asterisk_Eut
disallow=all
allow=alaw
allow=ulaw
register => 054117967**:*:054117967@voip.eutelia.it/054117967

[054117967**-out]
type=friend
secret=**** ; password dell’account SIP
username=054117967**; Username (numero telefonico)
fromuser=054117967**
host=voip.eutelia.it ; indirizzo del server SKYPHO
;dtmfmode=inband
context=from_sip ; per la gestione delle chiamate entranti da VoIP
insecure=very
language=it

[100]
context=aladino
type=friend
host=dynamic
username=100
fromuser=100
language=it

extensions.conf:
[from_sip]
exten => s,1,Dial(SIP/100,30,R)
exten => s,2,Hangup

[aladino]
include => outcoming

[outcoming]
exten => _X.,1,Dial(SIP/${EXTEN}@054117967**-out,30,R)
exten => _X.,2,Hangup
;exten => _X.,1,Dial(SIP/${EXTEN}@054117967**-out,30,R)

Rest of configrations is unchanged from default.

when I make a call from inside this debug:
CLI> Apr 30 12:05:01 DEBUG[9401]: chan_sip.c:3176 sip_alloc: Allocating new SIP dialog for 245cb2a8-c0a8010a-13c4-282-8b53a0a-282@192.168.1.254 - INVITE (With RTP)
Apr 30 12:05:01 DEBUG[9401]: chan_sip.c:11274 handle_request: **** Received INVITE (5) - Command in SIP INVITE
Apr 30 12:05:01 DEBUG[9401]: chan_sip.c:7267 check_user_full: Setting NAT on RTP to 0
Apr 30 12:05:01 DEBUG[9401]: chan_sip.c:10634 handle_request_invite: Checking SIP call limits for device 100
Apr 30 12:05:01 DEBUG[9401]: chan_sip.c:2220 update_call_counter: Updating call counter for incoming call
Apr 30 12:05:01 DEBUG[9401]: chan_sip.c:6243 build_route: build_route: Contact hop: sip:100@192.168.1.10:5060
Apr 30 12:05:01 DEBUG[9387]: chan_sip.c:11822 sip_devicestate: Checking device state for peer 100
Apr 30 12:05:01 DEBUG[9387]: devicestate.c:187 do_state_change: Changing state for SIP/100 - state 2 (In use)
Apr 30 12:05:01 DEBUG[9418]: app_queue.c:500 changethread: Device ‘SIP/100’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
Apr 30 12:05:01 DEBUG[9417]: pbx.c:1677 pbx_extension_helper: Launching ‘Dial’
– Executing Dial(“SIP/100-0816a660”, "SIP/3388908888@054117967*-out|30|R") in new stack
Apr 30 12:05:01 DEBUG[9417]: chan_sip.c:3176 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
Apr 30 12:05:01 DEBUG[9417]: chan_sip.c:1888 create_addr_from_peer: Setting NAT on RTP to 0
Apr 30 12:05:01 DEBUG[9417]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-aladino-3388908888-1.
Apr 30 12:05:01 DEBUG[9417]: channel.c:2902 ast_channel_inherit_variables: Not copying variable SIPCALLID.
Apr 30 12:05:01 DEBUG[9417]: channel.c:2902 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT.
Apr 30 12:05:01 DEBUG[9417]: channel.c:2902 ast_channel_inherit_variables: Not copying variable SIPDOMAIN.
Apr 30 12:05:01 DEBUG[9417]: channel.c:2902 ast_channel_inherit_variables: Not copying variable SIPURI.
Apr 30 12:05:01 DEBUG[9417]: chan_sip.c:2082 sip_call: Outgoing Call for 3388908888
Apr 30 12:05:01 DEBUG[9417]: chan_sip.c:2220 update_call_counter: Updating call counter for outgoing call
– Called 3388908888@054117967**-out
Apr 30 12:05:01 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 3126b5b911581609357e3b35485a836a@42.240.39.178 Their Tag Our tag: as51c1288f
Apr 30 12:05:01 DEBUG[9401]: chan_sip.c:1391 __sip_ack: Acked pending invite 102
Apr 30 12:05:01 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘3126b5b911581609357e3b35485a836a@42.240.39.178’ of Request 102: Match Found
Apr 30 12:05:01 DEBUG[9401]: chan_sip.c:9696 handle_response_invite: SIP response 407 to standard invite
Apr 30 12:05:01 DEBUG[9401]: chan_sip.c:9135 do_proxy_auth: Auth attempt 1 on INVITE
Apr 30 12:05:02 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 3126b5b911581609357e3b35485a836a@42.240.39.178 Their Tag Our tag: as51c1288f
Apr 30 12:05:02 DEBUG[9401]: chan_sip.c:1467 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on ‘3126b5b911581609357e3b35485a836a@42.240.39.178’ Request 103: Found
Apr 30 12:05:02 DEBUG[9401]: chan_sip.c:9696 handle_response_invite: SIP response 100 to standard invite
Apr 30 12:05:08 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 3126b5b911581609357e3b35485a836a@42.240.39.178 Their Tag Our tag: as51c1288f
Apr 30 12:05:08 DEBUG[9401]: chan_sip.c:1467 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on ‘3126b5b911581609357e3b35485a836a@42.240.39.178’ Request 103: Found
Apr 30 12:05:08 DEBUG[9401]: chan_sip.c:9696 handle_response_invite: SIP response 183 to standard invite
– SIP/054117967**-out-0818b4b0 is making progress passing it to SIP/100-0816a660
Apr 30 12:05:08 DEBUG[9417]: chan_sip.c:3036 sip_rtp_read: Oooh, format changed to 4
Apr 30 12:05:08 DEBUG[9417]: channel.c:2408 set_format: Set channel SIP/100-0816a660 to read format alaw
Apr 30 12:05:08 DEBUG[9417]: channel.c:2408 set_format: Set channel SIP/100-0816a660 to write format alaw
Apr 30 12:05:08 DEBUG[9417]: rtp.c:1361 ast_rtp_write: Ooh, format changed from unknown to alaw
Apr 30 12:05:08 DEBUG[9417]: rtp.c:411 ast_rtcp_read: Got RTCP report of 44 bytes
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 3126b5b911581609357e3b35485a836a@42.240.39.178 Their Tag 3DF6A598-716 Our tag: as51c1288f
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:1391 __sip_ack: Acked pending invite 103
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘3126b5b911581609357e3b35485a836a@42.240.39.178’ of Request 103: Match Found
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:9696 handle_response_invite: SIP response 200 to standard invite
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:6215 build_route: build_route: Record-Route hop: sip:83.211.227.14;ftag=as51c1288f;lr=on
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:6215 build_route: build_route: Record-Route hop: sip:83.211.227.21;ftag=as51c1288f;lr=on
– SIP/054117967**-out-0818b4b0 answered SIP/100-0816a660
Apr 30 12:05:10 DEBUG[9417]: channel.c:2408 set_format: Set channel SIP/100-0816a660 to read format slin
Apr 30 12:05:10 DEBUG[9417]: channel.c:2408 set_format: Set channel SIP/054117967**-out-0818b4b0 to write format slin
Apr 30 12:05:10 DEBUG[9417]: channel.c:2408 set_format: Set channel SIP/054117967**-out-0818b4b0 to read format slin
Apr 30 12:05:10 DEBUG[9417]: channel.c:2408 set_format: Set channel SIP/100-0816a660 to write format slin
Apr 30 12:05:10 DEBUG[9417]: chan_sip.c:2560 sip_answer: sip_answer(SIP/100-0816a660)
– Attempting native bridge of SIP/100-0816a660 and SIP/054117967**-out-0818b4b0
Apr 30 12:05:10 DEBUG[9417]: chan_sip.c:13089 sip_set_rtp_peer: Deferring reinvite on SIP ‘245cb2a8-c0a8010a-13c4-282-8b53a0a-282@192.168.1.254’ - It’s audio will be redirected to IP 83.211.227.15
Apr 30 12:05:10 DEBUG[9417]: chan_sip.c:13083 sip_set_rtp_peer: Sending reinvite on SIP ‘3126b5b911581609357e3b35485a836a@42.240.39.178’ - It’s audio soon redirected to IP 192.168.1.10
Apr 30 12:05:10 DEBUG[9387]: chan_sip.c:11822 sip_devicestate: Checking device state for peer 054117967**-out
Apr 30 12:05:10 DEBUG[9387]: devicestate.c:187 do_state_change: Changing state for SIP/054117967**-out - state 2 (In use)
Apr 30 12:05:10 DEBUG[9387]: chan_sip.c:11822 sip_devicestate: Checking device state for peer 100
Apr 30 12:05:10 DEBUG[9387]: devicestate.c:187 do_state_change: Changing state for SIP/100 - state 2 (In use)
Apr 30 12:05:10 DEBUG[9427]: app_queue.c:500 changethread: Device ‘SIP/054117967**-out’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
Apr 30 12:05:10 DEBUG[9428]: app_queue.c:500 changethread: Device ‘SIP/100’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 3126b5b911581609357e3b35485a836a@42.240.39.178 Their Tag 3DF6A598-716 Our tag: as51c1288f
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:1467 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on ‘3126b5b911581609357e3b35485a836a@42.240.39.178’ Request 104: Found
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:9694 handle_response_invite: SIP response 100 to RE-invite on outgoing call 3126b5b911581609357e3b35485a836a@42.240.39.178
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:3224 find_call: = No match Their Call ID: 3126b5b911581609357e3b35485a836a@42.240.39.178 Their Tag 3DF6A598-716 Our tag: as51c1288f
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 245cb2a8-c0a8010a-13c4-282-8b53a0a-282@192.168.1.254 Their Tag 245cbf48-c0a8010a-13c4-282-69a331b6-282 Our tag: as666a44c5
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:11274 handle_request: **** Received ACK (6) - Command in SIP ACK
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘245cb2a8-c0a8010a-13c4-282-8b53a0a-282@192.168.1.254’ of Response 1: Match Found
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:9679 check_pendings: Sending pending reinvite on '245cb2a8-c0a8010a-13c4-282-8b53a0a-282@192.168.1.254’
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 3126b5b911581609357e3b35485a836a@42.240.39.178 Their Tag 3DF6A598-716 Our tag: as51c1288f
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:1391 __sip_ack: Acked pending invite 104
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘3126b5b911581609357e3b35485a836a@42.240.39.178’ of Request 104: Match Found
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:9694 handle_response_invite: SIP response 200 to RE-invite on outgoing call 3126b5b911581609357e3b35485a836a@42.240.39.178
Apr 30 12:05:10 DEBUG[9401]: chan_sip.c:6186 build_route: build_route: Retaining previous route: sip:83.211.227.21;ftag=as51c1288f;lr=on
Apr 30 12:05:10 DEBUG[9417]: rtp.c:411 ast_rtcp_read: Got RTCP report of 44 bytes
Apr 30 12:05:11 DEBUG[9401]: chan_sip.c:3224 find_call: = No match Their Call ID: 3126b5b911581609357e3b35485a836a@42.240.39.178 Their Tag 3DF6A598-716 Our tag: as51c1288f
Apr 30 12:05:11 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 245cb2a8-c0a8010a-13c4-282-8b53a0a-282@192.168.1.254 Their Tag 245cbf48-c0a8010a-13c4-282-69a331b6-282 Our tag: as666a44c5
Apr 30 12:05:11 DEBUG[9401]: chan_sip.c:1391 __sip_ack: Acked pending invite 102
Apr 30 12:05:11 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘245cb2a8-c0a8010a-13c4-282-8b53a0a-282@192.168.1.254’ of Request 102: Match Found
Apr 30 12:05:11 DEBUG[9401]: chan_sip.c:9694 handle_response_invite: SIP response 200 to RE-invite on outgoing call 245cb2a8-c0a8010a-13c4-282-8b53a0a-282@192.168.1.254
Apr 30 12:05:11 DEBUG[9401]: chan_sip.c:3765 process_sdp: Oooh, we need to change our formats since our peer supports only 0x8 (alaw) and not 0x4 (ulaw)
Apr 30 12:05:11 DEBUG[9401]: channel.c:2408 set_format: Set channel SIP/100-0816a660 to read format slin
Apr 30 12:05:11 DEBUG[9401]: channel.c:2408 set_format: Set channel SIP/100-0816a660 to write format slin
Apr 30 12:05:11 DEBUG[9401]: chan_sip.c:6243 build_route: build_route: Contact hop: sip:100@192.168.1.10:5060
Apr 30 12:05:11 DEBUG[9417]: chan_sip.c:3036 sip_rtp_read: Oooh, format changed to 4
Apr 30 12:05:11 DEBUG[9417]: channel.c:2408 set_format: Set channel SIP/100-0816a660 to read format slin
Apr 30 12:05:11 DEBUG[9417]: channel.c:2408 set_format: Set channel SIP/100-0816a660 to write format slin
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:3224 find_call: = No match Their Call ID: 3126b5b911581609357e3b35485a836a@42.240.39.178 Their Tag 3DF6A598-716 Our tag: as51c1288f
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 245cb2a8-c0a8010a-13c4-282-8b53a0a-282@192.168.1.254 Their Tag 245cbf48-c0a8010a-13c4-282-69a331b6-282 Our tag: as666a44c5
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:11274 handle_request: **** Received BYE (8) - Command in SIP BYE
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:10923 handle_request_bye: Received bye, issuing owner hangup
.Apr 30 12:05:14 DEBUG[9417]: rtp.c:1722 ast_rtp_bridge: Oooh, got a hangup
Apr 30 12:05:14 DEBUG[9417]: chan_sip.c:13083 sip_set_rtp_peer: Sending reinvite on SIP ‘3126b5b911581609357e3b35485a836a@42.240.39.178’ - It’s audio soon redirected to IP 42.240.39.178
Apr 30 12:05:14 DEBUG[9417]: channel.c:3607 ast_channel_bridge: Returning from native bridge, channels: SIP/100-0816a660, SIP/054117967**-out-0818b4b0
Apr 30 12:05:14 DEBUG[9417]: channel.c:1367 ast_hangup: Hanging up channel 'SIP/054117967**-out-0818b4b0’
Apr 30 12:05:14 DEBUG[9417]: chan_sip.c:2430 sip_hangup: Hangup call SIP/054117967**-out-0818b4b0, SIP callid 3126b5b911581609357e3b35485a836a@42.240.39.178)
Apr 30 12:05:14 DEBUG[9417]: chan_sip.c:2438 sip_hangup: update_call_counter(3388908888) - decrement call limit counter
Apr 30 12:05:14 DEBUG[9417]: chan_sip.c:2220 update_call_counter: Updating call counter for outgoing call
Apr 30 12:05:14 DEBUG[9417]: app_dial.c:1636 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
Apr 30 12:05:14 DEBUG[9417]: pbx.c:2316 __ast_pbx_run: Spawn extension (aladino,3388908888,1) exited non-zero on ‘SIP/100-0816a660’
== Spawn extension (aladino, 3388908888, 1) exited non-zero on 'SIP/100-0816a660’
Apr 30 12:05:14 DEBUG[9387]: chan_sip.c:11822 sip_devicestate: Checking device state for peer 054117967**-out
Apr 30 12:05:14 DEBUG[9387]: devicestate.c:187 do_state_change: Changing state for SIP/054117967**-out - state 1 (Not in use)
Apr 30 12:05:14 DEBUG[9429]: app_queue.c:500 changethread: Device ‘SIP/054117967**-out’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '100’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '100’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '3388908888’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'aladino’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/100-0816a660’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/054117967**-out-0818b4b0’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Dial’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/3388908888@054117967**-out|30|R’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2007-04-30 12:05:01’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2007-04-30 12:05:10’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2007-04-30 12:05:14’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '13’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '4’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'ANSWERED’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)'
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1177927501.2’
Apr 30 12:05:14 DEBUG[9417]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)'
Apr 30 12:05:14 DEBUG[9417]: channel.c:1367 ast_hangup: Hanging up channel 'SIP/100-0816a660’
Apr 30 12:05:14 DEBUG[9417]: chan_sip.c:2430 sip_hangup: Hangup call SIP/100-0816a660, SIP callid 245cb2a8-c0a8010a-13c4-282-8b53a0a-282@192.168.1.254)
Apr 30 12:05:14 DEBUG[9417]: chan_sip.c:2438 sip_hangup: update_call_counter(100) - decrement call limit counter
Apr 30 12:05:14 DEBUG[9417]: chan_sip.c:2220 update_call_counter: Updating call counter for outgoing call
Apr 30 12:05:14 DEBUG[9387]: chan_sip.c:11822 sip_devicestate: Checking device state for peer 100
Apr 30 12:05:14 DEBUG[9387]: devicestate.c:187 do_state_change: Changing state for SIP/100 - state 1 (Not in use)
Apr 30 12:05:14 DEBUG[9430]: app_queue.c:500 changethread: Device ‘SIP/100’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 3126b5b911581609357e3b35485a836a@42.240.39.178 Their Tag 3DF6A598-716 Our tag: as51c1288f
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:1467 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on ‘3126b5b911581609357e3b35485a836a@42.240.39.178’ Request 105: Found
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:9696 handle_response_invite: SIP response 100 to standard invite
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 3126b5b911581609357e3b35485a836a@42.240.39.178 Their Tag 3DF6A598-716 Our tag: as51c1288f
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:1391 __sip_ack: Acked pending invite 105
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘3126b5b911581609357e3b35485a836a@42.240.39.178’ of Request 105: Match Found
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:9696 handle_response_invite: SIP response 200 to standard invite
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:6186 build_route: build_route: Retaining previous route: sip:83.211.227.21;ftag=as51c1288f;lr=on
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 3126b5b911581609357e3b35485a836a@42.240.39.178 Their Tag 3DF6A598-716 Our tag: as51c1288f
Apr 30 12:05:14 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘3126b5b911581609357e3b35485a836a@42.240.39.178’ of Request 106: Match Found
Apr 30 12:08:19 DEBUG[9401]: chan_sip.c:3176 sip_alloc: Allocating new SIP dialog for 5e29b6fe52edadff02da703a1c9a1562@127.0.0.1 - REGISTER (No RTP)
– parse_srv: SRV mapped to host voip.eutelia.it, port 5060
Apr 30 12:08:19 DEBUG[9401]: chan_sip.c:5610 transmit_register: Scheduled a registration timeout for voip.eutelia.it id #27
REGISTER attempt 1 to 054117967**@voip.eutelia.it
Apr 30 12:08:19 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 5e29b6fe52edadff02da703a1c9a1562@127.0.0.1 Their Tag Our tag: as14e95523
Apr 30 12:08:19 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘5e29b6fe52edadff02da703a1c9a1562@127.0.0.1’ of Request 104: Match Found
REGISTER attempt 2 to 054117967**@voip.eutelia.it
Apr 30 12:08:19 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 5e29b6fe52edadff02da703a1c9a1562@127.0.0.1 Their Tag Our tag: as7f1812a6
Apr 30 12:08:19 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘5e29b6fe52edadff02da703a1c9a1562@127.0.0.1’ of Request 105: Match Found
Apr 30 12:08:19 DEBUG[9401]: chan_sip.c:9911 handle_response_register: Registration successful
Apr 30 12:08:19 DEBUG[9401]: chan_sip.c:9913 handle_response_register: Cancelling timeout 27
Apr 30 12:08:51 DEBUG[9401]: chan_sip.c:1335 __sip_autodestruct: Auto destroying call '5e29b6fe52edadff02da703a1c9a1562@127.0.0.1’
Apr 30 12:13:34 DEBUG[9401]: chan_sip.c:3176 sip_alloc: Allocating new SIP dialog for 5e29b6fe52edadff02da703a1c9a1562@127.0.0.1 - REGISTER (No RTP)
– parse_srv: SRV mapped to host voip.eutelia.it, port 5060
Apr 30 12:13:34 DEBUG[9401]: chan_sip.c:5610 transmit_register: Scheduled a registration timeout for voip.eutelia.it id #32
REGISTER attempt 1 to 054117967**@voip.eutelia.it
Apr 30 12:13:34 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 5e29b6fe52edadff02da703a1c9a1562@127.0.0.1 Their Tag Our tag: as7dd4fb9e
Apr 30 12:13:34 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘5e29b6fe52edadff02da703a1c9a1562@127.0.0.1’ of Request 106: Match Found
REGISTER attempt 2 to 054117967**@voip.eutelia.it
Apr 30 12:13:34 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 5e29b6fe52edadff02da703a1c9a1562@127.0.0.1 Their Tag Our tag: as17d008d6
Apr 30 12:13:34 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘5e29b6fe52edadff02da703a1c9a1562@127.0.0.1’ of Request 107: Match Found
Apr 30 12:13:34 DEBUG[9401]: chan_sip.c:9911 handle_response_register: Registration successful
Apr 30 12:13:34 DEBUG[9401]: chan_sip.c:9913 handle_response_register: Cancelling timeout 32
Apr 30 12:14:06 DEBUG[9401]: chan_sip.c:1335 __sip_autodestruct: Auto destroying call '5e29b6fe52edadff02da703a1c9a1562@127.0.0.1’
Apr 30 12:18:49 DEBUG[9401]: chan_sip.c:3176 sip_alloc: Allocating new SIP dialog for 5e29b6fe52edadff02da703a1c9a1562@127.0.0.1 - REGISTER (No RTP)
– parse_srv: SRV mapped to host voip.eutelia.it, port 5060
Apr 30 12:18:49 DEBUG[9401]: chan_sip.c:5610 transmit_register: Scheduled a registration timeout for voip.eutelia.it id #37
REGISTER attempt 1 to 054117967**@voip.eutelia.it
Apr 30 12:18:49 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 5e29b6fe52edadff02da703a1c9a1562@127.0.0.1 Their Tag Our tag: as28bc48bb
Apr 30 12:18:49 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘5e29b6fe52edadff02da703a1c9a1562@127.0.0.1’ of Request 108: Match Found
REGISTER attempt 2 to 054117967**@voip.eutelia.it
Apr 30 12:18:50 DEBUG[9401]: chan_sip.c:3224 find_call: = Found Their Call ID: 5e29b6fe52edadff02da703a1c9a1562@127.0.0.1 Their Tag Our tag: as273a2c89
Apr 30 12:18:50 DEBUG[9401]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘5e29b6fe52edadff02da703a1c9a1562@127.0.0.1’ of Request 109: Match Found
Apr 30 12:18:50 DEBUG[9401]: chan_sip.c:9911 handle_response_register: Registration successful
Apr 30 12:18:50 DEBUG[9401]: chan_sip.c:9913 handle_response_register: Cancelling timeout 37
Apr 30 12:19:22 DEBUG[9401]: chan_sip.c:1335 __sip_autodestruct: Auto destroying call ‘5e29b6fe52edadff02da703a1c9a1562@127.0.0.1’

… and when make call from outside to my VOIP telephone:

*CLI> Apr 30 12:35:48 DEBUG[9715]: chan_sip.c:3176 sip_alloc: Allocating new SIP dialog for 88A6BCA7-F63D11DB-8B79DAFA-324CC9B0@83.211.172.173 - INVITE (With RTP)
Apr 30 12:35:48 DEBUG[9715]: chan_sip.c:11274 handle_request: **** Received INVITE (5) - Command in SIP INVITE
Apr 30 12:35:48 DEBUG[9715]: chan_sip.c:1043 parse_sip_options: * SIP extension value: 5 for call 88A6BCA7-F63D11DB-8B79DAFA-324CC9B0@83.211.172.173
Apr 30 12:35:48 DEBUG[9715]: chan_sip.c:7355 check_user_full: Setting NAT on RTP to 0
Apr 30 12:35:48 DEBUG[9715]: chan_sip.c:10634 handle_request_invite: Checking SIP call limits for device 05411796799
Apr 30 12:35:48 DEBUG[9715]: chan_sip.c:2220 update_call_counter: Updating call counter for incoming call
Apr 30 12:35:48 DEBUG[9715]: chan_sip.c:2220 update_call_counter: Updating call counter for incoming call
Apr 30 12:35:48 DEBUG[9715]: chan_sip.c:3224 find_call: = Found Their Call ID: 88A6BCA7-F63D11DB-8B79DAFA-324CC9B0@83.211.172.173 Their Tag 42A32440-153A Our tag: as703b158a
Apr 30 12:35:48 DEBUG[9715]: chan_sip.c:11274 handle_request: **** Received ACK (6) - Command in SIP ACK
Apr 30 12:35:48 DEBUG[9715]: chan_sip.c:1414 __sip_ack: Stopping retransmission on ‘88A6BCA7-F63D11DB-8B79DAFA-324CC9B0@83.211.172.173’ of Response 102: Match Found

Can someone help me ?
with regards, Alberto.

valley · May 1, 2007, 8:16am

Firewall?

tourmark · May 1, 2007, 3:42pm

Well, for my internal firewall I use shorewall with this rules (from some documentations online):

rules.conf:
[…]
DNAT net loc:192.168.1.10 udp 5060,5061,5004,5005,5006,5007,8000,10000
ACCEPT net $FW udp 4569,5060,5061,10000:20000
ACCEPT loc $FW udp 4569,5060,5061,10000:20000
ACCEPT net $FW udp 7070:7089
[…]
where 192.168.1.10 is my phone ip

I tryed use my softphone on local pc and works ok.
Yesterday I also added this in

rtp.conf:

[general]
rtpstart=8000
rtpend=10000

Thank U for replay.
Alberto

valley · May 1, 2007, 6:35pm

If local agents work fine, it’s almost certainly a firewall/NAT problem. Do you also use NAT?

tourmark · May 2, 2007, 2:36am

Thank U for replay.
I try describe my network.

I have two interfaces on my linux box:
eth0: connected to MAN with IP 42.240.39.178 (this is fixed ip on MAN) but no Public IP -> I don’t know structure of this net but “whatismyip.com” tell me I have outside IP : 81.208.83.249. MAN give my this ip by DHCP and also GW

eth1: is my local net with fixed IP 192.168.1.254 masq to eth0
on the same network is my IP phone with fixed ip: 192.168.1.10
gateway is on local net: 192.168.1.254.

ASTERISK is installed on linux box, I’ve just posted firewall rules.

Yes, my box use NAT for local IP’s, but strange thing is, if I use softphone, work well. Only one difference is that softphone use STUN server.
What do U think I must install stun server ? I’m very confused and U have right, problem is (I think) on my asterisk configuration because debug show me incoming call and outgoing but I can’t hear anything.
I’ve tryed make a call from my IP phone to mobile and he ringing…

Any sugestions ?
Thank a lot for ineteresting of my prob
Alberto.

valley · May 2, 2007, 7:10am

Your network is extremely complicated, but at least I started to see the IP addresses in your debug messages.

Do you mean 192.168.1.1? Or you are really using your Linux box as router? (Not that this is really important.)

Let me attempt to draw a picture.

VoIP phone -- (192.168.1.0/24)
                 |
               eth1 - Asterisk - eth0 -- (42.240.0.0/xx)
                                                  |
VoIP provider --  Internet -- (81.208.0.0/xx) -- NAT

You see, you only opened up host firewall on Asterisk box (I always recommend disable host firewall for testing). What about the NAT firewall in the MAN?

Is it possible to reconfigure VoIP phone to be used in the MAN to test firewall without Asterisk? Alternatively, is it possible to configure another VoIP phone (soft or hard) attached to eth0 to test Asterisk without MAN firewall?