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