[Freeswitch-users] Need help interpreting fs_cli debug messages

Sat Jun 4 02:48:30 MSD 2011

The debug log and siptrace would be more useful than the sofia stack
debugging...

Looks like it's failing to authenticate, which is likely bad credentials or
the configuration not quite matching what the provider needs.

-Steve

On 3 June 2011 23:04, Roman Gelfand <rgelfand2 at gmail.com> wrote:

> I was wondering if somebody could help interpret the registration issue.
>
> +OK log level  [7]
> freeswitch at internal> nua: nh_create_handle: entering
> nua: nua_handle_bind: entering
> 2011-06-02 13:35:18.401497 [NOTICE] sofia_reg.c:367 Registering
> ###########-callcentric.com
> nua: nua_register: entering
> nua(0x873dc88): sent signal r_register
> nua: nua_stack_set_params: entering
> soa_clone(static::0x86d2e30, 0x86fba08, 0x873dc88) called
> soa_set_params(static::0x8dd11008, ...) called
> soa_set_params(static::0x8dd11008, ...) called
> nua(0x873dc88): adding register usage
> nta_leg_tcreate(0x8dd16398)
> nta: selecting scheme sip
> tport_tsend(0x86afae0) tpn = */XX.XX.XXX.XXX:5060
> tport_resolve addrinfo = XX.XX.XXX.XXX:5060
> tport_by_addrinfo(0x86afae0): not found by name */XX.XX.XXX.XXX:5060
> tport_vsend returned 639
> nta: sent REGISTER (13181995) to */XX.XX.XXX.XXX:5060
> tport_pend(0x86afae0): pending 0x8dd0a588 for udp/XX.XX.XXX.XXX:5080
> (already 0)
> nta: timer set to 32000 ms
> nta: timer shortened to 1000 ms
> tport_wakeup_pri(0x86afae0): events IN
> tport_recv_event(0x86afae0)
> tport_recv_iovec(0x86afae0) msg 0x8dd08cf8 from
> (udp/XX.XX.XXX.XXX:5080) has 526 bytes, veclen = 1
> tport_deliver(0x86afae0): msg 0x8dd08cf8 (526 bytes) from
> udp/XX.XX.XXX.XXX:5080/sip next=(nil)
> nta: received 407 Proxy Authentication Required for REGISTER (13181995)
> nta: 407 Proxy Authentication Required is going to a transaction
> nta_outgoing: RTT is 135.683 ms
> tport_release(0x86afae0): 0x8dd0a588 by 0x8dd009d8 with 0x8dd08cf8
> auth_digest_challenge_get(): got 7
> nta: outgoing_free(0x8dd009d8)
> nua: nua_application_event: entering
> nua: nua_authenticate: entering
> nua(0x873dc88): sent signal r_authenticate
> nua: nua_handle_magic: entering
> auth_digest_a1() has A1 = MD5(###########:callcentric.com:passwd) =
> 8dddd49339918097d09e22dd7b15c38b
> A2 = MD5(REGISTER:sip:XX.XX.XXX.XXX:5060)
> auth_response: 9f45cc31d0328fdf18a7e4d3b547e3ea =
>
> MD5(8dddd49339918097d09e22dd7b15c38b:dbcc6c9095c35c4be730ec1110f970e5:db5f9cddc4d0d297aa85cc660f20595a)
> (qop=NONE)
> nta: selecting scheme sip
> tport_tsend(0x86afae0) tpn = */XX.XX.XXX.XXX:5060
> tport_resolve addrinfo = XX.XX.XXX.XXX:5060
> tport_by_addrinfo(0x86afae0): not found by name */XX.XX.XXX.XXX:5060
> tport_vsend returned 859
> nta: sent REGISTER (13181996) to */XX.XX.XXX.XXX:5060
> tport_pend(0x86afae0): pending 0x8dd08cf8 for udp/XX.XX.XXX.XXX:5080
> (already 0)
> tport_wakeup_pri(0x86afae0): events IN
> tport_recv_event(0x86afae0)
> tport_recv_iovec(0x86afae0) msg 0x8dd1ae88 from
> (udp/XX.XX.XXX.XXX:5080) has 526 bytes, veclen = 1
> tport_deliver(0x86afae0): msg 0x8dd1ae88 (526 bytes) from
> udp/XX.XX.XXX.XXX:5080/sip next=(nil)
> nta: received 407 Proxy Authentication Required for REGISTER (13181996)
> nta: 407 Proxy Authentication Required is going to a transaction
> nta_outgoing: RTT is 127.055 ms
> tport_release(0x86afae0): 0x8dd08cf8 by 0x8dd08a98 with 0x8dd1ae88
> auth_digest_challenge_get(): got 7
> auth_digest_a1() has A1 = MD5(###########:callcentric.com:passwd) =
> 8dddd49339918097d09e22dd7b15c38b
> A2 = MD5(REGISTER:sip:XX.XX.XXX.XXX:5060)
> auth_response: c0b3965ec27e2e3386277645ae14f324 =
>
> MD5(8dddd49339918097d09e22dd7b15c38b:c76385015930949803ca8b0946f81d0e:db5f9cddc4d0d297aa85cc660f20595a)
> (qop=NONE)
> nta: selecting scheme sip
> tport_tsend(0x86afae0) tpn = */XX.XX.XXX.XXX:5060
> tport_resolve addrinfo = XX.XX.XXX.XXX:5060
> tport_by_addrinfo(0x86afae0): not found by name */XX.XX.XXX.XXX:5060
> tport_vsend returned 859
> nta: sent REGISTER (13181997) to */XX.XX.XXX.XXX:5060
> tport_pend(0x86afae0): pending 0x8dd19ea8 for udp/XX.XX.XXX.XXX:5080
> (already 0)
> nta: outgoing_free(0x8dd08a98)
> nua: nua_application_event: entering
> nua: nua_handle_magic: entering
> tport_wakeup_pri(0x86afae0): events IN
> tport_recv_event(0x86afae0)
> tport_recv_iovec(0x86afae0) msg 0x8dd1ae88 from
> (udp/XX.XX.XXX.XXX:5080) has 526 bytes, veclen = 1
> tport_deliver(0x86afae0): msg 0x8dd1ae88 (526 bytes) from
> udp/XX.XX.XXX.XXX:5080/sip next=(nil)
> nta: received 407 Proxy Authentication Required for REGISTER (13181997)
> nta: 407 Proxy Authentication Required is going to a transaction
> nta_outgoing: RTT is 139.175 ms
> tport_release(0x86afae0): 0x8dd19ea8 by 0x8dd18790 with 0x8dd1ae88
> auth_digest_challenge_get(): got 7
> auth_digest_a1() has A1 = MD5(###########:callcentric.com:passwd) =
> 8dddd49339918097d09e22dd7b15c38b
> A2 = MD5(REGISTER:sip:XX.XX.XXX.XXX:5060)
> auth_response: f014cc64fa858ec3615b2b1caab196a6 =
>
> MD5(8dddd49339918097d09e22dd7b15c38b:274bba14cbca0384c30f227da6c42c35:db5f9cddc4d0d297aa85cc660f20595a)
> (qop=NONE)
> nta: selecting scheme sip
> tport_tsend(0x86afae0) tpn = */XX.XX.XXX.XXX:5060
> tport_resolve addrinfo = XX.XX.XXX.XXX:5060
> tport_by_addrinfo(0x86afae0): not found by name */XX.XX.XXX.XXX:5060
> tport_vsend returned 859
> nta: sent REGISTER (13181998) to */XX.XX.XXX.XXX:5060
> tport_pend(0x86afae0): pending 0x8dd18f80 for udp/XX.XX.XXX.XXX:5080
> (already 0)
> nta: outgoing_free(0x8dd18790)
> nua: nua_application_event: entering
> nua: nua_handle_magic: entering
> tport_wakeup_pri(0x86afae0): events IN
> tport_recv_event(0x86afae0)
> tport_recv_iovec(0x86afae0) msg 0x8dd1ae88 from
> (udp/XX.XX.XXX.XXX:5080) has 526 bytes, veclen = 1
> tport_deliver(0x86afae0): msg 0x8dd1ae88 (526 bytes) from
> udp/XX.XX.XXX.XXX:5080/sip next=(nil)
> nta: received 407 Proxy Authentication Required for REGISTER (13181998)
> nta: 407 Proxy Authentication Required is going to a transaction
> nta_outgoing: RTT is 114.044 ms
> tport_release(0x86afae0): 0x8dd18f80 by 0x8dd16e10 with 0x8dd1ae88
> nta: outgoing_free(0x8dd16e10)
> nua(0x873dc88): removing register usage
> nta_leg_destroy(0x8dd16398)
> nua: nua_application_event: entering
> nua: nua_authenticate: entering
> nua(0x873dc88): sent signal r_authenticate
> nua: nua_handle_magic: entering
> nua: nua_application_event: entering
> nua: nua_handle_destroy: entering
> nua(0x873dc88): sent signal r_destroy
> nua: nua_handle_magic: entering
> nua: nua_handle_bind: entering
> nua: nua_handle_destroy: entering
> nta_leg_destroy((nil))
> soa_destroy(static::0x8dd11008) called
> nta: timer not set
> 2011-06-02 13:36:19.875422 [WARNING] sofia_reg.c:401 Timeout
> Registering ###########-callcentric.com
> nua: nua_handle_destroy: entering
> 2011-06-02 13:36:20.881513 [WARNING] sofia_reg.c:425
> ###########-callcentric.com Failed Registration [0], setting retry to
> 30 seconds.
>
>
> Thanks in advance
>
> _______________________________________________
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20110603/b6188dae/attachment.html 