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 < mico...@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 > 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 < > mico...@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 < >> mico...@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 < >>> mico...@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@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 <jgalla...@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 >>>> listsr-us...@lists.sip-router.orghttp://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users >>>> >>>> >>>> -- >>>> Daniel-Constantin Mierla >>>> Kamailio (OpenSER) Advanced Training >>>> Jan 24-26, 2011, Irvine, CA, USAhttp://www.asipto.com >>>> >>>> >>> >>> _______________________________________________ >>> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing >>> listsr-us...@lists.sip-router.orghttp://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users >>> >>> >>> -- >>> Daniel-Constantin Mierla >>> Kamailio (OpenSER) Advanced Training >>> Jan 24-26, 2011, Irvine, CA, USAhttp://www.asipto.com >>> >>> >> >> -- >> Daniel-Constantin Mierla >> Kamailio (OpenSER) Advanced Training >> Jan 24-26, 2011, Irvine, CA, USAhttp://www.asipto.com >> >> > > _______________________________________________ > SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing > listsr-us...@lists.sip-router.orghttp://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users > > > -- > Daniel-Constantin Mierla > Kamailio (OpenSER) Advanced Training > Jan 24-26, 2011, Irvine, CA, USAhttp://www.asipto.com > >
_______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
