[Freeswitch-dev] sofia profile stop response

Tue Jul 2 17:12:21 MSD 2013

edit conf/autoload_configs/sofia.conf and uncomment the auto-restart param.
 The ip change detection code must be trying to restart your profile.

On Mon, Jul 1, 2013 at 10:47 PM, Xijing Dai <dxj19831029 at gmail.com> wrote:

> 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
>>
>>
>
> _________________________________________________________________________
> 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-dev/attachments/20130702/b324dcce/attachment-0001.html 