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_append_mode = 0;
56 : static tds_dir_char *g_dump_filename = NULL;
57 : /** Tell if TDS debug logging is turned on or off */
58 : bool tds_write_dump = false;
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 2254 : tds_util_deinit(void)
69 : {
70 2254 : tdsdump_close();
71 2254 : }
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 5964 : 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 5964 : if (!tds_write_dump)
85 : return;
86 :
87 3004 : off_item->thread_id = tds_thread_get_current_id();
88 3004 : tds_mutex_lock(&g_dump_mutex);
89 3004 : off_item->next = off_list;
90 3004 : off_list = off_item;
91 3004 : 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 5964 : tdsdump_on(TDSDUMP_OFF_ITEM *off_item)
102 : {
103 : TDSDUMP_OFF_ITEM **curr;
104 :
105 5964 : tds_mutex_lock(&g_dump_mutex);
106 8079 : for (curr = &off_list; *curr != NULL; curr = &(*curr)->next) {
107 5119 : if (*curr == off_item) {
108 3004 : *curr = (*curr)->next;
109 3004 : break;
110 : }
111 : }
112 5964 : tds_mutex_unlock(&g_dump_mutex);
113 5964 : }
114 :
115 : int
116 8 : tdsdump_isopen(void)
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 : #ifdef _WIN32
132 : tdsdump_wopen(const tds_dir_char *filename)
133 : #else
134 46 : tdsdump_open(const tds_dir_char *filename)
135 : #endif
136 : {
137 : int result; /* really should be a boolean, not an int */
138 :
139 46 : tds_mutex_lock(&g_dump_mutex);
140 :
141 : /* same append file */
142 46 : if (tds_append_mode && filename != NULL && g_dump_filename != NULL && tds_dir_cmp(filename, g_dump_filename) == 0) {
143 0 : tds_mutex_unlock(&g_dump_mutex);
144 0 : return 1;
145 : }
146 :
147 46 : tds_write_dump = false;
148 :
149 : /* free old one */
150 46 : if (g_dumpfile != NULL && g_dumpfile != stdout && g_dumpfile != stderr)
151 0 : fclose(g_dumpfile);
152 46 : g_dumpfile = NULL;
153 46 : if (g_dump_filename)
154 0 : TDS_ZERO_FREE(g_dump_filename);
155 :
156 : /* required to close just log ?? */
157 46 : if (filename == NULL || filename[0] == '\0') {
158 32 : tds_mutex_unlock(&g_dump_mutex);
159 32 : return 1;
160 : }
161 :
162 14 : result = 1;
163 14 : if (tds_append_mode) {
164 0 : g_dump_filename = tds_dir_dup(filename);
165 : /* if mutex are available do not reopen file every time */
166 : #ifdef TDS_HAVE_MUTEX
167 0 : g_dumpfile = tdsdump_append();
168 : #endif
169 14 : } else if (!tds_dir_cmp(filename, TDS_DIR("stdout"))) {
170 2 : g_dumpfile = stdout;
171 12 : } else if (!tds_dir_cmp(filename, TDS_DIR("stderr"))) {
172 0 : g_dumpfile = stderr;
173 12 : } else if (NULL == (g_dumpfile = tds_dir_open(filename, TDS_DIR("w")))) {
174 : result = 0;
175 : }
176 :
177 : if (result)
178 14 : tds_write_dump = true;
179 14 : tds_mutex_unlock(&g_dump_mutex);
180 :
181 14 : if (result) {
182 : char today[64];
183 : struct tm res;
184 : time_t t;
185 :
186 14 : time(&t);
187 14 : today[0] = 0;
188 14 : if (tds_localtime_r(&t, &res))
189 14 : strftime(today, sizeof(today), "%Y-%m-%d %H:%M:%S", &res);
190 :
191 14 : tdsdump_log(TDS_DBG_INFO1, "Starting log file for FreeTDS %s\n"
192 : "\ton %s with debug flags 0x%x.\n", VERSION, today, tds_debug_flags);
193 : }
194 : return result;
195 : } /* tdsdump_open() */
196 :
197 : #ifdef _WIN32
198 : int
199 : tdsdump_open(const char *filename)
200 : {
201 : int ret;
202 : tds_dir_char *fn = tds_dir_from_cstr(filename);
203 :
204 : if (!fn)
205 : return 0;
206 :
207 : ret = tdsdump_wopen(fn);
208 : free(fn);
209 : return ret;
210 : }
211 : #endif
212 :
213 : static FILE*
214 0 : tdsdump_append(void)
215 : {
216 0 : if (!g_dump_filename)
217 : return NULL;
218 :
219 0 : if (!tds_dir_cmp(g_dump_filename, TDS_DIR("stdout"))) {
220 0 : return stdout;
221 0 : } else if (!tds_dir_cmp(g_dump_filename, TDS_DIR("stderr"))) {
222 0 : return stderr;
223 : }
224 0 : return tds_dir_open(g_dump_filename, TDS_DIR("a"));
225 : }
226 :
227 :
228 : /**
229 : * Close the TDS dump log file.
230 : */
231 : void
232 2264 : tdsdump_close(void)
233 : {
234 2264 : tds_mutex_lock(&g_dump_mutex);
235 2264 : tds_write_dump = false;
236 2264 : if (g_dumpfile != NULL && g_dumpfile != stdout && g_dumpfile != stderr)
237 12 : fclose(g_dumpfile);
238 2264 : g_dumpfile = NULL;
239 2264 : if (g_dump_filename)
240 0 : TDS_ZERO_FREE(g_dump_filename);
241 2264 : tds_mutex_unlock(&g_dump_mutex);
242 2264 : } /* tdsdump_close() */
243 :
244 : static void
245 3892 : tdsdump_start(FILE *file, const char *fname, int line)
246 : {
247 : char buf[128], *pbuf;
248 3892 : bool started = false;
249 :
250 : /* write always time before log */
251 3892 : if (tds_debug_flags & TDS_DBGFLAG_TIME) {
252 882 : fputs(tds_timestamp_str(buf, sizeof(buf) - 1), file);
253 882 : started = true;
254 : }
255 :
256 3892 : pbuf = buf;
257 3892 : if (tds_debug_flags & TDS_DBGFLAG_PID) {
258 0 : if (started)
259 0 : *pbuf++ = ' ';
260 0 : pbuf += sprintf(pbuf, "%d", (int) getpid());
261 0 : started = true;
262 : }
263 :
264 3892 : if ((tds_debug_flags & TDS_DBGFLAG_SOURCE) && fname && line) {
265 : const char *p;
266 3892 : p = strrchr(fname, '/');
267 3892 : if (p)
268 0 : fname = p + 1;
269 3892 : p = strrchr(fname, '\\');
270 3892 : if (p)
271 0 : fname = p + 1;
272 3892 : if (started)
273 882 : pbuf += sprintf(pbuf, " (%s:%d)", fname, line);
274 : else
275 3010 : pbuf += sprintf(pbuf, "%s:%d", fname, line);
276 : started = true;
277 : }
278 0 : if (started)
279 3892 : *pbuf++ = ':';
280 3892 : *pbuf = 0;
281 3892 : fputs(buf, file);
282 3892 : }
283 :
284 : /**
285 : * Check if current thread is in the list of excluded threads
286 : * g_dump_mutex must be held.
287 : */
288 : static bool
289 6918 : current_thread_is_excluded(void)
290 : {
291 : TDSDUMP_OFF_ITEM *curr_off;
292 :
293 6918 : tds_mutex_check_owned(&g_dump_mutex);
294 :
295 9837 : for (curr_off = off_list; curr_off; curr_off = curr_off->next)
296 11890 : if (tds_thread_is_current(curr_off->thread_id))
297 : return true;
298 :
299 : return false;
300 : }
301 :
302 : static inline bool
303 : ascii_isprint(int ch)
304 : {
305 9598 : return ch >= ' ' && ch < 127;
306 : }
307 :
308 : #undef tdsdump_dump_buf
309 : /**
310 : * Dump the contents of data into the log file in a human readable format.
311 : * \param file source file name
312 : * \param level_line line and level combined. This and file are automatically computed by
313 : * TDS_DBG_* macros.
314 : * \param msg message to print before dump
315 : * \param buf buffer to dump
316 : * \param length number of bytes in the buffer
317 : */
318 : void
319 66 : tdsdump_dump_buf(const char* file, unsigned int level_line, const char *msg, const void *buf, size_t length)
320 : {
321 : size_t i, j;
322 : #define BYTES_PER_LINE 16
323 66 : const unsigned char *data = (const unsigned char *) buf;
324 66 : const int debug_lvl = level_line & 15;
325 66 : const int line = level_line >> 4;
326 : char line_buf[BYTES_PER_LINE * 8 + 16], *p;
327 : FILE *dumpfile;
328 :
329 66 : if (((tds_debug_flags >> debug_lvl) & 1) == 0 || !tds_write_dump)
330 4 : return;
331 :
332 66 : if (!g_dumpfile && !g_dump_filename)
333 : return;
334 :
335 66 : tds_mutex_lock(&g_dump_mutex);
336 :
337 66 : if (current_thread_is_excluded()) {
338 4 : tds_mutex_unlock(&g_dump_mutex);
339 4 : return;
340 : }
341 :
342 62 : dumpfile = g_dumpfile;
343 : #ifdef TDS_HAVE_MUTEX
344 62 : if (tds_append_mode && dumpfile == NULL)
345 0 : dumpfile = g_dumpfile = tdsdump_append();
346 : #else
347 : if (tds_append_mode)
348 : dumpfile = tdsdump_append();
349 : #endif
350 :
351 62 : if (dumpfile == NULL) {
352 0 : tds_mutex_unlock(&g_dump_mutex);
353 0 : return;
354 : }
355 :
356 62 : tdsdump_start(dumpfile, file, line);
357 :
358 62 : fprintf(dumpfile, "%s\n", msg);
359 :
360 694 : for (i = 0; i < length; i += BYTES_PER_LINE) {
361 632 : p = line_buf;
362 : /*
363 : * print the offset as a 4 digit hex number
364 : */
365 632 : p += sprintf(p, "%04x", ((unsigned int) i) & 0xffffu);
366 :
367 : /*
368 : * print each byte in hex
369 : */
370 10744 : for (j = 0; j < BYTES_PER_LINE; j++) {
371 10112 : if (j == BYTES_PER_LINE / 2)
372 632 : *p++ = '-';
373 : else
374 9480 : *p++ = ' ';
375 10112 : if (j + i >= length) {
376 514 : *p++ = ' ';
377 514 : *p++ = ' ';
378 : } else {
379 9598 : const unsigned char c = data[i + j];
380 :
381 9598 : *p++ = tds_hex_digits[c >> 4];
382 9598 : *p++ = tds_hex_digits[c & 15];
383 : }
384 : }
385 :
386 : /*
387 : * skip over to the ascii dump column
388 : */
389 632 : p += sprintf(p, " |");
390 :
391 : /*
392 : * print each byte in ascii
393 : */
394 10230 : for (j = 0; j + i < length && j < BYTES_PER_LINE; j++) {
395 9598 : if (j == BYTES_PER_LINE / 2)
396 596 : *p++ = ' ';
397 19196 : *p++ = ascii_isprint(data[j + i]) ? (char) data[j + i] : '.';
398 : }
399 632 : strcpy(p, "|\n");
400 632 : fputs(line_buf, dumpfile);
401 : }
402 62 : fputs("\n", dumpfile);
403 :
404 62 : fflush(dumpfile);
405 :
406 : #ifndef TDS_HAVE_MUTEX
407 : if (tds_append_mode) {
408 : if (dumpfile != stdout && dumpfile != stderr)
409 : fclose(dumpfile);
410 : }
411 : #endif
412 :
413 62 : tds_mutex_unlock(&g_dump_mutex);
414 :
415 : } /* tdsdump_dump_buf() */
416 : #define tdsdump_dump_buf TDSDUMP_BUF_FAST
417 :
418 :
419 : #undef tdsdump_log
420 : /**
421 : * Write a message to the debug log.
422 : * \param file name of the log file
423 : * \param level_line kind of detail to be included
424 : * \param fmt printf-like format string
425 : */
426 : void
427 6852 : tdsdump_log(const char* file, unsigned int level_line, const char *fmt, ...)
428 : {
429 6852 : const int debug_lvl = level_line & 15;
430 6852 : const int line = level_line >> 4;
431 : va_list ap;
432 : FILE *dumpfile;
433 :
434 6852 : if (((tds_debug_flags >> debug_lvl) & 1) == 0 || !tds_write_dump)
435 3022 : return;
436 :
437 6852 : if (!g_dumpfile && !g_dump_filename)
438 : return;
439 :
440 6852 : tds_mutex_lock(&g_dump_mutex);
441 :
442 6852 : if (current_thread_is_excluded()) {
443 3022 : tds_mutex_unlock(&g_dump_mutex);
444 3022 : return;
445 : }
446 :
447 3830 : dumpfile = g_dumpfile;
448 : #ifdef TDS_HAVE_MUTEX
449 3830 : if (tds_append_mode && dumpfile == NULL)
450 0 : dumpfile = g_dumpfile = tdsdump_append();
451 : #else
452 : if (tds_append_mode)
453 : dumpfile = tdsdump_append();
454 : #endif
455 :
456 3830 : if (dumpfile == NULL) {
457 0 : tds_mutex_unlock(&g_dump_mutex);
458 0 : return;
459 : }
460 :
461 3830 : tdsdump_start(dumpfile, file, line);
462 :
463 3830 : va_start(ap, fmt);
464 :
465 3830 : vfprintf(dumpfile, fmt, ap);
466 3830 : va_end(ap);
467 :
468 3830 : fflush(dumpfile);
469 :
470 : #ifndef TDS_HAVE_MUTEX
471 : if (tds_append_mode) {
472 : if (dumpfile != stdout && dumpfile != stderr)
473 : fclose(dumpfile);
474 : }
475 : #endif
476 3830 : tds_mutex_unlock(&g_dump_mutex);
477 : } /* tdsdump_log() */
478 : #define tdsdump_log TDSDUMP_LOG_FAST
479 :
480 :
481 : /**
482 : * Write a column value to the debug log.
483 : * \param col column to dump
484 : */
485 : void
486 0 : tdsdump_col(const TDSCOLUMN *col)
487 : {
488 : const char* type_name;
489 : char* data;
490 : TDS_SMALLINT type;
491 :
492 0 : assert(col);
493 0 : assert(col->column_data);
494 :
495 0 : type_name = tds_prtype(col->column_type);
496 0 : type = tds_get_conversion_type(col->column_type, col->column_size);
497 :
498 0 : switch(type) {
499 0 : case SYBCHAR:
500 : case SYBVARCHAR:
501 0 : if (col->column_cur_size >= 0) {
502 0 : data = tds_new0(char, 1 + col->column_cur_size);
503 0 : if (!data) {
504 0 : tdsdump_log(TDS_DBG_FUNC, "no memory to log data for type %s\n", type_name);
505 : return;
506 : }
507 0 : memcpy(data, col->column_data, col->column_cur_size);
508 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value \"%s\"\n", type_name, data);
509 0 : free(data);
510 : } else {
511 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value NULL\n", type_name);
512 : }
513 : break;
514 0 : case SYBINT1:
515 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value %d\n", type_name, (int)*(TDS_TINYINT*)col->column_data);
516 : break;
517 0 : case SYBINT2:
518 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value %d\n", type_name, (int)*(TDS_SMALLINT*)col->column_data);
519 : break;
520 0 : case SYBINT4:
521 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value %d\n", type_name, (int)*(TDS_INT*)col->column_data);
522 : break;
523 0 : case SYBREAL:
524 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value %f\n", type_name, (double)*(TDS_REAL*)col->column_data);
525 : break;
526 0 : case SYBFLT8:
527 0 : tdsdump_log(TDS_DBG_FUNC, "type %s has value %f\n", type_name, (double)*(TDS_FLOAT*)col->column_data);
528 : break;
529 0 : default:
530 0 : tdsdump_log(TDS_DBG_FUNC, "cannot log data for type %s\n", type_name);
531 : break;
532 : }
533 : }
|
