OpenWrt Forum Archive

Topic: Is this router based on the infineon danube?

The content of this topic has been archived between 1 Oct 2014 and 1 May 2018. Unfortunately there are posts – most likely complete pages – missing.

@pippolippi,

thanks for the new svd features. When I have a moment, I will try it.

About svd, firsts tests completed.

Now I can make calls, thanxs, thanxs, thanxs pippolini!!!!

Configuration /etc/config/svd :

config main 
option log_level 5 
option rtp_port_first 5000 
option rtp_port_last 6000 
option sip_tos 0x10 
option rtp_tos 0x10

config account voip1 
option user "+3493XXXXXXX" 
option domain "voipd.ya.com" 
option auth_name "93XXXXXXX"
option password "password1"
option registrar "proxy.voip.ya.com"
option outbound_proxy "proxy.voip.ya.com" 
option display "+3493XXXXXXX" 
option dtmf "rfc2883" 
option codecs "g729 pcma"

Related to the incoming calls, there are still problems, the phone rings but then no sound and svd debug message becomes to send "HLD:492|HLD:492|HLD:492|HLD:492|" for ever. 

Who is voip1?  I suppose it should be my home telephone number...I don't know perhaps it is the mobile dummy account....

inate 200 response
nta_incoming_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2 free
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|nta: received INVITE sip:voip1@89.XXX.XX.XXX SIP/2.0 
(CSeq 50120329)
nta: INVITE (50120329) going to existing leg
nta: sent 200 OK for INVITE (50120329)
Event : nua_i_invite
---[ SIP ]---
INVITE sip:voip1@89.XXX.XX.XXX (CSeq 50120329 INVITE)
        via 84.XX.X.XX:5060
        From: "+3467XXXXXXX" <sip:+3467XXXXXXX@voipd.ya.com>
        To: <sip:voip1@89.XXX.XX.XXX>
---[ === ]---
INCOMING CALL TO  voip1    ---> Who is voip1?  I suppose it should be my home telephone number...I don't know perhaps it is the mobile dummy ACCOUNT....
nua(0x603e78): ready call updated: completed received offer, sent answer
Event : nua_i_state
CALLSTATE NAME : init
Remote sdp:
v=0
o=- 5031900445 1307571805 IN IP4 84.7X.X.XXX
s=SDP Data
c=IN IP4 84.7X.X.XXX
t=0 0
m=audio 11938 RTP/AVP 8 101
a=rtpmap:101 telephone-event/8000
a=ptime:20
Got remote 84.7X.X.XXX:11938 with coder/payload [PCMA/8], fmtp: (null), telephone-event: 101
Local sdp:
v=0
o=- 4986805186065754385 6128786792834473016 IN IP4 89.XXX.XX.XXX
s=-
c=IN IP4 89.XXX.XX.XXX
t=0 0
m=audio 5001 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
HLD:492|nta: received ACK sip:voip1@89.XXX.XX.XXX SIP/2.0 (CSeq 50120329)
nta: ACK (50120329) is going to INVITE (50120329)
Event : nua_i_ack
---[ SIP ]---
ACK sip:voip1@89.XXX.XX.XXX (CSeq 50120329 ACK)
        via 84.XX.X.XX:5060
        From: "+3467XXXXXXX" <sip:+3467XXXXXXX@voipd.ya.com>
        To: <sip:voip1@89.XXX.XX.XXX>
---[ === ]---
nua(0x603e78): ready call updated: ready
Event : nua_i_state
CALLSTATE NAME : init
stop playing tone on [01]
Event : nua_i_active
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|nta: timer I fired, terminate 200 response
nta_incoming_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2 free
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|nta: timer I fired, terminate 200 response
nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|nta: received BYE sip:voip1@89.XXX.XX.XXX SIP/2.0 (CSeq 50120330)
nta: BYE (50120330) going to existing leg
nta: sent 200 OK for BYE (50120330)
Event : nua_i_bye
---[ SIP ]---
BYE sip:voip1@89.XXX.XX.XXX (CSeq 50120330 BYE)
        via 84.XX.X.XX:5060
        From: "+3467XXXXXXX" <sip:+3467XXXXXXX@voipd.ya.com>
        To: <sip:voip1@89.XXX.XX.XXX>
---[ === ]---
BYE received
nua(0x603e78): removing session usage
nua(0x603e78): call state changed: ready -> terminated
Event : nua_i_state
CALLSTATE NAME : init
call on [01] terminated
playing busy tone on [01]
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|
HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|HLD:492|

Another problem I have is that the router usually resets by itself after a time, sometimes 30minutes..... I use the mem command and it shows only 3MB free (total 64MB). I create a swap file in external usb storage disk but problem still appears.... the size of my custom openwrt image is 6,9MB. How can I debug the problem? is it possible to do a complete overlay? or perhaps only the /tmp to the external usb storage? Then I could analyse the logs.....

(Last edited by jjb_wii on 9 Jun 2011, 12:01)

jjb_wii wrote:

Who is voip1?  I suppose it should be my home telephone number...I don't know perhaps it is the mobile dummy account....

it's the name of the account in the configuration, so that's correct.
Regarding the incoming calls, now that I have a complete log I will analyze the problem, but I suspect it's here:

Got remote 84.7X.X.XXX:11938 with coder/payload [PCMA/8], fmtp: (null), telephone-event: 101

(i.e. the "fmtp: (null)" part).

jjb_wii wrote:

Another problem I have is that the router usually resets by itself after a time, sometimes 30minutes..... I use the mem command and it shows only 3MB free (total 64MB). I create a swap file in external usb storage disk but problem still appears.... the size of my custom openwrt image is 6,9MB. How can I debug the problem? is it possible to do a complete overlay? or perhaps only the /tmp to the external usb storage? Then I could analyse the logs.....

No idea, is svd sucking up all the memory or is it caused by something else?

Try plugging the phone in the other socket (I suppose it's currently connected to "Phone 1", so connect it to "Phone 2").
Another way to test is to just ring one line, e.g., if it's plugged to "Phone 1" (and that's not a typo, the first channel is "Phone 2" and the second channel is "Phone 1") add a line

  option ring 'off on'

to the account configuration.
If it works this way, it's a big bug in svd (that I need some time to fix).

(Last edited by pippolippi on 9 Jun 2011, 12:47)

I uploaded a new version of svd that (hopefully) should fix your remaining issues.

Note that I still have an issue on the first channel (marked "Phone 2"): after the first incoming call, it produces an highly pitched tone, and trying to stop svd and/or restart it produces a kernel oops and a router reboot (@jjb_wii, it's possible that's the same issue causing your router to reboot).

I don't know the cause, I think it's due to a too old voice firmware, at least that's what the vmmc/tapi/whatever driver complains about:

WARNING: FW version 12.1.0 too old.  Minimum required FW version is 12.4.0

alas I don't know where to get the required firmware version.

However I noticed that it's related to caller-id: if I disable caller-id on this channel, everything seems to be fine, so I added an "off" value to the caller id option, just add to the svd configuration:

config channel 1
    option cid "off"

(Last edited by pippolippi on 10 Jun 2011, 21:20)

OK, thanks pippolippi.

I will try it. I only need one channel, one simple question.... if I use the second channel (marked "Phone 1") and deactivate the caller-id of the first channel then all should work(with caller-id) and without resets..  is it correct?

Well, I don't know, just try wink

@pippolippi 

Here my results:

1) outgoing calls working ok!! perfect!!!

2) incoming calls working ok but only fails one thing, no sound on the remote caller (I hear myself but not sound on the remote mobile telephone)....

3) Resets/Reboots have disappeared.  (when I will try to activate the caller-id.... highly pitched tone appear and router reboots....I would like to use the caller identification, usually I receive many "useless" calls (telephony operators, marketing, etc...)  )

4) Now I am using socket Phone2 (first channel, marked "Phone 2", like you said) but socket Phone1 works similary....

(Last edited by jjb_wii on 12 Jun 2011, 01:24)

For the missing voice on the remote side I'd need a -d9 log (and even then I cannot guarantee I can fix it). I used ekiga echo server and I could hear the echo (hence voice works both ways) both with outgoing calls and with incoming calls.

In my case caller id works fine on the second channel (Phone 1).

My d9 log:

REGISTER: 200 OK
        Contact: <sip:voip1@89.XXX.XX.XXX>;expires=4500
        Contact: <sip:+34932XXXXXX@89.XXX.XX.XXX:5060;transport=udp>;expires=3139
  ^^^^ svd_r_register() ^^^^
^^^^ svd_nua_callback() ^^^^
outbound(0x7637f8): FAILED to validate <sip:voip1@89.XXX.XX.XXX>
outbound(0x7637f8): FAILED with 503 DNS Error
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_outbound
^^^^ svd_nua_callback() ^^^^
nta: timer set next to 4559 ms
nta: timer K fired, terminate REGISTER (13580047)
outgoing_reclaim_all((nil), (nil), 0x2b6f21bc)
nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/3 term, 1/3 free
nta: timer set next to 102 ms
nta: timer K fired, terminate REGISTER (13580048)
outgoing_reclaim_all((nil), (nil), 0x2b6f21bc)
nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2 free
nta: timer set next to 14 ms
nta: timer K fired, terminate OPTIONS (13580047)
outgoing_reclaim_all((nil), (nil), 0x2b6f21bc)
nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set
tport_wakeup_pri(0x75f950): events IN
tport_recv_event(0x75f950)
tport_recv_iovec(0x75f950) msg 0x762568 from (udp/89.XXX.XX.XXX:5060) has 786 bytes, veclen = 1
tport_deliver(0x75f950): msg 0x762568 (786 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received INVITE sip:voip1@89.XXX.XX.XXX SIP/2.0 (CSeq 3865125)
nta: canonizing sip:voip1@89.XXX.XX.XXX with contact
nta: INVITE (3865125) going to a default leg
nta: timer set to 200 ms
nua: nua_stack_process_request: entering
nua: nh_create: entering
nua: nh_create_handle: entering
nua: nua_stack_set_params: entering
soa_clone(static::0x75d138, 0x759cd0, 0x769a28) called
soa_set_params(static::0x763bb0, ...) called
nta_leg_tcreate(0x763ed8)
soa_init_offer_answer(static::0x763bb0) called
soa_set_remote_sdp(static::0x763bb0, (nil), 0x76900a, 168) called
nua(0x769a28): adding session usage
nua: nua_invite_server_respond: entering
tport_tsend(0x75f950) tpn = UDP/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x75f950): not found by name UDP/84.7X.X.XX:5060
tport_vsend returned 521
nta: sent 180 Ringing for INVITE (3865125)
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_invite
---[ SIP ]---
INVITE sip:voip1@89.XXX.XX.XXX (CSeq 3865125 INVITE)
        via 84.7X.X.XX:5060
        From: "+3467XXXXXXX" <sip:+3467XXXXXXX@voipd.ya.com>
        To: <sip:voip1@89.XXX.XX.XXX>
---[ === ]---
  vvvv svd_i_invite() vvvv
INCOMING CALL TO  voip1
Using from for the caller id
===========> Using cid +3467XXXXXXX, caller name (null)
nua: nua_handle_bind: entering
  ^^^^ svd_i_invite() ^^^^
^^^^ svd_nua_callback() ^^^^
nua(0x769a28): call state changed: init -> early, received offer
soa_get_remote_sdp(static::0x763bb0, [0x2b6f1dc0], [0x2b6f1dc4], [(nil)]) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
Remote sdp:
v=0
o=- 4316200443 1307832537 IN IP4 84.78.2.113
s=SDP Data
c=IN IP4 84.78.2.113
t=0 0
m=audio 15630 RTP/AVP 8 101
a=rtpmap:101 telephone-event/8000
a=ptime:20

    vvvv svd_parse_sdp() vvvv
      vvvv svd_set_te_codec() vvvv
Checking media for telephone-event: PCMA
Checking media for telephone-event: telephone-event
        found!
      ^^^^ svd_set_te_codec() ^^^^
Set parameters for channel 0, remote 84.78.2.113:15630 with coder/payload [PCMA/8], fmtp: (null), telephone-event: 101
      vvvv svd_set_te_codec() vvvv
Checking media for telephone-event: PCMA
Checking media for telephone-event: telephone-event
        found!
      ^^^^ svd_set_te_codec() ^^^^
Set parameters for channel 1, remote 84.78.2.113:15630 with coder/payload [PCMA/8], fmtp: (null), telephone-event: 101
    ^^^^ svd_parse_sdp() ^^^^
  ^^^^ svd_i_state() ^^^^
tport_wakeup_pri(0x75f950): events IN
tport_recv_event(0x75f950)
tport_recv_iovec(0x75f950) msg 0x7672f8 from (udp/89.XXX.XX.XXX:5060) has 838 bytes, veclen = 1
tport_deliver(0x75f950): msg 0x7672f8 (838 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received INVITE sip:+34932XXXXXX@89.XXX.XX.XXX:5060;transport=udp SIP/2.0 (CSeq 3865126)
nta: canonizing sip:+34932XXXXXX@89.XXX.XX.XXX:5060 with contact
nta: INVITE (3865126) going to a default leg
nua: nua_stack_process_request: entering
nua: nh_create: entering
nua: nh_create_handle: entering
^^^^ svd_nua_callback() ^^^^
nua: nua_stack_set_params: entering
soa_clone(static::0x75d138, 0x759cd0, 0x76a250) called
soa_set_params(static::0x7671c8, ...) called
nta_leg_tcreate(0x76a648)
soa_init_offer_answer(static::0x7671c8) called
soa_set_remote_sdp(static::0x7671c8, (nil), 0x7678b6, 168) called
nua(0x76a250): adding session usage
nua: nua_invite_server_respond: entering
tport_tsend(0x75f950) tpn = UDP/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x75f950): not found by name UDP/84.7X.X.XX:5060
tport_vsend returned 547
nta: sent 180 Ringing for INVITE (3865126)
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_invite
---[ SIP ]---
INVITE sip:+34932XXXXXX@89.XXX.XX.XXX:5060;transport=udp (CSeq 3865126 INVITE)
        via 84.7X.X.XX:5060
        From: "+3467XXXXXXX" <sip:+3467XXXXXXX@voipd.ya.com>
        To: <sip:+34932XXXXXX@89.XXX.XX.XXX:5060;transport=udp>
---[ === ]---
  vvvv svd_i_invite() vvvv
INCOMING CALL TO  +34932XXXXXX
nua: nua_respond: entering
nua(0x76a250): sent signal r_respond
nua: nua_handle_destroy: entering
nua(0x76a250): call state changed: init -> early, received offer
soa_get_remote_sdp(static::0x7671c8, [0x2b6f1dc0], [0x2b6f1dc4], [(nil)]) called
nua: nua_stack_set_params: entering
soa_set_params(static::0x7671c8, ...) called
nua: nua_invite_server_respond: entering
soa_clear_remote_sdp(static::0x7671c8) called
tport_tsend(0x75f950) tpn = UDP/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x75f950): not found by name UDP/84.7X.X.XX:5060
tport_vsend returned 500
nta: sent 500 Internal Server Error for INVITE (3865126)
nua(0x76a250): sent signal r_destroy
  ^^^^ svd_i_invite() ^^^^
^^^^ svd_nua_callback() ^^^^
nua: nua_application_event: entering
nua(0x76a250): removing session usage
nua(0x76a250): call state changed: early -> terminated
soa_destroy(static::0x7671c8) called
nta_leg_destroy(0x76a648)
nta_leg_destroy((nil))
tport_wakeup_pri(0x75f950): events IN
tport_recv_event(0x75f950)
tport_recv_iovec(0x75f950) msg 0x767010 from (udp/89.XXX.XX.XXX:5060) has 391 bytes, veclen = 1
tport_deliver(0x75f950): msg 0x767010 (391 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received ACK sip:+34932XXXXXX@89.XXX.XX.XXX:5060;transport=udp SIP/2.0 (CSeq 3865126)
nta: ACK (3865126) is going to INVITE (3865126)
nta: timer set next to 4952 ms
vvvv svd_atab_handler() vvvv
Got unknown event : 0x32000002 on [0/1]
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
Got fxs offhook event: 0x0 on [0/1]
  vvvv svd_handle_event_FXS_OFFHOOK() vvvv
    vvvv svd_clear_call() vvvv
    ^^^^ svd_clear_call() ^^^^
    vvvv svd_answer() vvvv
      vvvv svd_media_tapi_rtp_sock_rebinddev() vvvv
      ^^^^ svd_media_tapi_rtp_sock_rebinddev() ^^^^
nua: nua_respond: entering
nua(0x769a28): sent signal r_respond
nua: nua_get_hparams: entering
nua(0x769a28): sent signal r_get_params
    ^^^^ svd_answer() ^^^^
  ^^^^ svd_handle_event_FXS_OFFHOOK() ^^^^
^^^^ svd_atab_handler() ^^^^
nua: nua_stack_set_params: entering
soa_set_params(static::0x763bb0, ...) called
soa_set_user_sdp(static::0x763bb0, (nil), 0x76bbba, -1) called
soa_set_capability_sdp(static::0x763bb0, (nil), 0x76bbba, -1) called
soa_init_sdp_connection_with_session: selected IN IP4 89.XXX.XX.XXX (a local address)
nua: nua_invite_server_respond: entering
soa_generate_answer(static::0x763bb0) called
soa_static_offer_answer_action(0x763bb0, soa_generate_answer): called
soa_static(0x763bb0, soa_generate_answer): generating local description
soa_static(0x763bb0, soa_generate_answer): upgrade with remote description
soa_sdp_mode_set(0x2b6effc0, 0x764590, ""): called
soa_init_sdp_connection_with_session: using SOATAG_ADDRESS("89.XXX.XX.XXX")
soa_static(0x763bb0, soa_generate_answer): storing local description
soa_activate(static::0x763bb0, (nil)) called
soa_get_local_sdp(static::0x763bb0, [(nil)], [0x2b6f20d8], [0x2b6f20dc]) called
tport_tsend(0x75f950) tpn = UDP/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x75f950): not found by name UDP/84.7X.X.XX:5060
tport_vsend returned 762
nta: sent 200 OK for INVITE (3865125)
nta: timer shortened to 500 ms
nua(0x769a28): call state changed: early -> completed, sent answer
soa_get_local_sdp(static::0x763bb0, [0x2b6f2158], [0x2b6f215c], [(nil)]) called
soa_get_params(static::0x763bb0, ...) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
Local sdp:
v=0
o=- 825751060148318076 1110829611984627307 IN IP4 89.XXX.XX.XXX
s=-
c=IN IP4 89.XXX.XX.XXX
t=0 0
m=audio 5001 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
nua: nua_stack_get_params: entering
soa_get_paramlist(static::0x763bb0, ...) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_get_params
  vvvv svd_r_get_params() vvvv
rm_fmtp: (null)
    vvvv svd_set_te_codec() vvvv
Checking media for telephone-event: PCMA
Checking media for telephone-event: telephone-event
        found!
    ^^^^ svd_set_te_codec() ^^^^
soa::local_sdp_str: "v=0
o=- 825751060148318076 1110829611984627307 IN IP4 89.XXX.XX.XXX
s=-
c=IN IP4 89.XXX.XX.XXX
t=0 0
m=audio 5001 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
"
  ^^^^ svd_r_get_params() ^^^^
^^^^ svd_nua_callback() ^^^^
tport_wakeup_pri(0x75f950): events IN
tport_recv_event(0x75f950)
tport_recv_iovec(0x75f950) msg 0x76a1f0 from (udp/89.XXX.XX.XXX:5060) has 414 bytes, veclen = 1
tport_deliver(0x75f950): msg 0x76a1f0 (414 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received ACK sip:voip1@89.XXX.XX.XXX SIP/2.0 (CSeq 3865125)
nta: ACK (3865125) is going to INVITE (3865125)
nua: process_ack_or_cancel: entering
soa_clear_remote_sdp(static::0x763bb0) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_ack
---[ SIP ]---
ACK sip:voip1@89.XXX.XX.XXX (CSeq 3865125 ACK)
        via 84.7X.X.XX:5060
        From: "+3467XXXXXXX" <sip:+3467XXXXXXX@voipd.ya.com>
        To: <sip:voip1@89.XXX.XX.XXX>
---[ === ]---
^^^^ svd_nua_callback() ^^^^
nua(0x769a28): call state changed: completed -> ready
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
stop playing tone on [00]
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_active
^^^^ svd_nua_callback() ^^^^
vvvv svd_atab_handler() vvvv
Got coder event: 0x1 on [0/1]
^^^^ svd_atab_handler() ^^^^
nta: timer set next to 2341 ms
nta: timer I fired, terminate 500 response
incoming_reclaim_all((nil), (nil), 0x2b6f21bc)
nta_incoming_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2 free
nta: timer set next to 2233 ms
nta: timer I fired, terminate 200 response
incoming_reclaim_all((nil), (nil), 0x2b6f21bc)
nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set
vvvv svd_atab_handler() vvvv
Got fxs onhook event: 0x0 on [0/1]
  vvvv svd_handle_event_FXS_ONHOOK() vvvv
    vvvv svd_bye() vvvv
nua: nua_bye: entering
nua(0x769a28): sent signal r_bye
    ^^^^ svd_bye() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_ONHOOK() ^^^^
^^^^ svd_atab_handler() ^^^^
nua: nua_stack_set_params: entering
soa_set_params(static::0x763bb0, ...) called
soa_terminate(static::0x763bb0) called
soa_init_offer_answer(static::0x763bb0) called
nta: selecting scheme sip
tport_tsend(0x75f950) tpn = */84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x75f950): not found by name */84.7X.X.XX:5060
tport_vsend returned 476
nta: sent BYE (13580076) to */84.7X.X.XX:5060
tport_pend(0x75f950): pending 0x76b908 for udp/89.XXX.XX.XXX:5060 (already 0)
nta: timer set to 32000 ms
nta: timer shortened to 500 ms
tport_wakeup_pri(0x75f950): events IN
tport_recv_event(0x75f950)
tport_recv_iovec(0x75f950) msg 0x76b4b8 from (udp/89.XXX.XX.XXX:5060) has 305 bytes, veclen = 1
tport_deliver(0x75f950): msg 0x76b4b8 (305 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 200 OK for BYE (13580076)
nta: 200 OK is going to a transaction
nta_outgoing: RTT is 71.56 ms
tport_release(0x75f950): 0x76b908 by 0x762568 with 0x76b4b8
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_bye
---[ SIP ]---
200 OK (CSeq 13580076 BYE)
        From: <sip:voip1@89.XXX.XX.XXX>
        To: "+3467XXXXXXX" <sip:+3467XXXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_r_bye() vvvv
got answer on BYE: 200 OK
  ^^^^ svd_r_bye() ^^^^
^^^^ svd_nua_callback() ^^^^
nua(0x769a28): call state changed: terminating -> terminated
nua(0x769a28): removing session usage
soa_destroy(static::0x763bb0) called
nta_leg_destroy(0x763ed8)
nua: terminated session 0x769a28
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
call on [00] terminated
    vvvv svd_clear_call() vvvv
nua: nua_handle_destroy: entering
nua(0x769a28): sent signal r_destroy
    ^^^^ svd_clear_call() ^^^^
playing busy tone on [00]
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
nua: nua_application_event: entering
nta_leg_destroy((nil))
nta: timer set next to 4560 ms
nta: timer K fired, terminate BYE (13580076)
outgoing_reclaim_all((nil), (nil), 0x2b6f21bc)
nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set

Related to the caller id. I use the socked "marked Phone1 --> seccond channel" and set the "config channel 1 -> option cid "off"

(Last edited by jjb_wii on 12 Jun 2011, 02:03)

Unbelievable!
It seems yacom is making two calls in rapid succession, one with "voip1" as the contact (which svd recognizes as belonging to the account) and one with "+34xxx" (which svd ignores since it cannot identify the account).
The first call is the one that goes through, voice parameters are set correctly, so, apart from the double incoming call, I don't see what's wrong.
Maybe the "500 Internal Server Error" sent in reply to the second call confuses the server.
Try commenting out

     nua_respond(nh, SIP_500_INTERNAL_SERVER_ERROR, TAG_END());

at line 685 of svd_ua.c (inside the function svd_i_invite), though I doubt it'll change anything.

Edit: you could also try enabling only the g729 codec.

(Last edited by pippolippi on 12 Jun 2011, 13:35)

OK. Puff,  it seems strange pippolippi....(two incomming calls?? )  today or tomorrow I will try your new indications.

jjb_wii wrote:

OK. Puff,  it seems strange pippolippi....(two incomming calls?? )

Yes, it's there in your log, the first call (3865125):

Event : nua_i_invite
---[ SIP ]---
INVITE sip:voip1@89.XXX.XX.XXX (CSeq 3865125 INVITE)
        via 84.7X.X.XX:5060
        From: "+3467XXXXXXX" <sip:+3467XXXXXXX@voipd.ya.com>
        To: <sip:voip1@89.XXX.XX.XXX>
---[ === ]---

and right after that the second one (2865126):

Event : nua_i_invite
---[ SIP ]---
INVITE sip:+34932XXXXXX@89.XXX.XX.XXX:5060;transport=udp (CSeq 3865126 INVITE)
        via 84.7X.X.XX:5060
        From: "+3467XXXXXXX" <sip:+3467XXXXXXX@voipd.ya.com>
        To: <sip:+34932XXXXXX@89.XXX.XX.XXX:5060;transport=udp>
---[ === ]---

The second one is rejected because the account isn't identified

nta: sent 500 Internal Server Error for INVITE (3865126)

And the first one is accepted when you pick up the phone

nta: sent 200 OK for INVITE (3865125)

OK.

About "500 Internal Server Error"  line 685 of svd_ua.c.

I should replace

        nua_respond(nh, SIP_500_INTERNAL_SERVER_ERROR, TAG_END());
        nua_handle_destroy(nh);
        goto __exit;

with  this code?

    sip_account = su_vector_item(g_conf.sip_account, 0);

or it is better to delete this three lines without  sip_account.....


Edit:

Some important think, I have not propagate your last changes on the 'libab' library on my kernel perhaps because of this the callerid fails..... now I am compiling it before.

(Last edited by jjb_wii on 13 Jun 2011, 00:12)

Just remove the line "nua_respond...", leave everything else in place (I mean, leave the nua_handle_destroy and the goto).
Building the package should have also rebuilt libab.

(Last edited by pippolippi on 13 Jun 2011, 00:47)

With the new uImage the callerid now works ok ( with config "channel 1  -->  option cid "off" ")...... it seems it was my fault I never install the libab only "svd_lantiq.ipk" and sofia.ipk.... because of this I have been using your first "libab" danubevoip version... by the moment no reboots :-)

Related to the codec  I use "g729 pcma" (remote sound for outcoming and no remote sound for incoming),   If I put the "pcma  g729" remote sound no works (no incoming, no outcoming).  With Yacom official config first they use g729....


Now I have ended the test with nua_respond  commented, still no lucky:

REGISTER: 200 OK
        Contact: <sip:voip1@89.1XX.XX.XXX>;expires=4500
        Contact: <sip:voip1@89.1XX.XX.XXX>;expires=1281
  ^^^^ svd_r_register() ^^^^
^^^^ svd_nua_callback() ^^^^
outbound(0x774630): FAILED to validate <sip:voip1@89.1XX.XX.XXX>
outbound(0x774630): FAILED with 503 DNS Error
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_outbound
^^^^ svd_nua_callback() ^^^^
nta: timer set next to 4565 ms
nta: timer K fired, terminate REGISTER (13624145)
outgoing_reclaim_all((nil), (nil), 0x2c03f1bc)
nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/3 term, 1/3 free
nta: timer set next to 106 ms
nta: timer K fired, terminate REGISTER (13624146)
outgoing_reclaim_all((nil), (nil), 0x2c03f1bc)
nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2 free
nta: timer set next to 12 ms
nta: timer K fired, terminate OPTIONS (13624146)
outgoing_reclaim_all((nil), (nil), 0x2c03f1bc)
nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set
vvvv svd_atab_handler() vvvv
Got fxs offhook event: 0x0 on [0/1]
  vvvv svd_handle_event_FXS_OFFHOOK() vvvv
    vvvv svd_answer() vvvv
    ^^^^ svd_answer() ^^^^
play dialtone on [00]
  ^^^^ svd_handle_event_FXS_OFFHOOK() ^^^^
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
  vvvv svd_handle_event_FXS_DIGIT_X() vvvv
[00] DIGIT '6'(l:1,n:0)HN:(nil)
    vvvv svd_handle_digit() vvvv
    ^^^^ svd_handle_digit() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_DIGIT_X() ^^^^
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
Got tone event: 0x2 on [0/1]
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
  vvvv svd_handle_event_FXS_DIGIT_X() vvvv
[00] DIGIT '7'(l:1,n:0)HN:(nil)
    vvvv svd_handle_digit() vvvv
    ^^^^ svd_handle_digit() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_DIGIT_X() ^^^^
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
  vvvv svd_handle_event_FXS_DIGIT_X() vvvv
[00] DIGIT '0'(l:1,n:0)HN:(nil)
    vvvv svd_handle_digit() vvvv
    ^^^^ svd_handle_digit() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_DIGIT_X() ^^^^
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
  vvvv svd_handle_event_FXS_DIGIT_X() vvvv
[00] DIGIT '2'(l:1,n:0)HN:(nil)
    vvvv svd_handle_digit() vvvv
    ^^^^ svd_handle_digit() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_DIGIT_X() ^^^^
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
  vvvv svd_handle_event_FXS_DIGIT_X() vvvv
[00] DIGIT '5'(l:1,n:0)HN:(nil)
    vvvv svd_handle_digit() vvvv
    ^^^^ svd_handle_digit() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_DIGIT_X() ^^^^
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
  vvvv svd_handle_event_FXS_DIGIT_X() vvvv
[00] DIGIT '5'(l:1,n:0)HN:(nil)
    vvvv svd_handle_digit() vvvv
    ^^^^ svd_handle_digit() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_DIGIT_X() ^^^^
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
  vvvv svd_handle_event_FXS_DIGIT_X() vvvv
[00] DIGIT '3'(l:1,n:0)HN:(nil)
    vvvv svd_handle_digit() vvvv
    ^^^^ svd_handle_digit() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_DIGIT_X() ^^^^
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
  vvvv svd_handle_event_FXS_DIGIT_X() vvvv
[00] DIGIT '3'(l:1,n:0)HN:(nil)
    vvvv svd_handle_digit() vvvv
    ^^^^ svd_handle_digit() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_DIGIT_X() ^^^^
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
  vvvv svd_handle_event_FXS_DIGIT_X() vvvv
[00] DIGIT '8'(l:1,n:0)HN:(nil)
    vvvv svd_handle_digit() vvvv
    ^^^^ svd_handle_digit() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_DIGIT_X() ^^^^
^^^^ svd_atab_handler() ^^^^
vvvv svd_invite_to() vvvv
Going to call sip:67XXXXXXX@voipd.ya.com
nua: nh_create_handle: entering
  vvvv svd_media_tapi_rtp_sock_rebinddev() vvvv
  ^^^^ svd_media_tapi_rtp_sock_rebinddev() ^^^^
nua: nua_invite: entering
nua(0x775048): sent signal r_invite
^^^^ svd_invite_to() ^^^^
nua: nua_stack_set_params: entering
soa_clone(static::0x76e138, 0x76acd0, 0x775048) called
soa_set_params(static::0x773c98, ...) called
soa_set_params(static::0x773c98, ...) called
soa_set_user_sdp(static::0x773c98, (nil), 0x773c08, -1) called
soa_set_capability_sdp(static::0x773c98, (nil), 0x773c08, -1) called
soa_init_sdp_connection_with_session: selected IN IP4 89.1XX.XX.XXX (a local address)
nua(0x775048): adding session usage
nta_leg_tcreate(0x7751d8)
soa_init_offer_answer(static::0x773c98) called
soa_generate_offer(static::0x773c98, 0) called
soa_static_offer_answer_action(0x773c98, soa_generate_offer): called
soa_static(0x773c98, soa_generate_offer): generating local description
soa_static(0x773c98, soa_generate_offer): upgrade with local description
soa_sdp_mode_set(0x2c03cf78, (nil), ""): called
soa_init_sdp_connection_with_session: using SOATAG_ADDRESS("89.1XX.XX.XXX")
soa_static(0x773c98, soa_generate_offer): storing local description
soa_get_local_sdp(static::0x773c98, [(nil)], [0x2c03f090], [0x2c03f094]) called
nta: selecting scheme sip
sres_cache_get(0x76fd20, NAPTR, "proxy.voip.ya.com.") called
sres_cache_get(0x76fd20, NAPTR, "proxy.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy.voip.ya.com" NAPTR (cached)
sres_cache_get(0x76fd20, SRV, "_sip._udp.proxy.voip.ya.com.") called
sres_cache_get(0x76fd20, SRV, "_sip._udp.proxy.voip.ya.com.") returned 2 entries
nta: for "proxy.voip.ya.com" query "_sip._udp.proxy.voip.ya.com" SRV (cached)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy1.voip.ya.com. (udp)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy2.voip.ya.com. (udp)
sres_cache_get(0x76fd20, AAAA, "proxy1.voip.ya.com.") called
sres_cache_get(0x76fd20, AAAA, "proxy1.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy1.voip.ya.com." AAAA (cached)
nta(0x779d88): proxy1.voip.ya.com. A record still unresolved
sres_cache_get(0x76fd20, A, "proxy1.voip.ya.com.") called
sres_cache_get(0x76fd20, A, "proxy1.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy1.voip.ya.com." A (cached)
nta: proxy1.voip.ya.com. IN A 84.XX.X.XX
tport_tsend(0x770950) tpn = udp/84.XX.X.XX:5060
tport_resolve addrinfo = 84.XX.X.XX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.XX.X.XX:5060
tport_vsend returned 808
nta: sent INVITE (13624161) to udp/84.XX.X.XX:5060
tport_pend(0x770950): pending 0x776810 for udp/89.1XX.XX.XXX:5060 (already 0)
nta: timer set to 32000 ms
nta: timer shortened to 500 ms
nua(0x775048): call state changed: init -> calling, sent offer
soa_get_local_sdp(static::0x773c98, [0x2c03f058], [0x2c03f05c], [(nil)]) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
Local sdp:
v=0
o=- 2538976139942479331 4529527436623036693 IN IP4 89.1XX.XX.XXX
s=-
c=IN IP4 89.1XX.XX.XXX
t=0 0
m=audio 5001 RTP/AVP 18 8 106
a=rtpmap:18 G729/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 telephone-event/8000
a=fmtp:106 0-16

  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x77a810 from (udp/89.1XX.XX.XXX:5060) has 539 bytes, veclen = 1
tport_deliver(0x770950): msg 0x77a810 (539 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 401 Unauthorized for INVITE (13624161)
nta: 401 Unauthorized is going to a transaction
nta_outgoing: RTT is 81.144 ms
tport_release(0x770950): 0x776810 by 0x779d88 with 0x77a810
tport_tsend(0x770950) tpn = udp/84.XX.X.XX:5060
tport_resolve addrinfo = 84.XX.X.XX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.XX.X.XX:5060
tport_vsend returned 329
nta: sent ACK (13624161) to udp/84.XX.X.XX:5060
nta: outgoing_free(0x775de0)
auth_digest_challenge_get(): got 5
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_invite
---[ SIP ]---
401 Unauthorized (CSeq 13624161 INVITE)
        From: "+34932XXXXXX" <sip:+34932XXXXXX@voipd.ya.com>
        To: <sip:67XXXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_r_invite() vvvv
got answer on INVITE: 401 Unauthorized
    vvvv svd_authenticate() vvvv
Server auth: Digest algorithm=MD5, nonce="052dc21f48d88b420465d1aae33f719846556c5cf0f5ef29f5132d0b6448e95c", opaque="052dc21f48d88b420465d1aae33f719846556c5cf0f5ef29f5132d0b6448e95c", realm="DIRECTO-YA"
AUTHENTICATING WITH 'Digest:"DIRECTO-YA":932XXXXXX:eooo'.
nua: nua_authenticate: entering
nua(0x775048): sent signal r_authenticate
    ^^^^ svd_authenticate() ^^^^
  ^^^^ svd_r_invite() ^^^^
^^^^ svd_nua_callback() ^^^^
auth_digest_ha1() has A1 = MD5(932XXXXXX:"DIRECTO-YA":*******) = a16460c835108e19099210a142db65b3
soa_init_offer_answer(static::0x773c98) called
soa_generate_offer(static::0x773c98, 0) called
soa_static_offer_answer_action(0x773c98, soa_generate_offer): called
soa_sdp_mode_set(0x776ee0, (nil), ""): called
soa_get_local_sdp(static::0x773c98, [(nil)], [0x2c03f0b0], [0x2c03f0b4]) called
A2 = MD5(INVITE:sip:67XXXXXXX@voipd.ya.com)
auth_response: 63280d081edc20afff35232b96f17941 = MD5(a16460c835108e19099210a142db65b3:052dc21f48d88b420465d1aae33f719846556c5cf0f5ef29f5132d0b6448e95c:7731410336f28d6bea915c2e3ba28b43) (qop=NONE)
nta: selecting scheme sip
sres_cache_get(0x76fd20, NAPTR, "proxy.voip.ya.com.") called
sres_cache_get(0x76fd20, NAPTR, "proxy.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy.voip.ya.com" NAPTR (cached)
sres_cache_get(0x76fd20, SRV, "_sip._udp.proxy.voip.ya.com.") called
sres_cache_get(0x76fd20, SRV, "_sip._udp.proxy.voip.ya.com.") returned 2 entries
nta: for "proxy.voip.ya.com" query "_sip._udp.proxy.voip.ya.com" SRV (cached)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy1.voip.ya.com. (udp)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy2.voip.ya.com. (udp)
sres_cache_get(0x76fd20, AAAA, "proxy1.voip.ya.com.") called
sres_cache_get(0x76fd20, AAAA, "proxy1.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy1.voip.ya.com." AAAA (cached)
nta(0x77aea0): proxy1.voip.ya.com. A record still unresolved
sres_cache_get(0x76fd20, A, "proxy1.voip.ya.com.") called
sres_cache_get(0x76fd20, A, "proxy1.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy1.voip.ya.com." A (cached)
nta: proxy1.voip.ya.com. IN A 84.XX.X.XX
tport_tsend(0x770950) tpn = udp/84.XX.X.XX:5060
tport_resolve addrinfo = 84.XX.X.XX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.XX.X.XX:5060
tport_vsend returned 1115
nta: sent INVITE (13624162) to udp/84.XX.X.XX:5060
tport_pend(0x770950): pending 0x775790 for udp/89.1XX.XX.XXX:5060 (already 0)
nua(0x775048): call state changed: calling -> calling, sent offer
soa_get_local_sdp(static::0x773c98, [0x2c03f078], [0x2c03f07c], [(nil)]) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
Local sdp:
v=0
o=- 2538976139942479331 4529527436623036693 IN IP4 89.1XX.XX.XXX
s=-
c=IN IP4 89.1XX.XX.XXX
t=0 0
m=audio 5001 RTP/AVP 18 8 106
a=rtpmap:18 G729/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 telephone-event/8000
a=fmtp:106 0-16

  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x77b8e8 from (udp/89.1XX.XX.XXX:5060) has 315 bytes, veclen = 1
tport_deliver(0x770950): msg 0x77b8e8 (315 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 100 INTENTANDO for INVITE (13624162)
nta: 100 INTENTANDO is going to a transaction
nta_outgoing: RTT is 87.718 ms
tport_release(0x770950): 0x775790 by 0x77aea0 with 0x77b8e8 (preliminary)
nta: timer set next to 31573 ms
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x77b8e8 from (udp/89.1XX.XX.XXX:5060) has 699 bytes, veclen = 1
tport_deliver(0x770950): msg 0x77b8e8 (699 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 180 LLAMANDO for INVITE (13624162)
nta: 180 LLAMANDO is going to a transaction
tport_release(0x770950): 0x775790 by 0x77aea0 with 0x77b8e8 (preliminary)
soa_set_remote_sdp(static::0x773c98, (nil), 0x77be1b, 168) called
soa_process_answer(static::0x773c98) called
soa_static_offer_answer_action(0x773c98, soa_process_answer): called
soa_sdp_mode_set(0x776ee0, 0x77c540, ""): called
soa_static(0x773c98, soa_process_answer): upgrade codecs with remote description
soa_static(0x773c98, soa_process_answer): storing local description
soa_activate(static::0x773c98, (nil)) called
nua(0x775048): INVITE: processed SDP answer in 180 LLAMANDO
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_invite
---[ SIP ]---
180 LLAMANDO (CSeq 13624162 INVITE)
        From: "+34932XXXXXX" <sip:+34932XXXXXX@voipd.ya.com>
        To: <sip:67XXXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_r_invite() vvvv
got answer on INVITE: 180 LLAMANDO
  ^^^^ svd_r_invite() ^^^^
^^^^ svd_nua_callback() ^^^^
nua(0x775048): call state changed: calling -> proceeding, received answer
soa_get_remote_sdp(static::0x773c98, [0x2c03ec48], [0x2c03ec4c], [(nil)]) called
soa_get_params(static::0x773c98, ...) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
Remote sdp:
v=0
o=- 4872101020 1307920733 IN IP4 84.78.2.114
s=SDP Data
c=IN IP4 84.78.2.114
t=0 0
m=audio 9760 RTP/AVP 18 106
a=rtpmap:106 telephone-event/8000
a=ptime:20

    vvvv svd_parse_sdp() vvvv
      vvvv svd_set_te_codec() vvvv
Checking media for telephone-event: G729
Checking media for telephone-event: telephone-event
        found!
      ^^^^ svd_set_te_codec() ^^^^
Set parameters for channel 1, remote 84.78.2.114:9760 with coder/payload [G729/18], fmtp: (null), telephone-event: 106
    ^^^^ svd_parse_sdp() ^^^^
play ringback on [00]
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x776ee0 from (udp/89.1XX.XX.XXX:5060) has 704 bytes, veclen = 1
tport_deliver(0x770950): msg 0x776ee0 (704 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13624162)
nta: 200 OK is going to a transaction
tport_release(0x770950): 0x775790 by 0x77aea0 with 0x776ee0
nua(0x775048): INVITE: ignoring duplicate SDP in 200 OK
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_invite
---[ SIP ]---
200 OK (CSeq 13624162 INVITE)
        From: "+34932XXXXXX" <sip:+34932XXXXXX@voipd.ya.com>
        To: <sip:67XXXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_r_invite() vvvv
got answer on INVITE: 200 OK
  ^^^^ svd_r_invite() ^^^^
^^^^ svd_nua_callback() ^^^^
soa_activate(static::0x773c98, (nil)) called
nta: selecting scheme sip
sres_cache_get(0x76fd20, NAPTR, "proxy.voip.ya.com.") called
sres_cache_get(0x76fd20, NAPTR, "proxy.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy.voip.ya.com" NAPTR (cached)
sres_cache_get(0x76fd20, SRV, "_sip._udp.proxy.voip.ya.com.") called
sres_cache_get(0x76fd20, SRV, "_sip._udp.proxy.voip.ya.com.") returned 2 entries
nta: for "proxy.voip.ya.com" query "_sip._udp.proxy.voip.ya.com" SRV (cached)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy2.voip.ya.com. (udp)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy1.voip.ya.com. (udp)
sres_cache_get(0x76fd20, AAAA, "proxy2.voip.ya.com.") called
nta: for "proxy.voip.ya.com" query "proxy2.voip.ya.com." AAAA
sres_query(0x76fba8, 0x77d4d0, AAAA, "proxy2.voip.ya.com.") called
sres_send_dns_query(0x76fba8, 0x77d700) called
sres_send_dns_query(0x76fba8, 0x77d700) id=12114 AAAA proxy2.voip.ya.com. (to [127.0.0.1]:53)
nua(0x775048): call state changed: proceeding -> ready
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
stop playing tone on [00]
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
vvvv svd_atab_handler() vvvv
Got tone event: 0x2 on [0/1]
^^^^ svd_atab_handler() ^^^^
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_active
^^^^ svd_nua_callback() ^^^^
sres_resolver_receive(0x76fba8, 25) called
AUTHORITY RR received ya.com. SOA IN 300 rdlen=57
sres(q=0x77d700): reporting error RECORD_ERR for AAAA proxy2.voip.ya.com.
nta(0x77d4d0): proxy2.voip.ya.com. A record still unresolved
sres_cache_get(0x76fd20, A, "proxy2.voip.ya.com.") called
sres_cache_get(0x76fd20, A, "proxy2.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy2.voip.ya.com." A (cached)
nta: proxy2.voip.ya.com. IN A 84.7X.X.XXX
tport_tsend(0x770950) tpn = udp/84.7X.X.XXX:5060
tport_resolve addrinfo = 84.7X.X.XXX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.7X.X.XXX:5060
tport_vsend returned 641
nta: sent ACK (13624162) to udp/84.7X.X.XXX:5060
vvvv svd_atab_handler() vvvv
Got coder event: 0x1 on [0/1]
^^^^ svd_atab_handler() ^^^^
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x77e110 from (udp/89.1XX.XX.XXX:5060) has 704 bytes, veclen = 1
tport_deliver(0x770950): msg 0x77e110 (704 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13624162)
nta: 200 OK is going to a transaction
nta_outgoing: RTT is 302.118 ms
tport_tsend(0x770950) tpn = udp/84.7X.X.XXX:5060
tport_resolve addrinfo = 84.7X.X.XXX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.7X.X.XXX:5060
tport_vsend returned 641
nta: resent ACK (13624162) to udp/84.7X.X.XXX:5060
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x77e110 from (udp/89.1XX.XX.XXX:5060) has 704 bytes, veclen = 1
tport_deliver(0x770950): msg 0x77e110 (704 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13624162)
nta: 200 OK is going to a transaction
tport_tsend(0x770950) tpn = udp/84.7X.X.XXX:5060
tport_resolve addrinfo = 84.7X.X.XXX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.7X.X.XXX:5060
tport_vsend returned 641
nta: resent ACK (13624162) to udp/84.7X.X.XXX:5060
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x77e110 from (udp/89.1XX.XX.XXX:5060) has 704 bytes, veclen = 1
tport_deliver(0x770950): msg 0x77e110 (704 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13624162)
nta: 200 OK is going to a transaction
tport_tsend(0x770950) tpn = udp/84.7X.X.XXX:5060
tport_resolve addrinfo = 84.7X.X.XXX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.7X.X.XXX:5060
tport_vsend returned 641
nta: resent ACK (13624162) to udp/84.7X.X.XXX:5060
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x77e110 from (udp/89.1XX.XX.XXX:5060) has 704 bytes, veclen = 1
tport_deliver(0x770950): msg 0x77e110 (704 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13624162)
nta: 200 OK is going to a transaction
tport_tsend(0x770950) tpn = udp/84.7X.X.XXX:5060
tport_resolve addrinfo = 84.7X.X.XXX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.7X.X.XXX:5060
tport_vsend returned 641
nta: resent ACK (13624162) to udp/84.7X.X.XXX:5060
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x77e110 from (udp/89.1XX.XX.XXX:5060) has 704 bytes, veclen = 1
tport_deliver(0x770950): msg 0x77e110 (704 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13624162)
nta: 200 OK is going to a transaction
tport_tsend(0x770950) tpn = udp/84.7X.X.XXX:5060
tport_resolve addrinfo = 84.7X.X.XXX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.7X.X.XXX:5060
tport_vsend returned 641
nta: resent ACK (13624162) to udp/84.7X.X.XXX:5060
vvvv svd_atab_handler() vvvv
Got fxs onhook event: 0x0 on [0/1]
  vvvv svd_handle_event_FXS_ONHOOK() vvvv
    vvvv svd_bye() vvvv
nua: nua_bye: entering
nua: nua_stack_set_params: entering
soa_set_params(static::0x773c98, ...) called
soa_terminate(static::0x773c98) called
soa_init_offer_answer(static::0x773c98) called
A2 = MD5(BYE:sip:TASP001_CH2@84.XX.X.XX:5060)
auth_response: 3974441a1a54bb4cebb9717d16b42fd2 = MD5(a16460c835108e19099210a142db65b3:052dc21f48d88b420465d1aae33f719846556c5cf0f5ef29f5132d0b6448e95c:af0b9e460945895454c486b083d40ed9) (qop=NONE)
nua(0x775048): sent signal r_bye
    ^^^^ svd_bye() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_ONHOOK() ^^^^
^^^^ svd_atab_handler() ^^^^
nta: selecting scheme sip
sres_cache_get(0x76fd20, NAPTR, "proxy.voip.ya.com.") called
sres_cache_get(0x76fd20, NAPTR, "proxy.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy.voip.ya.com" NAPTR (cached)
sres_cache_get(0x76fd20, SRV, "_sip._udp.proxy.voip.ya.com.") called
sres_cache_get(0x76fd20, SRV, "_sip._udp.proxy.voip.ya.com.") returned 2 entries
nta: for "proxy.voip.ya.com" query "_sip._udp.proxy.voip.ya.com" SRV (cached)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy2.voip.ya.com. (udp)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy1.voip.ya.com. (udp)
sres_cache_get(0x76fd20, AAAA, "proxy2.voip.ya.com.") called
sres_cache_get(0x76fd20, AAAA, "proxy2.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy2.voip.ya.com." AAAA (cached)
nta(0x77e460): proxy2.voip.ya.com. A record still unresolved
sres_cache_get(0x76fd20, A, "proxy2.voip.ya.com.") called
sres_cache_get(0x76fd20, A, "proxy2.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy2.voip.ya.com." A (cached)
nta: proxy2.voip.ya.com. IN A 84.7X.X.XXX
tport_tsend(0x770950) tpn = udp/84.7X.X.XXX:5060
tport_resolve addrinfo = 84.7X.X.XXX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.7X.X.XXX:5060
tport_vsend returned 798
nta: sent BYE (13624163) to udp/84.7X.X.XXX:5060
tport_pend(0x770950): pending 0x77cdd8 for udp/89.1XX.XX.XXX:5060 (already 0)
nta: timer shortened to 500 ms
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x77f0f0 from (udp/89.1XX.XX.XXX:5060) has 346 bytes, veclen = 1
tport_deliver(0x770950): msg 0x77f0f0 (346 bytes) from udp/84.7X.X.XXX:5060/sip next=(nil)
nta: received 481 Call/Transaction Does Not Exist for BYE (13624163)
nta: 481 Call/Transaction Does Not Exist is going to a transaction
nta_outgoing: RTT is 78.003 ms
tport_release(0x770950): 0x77cdd8 by 0x77e460 with 0x77f0f0
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_bye
---[ SIP ]---
481 Call/Transaction Does Not Exist (CSeq 13624163 BYE)
        From: "+34932XXXXXX" <sip:+34932XXXXXX@voipd.ya.com>
        To: <sip:67XXXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_r_bye() vvvv
got answer on BYE: 481 Call/Transaction Does Not Exist
  ^^^^ svd_r_bye() ^^^^
^^^^ svd_nua_callback() ^^^^
nua(0x775048): call state changed: terminating -> terminated
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
call on [00] terminated
nua(0x775048): removing session usage
soa_destroy(static::0x773c98) called
nta_leg_destroy(0x7751d8)
nua: terminated session 0x775048
nta_leg_destroy((nil))
    vvvv svd_clear_call() vvvv
nua: nua_handle_destroy: entering
nua(0x775048): sent signal r_destroy
    ^^^^ svd_clear_call() ^^^^
playing busy tone on [00]
  ^^^^ svd_i_state() ^^^^
nta_leg_destroy((nil))
^^^^ svd_nua_callback() ^^^^
nua: nua_application_event: entering
nta: timer set next to 4571 ms
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x775cc8 from (udp/89.1XX.XX.XXX:5060) has 704 bytes, veclen = 1
tport_deliver(0x770950): msg 0x775cc8 (704 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13624162)
nta: 200 OK is going to a transaction
tport_tsend(0x770950) tpn = udp/84.7X.X.XXX:5060
tport_resolve addrinfo = 84.7X.X.XXX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.7X.X.XXX:5060
tport_vsend returned 641
nta: resent ACK (13624162) to udp/84.7X.X.XXX:5060
nta: timer K fired, terminate BYE (13624163)
outgoing_reclaim_all((nil), (nil), 0x2c03f1bc)
nta_outgoing_timer: 0/0 resent, 0/1 tout, 1/3 term, 1/4 free
nta: timer set next to 7882 ms
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x773b60 from (udp/89.1XX.XX.XXX:5060) has 704 bytes, veclen = 1
tport_deliver(0x770950): msg 0x773b60 (704 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13624162)
nta: 200 OK is going to a transaction
tport_tsend(0x770950) tpn = udp/84.7X.X.XXX:5060
tport_resolve addrinfo = 84.7X.X.XXX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.7X.X.XXX:5060
tport_vsend returned 641
nta: resent ACK (13624162) to udp/84.7X.X.XXX:5060
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x773b60 from (udp/89.1XX.XX.XXX:5060) has 704 bytes, veclen = 1
tport_deliver(0x770950): msg 0x773b60 (704 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13624162)
nta: 200 OK is going to a transaction
tport_tsend(0x770950) tpn = udp/84.7X.X.XXX:5060
tport_resolve addrinfo = 84.7X.X.XXX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.7X.X.XXX:5060
tport_vsend returned 641
nta: resent ACK (13624162) to udp/84.7X.X.XXX:5060
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x773b60 from (udp/89.1XX.XX.XXX:5060) has 786 bytes, veclen = 1
tport_deliver(0x770950): msg 0x773b60 (786 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received INVITE sip:voip1@89.1XX.XX.XXX SIP/2.0 (CSeq 4764234)
nta: canonizing sip:voip1@89.1XX.XX.XXX with contact
nta: INVITE (4764234) going to a default leg
nta: timer shortened to 200 ms
nua: nua_stack_process_request: entering
nua: nh_create: entering
nua: nh_create_handle: entering
nua: nua_stack_set_params: entering
soa_clone(static::0x76e138, 0x76acd0, 0x773ec0) called
soa_set_params(static::0x778cc8, ...) called
nta_leg_tcreate(0x773f58)
soa_init_offer_answer(static::0x778cc8) called
soa_set_remote_sdp(static::0x778cc8, (nil), 0x77c2da, 168) called
nua(0x773ec0): adding session usage
nua: nua_invite_server_respond: entering
tport_tsend(0x770950) tpn = UDP/84.XX.X.XX:5060
tport_resolve addrinfo = 84.XX.X.XX:5060
tport_by_addrinfo(0x770950): not found by name UDP/84.XX.X.XX:5060
tport_vsend returned 521
nta: sent 180 Ringing for INVITE (4764234)
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_invite
---[ SIP ]---
INVITE sip:voip1@89.1XX.XX.XXX (CSeq 4764234 INVITE)
        via 84.XX.X.XX:5060
        From: "+3467XXXXXXX" <sip:+3467XXXXXXX@voipd.ya.com>
        To: <sip:voip1@89.1XX.XX.XXX>
---[ === ]---
  vvvv svd_i_invite() vvvv
INCOMING CALL TO  voip1
Using from for the caller id
===========> Using cid +3467XXXXXXX, caller name (null)
nua: nua_handle_bind: entering
  ^^^^ svd_i_invite() ^^^^
^^^^ svd_nua_callback() ^^^^
nua(0x773ec0): call state changed: init -> early, received offer
soa_get_remote_sdp(static::0x778cc8, [0x2c03edc0], [0x2c03edc4], [(nil)]) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
Remote sdp:
v=0
o=- 3861200002 1307920764 IN IP4 84.78.2.110
s=SDP Data
c=IN IP4 84.78.2.110
t=0 0
m=audio 14510 RTP/AVP 8 101
a=rtpmap:101 telephone-event/8000
a=ptime:20

    vvvv svd_parse_sdp() vvvv
      vvvv svd_set_te_codec() vvvv
Checking media for telephone-event: PCMA
Checking media for telephone-event: telephone-event
        found!
      ^^^^ svd_set_te_codec() ^^^^
Set parameters for channel 0, remote 84.78.2.110:14510 with coder/payload [PCMA/8], fmtp: (null), telephone-event: 101
      vvvv svd_set_te_codec() vvvv
Checking media for telephone-event: PCMA
Checking media for telephone-event: telephone-event
        found!
      ^^^^ svd_set_te_codec() ^^^^
Set parameters for channel 1, remote 84.78.2.110:14510 with coder/payload [PCMA/8], fmtp: (null), telephone-event: 101
    ^^^^ svd_parse_sdp() ^^^^
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
nta: timer set next to 691 ms
nta: timer D fired, terminate INVITE (13624161)
outgoing_reclaim_all((nil), (nil), 0x2c03f1bc)
nta_outgoing_timer: 0/0 resent, 0/1 tout, 1/2 term, 1/3 free
nta: timer set next to 5456 ms
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x7752f8 from (udp/89.1XX.XX.XXX:5060) has 704 bytes, veclen = 1
tport_deliver(0x770950): msg 0x7752f8 (704 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13624162)
nta: 200 OK is going to a transaction
tport_tsend(0x770950) tpn = udp/84.7X.X.XXX:5060
tport_resolve addrinfo = 84.7X.X.XXX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.7X.X.XXX:5060
tport_vsend returned 641
nta: resent ACK (13624162) to udp/84.7X.X.XXX:5060
vvvv svd_atab_handler() vvvv
Got unknown event : 0x32000002 on [0/1]
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
Got fxs offhook event: 0x0 on [0/1]
  vvvv svd_handle_event_FXS_OFFHOOK() vvvv
    vvvv svd_clear_call() vvvv
    ^^^^ svd_clear_call() ^^^^
    vvvv svd_answer() vvvv
      vvvv svd_media_tapi_rtp_sock_rebinddev() vvvv
      ^^^^ svd_media_tapi_rtp_sock_rebinddev() ^^^^
nua: nua_respond: entering
nua(0x773ec0): sent signal r_respond
nua: nua_get_hparams: entering
nua(0x773ec0): sent signal r_get_params
    ^^^^ svd_answer() ^^^^
  ^^^^ svd_handle_event_FXS_OFFHOOK() ^^^^
^^^^ svd_atab_handler() ^^^^
nua: nua_stack_set_params: entering
soa_set_params(static::0x778cc8, ...) called
soa_set_user_sdp(static::0x778cc8, (nil), 0x777322, -1) called
soa_set_capability_sdp(static::0x778cc8, (nil), 0x777322, -1) called
soa_init_sdp_connection_with_session: selected IN IP4 89.1XX.XX.XXX (a local address)
nua: nua_invite_server_respond: entering
soa_generate_answer(static::0x778cc8) called
soa_static_offer_answer_action(0x778cc8, soa_generate_answer): called
soa_static(0x778cc8, soa_generate_answer): generating local description
soa_static(0x778cc8, soa_generate_answer): upgrade with remote description
soa_sdp_mode_set(0x2c03cfc0, 0x77e628, ""): called
soa_init_sdp_connection_with_session: using SOATAG_ADDRESS("89.1XX.XX.XXX")
soa_static(0x778cc8, soa_generate_answer): storing local description
soa_activate(static::0x778cc8, (nil)) called
soa_get_local_sdp(static::0x778cc8, [(nil)], [0x2c03f0d8], [0x2c03f0dc]) called
tport_tsend(0x770950) tpn = UDP/84.XX.X.XX:5060
tport_resolve addrinfo = 84.XX.X.XX:5060
tport_by_addrinfo(0x770950): not found by name UDP/84.XX.X.XX:5060
tport_vsend returned 763
nta: sent 200 OK for INVITE (4764234)
nta: timer shortened to 500 ms
nua(0x773ec0): call state changed: early -> completed, sent answer
soa_get_local_sdp(static::0x778cc8, [0x2c03f158], [0x2c03f15c], [(nil)]) called
soa_get_params(static::0x778cc8, ...) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
nua: nua_stack_get_params: entering
soa_get_paramlist(static::0x778cc8, ...) called
Local sdp:
v=0
o=- 3858154162693524999 1667993583865482717 IN IP4 89.1XX.XX.XXX
s=-
c=IN IP4 89.1XX.XX.XXX
t=0 0
m=audio 5001 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_get_params
  vvvv svd_r_get_params() vvvv
rm_fmtp: (null)
    vvvv svd_set_te_codec() vvvv
Checking media for telephone-event: PCMA
Checking media for telephone-event: telephone-event
        found!
    ^^^^ svd_set_te_codec() ^^^^
soa::local_sdp_str: "v=0
o=- 3858154162693524999 1667993583865482717 IN IP4 89.1XX.XX.XXX
s=-
c=IN IP4 89.1XX.XX.XXX
t=0 0
m=audio 5001 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
"
  ^^^^ svd_r_get_params() ^^^^
^^^^ svd_nua_callback() ^^^^
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x77a7c8 from (udp/89.1XX.XX.XXX:5060) has 414 bytes, veclen = 1
tport_deliver(0x770950): msg 0x77a7c8 (414 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received ACK sip:voip1@89.1XX.XX.XXX SIP/2.0 (CSeq 4764234)
nta: ACK (4764234) is going to INVITE (4764234)
nua: process_ack_or_cancel: entering
soa_clear_remote_sdp(static::0x778cc8) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_ack
---[ SIP ]---
ACK sip:voip1@89.1XX.XX.XXX (CSeq 4764234 ACK)
        via 84.XX.X.XX:5060
        From: "+3467XXXXXXX" <sip:+3467XXXXXXX@voipd.ya.com>
        To: <sip:voip1@89.1XX.XX.XXX>
---[ === ]---
^^^^ svd_nua_callback() ^^^^
nua(0x773ec0): call state changed: completed -> ready
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
stop playing tone on [00]
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
vvvv svd_atab_handler() vvvv
Got tone event: 0x2 on [0/1]
^^^^ svd_atab_handler() ^^^^
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_active
^^^^ svd_nua_callback() ^^^^
vvvv svd_atab_handler() vvvv
Got coder event: 0x1 on [0/1]
^^^^ svd_atab_handler() ^^^^
nta: timer set next to 2329 ms
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x77a7c8 from (udp/89.1XX.XX.XXX:5060) has 704 bytes, veclen = 1
tport_deliver(0x770950): msg 0x77a7c8 (704 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13624162)
nta: 200 OK is going to a transaction
tport_tsend(0x770950) tpn = udp/84.7X.X.XXX:5060
tport_resolve addrinfo = 84.7X.X.XXX:5060
tport_by_addrinfo(0x770950): not found by name udp/84.7X.X.XXX:5060
tport_vsend returned 641
nta: resent ACK (13624162) to udp/84.7X.X.XXX:5060
nta: timer D fired, terminate INVITE (13624162)
outgoing_reclaim_all((nil), (nil), 0x2c03f1bc)
nta_outgoing_timer: 0/0 resent, 0/1 tout, 1/1 term, 1/2 free
nta: timer set next to 102 ms
nta: timer F fired, terminating ACK (13624162)
outgoing_reclaim_all((nil), (nil), 0x2c03f1bc)
nta_outgoing_timer: 0/0 resent, 1/1 tout, 0/0 term, 1/1 free
nta: timer set next to 2138 ms
nta: timer I fired, terminate 200 response
incoming_reclaim_all((nil), (nil), 0x2c03f1bc)
nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set
nta: selecting scheme sip
sres_cache_get(0x76fd20, NAPTR, "voipd.ya.com.") called
sres_cache_get(0x76fd20, NAPTR, "voipd.ya.com.") returned 1 entries
nta: for "voipd.ya.com" query "voipd.ya.com" NAPTR (cached)
sres_cache_get(0x76fd20, SRV, "_sip._udp.voipd.ya.com.") called
sres_cache_get(0x76fd20, SRV, "_sip._udp.voipd.ya.com.") returned 1 entries
nta: for "voipd.ya.com" query "_sip._udp.voipd.ya.com" SRV (cached)
sres_cache_get(0x76fd20, AAAA, "voipd.ya.com.") called
sres_cache_get(0x76fd20, AAAA, "voipd.ya.com.") returned 1 entries
nta: for "voipd.ya.com" query "voipd.ya.com" AAAA (cached)
nta(0x77e548): voipd.ya.com A record still unresolved
sres_cache_get(0x76fd20, A, "voipd.ya.com.") called
sres_cache_get(0x76fd20, A, "voipd.ya.com.") returned 1 entries
nta: for "voipd.ya.com" query "voipd.ya.com" A (cached)
nta: timer set to 32000 ms
nta: timer shortened to 5000 ms
outbound(0x774630): FAILED to validate <sip:voip1@89.1XX.XX.XXX>
outbound(0x774630): FAILED with 503 DNS Error
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_outbound
^^^^ svd_nua_callback() ^^^^
nta: timer K fired, terminate OPTIONS (13624146)
outgoing_reclaim_all((nil), (nil), 0x2c03f1bc)
nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set
vvvv svd_atab_handler() vvvv
Got fxs onhook event: 0x0 on [0/1]
  vvvv svd_handle_event_FXS_ONHOOK() vvvv
    vvvv svd_bye() vvvv
nua: nua_bye: entering
nua(0x773ec0): sent signal r_bye
    ^^^^ svd_bye() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_ONHOOK() ^^^^
^^^^ svd_atab_handler() ^^^^
nua: nua_stack_set_params: entering
soa_set_params(static::0x778cc8, ...) called
soa_terminate(static::0x778cc8) called
soa_init_offer_answer(static::0x778cc8) called
nta: selecting scheme sip
tport_tsend(0x770950) tpn = */84.XX.X.XX:5060
tport_resolve addrinfo = 84.XX.X.XX:5060
tport_by_addrinfo(0x770950): not found by name */84.XX.X.XX:5060
tport_vsend returned 476
nta: sent BYE (13624204) to */84.XX.X.XX:5060
tport_pend(0x770950): pending 0x77e548 for udp/89.1XX.XX.XXX:5060 (already 0)
nta: timer set to 32000 ms
nta: timer shortened to 500 ms
tport_wakeup_pri(0x770950): events IN
tport_recv_event(0x770950)
tport_recv_iovec(0x770950) msg 0x776dd0 from (udp/89.1XX.XX.XXX:5060) has 305 bytes, veclen = 1
tport_deliver(0x770950): msg 0x776dd0 (305 bytes) from udp/84.XX.X.XX:5060/sip next=(nil)
nta: received 200 OK for BYE (13624204)
nta: 200 OK is going to a transaction
nta_outgoing: RTT is 85.512 ms
tport_release(0x770950): 0x77e548 by 0x77acd0 with 0x776dd0
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_bye
---[ SIP ]---
200 OK (CSeq 13624204 BYE)
        From: <sip:voip1@89.1XX.XX.XXX>
        To: "+3467XXXXXXX" <sip:+3467XXXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_r_bye() vvvv
got answer on BYE: 200 OK
  ^^^^ svd_r_bye() ^^^^
^^^^ svd_nua_callback() ^^^^
nua(0x773ec0): call state changed: terminating -> terminated
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
call on [00] terminated
nua(0x773ec0): removing session usage
soa_destroy(static::0x778cc8) called
nta_leg_destroy(0x773f58)
nua: terminated session 0x773ec0
    vvvv svd_clear_call() vvvv
nua: nua_handle_destroy: entering
nta_leg_destroy((nil))
nua(0x773ec0): sent signal r_destroy
    ^^^^ svd_clear_call() ^^^^
playing busy tone on [00]
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
nua: nua_application_event: entering
nta: timer set next to 4577 ms
nta: timer K fired, terminate BYE (13624204)
outgoing_reclaim_all((nil), (nil), 0x2c03f1bc)
nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set

Edit:

All night without reboots, :-) ,  all working : ADSL, usb external, storage, samba, wifi(gateway), svd (callerid working, .....only the remote call sound... now I am waiting someone calls me for more test... however I can call :-) )

(Last edited by jjb_wii on 13 Jun 2011, 11:34)

jjb_wii wrote:

With the new uImage the callerid now works ok ( with config "channel 1  -->  option cid "off" ")...... it seems it was my fault I never install the libab only "svd_lantiq.ipk" and sofia.ipk.... because of this I have been using your first "libab" danubevoip version... by the moment no reboots :-)

libab is statically linked, so there's no need to install it in the router


jjb_wii wrote:

Related to the codec  I use "g729 pcma" (remote sound for outcoming and no remote sound for incoming),   If I put the "pcma  g729" remote sound no works (no incoming, no outcoming).  With Yacom official config first they use g729....

Did you try g729 only? It appears that their server is a home grown piece of shit ("INTENTANDO", "LLAMANDO", etc.) and they offer pcma as an option but they obviously don't work with pcma.

Note here what the yacom server says.



For an outgoing call, the remote sdp is received after we send our sdp:

Edit: here's out local sdp we send before receiving the remote one below:

Local sdp:
v=0
o=- 2538976139942479331 4529527436623036693 IN IP4 89.1XX.XX.XXX
s=-
c=IN IP4 89.1XX.XX.XXX
t=0 0
m=audio 5001 RTP/AVP 18 8 106
a=rtpmap:18 G729/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 telephone-event/8000
a=fmtp:106 0-16

i.e, we're telling we're going to accept both g729(18) and pcma(8).

Remote sdp:
v=0
o=- 4872101020 1307920733 IN IP4 84.78.2.114
s=SDP Data
c=IN IP4 84.78.2.114
t=0 0
m=audio 9760 RTP/AVP 18 106
a=rtpmap:106 telephone-event/8000
a=ptime:20

The line that matters is "m=audio 9760 RTP/AVP 18 106", since there's no rtpmap for 18, it means it's G729 (see http://en.wikipedia.org/wiki/RTP_audio_video_profile), i.e. the audio will be encoded with g729.

Now for the incoming call, we receive the remote sdp before sending ours:

Remote sdp:
v=0
o=- 3861200002 1307920764 IN IP4 84.78.2.110
s=SDP Data
c=IN IP4 84.78.2.110
t=0 0
m=audio 14510 RTP/AVP 8 101
a=rtpmap:101 telephone-event/8000
a=ptime:20

note that here the yacom server says it wants to use PCMA (8) and it clearly doesn't work.
As I said, you could try to set g279 only, but I doubt it will work.

(Last edited by pippolippi on 13 Jun 2011, 12:07)

thanks for the sdp info, it is very usefull for my problem...

This morning I test the G729 only but no sound....neither outgoing and incoming...

Upss, here we are my yacom (original firmware) codecs:

PCMA
G729
G726-40
G726-32
G726-24
G726-16


First it use the PCMA not G729....


Related to the outgoing calls:

James wrote:

The line that matters is "m=audio 9760 RTP/AVP 18 106", since there's no rtpmap for 18, it means it's G729 (see http://en.wikipedia.org/wiki/RTP_audio_video_profile), i.e. the audio will be encoded with g729.

Despite this failure, the outgoing calls works ok.....

Related to the incoming calls, I understand... the yacom request our PCMA local codec but it fails... is this correct?

(Last edited by jjb_wii on 13 Jun 2011, 16:15)

It actually says that it wants PCMA for the remote side and it doesn't seem to work (as you said that the remote side doesn't hear any sound).
Sorry, I'm out of ideas, I can only say that PCMA works fine with svd, since ekiga.net only allows PCMA and I'm doing my tests with ekiga.net.
I also tried another provider that, just like yacom, claims support for PCMA but it only works with G729.

Edit:

the part you quoted:

The line that matters is "m=audio 9760 RTP/AVP 18 106", since there's no rtpmap for 18, it means it's G729 (see http://en.wikipedia.org/wiki/RTP_audio_video_profile), i.e. the audio will be encoded with g729.

Despite this failure, the outgoing calls works ok.....

That's not a failure, with that outgoing call, yacom says it wants to use g729, and that works fine.
Is in the incoming call that yacom says it wants to use PCMA, and that's the codec that doesn't seem to actually accept.

(Last edited by pippolippi on 13 Jun 2011, 16:25)

I uploaded a new version with support for leds.
You can define a main voip led in "config main" that will turn on when there's at least one account registered, and a led for each channel in "config channel" that will turn on when the phone is off-hook, blink slowly when a call is ongoing and blink fast when the phone is ringing.

Edit: new version 1.4, I forgot to turn off the led if the incoming call was cancelled.

(Last edited by pippolippi on 13 Jun 2011, 18:37)

OK. 

Is it possible to config ulaw/alaw of the PCMA coded?  where it is implemented? perhaps in sophia lib....

After some test with g729 "only" codec, here the results:

1) For outgoing all works ok.
2) For incoming calls no local sound, no remote sound.... however with two codecs selecteds(g729 pcma) I have local sound.

jjb_wii wrote:

Is it possible to config ulaw/alaw of the PCMA coded?  where it is implemented? perhaps in sophia lib....

No, I suppose that must be configured in the dsp (i.e. with some calls to ifx_tapi).
But, IIRC, that should only affect the quality of the voice, not the fact that it works at all.


jjb_wii wrote:

After some test with g729 "only" codec, here the results:

1) For outgoing all works ok.

Log?

jjb_wii wrote:

2) For incoming calls no local sound, no remote sound.... however with two codecs selecteds(g729 pcma) I have local sound.

Well, I though so sad
As I said before, I'm out of ideas.

@jjb_wii, I committed a small change in trunk to log something more, maybe the resulting log will give me some idea.
I didn't upload a binary package, just the updated sources.
The changeset is this one:

http://code.google.com/p/danube-voip/so … e664737cff

pippolippi wrote:

jjb_wii wrote:

After some test with g729 "only" codec, here the results:

1) For outgoing all works ok.

Log?

here the log (only with g729) :

CALLSTATE NAME : init
Local sdp:
v=0
o=- 8356452833252813635 483529646112684975 IN IP4 89.XXX.XX.XXX
s=-
c=IN IP4 89.XXX.XX.XXX
t=0 0
m=audio 5001 RTP/AVP 18 106
a=rtpmap:18 G729/8000
a=rtpmap:106 telephone-event/8000
a=fmtp:106 0-16

  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
sres_resolver_receive(0x474b78, 24) called
AUTHORITY RR received ya.com. SOA IN 300 rdlen=57
sres(q=0x47bb80): reporting error RECORD_ERR for AAAA proxy2.voip.ya.com.
nta(0x47ed30): proxy2.voip.ya.com. A record still unresolved
sres_cache_get(0x474cf0, A, "proxy2.voip.ya.com.") called
sres_cache_get(0x474cf0, A, "proxy2.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy2.voip.ya.com." A (cached)
nta: proxy2.voip.ya.com. IN A 84.7X.X.XX
tport_tsend(0x475928) tpn = udp/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x475928): not found by name udp/84.7X.X.XX:5060
tport_vsend returned 783
nta: sent INVITE (13661693) to udp/84.7X.X.XX:5060
tport_pend(0x475928): pending 0x47b948 for udp/89.XXX.XX.XXX:5060 (already 0)
nta: timer set to 32000 ms
nta: timer shortened to 500 ms
tport_wakeup_pri(0x475928): events IN
tport_recv_event(0x475928)
tport_recv_iovec(0x475928) msg 0x47a1f8 from (udp/89.XXX.XX.XXX:5060) has 539 bytes, veclen = 1
tport_deliver(0x475928): msg 0x47a1f8 (539 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 401 Unauthorized for INVITE (13661693)
nta: 401 Unauthorized is going to a transaction
nta_outgoing: RTT is 180.56 ms
tport_release(0x475928): 0x47b948 by 0x47ed30 with 0x47a1f8
tport_tsend(0x475928) tpn = udp/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x475928): not found by name udp/84.7X.X.XX:5060
tport_vsend returned 329
nta: sent ACK (13661693) to udp/84.7X.X.XX:5060
nta: outgoing_free(0x47aea0)
auth_digest_challenge_get(): got 5
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_invite
---[ SIP ]---
401 Unauthorized (CSeq 13661693 INVITE)
        From: "+34932XXXXXX" <sip:+34932XXXXXX@voipd.ya.com>
        To: <sip:67XXXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_r_invite() vvvv
got answer on INVITE: 401 Unauthorized
    vvvv svd_authenticate() vvvv
Server auth: Digest algorithm=MD5, nonce="beff8c58f309e2ccae81536bc697157bba02df150baf11f69bbe02c1f6f49f7a", opaque="beff8c58f309e2ccae81536bc697157bba02df150baf11f69bbe02c1f6f49f7a", realm="DIRECTO-YA"
AUTHENTICATING WITH 'Digest:"DIRECTO-YA":932XXXXXX:XX'.
nua: nua_authenticate: entering
nua(0x478e80): sent signal r_authenticate
    ^^^^ svd_authenticate() ^^^^
  ^^^^ svd_r_invite() ^^^^
^^^^ svd_nua_callback() ^^^^
auth_digest_ha1() has A1 = MD5(932XXXXXX:"DIRECTO-YA":*******) = a16460c835108e19099210a142db65b3
soa_init_offer_answer(static::0x4787f0) called
soa_generate_offer(static::0x4787f0, 0) called
soa_static_offer_answer_action(0x4787f0, soa_generate_offer): called
soa_sdp_mode_set(0x47c108, (nil), ""): called
soa_get_local_sdp(static::0x4787f0, [(nil)], [0x2b44a0b0], [0x2b44a0b4]) called
A2 = MD5(INVITE:sip:67XXXXXXX@voipd.ya.com)
auth_response: 8f00d55499fc8f9d05e5490a915d19ed = MD5(a16460c835108e19099210a142db65b3:beff8c58f309e2ccae81536bc697157bba02df150baf11f69bbe02c1f6f49f7a:7731410336f28d6bea915c2e3ba28b43) (qop=NONE)
nta: selecting scheme sip
sres_cache_get(0x474cf0, NAPTR, "proxy.voip.ya.com.") called
sres_cache_get(0x474cf0, NAPTR, "proxy.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy.voip.ya.com" NAPTR (cached)
sres_cache_get(0x474cf0, SRV, "_sip._udp.proxy.voip.ya.com.") called
sres_cache_get(0x474cf0, SRV, "_sip._udp.proxy.voip.ya.com.") returned 2 entries
nta: for "proxy.voip.ya.com" query "_sip._udp.proxy.voip.ya.com" SRV (cached)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy2.voip.ya.com. (udp)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy1.voip.ya.com. (udp)
sres_cache_get(0x474cf0, AAAA, "proxy2.voip.ya.com.") called
sres_cache_get(0x474cf0, AAAA, "proxy2.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy2.voip.ya.com." AAAA (cached)
nta(0x47fe70): proxy2.voip.ya.com. A record still unresolved
sres_cache_get(0x474cf0, A, "proxy2.voip.ya.com.") called
sres_cache_get(0x474cf0, A, "proxy2.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy2.voip.ya.com." A (cached)
nta: proxy2.voip.ya.com. IN A 84.7X.X.XX
tport_tsend(0x475928) tpn = udp/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x475928): not found by name udp/84.7X.X.XX:5060
tport_vsend returned 1090
nta: sent INVITE (13661694) to udp/84.7X.X.XX:5060
tport_pend(0x475928): pending 0x47a850 for udp/89.XXX.XX.XXX:5060 (already 0)
nua(0x478e80): call state changed: calling -> calling, sent offer
soa_get_local_sdp(static::0x4787f0, [0x2b44a078], [0x2b44a07c], [(nil)]) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
Local sdp:
v=0
o=- 8356452833252813635 483529646112684975 IN IP4 89.XXX.XX.XXX
s=-
c=IN IP4 89.XXX.XX.XXX
t=0 0
m=audio 5001 RTP/AVP 18 106
a=rtpmap:18 G729/8000
a=rtpmap:106 telephone-event/8000
a=fmtp:106 0-16

  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
tport_wakeup_pri(0x475928): events IN
tport_recv_event(0x475928)
tport_recv_iovec(0x475928) msg 0x4808a8 from (udp/89.XXX.XX.XXX:5060) has 315 bytes, veclen = 1
tport_deliver(0x475928): msg 0x4808a8 (315 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 100 INTENTANDO for INVITE (13661694)
nta: 100 INTENTANDO is going to a transaction
nta_outgoing: RTT is 183.731 ms
tport_release(0x475928): 0x47a850 by 0x47fe70 with 0x4808a8 (preliminary)
nta: timer set next to 31671 ms
tport_wakeup_pri(0x475928): events IN
tport_recv_event(0x475928)
tport_recv_iovec(0x475928) msg 0x4808a8 from (udp/89.XXX.XX.XXX:5060) has 701 bytes, veclen = 1
tport_deliver(0x475928): msg 0x4808a8 (701 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 180 LLAMANDO for INVITE (13661694)
nta: 180 LLAMANDO is going to a transaction
tport_release(0x475928): 0x47a850 by 0x47fe70 with 0x4808a8 (preliminary)
soa_set_remote_sdp(static::0x4787f0, (nil), 0x480ddc, 169) called
soa_process_answer(static::0x4787f0) called
soa_static_offer_answer_action(0x4787f0, soa_process_answer): called
soa_sdp_mode_set(0x47c108, 0x481510, ""): called
soa_static(0x4787f0, soa_process_answer): upgrade codecs with remote description
soa_activate(static::0x4787f0, (nil)) called
nua(0x478e80): INVITE: processed SDP answer in 180 LLAMANDO
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_invite
---[ SIP ]---
180 LLAMANDO (CSeq 13661694 INVITE)
        From: "+34932XXXXXX" <sip:+34932XXXXXX@voipd.ya.com>
        To: <sip:67XXXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_r_invite() vvvv
got answer on INVITE: 180 LLAMANDO
  ^^^^ svd_r_invite() ^^^^
^^^^ svd_nua_callback() ^^^^
nua(0x478e80): call state changed: calling -> proceeding, received answer
soa_get_remote_sdp(static::0x4787f0, [0x2b449c48], [0x2b449c4c], [(nil)]) called
soa_get_params(static::0x4787f0, ...) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
Remote sdp:
v=0
o=- 4871900755 1307995796 IN IP4 84.7X.X.XXX
s=SDP Data
c=IN IP4 84.XX.X.XXX
t=0 0
m=audio 16490 RTP/AVP 18 106
a=rtpmap:106 telephone-event/8000
a=ptime:20

    vvvv svd_parse_sdp() vvvv
      vvvv svd_set_te_codec() vvvv
Checking media for telephone-event: G729
Checking media for telephone-event: telephone-event
        found!
      ^^^^ svd_set_te_codec() ^^^^
Set parameters for channel 1, remote 84.XX.X.XXX:16490 with coder/payload [G729/18], fmtp: (null), telephone-event: 106
    ^^^^ svd_parse_sdp() ^^^^
play ringback on [00]
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
tport_wakeup_pri(0x475928): events IN
tport_recv_event(0x475928)
tport_recv_iovec(0x475928) msg 0x481988 from (udp/89.XXX.XX.XXX:5060) has 706 bytes, veclen = 1
tport_deliver(0x475928): msg 0x481988 (706 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13661694)
nta: 200 OK is going to a transaction
tport_release(0x475928): 0x47a850 by 0x47fe70 with 0x481988
nua(0x478e80): INVITE: ignoring duplicate SDP in 200 OK
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_invite
---[ SIP ]---
200 OK (CSeq 13661694 INVITE)
        From: "+34932XXXXXX" <sip:+34932XXXXXX@voipd.ya.com>
        To: <sip:67XXXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_r_invite() vvvv
got answer on INVITE: 200 OK
  ^^^^ svd_r_invite() ^^^^
^^^^ svd_nua_callback() ^^^^
soa_activate(static::0x4787f0, (nil)) called
nta: selecting scheme sip
sres_cache_get(0x474cf0, NAPTR, "proxy.voip.ya.com.") called
sres_cache_get(0x474cf0, NAPTR, "proxy.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy.voip.ya.com" NAPTR (cached)
sres_cache_get(0x474cf0, SRV, "_sip._udp.proxy.voip.ya.com.") called
sres_cache_get(0x474cf0, SRV, "_sip._udp.proxy.voip.ya.com.") returned 2 entries
nta: for "proxy.voip.ya.com" query "_sip._udp.proxy.voip.ya.com" SRV (cached)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy1.voip.ya.com. (udp)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy2.voip.ya.com. (udp)
sres_cache_get(0x474cf0, AAAA, "proxy1.voip.ya.com.") called
sres_cache_get(0x474cf0, AAAA, "proxy1.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy1.voip.ya.com." AAAA (cached)
nta(0x482198): proxy1.voip.ya.com. A record still unresolved
sres_cache_get(0x474cf0, A, "proxy1.voip.ya.com.") called
sres_cache_get(0x474cf0, A, "proxy1.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy1.voip.ya.com." A (cached)
nta: proxy1.voip.ya.com. IN A 84.7X.X.XX
tport_tsend(0x475928) tpn = udp/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x475928): not found by name udp/84.7X.X.XX:5060
tport_vsend returned 642
nta: sent ACK (13661694) to udp/84.7X.X.XX:5060
nua(0x478e80): call state changed: proceeding -> ready
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
stop playing tone on [00]
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
vvvv svd_atab_handler() vvvv
Got tone event: 0x2 on [0/1]
^^^^ svd_atab_handler() ^^^^
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_active
^^^^ svd_nua_callback() ^^^^
vvvv svd_atab_handler() vvvv
Got coder event: 0x1 on [0/1]
^^^^ svd_atab_handler() ^^^^
tport_wakeup_pri(0x475928): events IN
tport_recv_event(0x475928)
tport_recv_iovec(0x475928) msg 0x482c10 from (udp/89.XXX.XX.XXX:5060) has 706 bytes, veclen = 1
tport_deliver(0x475928): msg 0x482c10 (706 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13661694)
nta: 200 OK is going to a transaction
nta_outgoing: RTT is 367.92 ms
tport_tsend(0x475928) tpn = udp/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x475928): not found by name udp/84.7X.X.XX:5060
tport_vsend returned 642
nta: resent ACK (13661694) to udp/84.7X.X.XX:5060
tport_wakeup_pri(0x475928): events IN
tport_recv_event(0x475928)
tport_recv_iovec(0x475928) msg 0x482c10 from (udp/89.XXX.XX.XXX:5060) has 706 bytes, veclen = 1
tport_deliver(0x475928): msg 0x482c10 (706 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13661694)
nta: 200 OK is going to a transaction
tport_tsend(0x475928) tpn = udp/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x475928): not found by name udp/84.7X.X.XX:5060
tport_vsend returned 642
nta: resent ACK (13661694) to udp/84.7X.X.XX:5060
tport_wakeup_pri(0x475928): events IN
tport_recv_event(0x475928)
tport_recv_iovec(0x475928) msg 0x482c10 from (udp/89.XXX.XX.XXX:5060) has 706 bytes, veclen = 1
tport_deliver(0x475928): msg 0x482c10 (706 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13661694)
nta: 200 OK is going to a transaction
tport_tsend(0x475928) tpn = udp/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x475928): not found by name udp/84.7X.X.XX:5060
tport_vsend returned 642
nta: resent ACK (13661694) to udp/84.7X.X.XX:5060
tport_wakeup_pri(0x475928): events IN
tport_recv_event(0x475928)
tport_recv_iovec(0x475928) msg 0x482c10 from (udp/89.XXX.XX.XXX:5060) has 706 bytes, veclen = 1
tport_deliver(0x475928): msg 0x482c10 (706 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13661694)
nta: 200 OK is going to a transaction
tport_tsend(0x475928) tpn = udp/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x475928): not found by name udp/84.7X.X.XX:5060
tport_vsend returned 642
nta: resent ACK (13661694) to udp/84.7X.X.XX:5060
tport_wakeup_pri(0x475928): events IN
tport_recv_event(0x475928)
tport_recv_iovec(0x475928) msg 0x482c10 from (udp/89.XXX.XX.XXX:5060) has 706 bytes, veclen = 1
tport_deliver(0x475928): msg 0x482c10 (706 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13661694)
nta: 200 OK is going to a transaction
tport_tsend(0x475928) tpn = udp/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x475928): not found by name udp/84.7X.X.XX:5060
tport_vsend returned 642
nta: resent ACK (13661694) to udp/84.7X.X.XX:5060
vvvv svd_atab_handler() vvvv
Got fxs onhook event: 0x0 on [0/1]
  vvvv svd_handle_event_FXS_ONHOOK() vvvv
    vvvv svd_bye() vvvv
nua: nua_bye: entering
nua(0x478e80): sent signal r_bye
    ^^^^ svd_bye() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_ONHOOK() ^^^^
^^^^ svd_atab_handler() ^^^^
nua: nua_stack_set_params: entering
soa_set_params(static::0x4787f0, ...) called
soa_terminate(static::0x4787f0) called
soa_init_offer_answer(static::0x4787f0) called
A2 = MD5(BYE:sip:TASP001_NTX@84.7X.X.XX:5060)
auth_response: 95fd969bc2823c51615e4d63b239765d = MD5(a16460c835108e19099210a142db65b3:beff8c58f309e2ccae81536bc697157bba02df150baf11f69bbe02c1f6f49f7a:d935f576647fd2f680c5f1fd9dfff02f) (qop=NONE)
nta: selecting scheme sip
sres_cache_get(0x474cf0, NAPTR, "proxy.voip.ya.com.") called
sres_cache_get(0x474cf0, NAPTR, "proxy.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy.voip.ya.com" NAPTR (cached)
sres_cache_get(0x474cf0, SRV, "_sip._udp.proxy.voip.ya.com.") called
sres_cache_get(0x474cf0, SRV, "_sip._udp.proxy.voip.ya.com.") returned 2 entries
nta: for "proxy.voip.ya.com" query "_sip._udp.proxy.voip.ya.com" SRV (cached)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy2.voip.ya.com. (udp)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy1.voip.ya.com. (udp)
sres_cache_get(0x474cf0, AAAA, "proxy2.voip.ya.com.") called
sres_cache_get(0x474cf0, AAAA, "proxy2.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy2.voip.ya.com." AAAA (cached)
nta(0x4830c0): proxy2.voip.ya.com. A record still unresolved
sres_cache_get(0x474cf0, A, "proxy2.voip.ya.com.") called
sres_cache_get(0x474cf0, A, "proxy2.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy2.voip.ya.com." A (cached)
nta: proxy2.voip.ya.com. IN A 84.7X.X.XX
tport_tsend(0x475928) tpn = udp/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x475928): not found by name udp/84.7X.X.XX:5060
tport_vsend returned 800
nta: sent BYE (13661695) to udp/84.7X.X.XX:5060
tport_pend(0x475928): pending 0x47eb28 for udp/89.XXX.XX.XXX:5060 (already 0)
nta: timer shortened to 500 ms
tport_wakeup_pri(0x475928): events IN
tport_recv_event(0x475928)
tport_recv_iovec(0x475928) msg 0x481588 from (udp/89.XXX.XX.XXX:5060) has 706 bytes, veclen = 1
tport_deliver(0x475928): msg 0x481588 (706 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13661694)
nta: 200 OK is going to a transaction
tport_tsend(0x475928) tpn = udp/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x475928): not found by name udp/84.7X.X.XX:5060
tport_vsend returned 642
nta: resent ACK (13661694) to udp/84.7X.X.XX:5060
tport_wakeup_pri(0x475928): events IN
tport_recv_event(0x475928)
tport_recv_iovec(0x475928) msg 0x481588 from (udp/89.XXX.XX.XXX:5060) has 317 bytes, veclen = 1
tport_deliver(0x475928): msg 0x481588 (317 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 200 OK for BYE (13661695)
nta: 200 OK is going to a transaction
nta_outgoing: RTT is 177.685 ms
tport_release(0x475928): 0x47eb28 by 0x4830c0 with 0x481588
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_bye
---[ SIP ]---
200 OK (CSeq 13661695 BYE)
        From: "+34932XXXXXX" <sip:+34932XXXXXX@voipd.ya.com>
        To: <sip:67XXXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_r_bye() vvvv
got answer on BYE: 200 OK
  ^^^^ svd_r_bye() ^^^^
^^^^ svd_nua_callback() ^^^^
nua(0x478e80): call state changed: terminating -> terminated
nua(0x478e80): removing session usage
soa_destroy(static::0x4787f0) called
nta_leg_destroy(0x479080)
nua: terminated session 0x478e80
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
call on [00] terminated
    vvvv svd_clear_call() vvvv
nua: nua_handle_destroy: entering
nta_leg_destroy((nil))
nua(0x478e80): sent signal r_destroy
    ^^^^ svd_clear_call() ^^^^
playing busy tone on [00]
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
nua: nua_application_event: entering
nta: timer set next to 4668 ms
nta: timer K fired, terminate BYE (13661695)
outgoing_reclaim_all((nil), (nil), 0x2b44a1bc)
nta_outgoing_timer: 0/0 resent, 0/1 tout, 1/3 term, 1/4 free
nta: timer set next to 4331 ms
nta: timer D fired, terminate INVITE (13661693)
outgoing_reclaim_all((nil), (nil), 0x2b44a1bc)
nta_outgoing_timer: 0/0 resent, 0/1 tout, 1/2 term, 1/3 free
nta: timer set next to 7140 ms
nta: timer D fired, terminate INVITE (13661694)
nta: timer F fired, terminating ACK (13661694)
outgoing_reclaim_all((nil), (nil), 0x2b44a1bc)
nta_outgoing_timer: 0/0 resent, 1/1 tout, 1/1 term, 2/2 free
nta: timer not set
nta: selecting scheme sip
sres_cache_get(0x474cf0, NAPTR, "voipd.ya.com.") called
sres_cache_get(0x474cf0, NAPTR, "voipd.ya.com.") returned 1 entries
nta: for "voipd.ya.com" query "voipd.ya.com" NAPTR (cached)
sres_cache_get(0x474cf0, SRV, "_sip._udp.voipd.ya.com.") called
sres_cache_get(0x474cf0, SRV, "_sip._udp.voipd.ya.com.") returned 1 entries
nta: for "voipd.ya.com" query "_sip._udp.voipd.ya.com" SRV (cached)
sres_cache_get(0x474cf0, AAAA, "voipd.ya.com.") called
sres_cache_get(0x474cf0, AAAA, "voipd.ya.com.") returned 1 entries
nta: for "voipd.ya.com" query "voipd.ya.com" AAAA (cached)
nta(0x478e80): voipd.ya.com A record still unresolved
sres_cache_get(0x474cf0, A, "voipd.ya.com.") called
sres_cache_get(0x474cf0, A, "voipd.ya.com.") returned 1 entries
nta: for "voipd.ya.com" query "voipd.ya.com" A (cached)
nta: timer set to 32000 ms
nta: timer shortened to 5000 ms
outbound(0x478238): FAILED to validate <sip:voip1@89.XXX.XX.XXX>
outbound(0x478238): FAILED with 503 DNS Error
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_outbound
^^^^ svd_nua_callback() ^^^^

here the log (with "g729 pcma".....):


CALLSTATE NAME : init
Local sdp:
v=0
o=- 6306973768730916163 5120776500560206518 IN IP4 89.XXX.XX.XXX
s=-
c=IN IP4 89.XXX.XX.XXX
t=0 0
m=audio 5001 RTP/AVP 18 8 106
a=rtpmap:18 G729/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 telephone-event/8000
a=fmtp:106 0-16

  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
tport_wakeup_pri(0x978950): events IN
tport_recv_event(0x978950)
tport_recv_iovec(0x978950) msg 0x983980 from (udp/89.XXX.XX.XXX:5060) has 315 bytes, veclen = 1
tport_deliver(0x978950): msg 0x983980 (315 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 100 INTENTANDO for INVITE (13650048)
nta: 100 INTENTANDO is going to a transaction
nta_outgoing: RTT is 88.849 ms
tport_release(0x978950): 0x980738 by 0x982f48 with 0x983980 (preliminary)
nta: timer set next to 31570 ms
tport_wakeup_pri(0x978950): events IN
tport_recv_event(0x978950)
tport_recv_iovec(0x978950) msg 0x983980 from (udp/89.XXX.XX.XXX:5060) has 700 bytes, veclen = 1
tport_deliver(0x978950): msg 0x983980 (700 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 180 LLAMANDO for INVITE (13650048)
nta: 180 LLAMANDO is going to a transaction
tport_release(0x978950): 0x980738 by 0x982f48 with 0x983980 (preliminary)
soa_set_remote_sdp(static::0x97be88, (nil), 0x983eb3, 169) called
soa_process_answer(static::0x97be88) called
soa_static_offer_answer_action(0x97be88, soa_process_answer): called
soa_sdp_mode_set(0x982118, 0x9845e8, ""): called
soa_static(0x97be88, soa_process_answer): upgrade codecs with remote description
soa_static(0x97be88, soa_process_answer): storing local description
soa_activate(static::0x97be88, (nil)) called
nua(0x97f5c0): INVITE: processed SDP answer in 180 LLAMANDO
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_invite
---[ SIP ]---
180 LLAMANDO (CSeq 13650048 INVITE)
        From: "+34932XXXXXX" <sip:+34932XXXXXX@voipd.ya.com>
        To: <sip:67XXXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_r_invite() vvvv
got answer on INVITE: 180 LLAMANDO
  ^^^^ svd_r_invite() ^^^^
^^^^ svd_nua_callback() ^^^^
nua(0x97f5c0): call state changed: calling -> proceeding, received answer
soa_get_remote_sdp(static::0x97be88, [0x2b711c48], [0x2b711c4c], [(nil)]) called
soa_get_params(static::0x97be88, ...) called
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
Remote sdp:
v=0
o=- 5370200774 1307972505 IN IP4 84.XX.X.XXX
s=SDP Data
c=IN IP4 84.XX.X.XXX
t=0 0
m=audio 12700 RTP/AVP 18 106
a=rtpmap:106 telephone-event/8000
a=ptime:20

    vvvv svd_parse_sdp() vvvv
      vvvv svd_set_te_codec() vvvv
Checking media for telephone-event: G729
Checking media for telephone-event: telephone-event
        found!
      ^^^^ svd_set_te_codec() ^^^^
Set parameters for channel 1, remote 84.XX.X.XXX:12700 with coder/payload [G729/18], fmtp: (null), telephone-event: 106
    ^^^^ svd_parse_sdp() ^^^^
play ringback on [00]
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
tport_wakeup_pri(0x978950): events IN
tport_recv_event(0x978950)
tport_recv_iovec(0x978950) msg 0x982118 from (udp/89.XXX.XX.XXX:5060) has 705 bytes, veclen = 1
tport_deliver(0x978950): msg 0x982118 (705 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received 200 OK for INVITE (13650048)
nta: 200 OK is going to a transaction
tport_release(0x978950): 0x980738 by 0x982f48 with 0x982118
nua(0x97f5c0): INVITE: ignoring duplicate SDP in 200 OK
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_r_invite
---[ SIP ]---
200 OK (CSeq 13650048 INVITE)
        From: "+34932XXXXXXX" <sip:+34932XXXXXX@voipd.ya.com>
        To: <sip:67XXXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_r_invite() vvvv
got answer on INVITE: 200 OK
  ^^^^ svd_r_invite() ^^^^
^^^^ svd_nua_callback() ^^^^
soa_activate(static::0x97be88, (nil)) called
nta: selecting scheme sip
sres_cache_get(0x977d20, NAPTR, "proxy.voip.ya.com.") called
sres_cache_get(0x977d20, NAPTR, "proxy.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy.voip.ya.com" NAPTR (cached)
sres_cache_get(0x977d20, SRV, "_sip._udp.proxy.voip.ya.com.") called
sres_cache_get(0x977d20, SRV, "_sip._udp.proxy.voip.ya.com.") returned 2 entries
nta: for "proxy.voip.ya.com" query "_sip._udp.proxy.voip.ya.com" SRV (cached)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy1.voip.ya.com. (udp)
nta: _sip._udp.proxy.voip.ya.com IN SRV 1 1  5060 proxy2.voip.ya.com. (udp)
sres_cache_get(0x977d20, AAAA, "proxy1.voip.ya.com.") called
sres_cache_get(0x977d20, AAAA, "proxy1.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy1.voip.ya.com." AAAA (cached)
nta(0x985578): proxy1.voip.ya.com. A record still unresolved
sres_cache_get(0x977d20, A, "proxy1.voip.ya.com.") called
sres_cache_get(0x977d20, A, "proxy1.voip.ya.com.") returned 1 entries
nta: for "proxy.voip.ya.com" query "proxy1.voip.ya.com." A (cached)
nta: proxy1.voip.ya.com. IN A 84.7X.X.XX
tport_tsend(0x978950) tpn = udp/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x978950): not found by name udp/84.7X.X.XX:5060
tport_vsend returned 641
nta: sent ACK (13650048) to udp/84.7X.X.XX:5060
nua(0x97f5c0): call state changed: proceeding -> ready
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
stop playing tone on [00]
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
vvvv svd_atab_handler() vvvv
Got tone event: 0x2 on [0/1]
^^^^ svd_atab_handler() ^^^^
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_active
^^^^ svd_nua_callback() ^^^^
vvvv svd_atab_handler() vvvv
Got coder event: 0x1 on [0/1]
^^^^ svd_atab_handler() ^^^^
nta: timer D fired, terminate INVITE (13650047)
outgoing_reclaim_all((nil), (nil), 0x2b7121bc)
nta_outgoing_timer: 0/0 resent, 0/1 tout, 1/2 term, 1/3 free
nta: timer set next to 9397 ms
tport_wakeup_pri(0x978950): events IN
tport_recv_event(0x978950)
tport_recv_iovec(0x978950) msg 0x97f1a8 from (udp/89.XXX.XX.XXX:5060) has 416 bytes, veclen = 1
tport_deliver(0x978950): msg 0x97f1a8 (416 bytes) from udp/84.7X.X.XX:5060/sip next=(nil)
nta: received BYE sip:voip1@89.XXX.XX.XXX SIP/2.0 (CSeq 5416021)
nta: canonizing sip:voip1@89.XXX.XX.XXX with contact
nta: BYE (5416021) going to existing leg
nua: nua_stack_process_request: entering
tport_tsend(0x978950) tpn = UDP/84.7X.X.XX:5060
tport_resolve addrinfo = 84.7X.X.XX:5060
tport_by_addrinfo(0x978950): not found by name UDP/84.7X.X.XX:5060
tport_vsend returned 464
nta: sent 200 OK for BYE (5416021)
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_bye
---[ SIP ]---
BYE sip:voip1@89.XXX.XX.XXX (CSeq 5416021 BYE)
        via 84.7X.X.XX:5060
        From: <sip:67XXXXXXX@voipd.ya.com>
        To: "+34932XXXXXX" <sip:+34932XXXXXX@voipd.ya.com>
---[ === ]---
  vvvv svd_i_bye() vvvv
BYE received
  ^^^^ svd_i_bye() ^^^^
^^^^ svd_nua_callback() ^^^^
nua(0x97f5c0): removing session usage
nua(0x97f5c0): call state changed: ready -> terminated
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_state
  vvvv svd_i_state() vvvv
CALLSTATE NAME : init
call on [00] terminated
soa_destroy(static::0x97be88) called
nta_leg_destroy(0x97b8e8)
    vvvv svd_clear_call() vvvv
nua: nua_handle_destroy: entering
nua(0x97f5c0): sent signal r_destroy
    ^^^^ svd_clear_call() ^^^^
playing busy tone on [00]
  ^^^^ svd_i_state() ^^^^
^^^^ svd_nua_callback() ^^^^
nua: nua_application_event: entering
nta_leg_destroy((nil))
vvvv svd_atab_handler() vvvv
Got fxs onhook event: 0x0 on [0/1]
  vvvv svd_handle_event_FXS_ONHOOK() vvvv
    vvvv svd_bye() vvvv
      vvvv svd_clear_call() vvvv
      ^^^^ svd_clear_call() ^^^^
    ^^^^ svd_bye() ^^^^
stop playing tone on [00]
  ^^^^ svd_handle_event_FXS_ONHOOK() ^^^^
^^^^ svd_atab_handler() ^^^^
vvvv svd_atab_handler() vvvv
Got tone event: 0x2 on [0/1]
^^^^ svd_atab_handler() ^^^^
nta: timer D fired, terminate INVITE (13650048)
nta: timer F fired, terminating ACK (13650048)
outgoing_reclaim_all((nil), (nil), 0x2b7121bc)
nta_outgoing_timer: 0/0 resent, 1/1 tout, 1/1 term, 2/2 free
nta: timer set next to 28242 ms
nta: selecting scheme sip
sres_cache_get(0x977d20, NAPTR, "voipd.ya.com.") called
sres_cache_get(0x977d20, NAPTR, "voipd.ya.com.") returned 1 entries
nta: for "voipd.ya.com" query "voipd.ya.com" NAPTR (cached)
sres_cache_get(0x977d20, SRV, "_sip._udp.voipd.ya.com.") called
sres_cache_get(0x977d20, SRV, "_sip._udp.voipd.ya.com.") returned 1 entries
nta: for "voipd.ya.com" query "_sip._udp.voipd.ya.com" SRV (cached)
sres_cache_get(0x977d20, AAAA, "voipd.ya.com.") called
sres_cache_get(0x977d20, AAAA, "voipd.ya.com.") returned 1 entries
nta: for "voipd.ya.com" query "voipd.ya.com" AAAA (cached)
nta(0x97f5c0): voipd.ya.com A record still unresolved
sres_cache_get(0x977d20, A, "voipd.ya.com.") called
sres_cache_get(0x977d20, A, "voipd.ya.com.") returned 1 entries
nta: for "voipd.ya.com" query "voipd.ya.com" A (cached)
nta: timer shortened to 5000 ms
outbound(0x97c630): FAILED to validate <sip:voip1@89.XXX.XX.XXX>
outbound(0x97c630): FAILED with 503 DNS Error
nua: nua_application_event: entering
vvvv svd_nua_callback() vvvv
Event : nua_i_outbound
^^^^ svd_nua_callback() ^^^^
nta: timer K fired, terminate OPTIONS (13650020)
outgoing_reclaim_all((nil), (nil), 0x2b7121bc)
nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer set next to 12874 ms
nta: timer J fired, terminate 200 response
incoming_reclaim_all((nil), (nil), 0x2b7121bc)
nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set

(Last edited by jjb_wii on 13 Jun 2011, 23:20)

Sorry, posts 401 to 400 are missing from our archive.