[OpenSIPS-Users] Opensips, avpops and avp_db_query( ), and pgpool2 -- questions, suggestions, issues

Bobby Smith bobby.smith at gmail.com
Fri Apr 17 23:32:55 CEST 2009


An example of what happens -- on processing a call right before a database
lookup (the select query below in the previous message):

00:00:00 pgpool: opensips my_database localhost(46362) SELECT
postgres   445   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46383) SELECT
postgres   446   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   447   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   448   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   449   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   450   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   451   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46366) SELECT
postgres   452   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46371) SELECT
postgres   453   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   454   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46367) SELECT
postgres   455   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46372) SELECT
postgres   456   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46393) idle
postgres   457   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46391) SELECT
postgres   458   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46377) SELECT
postgres   459   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46378) SELECT
postgres   460   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46374) SELECT
postgres   461   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   462   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46387) SELECT
postgres   463   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   464   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46380) SELECT
postgres   465   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   466   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46385) SELECT
postgres   468   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46389) SELECT
postgres   469   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46361) SELECT
postgres   471   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   473   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   474   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   475   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   476   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   477   438  0 09:00 ?        00:00:00 pgpool: wait for connection
request
postgres   478   438  0 09:00 ?        00:00:00 pgpool: opensips my_database
localhost(46365) SELECT

I have 32 "available" connections, 16 of which are occupied by opensips
children processes.  On this one query, it looks like "every" opensips
process does the same processing to *all* the pgpool connections.  This is
just for a single INVITE.  I don't know if the database lookup is failing or
not, but it looks like the next child processes the message until none are
left?

It will kind of just float here in this state for some time now -- I've got
a heartbeat script that can come back and clean this up (transparent to the
endusers as we're in a failover setup), but I would like to know how to go
about troubleshooting this particular type of issue.

I know it's not the database dying or pgpool losing it's connections, as I
have logging enabled on both.

Any suggestions on troubleshooting, or has anyone tried this sort of
configuration before?

Thanks much in advance.

On Thu, Apr 16, 2009 at 4:39 PM, Bobby Smith <bobby.smith at gmail.com> wrote:

> All,
>
> We're currently (successfully) testing a configuration of Opensips as a
> stateless proxy.  I wanted to be able to execute an arbitrary database query
> to a database that's NOT the opensips database, when I realized the power of
> the avp_db_query( ) function in avpops.  The database is a backend postgres
> database in an basic failover configuration (16 max connections cached,
> primary db, failover to secondary db for those connections).
>
> Currently, opensips has 16 children processes.  In the configuration, we
> have the following:
>
> modparam("avpops", "db_url", "postgres://opensips:opensips@localhost
> :9999/my_database")
> modparam("avpops", "avp_table", "")
>
> A few of the issues I'm concerned about or experiencing with the operation
> of it.
>
> a) Why is that second parameter necessary (avp_table)?  It feels like if I
> have to set this that it's always going to keep open connections with the
> database, and indeed, it is.  When I ps -ef, it shows I have 16 pgpool
> connections that are idle to my_database.  The problem that this is causing
> is that, if for some reason one of the connections has an issue and dies or
> times out, this happens in the logs:
>
> Apr 16 05:46:02 serinbound1 /sbin/opensips[30773]:
> ERROR:db_postgres:db_postgres_store_result: 0x76e008 - invalid query,
> execution aborted
> Apr 16 05:46:02 serinbound1 /sbin/opensips[30773]:
> ERROR:db_postgres:db_postgres_store_result: 0x76e008: PGRES_FATAL_ERROR
> Apr 16 05:46:02 serinbound1 /sbin/opensips[30773]:
> ERROR:db_postgres:db_postgres_store_result: 0x76e008: server closed the
> connection unexpectedly#012#011This probably means the server terminated
> abnormally#012#011before or while processing the request.#012
> Apr 16 05:46:02 serinbound1 /sbin/opensips[30773]:
> ERROR:core:db_do_raw_query: error while storing result
> Apr 16 05:46:02 serinbound1 /sbin/opensips[30773]:
> ERROR:avpops:db_query_avp: cannot do the query
> Apr 16 05:46:02 serinbound1 /sbin/opensips[30773]: Database Error!  No
> Lookup!
> Apr 16 05:46:02 serinbound1 /sbin/opensips[30773]: Query Executed:  Account
> Number is <null>
>
> The query I'm executing (from the config):
> avp_db_query("SELECT value FROM schema.table WHERE value =
> '$avp(s:string_a)'", "$avp(s:string_b)");
>
> When these error messages pop up, pgpool still has active database
> connections to postgres, but not held by opensips.  I can use one of the
> pooled connections to connect to the backend database and execute a query,
> but for some reason opensips cannot.
>
> And, having a restart work (scripted), I occasionally see the following:
>
> Apr 16 03:59:05 serinbound2 /sbin/opensips[23105]:
> ERROR:db_postgres:db_postgres_new_connection: server closed the connection
> unexpectedly#012#011This probably means the server terminated
> abnormally#012#011before or while processing the request.#012
> Apr 16 03:59:05 serinbound2 /sbin/opensips[23105]:
> ERROR:db_postgres:db_postgres_new_connection: cleaning up
> 0x76e090=pkg_free()
> Apr 16 03:59:05 serinbound2 /sbin/opensips[23105]: ERROR:core:db_do_init:
> could not add connection to the pool
> Apr 16 03:59:05 serinbound2 /sbin/opensips[23105]:
> ERROR:avpops:avpops_db_init: cannot initialize database connection
> Apr 16 03:59:05 serinbound2 /sbin/opensips[23105]:
> ERROR:core:init_mod_child: failed to initializing module avpops, rank -1
> Apr 16 03:59:05 serinbound2 /sbin/opensips[23105]:
> ERROR:core:start_timer_processes: init_child failed for timer proc
> Apr 16 03:59:05 serinbound2 /sbin/opensips[23083]: INFO:core:handle_sigs:
> child process 23105 exited normally, status=255
> Apr 16 03:59:05 serinbound2 /sbin/opensips[23083]: INFO:core:handle_sigs:
> terminating due to SIGCHLD
> Apr 16 03:59:05 serinbound2 /sbin/opensips[23107]: INFO:core:sig_usr:
> signal 15 received
>
> At this point, the application crashes.
>
> Any suggestions or workarounds for this?  More specifically, I'd like
> opensips to not have to grab the DB connection if it doesn't need it at that
> time performing a lookup (as i'm not really using avp's in the lookup, just
> to save the results), also, I'd like to see it not crash completely if it
> loses that connection.  Instead, just send a error message back and allow me
> to insert a statement like:
>
>                if(! what i expect the value of the saved avp from teh
> database query to be)
>                 {
>                         sl_send_reply("500", "Internal Server Error");
>                         exit;
>                 }
>
> Thanks for your help, I know this was fairly detailed but without much in
> terms of logging.
>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.opensips.org/pipermail/users/attachments/20090417/a5d4406d/attachment-0001.htm 


More information about the Users mailing list