[SR-Users] Reconnection to db
Daniel-Constantin Mierla
miconda at gmail.com
Wed Jan 19 12:27:08 CET 2011
Hello,
thanks for assisting with testing. So right now there is no more issue
that you could spot, right?
I will wait a bit more and then backport the fixes.
Thanks,
Daniel
On 1/19/11 11:09 AM, Javier Gallart wrote:
> Hi Daniel
>
>
> i just tested the new version, now the mtree module is properly loaded.
> Logs when the server has been stopped (fisrt attempt):
> r_ctl
> Jan 19 04:49:58 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: db_postgres
> [km_dbase.c:130]: connection OK
> Jan 19 04:49:58 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: db_postgres
> [km_dbase.c:159]: sending query ok: 0x92fc00 (7) - [select
> tname,tprefix,tvalue from mtree order by tname]
> Jan 19 04:49:58 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: <core>
> [db_res.c:118]: allocate 48 bytes for result set at 0x94d020
> Jan 19 04:49:58 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: db_postgres
> [km_dbase.c:229]: 0x92fc00 PQresultStatus(PGRES_FATAL_ERROR)
> PQgetResult(0x2b52d00)
> Jan 19 04:49:58 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: ERROR: db_postgres
> [km_dbase.c:247]: 0x92fc00 - invalid query, execution aborted
> Jan 19 04:49:58 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: ERROR: db_postgres
> [km_dbase.c:249]: 0x92fc00 - PQresultStatus(PGRES_FATAL_ERROR)
> Jan 19 04:49:58 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: ERROR: db_postgres
> [km_dbase.c:251]: 0x92fc00: server closed the connection
> unexpectedly#012#011This probably means the server terminated
> abnormally#012#011before or while processing the request.#012
>
> Server down, second attempt (the server down condition is properly
> detected):
>
> Jan 19 04:50:18 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: db_postgres
> [km_dbase.c:133]: connection reset
> Jan 19 04:50:18 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: db_postgres
> [km_dbase.c:326]: PQclear(0x2b52d00) result set
> Jan 19 04:50:18 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: WARNING: db_postgres
> [km_dbase.c:167]: postgres query command failed, connection status 1,
> error [no connection to the server#012]
> Jan 19 04:50:18 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: db_postgres
> [km_dbase.c:170]: reseting the connection to postgress server
> Jan 19 04:50:18 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: WARNING: db_postgres
> [km_dbase.c:167]: postgres query command failed, connection status 1,
> error [no connection to the server#012]
> Jan 19 04:50:18 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: db_postgres
> [km_dbase.c:170]: reseting the connection to postgress server
> Jan 19 04:50:18 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: WARNING: db_postgres
> [km_dbase.c:167]: postgres query command failed, connection status 1,
> error [no connection to the server#012]
> Jan 19 04:50:18 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: db_postgres
> [km_dbase.c:170]: reseting the connection to postgress server
> Jan 19 04:50:18 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: ERROR: db_postgres
> [km_dbase.c:175]: 0x92fc00 PQsendQuery Error: no connection to the
> server#012could not connect to server: Connection refused#012#011Is
> the server running on host "x.x.x.x" and accepting#012#011TCP/IP
> connections on port 5432?#012 Query: select tname,tprefix,tvalue from
> mtree order by tname
>
> Server back up (the connection is restarted nad it works fine):
>
> Jan 19 04:50:44 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: db_postgres
> [km_dbase.c:133]: connection reset
> Jan 19 04:50:44 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: db_postgres
> [km_dbase.c:159]: sending query ok: 0x92fc00 (7) - [select
> tname,tprefix,tvalue from mtree order by tname]
> Jan 19 04:50:44 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: <core>
> [db_res.c:118]: allocate 48 bytes for result set at 0x94d020
> Jan 19 04:50:44 kam-test
> /usr/local/kamailio.20110118/sbin/kamailio[7403]: DEBUG: db_postgres
> [km_dbase.c:229]: 0x92fc00 PQresultStatus(PGRES_TUPLES_OK)
> PQgetResult(0x2b52d00)
>
>
> Regards
>
> Javi
>
>
>
>
> On Tue, Jan 18, 2011 at 11:55 AM, Daniel-Constantin Mierla
> <miconda at gmail.com <mailto:miconda at gmail.com>> wrote:
>
> Hello,
>
> I did a new tuning, skipping reconnect in submit query if
> connection is ok - the result might be broken due to other
> reasons and will be reported when fetching it. If you can try
> again and report, would be appreciated.
>
> Thanks,
> Daniel
>
>
> On 1/18/11 11:34 AM, Javier Gallart wrote:
>> Hi Daniel
>>
>>
>> I tested the patch but the mtree module fails to start:
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: DEBUG: <core>
>> [db.c:202]: using db bind api for db_postgres
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: DEBUG: <core>
>> [db.c:285]: connection 0x931768 not found in pool
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: DEBUG: db_postgres
>> [km_pg_con.c:51]: db_id = 0x931768
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: DEBUG: db_postgres
>> [km_pg_con.c:64]: 0x9319b8=pkg_malloc(72)
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: DEBUG: db_postgres
>> [km_pg_con.c:76]: opening connection:
>> postgres://xxxx:xxxx@79.170.68.171/routing
>> <http://xxxx:xxxx@79.170.68.171/routing>
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: DEBUG: db_postgres
>> [km_pg_con.c:80]: PQsetdbLogin(0x2259780)
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: DEBUG: mtree
>> [mtree_mod.c:255]: database connection opened successfully
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: WARNING: db_postgres
>> [km_dbase.c:161]: postgres result check failed with code 7
>> (PGRES_FATAL_ERROR)
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: WARNING: db_postgres
>> [km_dbase.c:165]: postgres query command failed, connection
>> status 0, error []
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: WARNING: db_postgres
>> [km_dbase.c:165]: postgres query command failed, connection
>> status 0, error [another command is already in progress#012]
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: WARNING: db_postgres
>> [km_dbase.c:165]: postgres query command failed, connection
>> status 0, error [another command is already in progress#012]
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: ERROR: db_postgres
>> [km_dbase.c:173]: 0x931660 PQsendQuery Error: another command is
>> already in progress#012 Query: select tname,tprefix,tvalue from
>> mtree order by tname
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: ERROR: <core>
>> [db_query.c:101]: error while submitting query
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: ERROR: mtree
>> [mtree_mod.c:626]: Error while querying db
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: ERROR: mtree
>> [mtree_mod.c:296]: cannot load trees from database
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: DEBUG: <core>
>> [db_pool.c:102]: removing connection from the pool
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: DEBUG: db_postgres
>> [km_pg_con.c:124]: PQfinish(0x2259780)
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: DEBUG: db_postgres
>> [km_pg_con.c:128]: pkg_free(0x9319b8)
>> Jan 18 04:15:55 kam-test ./kamailio[4616]: ERROR: <core>
>> [sr_module.c:875]: init_mod(): Error while initializing module
>> mtree (/usr/local/kamailio.20110117/lib/kamailio/modules/mtree.so)
>>
>> I don't see an easy way to fix this, because even after the
>> server restart, PQsendQuery will return 1, and therefore
>> db_postgres_fetch_result is executed and fails. I will keep
>> looking into this, for now it's not a big issue since we know
>> that the second attempt works fine....
>>
>>
>> Thanks
>>
>> Javi
>>
>> On Sun, Jan 16, 2011 at 11:09 PM, Daniel-Constantin Mierla
>> <miconda at gmail.com <mailto:miconda at gmail.com>> wrote:
>>
>> Hello,
>>
>> made a commit to fix in such case, when the broken connection
>> is reported after doing actually the query, attempting to
>> reconnect then. Let me know if works now.
>>
>> Cheers,
>> Daniel
>>
>>
>> On 1/16/11 6:17 PM, Javier Gallart wrote:
>>> Hi Daniel,
>>>
>>> I'm using postgres 8.4 at the server and libpq5 library for
>>> the client. I've been testing again and the problem is that
>>> after a db restart (no matter if done through a service
>>> restart or having t down for some time), the
>>> PQstatus(CON_CONNECTION(_con)) function returns a
>>> CONNECTION_OK and therefore it doesn't try to reconnect.
>>> It's on the second attempt of the mt_reload that it returns
>>> the correct CONNECTION_BAD value, and reconnection at that
>>> point works perfectly well.
>>>
>>> First attempt after db restart (I've added a dbg message if
>>> we get a CONNECTION_OK):
>>>
>>> Jan 16 12:03:00 kam-test ./kamailio[22214]: DEBUG:
>>> db_postgres [km_dbase.c:129]: connection OK
>>> Jan 16 12:03:00 kam-test ./kamailio[22214]: DEBUG:
>>> db_postgres [km_dbase.c:155]: sending query ok: 0x92f888 -
>>> [select tname,tprefix,tvalue from mtree order by tname]
>>> Jan 16 12:03:00 kam-test ./kamailio[22214]: DEBUG: <core>
>>> [db_res.c:118]: allocate 48 bytes for result set at 0x94cd08
>>> Jan 16 12:03:00 kam-test ./kamailio[22214]: DEBUG:
>>> db_postgres [km_dbase.c:222]: 0x92f888
>>> PQresultStatus(PGRES_FATAL_ERROR) PQgetResult(0x1a30d10)
>>> Jan 16 12:03:00 kam-test ./kamailio[22214]: ERROR:
>>> db_postgres [km_dbase.c:238]: 0x92f888 - invalid query,
>>> execution aborted
>>> Jan 16 12:03:00 kam-test ./kamailio[22214]: ERROR:
>>> db_postgres [km_dbase.c:239]: 0x92f888 -
>>> PQresultStatus(PGRES_FATAL_ERROR)
>>> Jan 16 12:03:00 kam-test ./kamailio[22214]: ERROR:
>>> db_postgres [km_dbase.c:240]: 0x92f888: server closed the
>>> connection unexpectedly#012#011This probably means the
>>> server terminated abnormally#012#011before or while
>>> processing the request.#012
>>>
>>> Second attempt:
>>>
>>> Jan 16 12:03:08 kam-test ./kamailio[22214]: DEBUG:
>>> db_postgres [km_dbase.c:132]: connection reset
>>> Jan 16 12:03:08 kam-test ./kamailio[22214]: DEBUG:
>>> db_postgres [km_dbase.c:315]: PQclear(0x1a30d10) result set
>>> Jan 16 12:03:08 kam-test ./kamailio[22214]: DEBUG:
>>> db_postgres [km_dbase.c:155]: sending query ok: 0x92f888 -
>>> [select tname,tprefix,tvalue from mtree order by tname]
>>>
>>> Thanks!
>>>
>>> Javi
>>>
>>>
>>>
>>> On Fri, Jan 14, 2011 at 11:42 AM, Daniel-Constantin Mierla
>>> <miconda at gmail.com <mailto:miconda at gmail.com>> wrote:
>>>
>>> Hello,
>>>
>>> what version of postgres and postgres client library are
>>> you using?
>>>
>>> According to the docs from devel manual, this is the
>>> function that should be used to reconnect:
>>>
>>> |PQreset|
>>> Resets the communication channel to the server.
>>>
>>> void PQreset(PGconn *conn);
>>>
>>> This function will close the connection to the
>>> server and attempt to reestablish a new connection
>>> to the same server, using all the same parameters
>>> previously used. This may be useful for error
>>> recovery if a working connection is lost.
>>>
>>> You may see more here:
>>> http://www.network-theory.co.uk/docs/postgresql/vol2/DatabaseConnectionControlFunctions.html
>>>
>>> Somehow seems not to work in this case. Can you try also
>>> with a shorter down time for postgres server, like a
>>> normal restart? Would be intrested to see if the client
>>> side loses somehow connection parameters due to long
>>> time unconnected.
>>>
>>> Cheers,
>>> Daniel
>>>
>>>
>>> On 1/14/11 11:15 AM, Javier Gallart wrote:
>>>> Hi Daniel
>>>>
>>>>
>>>> this is my test:
>>>>
>>>> 1- Kamailio starts and correctly loads the mtree
>>>> 2- I make whatever modification in the tree and reload
>>>> with mt_reload
>>>> Jan 14 04:19:06 kam-test ./kamailio[31205]: DEBUG:
>>>> db_postgres [km_dbase.c:153]: sending query ok:
>>>> 0x92f880 - [select tname,tprefix,tvalue from mtree
>>>> order by tname]
>>>> Jan 14 04:19:06 kam-test ./kamailio[31205]: DEBUG:
>>>> <core> [db_res.c:118]: allocate 48 bytes for result set
>>>> at 0x94cd00
>>>> Jan 14 04:19:06 kam-test ./kamailio[31205]: DEBUG:
>>>> db_postgres [km_dbase.c:220]: 0x92f880
>>>> PQresultStatus(PGRES_TUPLES_OK) PQgetResult(0x29f05f0)
>>>> Jan 14 04:19:06 kam-test ./kamailio[31205]: DEBUG:
>>>> db_postgres [km_res.c:108]: 3 columns returned from the
>>>> query
>>>> Jan 14 04:19:06 kam-test ./kamailio[31205]: DEBUG:
>>>> <core> [db_res.c:155]: allocate 24 bytes for result
>>>> names at 0x94cc60
>>>> [....]
>>>> Jan 14 04:19:06 kam-test ./kamailio[31205]: DEBUG:
>>>> db_postgres [km_res.c:267]: freeing row buffer at 0x94c940
>>>> Jan 14 04:19:06 kam-test ./kamailio[31205]: DEBUG:
>>>> mtree [mtree.c:738]: adding new tname [1]
>>>> Jan 14 04:19:06 kam-test ./kamailio[31205]: DEBUG:
>>>> <core> [db_res.c:54]: freeing 3 rows
>>>> [...]
>>>> Jan 14 04:19:06 kam-test ./kamailio[31205]: DEBUG:
>>>> <core> [db_res.c:94]: freeing result names at 0x94cc60
>>>> Jan 14 04:19:06 kam-test ./kamailio[31205]: DEBUG:
>>>> <core> [db_res.c:99]: freeing result types at 0x94cbc0
>>>> Jan 14 04:19:06 kam-test ./kamailio[31205]: DEBUG:
>>>> <core> [db_res.c:136]: freeing result set at 0x94cd00
>>>> Jan 14 04:19:06 kam-test ./kamailio[31205]: DEBUG:
>>>> db_postgres [km_dbase.c:313]: PQclear(0x29f05f0) result set
>>>>
>>>> 3. Postgres DB restarts (either through restart, or
>>>> /stop/wait a minute/start)
>>>> No log is written in Kamailio when this happens.
>>>>
>>>> 4.- I try again to reload the tree, and these are the logs:
>>>> Jan 14 04:21:42 kam-test ./kamailio[31205]: DEBUG:
>>>> db_postgres [km_dbase.c:153]: sending query ok:
>>>> 0x92f880 - [select tname,tprefix,tvalue from mtree
>>>> order by tname]
>>>> Jan 14 04:21:42 kam-test ./kamailio[31205]: DEBUG:
>>>> <core> [db_res.c:118]: allocate 48 bytes for result set
>>>> at 0x94cd00
>>>> Jan 14 04:21:42 kam-test ./kamailio[31205]: DEBUG:
>>>> db_postgres [km_dbase.c:220]: 0x92f880
>>>> PQresultStatus(PGRES_FATAL_ERROR) PQgetResult(0x29ef0a0)
>>>> Jan 14 04:21:42 kam-test ./kamailio[31205]: ERROR:
>>>> db_postgres [km_dbase.c:236]: 0x92f880 - invalid query,
>>>> execution aborted
>>>> Jan 14 04:21:42 kam-test ./kamailio[31205]: ERROR:
>>>> db_postgres [km_dbase.c:237]: 0x92f880 -
>>>> PQresultStatus(PGRES_FATAL_ERROR)
>>>> Jan 14 04:21:42 kam-test ./kamailio[31205]: ERROR:
>>>> db_postgres [km_dbase.c:238]: 0x92f880: server closed
>>>> the connection unexpectedly#012#011This probably means
>>>> the server terminated abnormally#012#011before or while
>>>> processing the request.#012
>>>> Jan 14 04:21:42 kam-test ./kamailio[31205]: DEBUG:
>>>> <core> [db_res.c:81]: freeing 0 columns
>>>> Jan 14 04:21:42 kam-test ./kamailio[31205]: DEBUG:
>>>> <core> [db_res.c:136]: freeing result set at 0x94cd00
>>>> Jan 14 04:21:42 kam-test ./kamailio[31205]: ERROR:
>>>> mtree [mtree_mod.c:633]: Error while fetching result
>>>> Jan 14 04:21:42 kam-test ./kamailio[31205]: ERROR:
>>>> db_postgres [km_dbase.c:329]: invalid parameter value
>>>> Jan 14 04:21:42 kam-test ./kamailio[31205]: ERROR:
>>>> mtree [mtree_mod.c:744]: cannot re-load info from database
>>>>
>>>> Thanks in advance
>>>>
>>>>
>>>> Regards
>>>>
>>>> Javi
>>>>
>>>> On Thu, Jan 13, 2011 at 1:56 PM, Daniel-Constantin
>>>> Mierla <miconda at gmail.com <mailto:miconda at gmail.com>>
>>>> wrote:
>>>>
>>>> Can you send the log messages (debug=3) for that
>>>> moment (restart of pg server and making a new
>>>> call/registration)?
>>>>
>>>> Daniel
>>>>
>>>>
>>>> On 1/13/11 12:00 PM, Javier Gallart wrote:
>>>>> Hi Daniel
>>>>>
>>>>> I have just tested it and I'm getting the same
>>>>> results. This is the kamailio version I'm testing:
>>>>> root at kam-test:/usr/local/kamailio/sbin# ./kamailio -V
>>>>> version: kamailio 3.2.0-dev2 (x86_64/linux) 35568f
>>>>>
>>>>> Thanks!
>>>>>
>>>>> Javi
>>>>>
>>>>>
>>>>> On Tue, Jan 4, 2011 at 3:46 PM, Javier Gallart
>>>>> <jgallartm at gmail.com <mailto:jgallartm at gmail.com>>
>>>>> wrote:
>>>>>
>>>>> Hi list
>>>>>
>>>>> we have been testing the mtree module. We do
>>>>> periodical reloads of the mtree table with the
>>>>> "mi mt_reload" command through xmlrpc. It
>>>>> works fine except when the db is restarted. If
>>>>> we manually restart the db and then try the
>>>>> mt_reload commands we get this error:
>>>>> Jan 4 09:13:17
>>>>> server /usr/local/kamailio-3.1.1/sbin/kamailio[28534]:
>>>>> ERROR: db_postgres [km_dbase.c:152]: 0xa6a490
>>>>> PQsendQuery Error: server closed the
>>>>> connection unexpectedly#012#011This probably
>>>>> means the server terminated
>>>>> abnormally#012#011before or while processing
>>>>> the request.#012 Query: select
>>>>> partition,prefix,route from trees order by
>>>>> partition
>>>>> Jan 4 09:13:17 server
>>>>> /usr/local/kamailio-3.1.1/sbin/kamailio[28534]: ERROR:
>>>>> <core> [db_query.c:101]: error while
>>>>> submitting query
>>>>> Jan 4 09:13:17 server
>>>>> /usr/local/kamailio-3.1.1/sbin/kamailio[28534]: ERROR:
>>>>> mtree [mtree_mod.c:622]: Error while querying db
>>>>> Jan 4 09:13:17 server
>>>>> /usr/local/kamailio-3.1.1/sbin/kamailio[28534]: ERROR:
>>>>> mtree [mtree_mod.c:738]: cannot re-load info
>>>>> from database
>>>>>
>>>>> Is there a way to reconnect to the db before
>>>>> sending that command?
>>>>>
>>>>> Thanks in advance
>>>>>
>>>>> Regards
>>>>>
>>>>> Javi
>>>>>
>>>>>
>>>>>
>>>>> _______________________________________________
>>>>> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
>>>>> sr-users at lists.sip-router.org <mailto:sr-users at lists.sip-router.org>
>>>>> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>>>>
>>>> --
>>>> Daniel-Constantin Mierla
>>>> Kamailio (OpenSER) Advanced Training
>>>> Jan 24-26, 2011, Irvine, CA, USA
>>>> http://www.asipto.com
>>>>
>>>>
>>>>
>>>> _______________________________________________
>>>> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
>>>> sr-users at lists.sip-router.org <mailto:sr-users at lists.sip-router.org>
>>>> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>>>
>>> --
>>> Daniel-Constantin Mierla
>>> Kamailio (OpenSER) Advanced Training
>>> Jan 24-26, 2011, Irvine, CA, USA
>>> http://www.asipto.com
>>>
>>>
>>
>> --
>> Daniel-Constantin Mierla
>> Kamailio (OpenSER) Advanced Training
>> Jan 24-26, 2011, Irvine, CA, USA
>> http://www.asipto.com
>>
>>
>>
>> _______________________________________________
>> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
>> sr-users at lists.sip-router.org <mailto:sr-users at lists.sip-router.org>
>> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>
> --
> Daniel-Constantin Mierla
> Kamailio (OpenSER) Advanced Training
> Jan 24-26, 2011, Irvine, CA, USA
> http://www.asipto.com
>
>
--
Daniel-Constantin Mierla
Kamailio (OpenSER) Advanced Training
Jan 24-26, 2011, Irvine, CA, USA
http://www.asipto.com
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20110119/f44e9013/attachment-0001.htm>
More information about the sr-users
mailing list