sqlippool on 3.0.18

[Nathan Ward]

Hi,

Wading in to this one now - not sure if this is a bug or if it’s known/fixed so posting here in the hope someone else has had this and looked in to it. If not, I’m learning a lot, so, that’s good. Will post more when I have it.

I’m testing upgrading to 3.0.18, and when I get an Accounting-On with sqlippool (I am running a NAS simulator which sends Accounting-On first, not sure if other messages are impacted), I get:

<snip>
rlm_sql (sql-radiusippool): Reserved connection (0)
(0) sqlippool-ipv4: EXPAND %{%{Chargeable-User-Identity}:-%{%{Stripped-User-Name}:-UNKNOWN}}
(0) sqlippool-ipv4:    --> UNKNOWN
(0) sqlippool-ipv4: SQL-User-Name set to 'UNKNOWN'
(0) sqlippool-ipv4: EXPAND START TRANSACTION
(0) sqlippool-ipv4:    --> START TRANSACTION
(0) sqlippool-ipv4: Executing query: START TRANSACTION
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 0
src/modules/rlm_sql/rlm_sql.c:381: Type mismatch: name[rlm_sql_t] expected[rlm_sql_handle_t]

talloc abort: src/modules/rlm_sql/rlm_sql.c:381: Type mismatch: name[rlm_sql_t] expected[rlm_sql_handle_t]
</snip>


src/modules/rlm_sqlippool/rlm_sqlippool.c:320 is:
	if (radius_axlat(&expanded, request, query, data->sql_inst->sql_escape_func, data->sql_inst) < 0) return -1;

And I notice in Herwin Weststrate’s commit @ c8736367583 there is a lot of use of the handle as the last param for that function rather than the sql module instance:
-       if (radius_axlat(&expanded, request, inst->config->simul_verify_query, sql_escape_func, inst) < 0) {
+       if (radius_axlat(&expanded, request, inst->config->simul_verify_query, inst->sql_escape_func, handle) < 0) {

Etc. so I’m thinking that commit didn’t take sqlippool in to account.

I notice there’s a new function, sql_escape_for_xlat_func, which gets a connection from the pool then releases it, but I’m not sure that’s right for this situation in sqlippool - we’re doing these xlats in the middle of a transaction, so we should have a handle already?

I've tried passing the handle to radius_axlat rather than the instance, i.e. (in rlm_sqlippool.c):
-	if (radius_axlat(&expanded, request, query, data->sql_inst->sql_escape_func, data->sql_inst) < 0) return -1;
+	if (radius_axlat(&expanded, request, query, data->sql_inst->sql_escape_func, handle) < 0) return -1;

But now I get a talloc error - 
<snip>
(0) sqlippool-ipv4: Executing query: START TRANSACTION
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 0
Bad talloc magic value - unknown value

talloc abort: Bad talloc magic value - unknown value
</snip>

Here’s a backtrace for that - note the handle is passed through, so I’m not entirely clear why this is objecting.
Is the handle freed somewhere? I’m wondering if this is simply because we’re running several queries in a transaction - the first query (i.e. START TRANSACTION) is always fine, even if I put an xlat in it. The second query always triggers this error.
Should this handle even still be useable? The next line after the one I’ve changed above calls sql_query, which needs handle to have a ‘conn’ member, so, I expect so..

#3  0x00007fa228d5e77a in _talloc_get_type_abort () from /lib64/libtalloc.so.2
#4  0x00007fa2210f0f40 in sql_escape_func (request=request at entry=0x55a14277f330, out=out at entry=0x55a1427820d0 "", outlen=outlen at entry=30, in=0x55a1427819b0 "192.0.2.0",
    arg=arg at entry=0x7ffeb7db2ba0) at src/modules/rlm_sql/rlm_sql.c:381
#5  0x00007fa229aa6afe in xlat_aprint (ctx=ctx at entry=0x55a14277f330, request=0x55a14277f330, node=<optimized out>, escape=escape at entry=0x7fa2210f0f10 <sql_escape_func>, escape_ctx=0x7ffeb7db2ba0,
    lvl=0) at src/main/xlat.c:2371
#6  0x00007fa229aa7aed in xlat_process (out=0x7ffeb7db1990, request=0x55a14277f330, head=0x55a142781f60, escape=0x7fa2210f0f10 <sql_escape_func>, escape_ctx=0x7ffeb7db2ba0) at src/main/xlat.c:2410
#7  0x00007fa229aa6b51 in xlat_aprint (ctx=ctx at entry=0x55a142781a30, request=request at entry=0x55a14277f330, node=node at entry=0x55a142781df0, escape=escape at entry=0x7fa2210f0f10 <sql_escape_func>,
    escape_ctx=escape_ctx at entry=0x7ffeb7db2ba0, lvl=0) at src/main/xlat.c:2344
#8  0x00007fa229aa79d1 in xlat_process (out=0x7ffeb7db1a90, request=0x55a14277f330, head=<optimized out>, escape=0x7fa2210f0f10 <sql_escape_func>, escape_ctx=0x7ffeb7db2ba0) at src/main/xlat.c:2428
#9  0x00007fa229aa7b44 in xlat_expand_struct (out=out at entry=0x7ffeb7db1b48, outlen=outlen at entry=0, request=request at entry=0x55a14277f330, node=<optimized out>,
    escape=escape at entry=0x7fa2210f0f10 <sql_escape_func>, escape_ctx=escape_ctx at entry=0x7ffeb7db2ba0) at src/main/xlat.c:2482
#10 0x00007fa229aa8094 in xlat_expand (out=out at entry=0x7ffeb7db1b48, outlen=outlen at entry=0, request=request at entry=0x55a14277f330,
    fmt=fmt at entry=0x7ffeb7db1b50 "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', expiry_time = 'now'::timestamp(0) - '1 second'::interval WHERE nasipaddress = '%{%{Nas-IP-Address}:-%{Nas-IPv6-Address}}'", escape=0x7fa2210f0f10 <sql_escape_func>, escape_ctx=escape_ctx at entry=0x7ffeb7db2ba0) at src/main/xlat.c:2547
#11 0x00007fa229aa95fa in radius_axlat (out=out at entry=0x7ffeb7db1b48, request=request at entry=0x55a14277f330,
    fmt=fmt at entry=0x7ffeb7db1b50 "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', expiry_time = 'now'::timestamp(0) - '1 second'::interval WHERE nasipaddress = '%{%{Nas-IP-Address}:-%{Nas-IPv6-Address}}'", escape=<optimized out>, ctx=ctx at entry=0x7ffeb7db2ba0) at src/main/xlat.c:2617
#12 0x00007fa2212fae4f in sqlippool_command (fmt=<optimized out>, handle=handle at entry=0x7ffeb7db2ba0, data=data at entry=0x55a14264d250, request=request at entry=0x55a14277f330, param=param at entry=0x0,
    param_len=param_len at entry=0) at src/modules/rlm_sqlippool/rlm_sqlippool.c:320
#13 0x00007fa2212fb66e in mod_accounting_on (request=0x55a14277f330, inst=0x55a14264d250, handle=0x7ffeb7db2ba0) at src/modules/rlm_sqlippool/rlm_sqlippool.c:706
#14 mod_accounting (instance=0x55a14264d250, request=0x55a14277f330) at src/modules/rlm_sqlippool/rlm_sqlippool.c:779

--
Nathan Ward