Line data Source code
1 : /* FreeTDS - Library of routines accessing Sybase and Microsoft databases
2 : * Copyright (C) 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005 Brian Bruns
3 : * Copyright (C) 2006-2015 Frediano Ziglio
4 : *
5 : * This library is free software; you can redistribute it and/or
6 : * modify it under the terms of the GNU Library General Public
7 : * License as published by the Free Software Foundation; either
8 : * version 2 of the License, or (at your option) any later version.
9 : *
10 : * This library is distributed in the hope that it will be useful,
11 : * but WITHOUT ANY WARRANTY; without even the implied warranty of
12 : * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
13 : * Library General Public License for more details.
14 : *
15 : * You should have received a copy of the GNU Library General Public
16 : * License along with this library; if not, write to the
17 : * Free Software Foundation, Inc., 59 Temple Place - Suite 330,
18 : * Boston, MA 02111-1307, USA.
19 : */
20 :
21 : #include <config.h>
22 :
23 : #include <stdarg.h>
24 :
25 : #include <freetds/time.h>
26 :
27 : #include <assert.h>
28 : #include <ctype.h>
29 : #include <limits.h>
30 : #include <stdio.h>
31 :
32 : #if HAVE_STDLIB_H
33 : #include <stdlib.h>
34 : #endif /* HAVE_STDLIB_H */
35 :
36 : #if HAVE_STRING_H
37 : #include <string.h>
38 : #endif /* HAVE_STRING_H */
39 :
40 : #if HAVE_UNISTD_H
41 : #include <unistd.h>
42 : #endif /* HAVE_UNISTD_H */
43 :
44 : #ifdef _WIN32
45 : # include <process.h>
46 : #endif
47 :
48 : #include <freetds/tds.h>
49 : #include <freetds/checks.h>
50 : #include <freetds/thread.h>
51 : #include <freetds/utils.h>
52 :
53 : /* for now all messages go to the log */
54 : int tds_debug_flags = TDS_DBGFLAG_ALL | TDS_DBGFLAG_SOURCE;
55 : int tds_g_append_mode = 0;
56 : static char *g_dump_filename = NULL;
57 : /** Tell if TDS debug logging is turned on or off */
58 : int tds_write_dump = 0;
59 : /** List of threads excluded from logging, used to exclude some sensitive data */
60 : static TDSDUMP_OFF_ITEM *off_list;
61 : static FILE *g_dumpfile = NULL; /* file pointer for dump log */
62 : static tds_mutex g_dump_mutex = TDS_MUTEX_INITIALIZER;
63 :
64 : static FILE* tdsdump_append(void);
65 :
66 : #ifdef TDS_ATTRIBUTE_DESTRUCTOR
67 : static void __attribute__((destructor))
68 1694 : tds_util_deinit(void)
69 : {
70 1694 : tdsdump_close();
71 1694 : }
72 : #endif
73 :
74 : /**
75 : * Temporarily turn off logging for current thread.
76 : * @param off_item List item to be used by the function.
77 : * The item will be initialized by the function.
78 : * It's retained till is removed with tdsdump_on so it must be kept alive.
79 : */
80 : void
81 4572 : tdsdump_off(TDSDUMP_OFF_ITEM *off_item)
82 : {
83 : /* if already off don't add current thread to exclude list to make it faster */
84 4572 : if (!tds_write_dump)
85 : return;
86 :
87 2404 : off_item->thread_id = tds_thread_get_current_id();
88 2404 : tds_mutex_lock(&g_dump_mutex);
89 2404 : off_item->next = off_list;
90 2404 : off_list = off_item;
91 2404 : tds_mutex_unlock(&g_dump_mutex);
92 : } /* tdsdump_off() */
93 :
94 :
95 : /**
96 : * Turn logging back on for current thread.
97 : * @param off_item List item to remove from global list.
98 : * Previously used by tdsdump_off().
99 : */
100 : void
101 4572 : tdsdump_on(TDSDUMP_OFF_ITEM *off_item)
102 : {
103 : TDSDUMP_OFF_ITEM **curr;
104 :
105 4572 : tds_mutex_lock(&g_dump_mutex);
106 6212 : for (curr = &off_list; *curr != NULL; curr = &(*curr)->next) {
107 4044 : if (*curr == off_item) {
108 2404 : *curr = (*curr)->next;
109 2404 : break;
110 : }
111 : }
112 4572 : tds_mutex_unlock(&g_dump_mutex);
113 4572 : }
114 :
115 : int
116 8 : tdsdump_isopen()
117 : {
118 8 : return g_dumpfile || g_dump_filename;
119 : }
120 :
121 :
122 : /**
123 : * Create and truncate a human readable dump file for the TDS
124 : * traffic. The name of the file is specified by the filename
125 : * parameter. If that is given as NULL or an empty string,
126 : * any existing log file will be closed.
127 : *
128 : * \return true if the file was opened, false if it couldn't be opened.
129 : */
130 : int
131 38 : tdsdump_open(const char *filename)
132 : {
133 : int result; /* really should be a boolean, not an int */
134 :
135 38 : tds_mutex_lock(&g_dump_mutex);
136 :
137 : /* same append file */
138 38 : if (tds_g_append_mode && filename != NULL && g_dump_filename != NULL && strcmp(filename, g_dump_filename) == 0) {
139 0 : tds_mutex_unlock(&g_dump_mutex);
140 0 : return 1;
141 : }
142 :
143 38 : tds_write_dump = 0;
144 :
145 : /* free old one */
146 38 : if (g_dumpfile != NULL && g_dumpfile != stdout && g_dumpfile != stderr)
147 0 : fclose(g_dumpfile);
148 38 : g_dumpfile = NULL;
149 38 : if (g_dump_filename)
150 0 : TDS_ZERO_FREE(g_dump_filename);
151 :
152 : /* required to close just log ?? */
153 38 : if (filename == NULL || filename[0] == '\0') {
154 26 : tds_mutex_unlock(&g_dump_mutex);
155 26 : return 1;
156 : }
157 :
158 12 : result = 1;
159 12 : if (tds_g_append_mode) {
160 0 : g_dump_filename = strdup(filename);
161 : /* if mutex are available do not reopen file every time */
162 : #ifdef TDS_HAVE_MUTEX
163 0 : g_dumpfile = tdsdump_append();
164 : #endif
165 12 : } else if (!strcmp(filename, "stdout")) {
166 2 : g_dumpfile = stdout;
167 10 : } else if (!strcmp(filename, "stderr")) {
168 0 : g_dumpfile = stderr;
169 10 : } else if (NULL == (g_dumpfile = fopen(filename, "w"))) {
170 : result = 0;
171 : }
172 :
173 : if (result)
174 12 : tds_write_dump = 1;
175 12 : tds_mutex_unlock(&g_dump_mutex);
176 :
177 12 : if (result) {
178 : char today[64];
179 : struct tm res;
180 : time_t t;
181 :
182 12 : time(&t);
183 12 : today[0] = 0;
184 12 : if (tds_localtime_r(&t, &res))
185 12 : strftime(today, sizeof(today), "%Y-%m-%d %H:%M:%S", &res);
186 :
187 12 : tdsdump_log(TDS_DBG_INFO1, "Starting log file for FreeTDS %s\n"
188 : "\ton %s with debug flags 0x%x.\n", VERSION, today, tds_debug_flags);
189 : }
190 : return result;
191 : } /* tdsdump_open() */
192 :
193 : static FILE*
194 0 : tdsdump_append(void)
195 : {
196 0 : if (!g_dump_filename)
197 : return NULL;
198 :
199 0 : if (!strcmp(g_dump_filename, "stdout")) {
200 0 : return stdout;
201 0 : } else if (!strcmp(g_dump_filename, "stderr")) {
202 0 : return stderr;
203 : }
204 0 : return fopen(g_dump_filename, "a");
205 : }
206 :
207 :
208 : /**
209 : * Close the TDS dump log file.
210 : */
211 : void
212 1702 : tdsdump_close(void)
213 : {
214 1702 : tds_mutex_lock(&g_dump_mutex);
215 1702 : tds_write_dump = 0;
216 1702 : if (g_dumpfile != NULL && g_dumpfile != stdout && g_dumpfile != stderr)
217 10 : fclose(g_dumpfile);
218 1702 : g_dumpfile = NULL;
219 1702 : if (g_dump_filename)
220 0 : TDS_ZERO_FREE(g_dump_filename);
221 1702 : tds_mutex_unlock(&g_dump_mutex);
222 1702 : } /* tdsdump_close() */
223 :
224 : static void
225 3286 : tdsdump_start(FILE *file, const char *fname, int line)
226 : {
227 : char buf[128], *pbuf;
228 3286 : int started = 0;
229 :
230 : /* write always time before log */
231 3286 : if (tds_debug_flags & TDS_DBGFLAG_TIME) {
232 878 : fputs(tds_timestamp_str(buf, 127), file);
233 878 : started = 1;
234 : }
235 :
236 3286 : pbuf = buf;
237 3286 : if (tds_debug_flags & TDS_DBGFLAG_PID) {
238 0 : if (started)
239 0 : *pbuf++ = ' ';
240 0 : pbuf += sprintf(pbuf, "%d", (int) getpid());
241 0 : started = 1;
242 : }
243 :
244 3286 : if ((tds_debug_flags & TDS_DBGFLAG_SOURCE) && fname && line) {
245 : const char *p;
246 3286 : p = strrchr(fname, '/');
247 3286 : if (p)
248 0 : fname = p + 1;
249 3286 : p = strrchr(fname, '\\');
250 3286 : if (p)
251 0 : fname = p + 1;
252 3286 : if (started)
253 878 : pbuf += sprintf(pbuf, " (%s:%d)", fname, line);
254 : else
255 2408 : pbuf += sprintf(pbuf, "%s:%d", fname, line);
256 : started = 1;
257 : }
258 0 : if (started)
259 3286 : *pbuf++ = ':';
260 3286 : *pbuf = 0;
261 3286 : fputs(buf, file);
262 3286 : }
263 :
264 : /**
265 : * Check if current thread is in the list of excluded threads
266 : * g_dump_mutex must be held.
267 : */
268 : static bool
269 5712 : current_thread_is_excluded(void)
270 : {
271 : TDSDUMP_OFF_ITEM *curr_off;
272 :
273 5712 : tds_mutex_check_owned(&g_dump_mutex);
274 :
275 8010 : for (curr_off = off_list; curr_off; curr_off = curr_off->next)
276 9448 : if (tds_thread_is_current(curr_off->thread_id))
277 : return true;
278 :
279 : return false;
280 : }
281 :
282 : #undef tdsdump_dump_buf
283 : /**
284 : * Dump the contents of data into the log file in a human readable format.
285 : * \param file source file name
286 : * \param level_line line and level combined. This and file are automatically computed by
287 : * TDS_DBG_* macros.
288 : * \param msg message to print before dump
289 : * \param buf buffer to dump
290 : * \param length number of bytes in the buffer
291 : */
292 : void
293 62 : tdsdump_dump_buf(const char* file, unsigned int level_line, const char *msg, const void *buf, size_t length)
294 : {
295 : size_t i, j;
296 : #define BYTES_PER_LINE 16
297 62 : const unsigned char *data = (const unsigned char *) buf;
298 62 : const int debug_lvl = level_line & 15;
299 62 : const int line = level_line >> 4;
300 : char line_buf[BYTES_PER_LINE * 8 + 16], *p;
301 : FILE *dumpfile;
302 :
303 62 : if (((tds_debug_flags >> debug_lvl) & 1) == 0 || !tds_write_dump)
304 4 : return;
305 :
306 62 : if (!g_dumpfile && !g_dump_filename)
307 : return;
308 :
309 62 : tds_mutex_lock(&g_dump_mutex);
310 :
311 62 : if (current_thread_is_excluded()) {
312 4 : tds_mutex_unlock(&g_dump_mutex);
313 4 : return;
314 : }
315 :
316 58 : dumpfile = g_dumpfile;
317 : #ifdef TDS_HAVE_MUTEX
318 58 : if (tds_g_append_mode && dumpfile == NULL)
319 0 : dumpfile = g_dumpfile = tdsdump_append();
320 : #else
321 : if (tds_g_append_mode)
322 : dumpfile = tdsdump_append();
323 : #endif
324 :
325 58 : if (dumpfile == NULL) {
326 0 : tds_mutex_unlock(&g_dump_mutex);
327 0 : return;
328 : }
329 :
330 58 : tdsdump_start(dumpfile, file, line);
331 :
332 58 : fprintf(dumpfile, "%s\n", msg);
333 :
334 698 : for (i = 0; i < length; i += BYTES_PER_LINE) {
335 640 : p = line_buf;
336 : /*
337 : * print the offset as a 4 digit hex number
338 : */
339 640 : p += sprintf(p, "%04x", ((unsigned int) i) & 0xffffu);
340 :
341 : /*
342 : * print each byte in hex
343 : */
344 10880 : for (j = 0; j < BYTES_PER_LINE; j++) {
345 10240 : if (j == BYTES_PER_LINE / 2)
346 640 : *p++ = '-';
347 : else
348 9600 : *p++ = ' ';
349 10240 : if (j + i >= length)
350 516 : p += sprintf(p, " ");
351 : else
352 9724 : p += sprintf(p, "%02x", data[i + j]);
353 : }
354 :
355 : /*
356 : * skip over to the ascii dump column
357 : */
358 640 : p += sprintf(p, " |");
359 :
360 : /*
361 : * print each byte in ascii
362 : */
363 10364 : for (j = i; j < length && (j - i) < BYTES_PER_LINE; j++) {
364 9724 : if (j - i == BYTES_PER_LINE / 2)
365 604 : *p++ = ' ';
366 9724 : p += sprintf(p, "%c", (isprint(data[j])) ? data[j] : '.');
367 : }
368 640 : strcpy(p, "|\n");
369 640 : fputs(line_buf, dumpfile);
370 : }
371 58 : fputs("\n", dumpfile);
372 :
373 58 : fflush(dumpfile);
374 :
375 : #ifndef TDS_HAVE_MUTEX
376 : if (tds_g_append_mode) {
377 : if (dumpfile != stdout && dumpfile != stderr)
378 : fclose(dumpfile);
379 : }
380 : #endif
381 :
382 58 : tds_mutex_unlock(&g_dump_mutex);
383 :
384 : } /* tdsdump_dump_buf() */
385 : #define tdsdump_dump_buf TDSDUMP_BUF_FAST
386 :
387 :
388 : #undef tdsdump_log
389 : /**
390 : * Write a message to the debug log.
391 : * \param file name of the log file
392 : * \param level_line kind of detail to be included
393 : * \param fmt printf-like format string
394 : */
395 : void
396 5650 : tdsdump_log(const char* file, unsigned int level_line, const char *fmt, ...)
397 : {
398 5650 : const int debug_lvl = level_line & 15;
399 5650 : const int line = level_line >> 4;
400 : va_list ap;
401 : FILE *dumpfile;
402 :
403 5650 : if (((tds_debug_flags >> debug_lvl) & 1) == 0 || !tds_write_dump)
404 2422 : return;
405 :
406 5650 : if (!g_dumpfile && !g_dump_filename)
407 : return;
408 :
409 5650 : tds_mutex_lock(&g_dump_mutex);
410 :
411 5650 : if (current_thread_is_excluded()) {
412 2422 : tds_mutex_unlock(&g_dump_mutex);
413 2422 : return;
414 : }
415 :
416 3228 : dumpfile = g_dumpfile;
417 : #ifdef TDS_HAVE_MUTEX
418 3228 : if (tds_g_append_mode && dumpfile == NULL)
419 0 : dumpfile = g_dumpfile = tdsdump_append();
420 : #else
421 : if (tds_g_append_mode)
422 : dumpfile = tdsdump_append();
423 : #endif
424 :
425 3228 : if (dumpfile == NULL) {
426 0 : tds_mutex_unlock(&g_dump_mutex);
427 0 : return;
428 : }
429 :
430 3228 : tdsdump_start(dumpfile, file, line);
431 :
432 3228 : va_start(ap, fmt);
433 :
434 3228 : vfprintf(dumpfile, fmt, ap);
435 3228 : va_end(ap);
436 :
437 3228 : fflush(dumpfile);
438 :
439 : #ifndef TDS_HAVE_MUTEX
440 : if (tds_g_append_mode) {
441 : if (dumpfile != stdout && dumpfile != stderr)
442 : fclose(dumpfile);
443 : }
444 : #endif
445 3228 : tds_mutex_unlock(&g_dump_mutex);
446 : } /* tdsdump_log() */
447 : #define tdsdump_log TDSDUMP_LOG_FAST
448 :
449 :
450 : /**
451 : * Write a column value to the debug log.
452 : * \param col column to dump
453 : */
454 : void
455 0 : tdsdump_col(const TDSCOLUMN *col)
456 : {
457 : const char* type_name;
458 : char* data;
459 : TDS_SMALLINT type;
460 :
461 0 : assert(col);
462 0 : assert(col->column_data);
463 :
464 0 : type_name = tds_prtype(col->column_type);
465 0 : type = tds_get_conversion_type(col->column_type, col->column_size);
466 :
467 0 : switch(type) {
468 0 : case SYBCHAR:
469 : case SYBVARCHAR:
470 0 : if (col->column_cur_size >= 0) {
471 0 : data = tds_new0(char, 1 + col->column_cur_size);
472 0 : if (!data) {
473 0 : tdsdump_log(TDS_DBG_FUNC, "no memory to log data for type %s\n", type_name);
474 : return;
475 : }
476 0 : memcpy(data, col->column_data, col->column_cur_size);
477 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value \"%s\"\n", type_name, data);
478 0 : free(data);
479 : } else {
480 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value NULL\n", type_name);
481 : }
482 : break;
483 0 : case SYBINT1:
484 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value %d\n", type_name, (int)*(TDS_TINYINT*)col->column_data);
485 : break;
486 0 : case SYBINT2:
487 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value %d\n", type_name, (int)*(TDS_SMALLINT*)col->column_data);
488 : break;
489 0 : case SYBINT4:
490 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value %d\n", type_name, (int)*(TDS_INT*)col->column_data);
491 : break;
492 0 : case SYBREAL:
493 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value %f\n", type_name, (double)*(TDS_REAL*)col->column_data);
494 : break;
495 0 : case SYBFLT8:
496 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value %f\n", type_name, (double)*(TDS_FLOAT*)col->column_data);
497 : break;
498 0 : default:
499 0 : tdsdump_log(TDS_DBG_FUNC, "cannot log data for type %s\n", type_name);
500 : break;
501 : }
502 : }
|