[Freeswitch-dev] sofia profile stop response

Tue Jul 2 07:47:04 MSD 2013

hey Anthony,

Thanks for help!

ok, I can see a deadlock from logs, but why? I had two profile, internal
and igmp profile.
For me, it looks like profiler are restarting itself, isn't it?

Logs are:

internal relates (works) :
2013-07-01 17:09:40.406838 [CRIT] sofia.c:2627 Waiting for 1 session(s)
2013-07-01 17:09:40.486904 [NOTICE] sofia.c:2650 Waiting for worker thread
2013-07-01 17:09:40.486904 [INFO] switch_core_sqldb.c:1490 sofia:internal
Destroying SQL queue.
2013-07-01 17:09:40.686902 [INFO] switch_core_sqldb.c:1434 sofia:internal
Stopping SQL thread.
2013-07-01 17:09:40.686902 [DEBUG] sofia.c:2705 Write lock internal
2013-07-01 17:09:40.686902 [DEBUG] sofia.c:2717 Write unlock internal
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 debug [0]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 sip-trace [no]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 sip-capture [no]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 watchdog-enabled [no]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 watchdog-step-timeout
[30000]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 watchdog-event-timeout
[30000]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 log-auth-failures [true]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669
forward-unsolicited-mwi-notify [false]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 context [default]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 rfc2833-pt [101]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 sip-port [5060]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 dialplan [XML]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 dtmf-duration [2000]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 inbound-codec-prefs
[G722,PCMU,PCMA,GSM]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 outbound-codec-prefs
[G722,PCMU,PCMA,GSM]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 rtp-timer-name [soft]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 rtp-ip [10.0.1.45]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 sip-ip [10.0.1.45]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 hold-music
[local_stream://moh]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 apply-nat-acl [nat.auto]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 apply-inbound-acl [domains]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 local-network-acl
[localnet.auto]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 record-path
[/usr/local/freeswitch/recordings]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 record-template
[${caller_id_number}.${target_domain}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 manage-presence [true]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 presence-hosts
[10.0.1.45,10.0.1.45]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 presence-privacy [false]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 inbound-codec-negotiation
[greedy]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 tls [false]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 tls-only [false]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 tls-bind-params
[transport=tls]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 tls-sip-port [5061]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 tls-cert-dir
[/usr/local/freeswitch/conf/ssl]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 tls-passphrase []
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 tls-verify-date [true]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 tls-verify-policy [none]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 tls-verify-depth [2]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 tls-verify-in-subjects []
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 tls-version [tlsv1]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 inbound-late-negotiation
[true]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 inbound-zrtp-passthru [true]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 suppress-cng [true]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 nonce-ttl [60]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 auth-calls [true]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669
inbound-reg-force-matching-username [true]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 auth-all-packets [false]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 ext-rtp-ip [auto-nat]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 ext-sip-ip [auto-nat]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 rtp-timeout-sec [300]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 rtp-hold-timeout-sec [1800]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 force-register-domain
[10.0.1.45]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 force-subscription-domain
[10.0.1.45]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 force-register-db-domain
[10.0.1.45]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:3669 challenge-realm [auto_from]
2013-07-01 17:09:41.146829 [NOTICE] sofia.c:4755 Started Profile internal
[sofia_reg_internal]
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:2385 Creating agent for internal
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:2482 Created agent for internal
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:2525 Set params for internal
2013-07-01 17:09:41.146829 [DEBUG] sofia.c:2569 Activated db for internal
2013-07-01 17:09:41.156827 [INFO] switch_core_sqldb.c:1449 sofia:internal
Starting SQL thread.
2013-07-01 17:09:41.156827 [DEBUG] sofia.c:2607 Starting thread for internal
2013-07-01 17:09:41.156827 [DEBUG] sofia.c:2285 Launching worker thread for
internal
2013-07-01 17:09:41.406840 [CRIT] sofia.c:2627 Waiting for 1 session(s)

IGMP parts(deadlock on sofia.c:2705 ):

2013-07-01 17:09:43.406902 [NOTICE] sofia.c:2650 Waiting for worker thread
2013-07-01 17:09:43.406902 [INFO] switch_core_sqldb.c:1490 sofia:igmp
Destroying SQL queue.
2013-07-01 17:09:43.606848 [INFO] switch_core_sqldb.c:1434 sofia:igmp
Stopping SQL thread.
2013-07-01 17:09:43.606848 [DEBUG] sofia.c:2705 Write lock igmp
2013-07-01 18:10:42.696829 [DEBUG] switch_ivr_originate.c:2044 Parsing
global variables
2013-07-01 18:10:42.696829 [DEBUG] switch_event.c:1608 Parsing variable
[originate_timeout]=[10]
2013-07-01 18:10:42.696829 [DEBUG] switch_event.c:1608 Parsing variable
[channel_username]=[server_user_admin]
2013-07-01 18:10:42.696829 [DEBUG] switch_event.c:1608 Parsing variable
[channel_caller_id_number]=[server_user_admin]
2013-07-01 18:10:42.696829 [DEBUG] switch_event.c:1608 Parsing variable
[origination_caller_id_name]=[server_user_admin]
2013-07-01 18:10:42.696829 [DEBUG] switch_event.c:1608 Parsing variable
[origination_caller_id_number]=[server_user_admin]
2013-07-01 18:10:42.696829 [DEBUG] switch_ivr_originate.c:2044 Parsing
global variables
2013-07-01 18:10:42.696829 [ERR] mod_sofia.c:5190 Invalid Profile
2013-07-01 18:10:42.696829 [NOTICE] mod_sofia.c:5473 Close Channel N/A
[CS_NEW]
2013-07-01 18:10:42.696829 [DEBUG] switch_core_state_machine.c:568 ()
Running State Change CS_DESTROY
2013-07-01 18:10:42.696829 [DEBUG] switch_core_state_machine.c:578 (N/A)
State DESTROY
2013-07-01 18:10:42.696829 [DEBUG] mod_sofia.c:401 N/A SOFIA DESTROY
2013-07-01 18:10:42.696829 [DEBUG] switch_core_state_machine.c:578 (N/A)
State DESTROY going to sleep
2013-07-01 18:10:42.696829 [NOTICE] switch_ivr_originate.c:2639 Cannot
create outgoing channel of type [sofia] cause: [INVALID_PROFILE]
2013-07-01 18:10:42.696829 [NOTICE] switch_ivr_originate.c:2639 Cannot
create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2013-07-01 18:10:42.696829 [DEBUG] switch_ivr_originate.c:3605 Originate
Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2013-07-01 18:10:42.696829 [NOTICE] switch_ivr_originate.c:2639 Cannot
create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2013-07-01 18:10:42.696829 [DEBUG] switch_ivr_originate.c:3605 Originate
Resulted in Error Cause: 606 [USER_NOT_REGISTERED]

I did use 'show channels', and there is none.

Any idea?

Cheers

On Fri, Jun 28, 2013 at 11:50 PM, Anthony Minessale <
anthony.minessale at gmail.com> wrote:

> Look in your logs for any messages about that profile.
> Also gcore the process and do a thread apply all bt to see any hints.
>
>
>
> On Thu, Jun 27, 2013 at 10:39 PM, Xijing Dai <dxj19831029 at gmail.com>wrote:
>
>> hey all,
>>
>>
>> I have experienced a lot of times that sofia profile stops to response
>> for any sip messages. And when you type sofia status, that profile is gone,
>> but if we check the port by netstat, the port is still opened by freeswitch.
>>
>> This happens if we keep freeswitch running in 1 - 2 days. And there is no
>> error log.
>>
>>
>> Any idea on how to debug?
>>
>>
>> Cheers.
>>
>>
>>
>>
>>
>>
>>
>> _________________________________________________________________________
>> Professional FreeSWITCH Consulting Services:
>> consulting at freeswitch.org
>> http://www.freeswitchsolutions.com
>>
>> 
>> 
>>
>> Official FreeSWITCH Sites
>> http://www.freeswitch.org
>> http://wiki.freeswitch.org
>> http://www.cluecon.com
>>
>> FreeSWITCH-dev mailing list
>> FreeSWITCH-dev at lists.freeswitch.org
>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev
>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev
>> http://www.freeswitch.org
>>
>>
>
>
> --
> Anthony Minessale II
>
> FreeSWITCH http://www.freeswitch.org/
> ClueCon http://www.cluecon.com/
> Twitter: http://twitter.com/FreeSWITCH_wire
>
> AIM: anthm
> MSN:anthony_minessale at hotmail.com
> GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com
> IRC: irc.freenode.net #freeswitch
>
> FreeSWITCH Developer Conference
> sip:888 at conference.freeswitch.org
> googletalk:conf+888 at conference.freeswitch.org
> pstn:+19193869900
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> 
> 
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-dev mailing list
> FreeSWITCH-dev at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev
> http://www.freeswitch.org
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-dev/attachments/20130702/53aee37b/attachment-0001.html 