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