[Freeswitch-users] Strange errors from sqlite DB

Ashley B ashley at midletearth.com
Mon Sep 27 05:48:00 PDT 2010 

Hi, 

I was experiencing the same issue all of a sudden on FreeSWITCH (Windows -
17048M). FS was running without a hitch for 2 months, until I started seeing
the below on our console log whenever receiving an inbound call (the call
never made it through to the client obviously). After restarting FS, the
problem went away but I saw it happen once about 5 months ago as well. 

We make no external calls whatsoever to the SQLite db's. 

Has anyone identified why this could happen and how to prevent future
occurrences of it?

Thanks
Ashley


...see log:

2010-09-25 13:22:56.136423 [ERR] switch_core_sqldb.c:722 SQL ERR: [select
call_id,sip_user,sip_host,contact,status,rpid,expires,user_agent,server_user
,server_host,profile_name,network_ip,0 from sip_registrations where expires
> 0 and expires <= 1285417376] library routine called out of sequence
2010-09-25 13:22:56.136423 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
delete from sip_registrations where expires > 0 and expires <= 1285417376
and hostname='bet'
2010-09-25 13:22:56.136423 [ERR] switch_core_sqldb.c:722 SQL ERR: [select
call_id from sip_shared_appearance_dialogs where hostname='bet' and
profile_name='internal' and expires <= 1285417376] library routine called
out of sequence
2010-09-25 13:22:56.136423 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
delete from sip_registrations where expires > 0 and hostname='bet' and
expires <= 1285417376
2010-09-25 13:22:56.136423 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
delete from sip_presence where expires > 0 and expires <= 1285417376 and
hostname='bet'
2010-09-25 13:22:56.136423 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
delete from sip_authentication where expires > 0 and expires <= 1285417376
and hostname='bet'
2010-09-25 13:22:56.136423 [ERR] switch_core_sqldb.c:722 SQL ERR: [select
call_id from sip_subscriptions where (expires = -1 or (expires > 0 and
expires <= 1285417376)) and hostname='bet'] library routine called out of
sequence
2010-09-25 13:22:56.136423 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
delete from sip_subscriptions where (expires = -1 or (expires > 0 and
expires <= 1285417376)) and hostname='bet'
2010-09-25 13:22:56.136423 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
delete from sip_dialogs where (expires = -1 or (expires > 0 and expires <=
1285417376)) and hostname='bet'
2010-09-25 13:23:20.970384 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
BEGIN
2010-09-25 13:23:20.970384 [DEBUG] switch_core_sqldb.c:643 SQL Retry
[library routine called out of sequence]
2010-09-25 13:23:21.069997 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
BEGIN
2010-09-25 13:23:21.069997 [DEBUG] switch_core_sqldb.c:643 SQL Retry
[library routine called out of sequence]
2010-09-25 13:23:21.171564 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
BEGIN
2010-09-25 13:23:21.171564 [DEBUG] switch_core_sqldb.c:643 SQL Retry
[library routine called out of sequence]
2010-09-25 13:23:21.271177 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
BEGIN
2010-09-25 13:23:21.271177 [DEBUG] switch_core_sqldb.c:643 SQL Retry
[library routine called out of sequence]
2010-09-25 13:23:21.372743 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
BEGIN
2010-09-25 13:23:21.372743 [DEBUG] switch_core_sqldb.c:643 SQL Retry
[library routine called out of sequence]
2010-09-25 13:23:21.472357 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
BEGIN
2010-09-25 13:23:21.472357 [DEBUG] switch_core_sqldb.c:643 SQL Retry
[library routine called out of sequence]
2010-09-25 13:23:21.573923 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
BEGIN
2010-09-25 13:23:21.573923 [DEBUG] switch_core_sqldb.c:643 SQL Retry
[library routine called out of sequence]
2010-09-25 13:23:21.673536 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
BEGIN
2010-09-25 13:23:21.673536 [DEBUG] switch_core_sqldb.c:643 SQL Retry
[library routine called out of sequence]
2010-09-25 13:23:21.775103 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
BEGIN
2010-09-25 13:23:21.775103 [DEBUG] switch_core_sqldb.c:643 SQL Retry
[library routine called out of sequence]
2010-09-25 13:23:21.874716 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]



-----Original Message-----
From: Peter Olsson [mailto: peter.olsson at visionutveckling.se] 
Sent: 3 May 2010 12:58 PM
To: FreeSWITCH Users Help
Subject: RE: [Freeswitch-users] Strange errors from sqlite DB

Brian,

This is the log when it first occured. I'm not sure if I'll ever recreate
the issue, so do you think I should open a jira anyway? This log is more or
less all I have.

2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:119
(sofia/internal/50711 at 10.10.1.35) State Change CS_ROUTING -> CS_EXECUTE
2010-05-03 20:25:32.673126 [DEBUG] switch_core_session.c:1021 Send signal
sofia/internal/50711 at 10.10.1.35 [BREAK]
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/50711 at 10.10.1.35) State ROUTING going to sleep
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/50711 at 10.10.1.35) Running State Change CS_EXECUTE
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:348
(sofia/internal/50711 at 10.10.1.35) State EXECUTE
2010-05-03 20:25:32.673126 [DEBUG] mod_sofia.c:226 sofia/internal/50711 at
10.10.1.35 SOFIA EXECUTE
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:157
sofia/internal/50711 at 10.10.1.35 Standard EXECUTE
EXECUTE sofia/internal/50711 at 10.10.1.35 set(hangup_after_bridge=true)
2010-05-03 20:25:32.673126 [DEBUG] mod_dptools.c:816 sofia/internal/50711 at
10.10.1.35 SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/50711 at 10.10.1.35
bridge(sofia/gateway/vip2000-trunk/00709275071)
2010-05-03 20:25:32.673126 [NOTICE] switch_channel.c:669 New Channel
sofia/internal/00709275071 [41b995f9-df54-4053-a521-ae804c6c1c6b]
2010-05-03 20:25:32.673126 [DEBUG] mod_sofia.c:3386
(sofia/internal/00709275071) State Change CS_NEW -> CS_INIT
2010-05-03 20:25:32.673126 [DEBUG] switch_core_session.c:1021 Send signal
sofia/internal/00709275071 [BREAK]
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/00709275071) Running State Change CS_INIT
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/00709275071) State INIT
2010-05-03 20:25:32.673126 [DEBUG] mod_sofia.c:83 sofia/internal/00709275071
SOFIA INIT
2010-05-03 20:25:32.673126 [DEBUG] mod_sofia.c:117
(sofia/internal/00709275071) State Change CS_INIT -> CS_ROUTING
2010-05-03 20:25:32.673126 [DEBUG] switch_core_session.c:1021 Send signal
sofia/internal/00709275071 [BREAK]
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/00709275071) State INIT going to sleep
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/00709275071) Running State Change CS_ROUTING
2010-05-03 20:25:32.673126 [DEBUG] sofia.c:4153 Channel
sofia/internal/00709275071 entering state [calling][0]
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/00709275071) State ROUTING
2010-05-03 20:25:32.673126 [DEBUG] mod_sofia.c:140
sofia/internal/00709275071 SOFIA ROUTING
2010-05-03 20:25:32.673126 [DEBUG] switch_ivr_originate.c:66
(sofia/internal/00709275071) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2010-05-03 20:25:32.673126 [DEBUG] switch_core_session.c:1021 Send signal
sofia/internal/00709275071 [BREAK]
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/00709275071) State ROUTING going to sleep
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/00709275071) Running State Change CS_CONSUME_MEDIA
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/00709275071) State CONSUME_MEDIA
2010-05-03 20:25:32.673126 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/00709275071) State CONSUME_MEDIA going to sleep
2010-05-03 20:25:32.688751 [INFO] sofia.c:662 Update Callee ID to
"00709275071" <00709275071>
2010-05-03 20:25:32.751251 [ERR] switch_core_sqldb.c:722 SQL ERR: [select
sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_hos
t,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscripti
ons.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscripti
ons.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subsc
riptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,
'CS_ROUTING','unknown','10.10.1.35',sip_presence.status,sip_presence.rpid
from sip_subscriptions left join sip_presence on
(sip_subscriptions.sub_to_user=sip_presence.sip_user and
sip_subscriptions.sub_to_host=sip_presence.sip_host and
sip_subscriptions.profile_name=sip_presence.profile_name) where
sip_subscriptions.expires > -1 and (event='presence' or event='dialog') and
sub_to_user='50711' and (sub_to_host='10.10.1.35' or presence_hosts like
'%10.10.1.35%') and (sip_subscriptions.profile_name = 'internal' or
sip_subscriptions.presence_hosts != sip_subscriptions.sub_to_host)] library
routine called out of sequence
2010-05-03 20:25:32.782501 [DEBUG] sofia.c:4153 Channel
sofia/internal/00709275071 entering state [proceeding][180]
2010-05-03 20:25:32.782501 [NOTICE] sofia.c:4223 Ring-Ready
sofia/internal/00709275071!
2010-05-03 20:25:32.782501 [NOTICE] mod_sofia.c:1837 Ring-Ready
sofia/internal/50711 at 10.10.1.35!
2010-05-03 20:25:32.782501 [ERR] switch_core_sqldb.c:525 Statement Error
[select 'appearance-index=1' from sip_subscriptions where expires > -1 and
hostname='teller' and event='call-info' and sub_to_user='00709275071' and
sub_to_host='192.168.1.55']!
2010-05-03 20:25:32.782501 [DEBUG] switch_core_session.c:641 Send signal
sofia/internal/50711 at 10.10.1.35 [BREAK]
2010-05-03 20:25:32.782501 [NOTICE] switch_ivr_originate.c:437 Ring Ready
sofia/internal/50711 at 10.10.1.35!
2010-05-03 20:25:32.782501 [DEBUG] sofia.c:4153 Channel
sofia/internal/00709275071 entering state [proceeding][183]
2010-05-03 20:25:32.782501 [DEBUG] sofia.c:4164 Remote SDP:

________________________________________
Från: freeswitch-users-bounces at lists.freeswitch.org
[freeswitch-users-bounces at lists.freeswitch.org] f&#246;r Brian West
[brian at freeswitch.org]
Skickat: den 3 maj 2010 21:33
Till: freeswitch-users at lists.freeswitch.org
Ämne: Re: [Freeswitch-users] Strange errors from sqlite DB

Happen to be touching core.db from outside of FreeSWITCH?  Also what SVN/GIT
are you on?

/b

On May 3, 2010, at 2:27 PM, Peter Olsson wrote:

> ----
>
> 2010-05-03 20:29:21.032501 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
> insert into sip_authentication (nonce,expires,profile_name,hostname,
last_nc) values('6e5df620-d388-4f93-b0b0-8da4cf880ef1', 1272911421,
'(NULL)', 'internal', 0)
> 2010-05-03 20:29:21.048126 [ERR] switch_core_sqldb.c:722 SQL ERR: [select
nonce,last_nc from sip_authentication where
nonce='6e5df620-d388-4f93-b0b0-8da4cf880ef1' and last_nc < 1] library
routine called out of sequence
> 2010-05-03 20:29:21.048126 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
> update sip_authentication set expires='1272911421',last_nc=1 where
nonce='6e5df620-d388-4f93-b0b0-8da4cf880ef1'
> 2010-05-03 20:29:21.048126 [ERR] switch_core_sqldb.c:404 SQL ERR [library
routine called out of sequence]
>
> Regards,
>
> Peter

More information about the FreeSWITCH-users mailing list