Use a mutex around writing to the SQL log
[freeradius.git] / src / modules / rlm_sql / sql.c
1 /*
2  *  sql.c               rlm_sql - FreeRADIUS SQL Module
3  *              Main code directly taken from ICRADIUS
4  *
5  * Version:     $Id$
6  *
7  *   This program is free software; you can redistribute it and/or modify
8  *   it under the terms of the GNU General Public License as published by
9  *   the Free Software Foundation; either version 2 of the License, or
10  *   (at your option) any later version.
11  *
12  *   This program is distributed in the hope that it will be useful,
13  *   but WITHOUT ANY WARRANTY; without even the implied warranty of
14  *   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
15  *   GNU General Public License for more details.
16  *
17  *   You should have received a copy of the GNU General Public License
18  *   along with this program; if not, write to the Free Software
19  *   Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301, USA
20  *
21  * Copyright 2001,2006  The FreeRADIUS server project
22  * Copyright 2000  Mike Machado <mike@innercite.com>
23  * Copyright 2000  Alan DeKok <aland@ox.org>
24  * Copyright 2001  Chad Miller <cmiller@surfsouth.com>
25  */
26
27 RCSID("$Id$")
28
29 #include        <freeradius-devel/radiusd.h>
30 #include        <freeradius-devel/rad_assert.h>
31
32 #include        <sys/file.h>
33 #include        <sys/stat.h>
34
35 #include        <ctype.h>
36
37 #include        "rlm_sql.h"
38
39 #ifdef HAVE_PTHREAD_H
40 #endif
41
42 static int sql_conn_destructor(void *conn)
43 {
44         rlm_sql_handle_t *handle = conn;
45         rlm_sql_t *inst = handle->inst;
46
47         rad_assert(inst);
48
49         exec_trigger(NULL, inst->cs, "modules.sql.close", false);
50
51         return 0;
52 }
53
54 static void *mod_conn_create(void *instance)
55 {
56         int rcode;
57         rlm_sql_t *inst = instance;
58         rlm_sql_handle_t *handle;
59
60         handle = talloc_zero(instance, rlm_sql_handle_t);
61
62         /*
63          *      Handle requires a pointer to the SQL inst so the
64          *      destructor has access to the module configuration.
65          */
66         handle->inst = inst;
67
68         /*
69          *      When something frees this handle the destructor set by
70          *      the driver will be called first, closing any open sockets.
71          *      Then we call our destructor to trigger an modules.sql.close
72          *      event, then all the memory is freed.
73          */
74         talloc_set_destructor((void *) handle, sql_conn_destructor);
75
76         rcode = (inst->module->sql_socket_init)(handle, inst->config);
77         if (rcode == 0) {
78                 exec_trigger(NULL, inst->cs, "modules.sql.open", false);
79
80                 return handle;
81         }
82
83         exec_trigger(NULL, inst->cs, "modules.sql.fail", true);
84
85         /*
86          *      Destroy any half opened connections.
87          */
88         talloc_free(handle);
89         return NULL;
90 }
91
92 /*
93  *      @todo Calls to this should eventually go away.
94  */
95 static int mod_conn_delete(UNUSED void *instance, void *handle)
96 {
97         return talloc_free(handle);
98 }
99
100 /*************************************************************************
101  *
102  *      Function: sql_socket_pool_init
103  *
104  *      Purpose: Connect to the sql server, if possible
105  *
106  *************************************************************************/
107 int sql_socket_pool_init(rlm_sql_t * inst)
108 {
109         inst->pool = fr_connection_pool_init(inst->cs, inst,
110                                              mod_conn_create, NULL, mod_conn_delete,
111                                              NULL);
112         if (!inst->pool) return -1;
113
114         return 1;
115 }
116
117 /*************************************************************************
118  *
119  *     Function: sql_poolfree
120  *
121  *     Purpose: Clean up and free sql pool
122  *
123  *************************************************************************/
124 void sql_poolfree(rlm_sql_t * inst)
125 {
126         fr_connection_pool_delete(inst->pool);
127 }
128
129
130 /*************************************************************************
131  *
132  *      Function: sql_get_socket
133  *
134  *      Purpose: Return a SQL handle from the connection pool
135  *
136  *************************************************************************/
137 rlm_sql_handle_t * sql_get_socket(rlm_sql_t * inst)
138 {
139         return fr_connection_get(inst->pool);
140 }
141
142 /*************************************************************************
143  *
144  *      Function: sql_release_socket
145  *
146  *      Purpose: Frees a SQL handle back to the connection pool
147  *
148  *************************************************************************/
149 int sql_release_socket(rlm_sql_t * inst, rlm_sql_handle_t * handle)
150 {
151         fr_connection_release(inst->pool, handle);
152         return 0;
153 }
154
155
156 /*************************************************************************
157  *
158  *      Function: sql_userparse
159  *
160  *      Purpose: Read entries from the database and fill VALUE_PAIR structures
161  *
162  *************************************************************************/
163 int sql_userparse(TALLOC_CTX *ctx, VALUE_PAIR **head, rlm_sql_row_t row)
164 {
165         VALUE_PAIR *vp;
166         char const *ptr, *value;
167         char buf[MAX_STRING_LEN];
168         char do_xlat = 0;
169         FR_TOKEN token, operator = T_EOL;
170
171         /*
172          *      Verify the 'Attribute' field
173          */
174         if (!row[2] || row[2][0] == '\0') {
175                 ERROR("rlm_sql: The 'Attribute' field is empty or NULL, skipping the entire row.");
176                 return -1;
177         }
178
179         /*
180          *      Verify the 'op' field
181          */
182         if (row[4] != NULL && row[4][0] != '\0') {
183                 ptr = row[4];
184                 operator = gettoken(&ptr, buf, sizeof(buf));
185                 if ((operator < T_OP_ADD) ||
186                     (operator > T_OP_CMP_EQ)) {
187                         ERROR("rlm_sql: Invalid operator \"%s\" for attribute %s", row[4], row[2]);
188                         return -1;
189                 }
190
191         } else {
192                 /*
193                  *  Complain about empty or invalid 'op' field
194                  */
195                 operator = T_OP_CMP_EQ;
196                 ERROR("rlm_sql: The 'op' field for attribute '%s = %s' is NULL, or non-existent.", row[2], row[3]);
197                 ERROR("rlm_sql: You MUST FIX THIS if you want the configuration to behave as you expect.");
198         }
199
200         /*
201          *      The 'Value' field may be empty or NULL
202          */
203         value = row[3];
204         /*
205          *      If we have a new-style quoted string, where the
206          *      *entire* string is quoted, do xlat's.
207          */
208         if (row[3] != NULL &&
209            ((row[3][0] == '\'') || (row[3][0] == '`') || (row[3][0] == '"')) &&
210            (row[3][0] == row[3][strlen(row[3])-1])) {
211
212                 token = gettoken(&value, buf, sizeof(buf));
213                 switch (token) {
214                 /*
215                  *      Take the unquoted string.
216                  */
217                 case T_SINGLE_QUOTED_STRING:
218                 case T_DOUBLE_QUOTED_STRING:
219                         value = buf;
220                         break;
221
222                 /*
223                  *      Mark the pair to be allocated later.
224                  */
225                 case T_BACK_QUOTED_STRING:
226                         value = NULL;
227                         do_xlat = 1;
228                         break;
229
230                 /*
231                  *      Keep the original string.
232                  */
233                 default:
234                         value = row[3];
235                         break;
236                 }
237         }
238
239         /*
240          *      Create the pair
241          */
242         vp = pairmake(ctx, NULL, row[2], NULL, operator);
243         if (!vp) {
244                 ERROR("rlm_sql: Failed to create the pair: %s",
245                        fr_strerror());
246                 return -1;
247         }
248
249         if (do_xlat) {
250                 if (pairmark_xlat(vp, value) < 0) {
251                         ERROR("rlm_sql: Error marking pair for xlat");
252
253                         talloc_free(vp);
254                         return -1;
255                 }
256         } else {
257                 if (!pairparsevalue(vp, value)) {
258                         ERROR("rlm_sql: Error parsing value: %s", fr_strerror());
259
260                         talloc_free(vp);
261                         return -1;
262                 }
263         }
264
265         /*
266          *      Add the pair into the packet
267          */
268         pairadd(head, vp);
269         return 0;
270 }
271
272
273 /*************************************************************************
274  *
275  *      Function: rlm_sql_fetch_row
276  *
277  *      Purpose: call the module's sql_fetch_row and implement re-connect
278  *
279  *************************************************************************/
280 int rlm_sql_fetch_row(rlm_sql_handle_t **handle, rlm_sql_t *inst)
281 {
282         int ret;
283
284         if (!*handle || !(*handle)->conn) {
285                 return -1;
286         }
287
288         /*
289          * We can't implement reconnect logic here, because the caller may require
290          * the original connection to free up queries or result sets associated with
291          * that connection.
292          */
293         ret = (inst->module->sql_fetch_row)(*handle, inst->config);
294         if (ret < 0) {
295                 char const *error = (inst->module->sql_error)(*handle, inst->config);
296                 EDEBUG("rlm_sql (%s): Error fetching row: %s",
297                        inst->config->xlat_name, error ? error : "<UNKNOWN>");
298         }
299
300         return ret;
301 }
302
303 static void rlm_sql_query_error(rlm_sql_handle_t *handle, rlm_sql_t *inst)
304 {
305         char const *p, *q;
306
307         p = (inst->module->sql_error)(handle, inst->config);
308         if (!p) {
309                 ERROR("rlm_sql (%s): Unknown query error", inst->config->xlat_name);
310                 return;
311         }
312
313         /*
314          *      Some drivers are nice and provide us with a ^ pointer to
315          *      the place in the query string where the error occurred.
316          *
317          *      For this to be useful we need to split log messages on
318          *      \n and output each of the lines individually.
319          */
320         while ((q = strchr(p, '\n'))) {
321                 ERROR("rlm_sql (%s): %.*s", inst->config->xlat_name, (int) (q - p), p);
322                 p = q + 1;
323         }
324
325         if (*p != '\0') {
326                 ERROR("rlm_sql (%s): %s", inst->config->xlat_name, p);
327         }
328 }
329
330 static void rlm_sql_query_debug(rlm_sql_handle_t *handle, rlm_sql_t *inst)
331 {
332         char const *p, *q;
333
334         p = (inst->module->sql_error)(handle, inst->config);
335         if (!p) {
336                 return;
337         }
338
339         /*
340          *      Some drivers are nice and provide us with a ^ pointer to
341          *      the place in the query string where the error occurred.
342          *
343          *      For this to be useful we need to split log messages on
344          *      \n and output each of the lines individually.
345          */
346         while ((q = strchr(p, '\n'))) {
347                 DEBUG2("rlm_sql (%s): %.*s", inst->config->xlat_name, (int) (q - p), p);
348                 p = q + 1;
349         }
350
351         if (*p != '\0') {
352                 DEBUG2("rlm_sql (%s): %s", inst->config->xlat_name, p);
353         }
354 }
355
356 /*************************************************************************
357  *
358  *      Function: rlm_sql_query
359  *
360  *      Purpose: call the module's sql_query and implement re-connect
361  *
362  *************************************************************************/
363 int rlm_sql_query(rlm_sql_handle_t **handle, rlm_sql_t *inst, char const *query)
364 {
365         int ret = -1;
366
367         /*
368          *      If there's no query, return an error.
369          */
370         if (!query || !*query) {
371                 return -1;
372         }
373
374         if (!*handle || !(*handle)->conn) {
375                 goto sql_down;
376         }
377
378         while (true) {
379                 DEBUG("rlm_sql (%s): Executing query: '%s'", inst->config->xlat_name, query);
380
381                 ret = (inst->module->sql_query)(*handle, inst->config, query);
382                 switch (ret) {
383                 case RLM_SQL_OK:
384                         break;
385
386                 /*
387                  *      Run through all available sockets until we exhaust all existing
388                  *      sockets in the pool and fail to establish a *new* connection.
389                  */
390                 case RLM_SQL_RECONNECT:
391                 sql_down:
392                         *handle = fr_connection_reconnect(inst->pool, *handle);
393                         if (!*handle) return RLM_SQL_RECONNECT;
394                         continue;
395
396                 case RLM_SQL_QUERY_ERROR:
397                 case RLM_SQL_ERROR:
398                         rlm_sql_query_error(*handle, inst);
399                         break;
400
401                 case RLM_SQL_DUPLICATE:
402                         rlm_sql_query_debug(*handle, inst);
403                         break;
404
405                 }
406
407                 return ret;
408         }
409 }
410
411 /*************************************************************************
412  *
413  *      Function: rlm_sql_select_query
414  *
415  *      Purpose: call the module's sql_select_query and implement re-connect
416  *
417  *************************************************************************/
418 int rlm_sql_select_query(rlm_sql_handle_t **handle, rlm_sql_t *inst, char const *query)
419 {
420         int ret = -1;
421
422         /*
423          *      If there's no query, return an error.
424          */
425         if (!query || !*query) {
426                 return -1;
427         }
428
429         if (!*handle || !(*handle)->conn) {
430                 goto sql_down;
431         }
432
433         while (true) {
434                 DEBUG("rlm_sql (%s): Executing query: '%s'", inst->config->xlat_name, query);
435
436                 ret = (inst->module->sql_select_query)(*handle, inst->config, query);
437                 switch (ret) {
438                 case RLM_SQL_OK:
439                         break;
440
441                 /*
442                  *      Run through all available sockets until we exhaust all existing
443                  *      sockets in the pool and fail to establish a *new* connection.
444                  */
445                 case RLM_SQL_RECONNECT:
446                 sql_down:
447                         *handle = fr_connection_reconnect(inst->pool, *handle);
448                         if (!*handle) return RLM_SQL_RECONNECT;
449                         continue;
450
451                 case RLM_SQL_QUERY_ERROR:
452                 case RLM_SQL_ERROR:
453                         rlm_sql_query_error(*handle, inst);
454                         break;
455
456                 case RLM_SQL_DUPLICATE:
457                         rlm_sql_query_debug(*handle, inst);
458                         break;
459
460                 }
461
462                 return ret;
463         }
464 }
465
466
467 /*************************************************************************
468  *
469  *      Function: sql_getvpdata
470  *
471  *      Purpose: Get any group check or reply pairs
472  *
473  *************************************************************************/
474 int sql_getvpdata(rlm_sql_t * inst, rlm_sql_handle_t **handle,
475                   TALLOC_CTX *ctx, VALUE_PAIR **pair, char const *query)
476 {
477         rlm_sql_row_t row;
478         int     rows = 0;
479
480         if (rlm_sql_select_query(handle, inst, query)) {
481                 return -1;
482         }
483
484         while (rlm_sql_fetch_row(handle, inst) == 0) {
485                 row = (*handle)->row;
486                 if (!row)
487                         break;
488                 if (sql_userparse(ctx, pair, row) != 0) {
489                         ERROR("rlm_sql (%s): Error parsing user data from database result", inst->config->xlat_name);
490
491                         (inst->module->sql_finish_select_query)(*handle, inst->config);
492
493                         return -1;
494                 }
495                 rows++;
496         }
497         (inst->module->sql_finish_select_query)(*handle, inst->config);
498
499         return rows;
500 }
501
502 /*
503  *      Log the query to a file.
504  */
505 void rlm_sql_query_log(rlm_sql_t *inst, REQUEST *request,
506                        sql_acct_section_t *section, char const *query)
507 {
508         int fd;
509         char const *filename = NULL;
510         char *expanded = NULL;
511         size_t len;
512         bool failed = false;    /* Write the log message outside of the critical region */
513
514         if (section) {
515                 filename = section->logfile;
516         } else {
517                 filename = inst->config->logfile;
518         }
519
520         if (!filename) {
521                 return;
522         }
523
524         if (radius_axlat(&expanded, request, filename, NULL, NULL) < 0) {
525                 return;
526         }
527
528         fd = open(filename, O_WRONLY | O_APPEND | O_CREAT, 0666);
529         if (fd < 0) {
530                 ERROR("rlm_sql (%s): Couldn't open logfile '%s': %s", inst->config->xlat_name,
531                       expanded, fr_syserror(errno));
532
533                 talloc_free(expanded);
534                 return;
535         }
536
537         len = strlen(query);
538 #ifdef HAVE_PTHREAD_H
539         pthread_mutex_lock(&inst->log);
540 #endif
541         if ((rad_lockfd(fd, len + 2) < 0) || (write(fd, query, len) < 0) || (write(fd, ";\n", 2) < 0)) {
542                 failed = true;
543         }
544 #ifdef HAVE_PTHREAD_H
545         pthread_mutex_unlock(&inst->log);
546 #endif
547
548         if (failed) {
549                 ERROR("rlm_sql (%s): Failed writing to logfile '%s': %s", inst->config->xlat_name, expanded,
550                       fr_syserror(errno));
551         }
552
553         talloc_free(expanded);
554         close(fd);              /* and release the lock */
555 }