Browse code

Introduce '$' in logg, it is active when logg_verbose=2, i.e. when Debug yes. Fix leak reported by valgrind.

git-svn: trunk@4806

Török Edvin authored on 2009/02/18 00:59:36
Showing 11 changed files
... ...
@@ -1,3 +1,9 @@
1
+Tue Feb 17 18:29:27 EET 2009 (edwin)
2
+------------------------------------
3
+ * clamd/, shared/, unit_tests/: Introduce '$' in logg, it is active
4
+ when logg_verbose=2, i.e. when Debug yes.  Fix leak reported by
5
+ valgrind.
6
+
1 7
 Tue Feb 17 17:33:06 EET 2009 (edwin)
2 8
 ------------------------------------
3 9
  * clamd/server-th.c, unit_tests/check_clamd.c: make sending
... ...
@@ -236,8 +236,10 @@ int main(int argc, char **argv)
236 236
 	break;
237 237
     }
238 238
 
239
-    if(optget(opts, "Debug")->enabled) /* enable debug messages in libclamav */
239
+    if(optget(opts, "Debug")->enabled) /* enable debug messages in libclamav */ {
240 240
 	cl_debug();
241
+	logg_verbose = 2;
242
+    }
241 243
 
242 244
 #if defined(USE_SYSLOG) && !defined(C_AIX)
243 245
     if(optget(opts, "LogSyslog")->enabled) {
... ...
@@ -247,7 +247,7 @@ void fds_cleanup(struct fd_data *data)
247 247
     for (i = j ; i < data->nfds; i++)
248 248
 	data->buf[i].fd = -1;
249 249
     data->nfds = j;
250
-    logg("*CLEANUP_FDS: %u fds\n", data->nfds);
250
+    logg("$Number of file descriptors polled: %u fds\n", data->nfds);
251 251
     /* Shrink buffer */
252 252
     newbuf = realloc(data->buf, j*sizeof(*newbuf));
253 253
     if (newbuf)
... ...
@@ -277,6 +277,7 @@ static int read_fd_data(struct fd_buf *buf)
277 277
       struct iovec iov[1];
278 278
 
279 279
       if (buf->recvfd != -1) {
280
+	  logg("$Closing unclaimed FD: %d\n", buf->recvfd);
280 281
 	  close(buf->recvfd);
281 282
 	  buf->recvfd = -1;
282 283
       }
... ...
@@ -292,7 +293,7 @@ static int read_fd_data(struct fd_buf *buf)
292 292
       if (n < 0)
293 293
 	  return -1;
294 294
       if ((msg.msg_flags & MSG_TRUNC) || (msg.msg_flags & MSG_CTRUNC)) {
295
-	  logg("!control message truncated");
295
+	  logg("^Control message truncated");
296 296
 	  return -1;
297 297
       }
298 298
       if (msg.msg_controllen) {
... ...
@@ -302,11 +303,11 @@ static int read_fd_data(struct fd_buf *buf)
302 302
 		  cmsg->cmsg_level == SOL_SOCKET &&
303 303
 		  cmsg->cmsg_type == SCM_RIGHTS) {
304 304
 		  if (buf->recvfd != -1) {
305
-		      logg("^Unclaimed file descriptor received. closing\n");
305
+		      logg("$Unclaimed file descriptor received. closing: %d\n");
306 306
 		      close(buf->recvfd);
307 307
 		  }
308 308
 		  buf->recvfd = *(int *)CMSG_DATA(cmsg);
309
-		  logg("*RECVMSG: got FD %d\n", buf->recvfd);
309
+		  logg("$Receveived a file descriptor: %d\n", buf->recvfd);
310 310
 	      }
311 311
 	  }
312 312
       }
... ...
@@ -458,6 +459,8 @@ int fds_poll_recv(struct fd_data *data, int timeout, int check_signals)
458 458
 	timeout = closest_timeout - now;
459 459
     else
460 460
 	timeout = -1;
461
+    if (timeout > 0)
462
+	logg("$fds_poll_recv: timeout after %d seconds\n", timeout);
461 463
 #ifdef HAVE_POLL
462 464
     /* Use poll() if available, preferred because:
463 465
      *  - can poll any number of FDs
... ...
@@ -500,7 +503,7 @@ int fds_poll_recv(struct fd_data *data, int timeout, int check_signals)
500 500
 		}
501 501
 		revents = data->poll_data[i].revents;
502 502
 		if (revents & (POLLIN|POLLHUP)) {
503
-		    logg("*POLL: POLLIN|POLLHUP on fd %d\n",data->poll_data[i].fd);
503
+		    logg("$Received POLLIN|POLLHUP on fd %d\n",data->poll_data[i].fd);
504 504
 		}
505 505
 		if (revents & POLLIN) {
506 506
 		    int ret = read_fd_data(&data->buf[i]);
... ...
@@ -514,11 +517,11 @@ int fds_poll_recv(struct fd_data *data, int timeout, int check_signals)
514 514
 		if (revents & (POLLHUP | POLLERR | POLLNVAL)) {
515 515
 		    if (revents & (POLLHUP| POLLNVAL)) {
516 516
 			/* remote disconnected */
517
-			logg("^poll_recv_fds: Client disconnected (FD %d)\n",
517
+			logg("*Client disconnected (FD %d)\n",
518 518
 			     data->poll_data[i].fd);
519 519
 		    } else {
520 520
 			/* error on file descriptor */
521
-			logg("!poll_recv_fds: Error condition on fd %d\n",
521
+			logg("^Error condition on fd %d\n",
522 522
 			     data->poll_data[i].fd);
523 523
 		    }
524 524
 		    data->buf[i].got_newdata = -1;
... ...
@@ -536,7 +539,7 @@ int fds_poll_recv(struct fd_data *data, int timeout, int check_signals)
536 536
     for (i=0;i < data->nfds; i++) {
537 537
 	int fd = data->buf[i].fd;
538 538
 	if (fd >= FD_SETSIZE) {
539
-	    logg ("!poll_recv_fds: file descriptor is not valid for FD_SET\n");
539
+	    logg ("!File descriptor is too high for FD_SET\n");
540 540
 	    return -1;
541 541
 	}
542 542
 
... ...
@@ -567,10 +570,10 @@ int fds_poll_recv(struct fd_data *data, int timeout, int check_signals)
567 567
 		    int ret = read_fd_data(&data->buf[i]);
568 568
 		    if (ret == -1 || !ret) {
569 569
 			if (ret == -1)
570
-			    logg("!poll_recv_fds: Error condition on fd %d\n",
570
+			    logg("!Error condition on fd %d\n",
571 571
 				 data->buf[i].fd);
572 572
 			else
573
-			    logg("^poll_recv_fds: Client disconnected\n");
573
+			    logg("*Client disconnected\n");
574 574
 			data->buf[i].got_newdata = -1;
575 575
 		    }
576 576
 		}
... ...
@@ -115,7 +115,7 @@ int scan_callback(struct stat *sb, char *filename, const char *msg, enum cli_ftw
115 115
 		     msg);
116 116
 	    return CL_SUCCESS;
117 117
 	case warning_skipped_link:
118
-	    logg("*Skipping symlink: %s\n", msg);
118
+	    logg("$Skipping symlink: %s\n", msg);
119 119
 	    return CL_SUCCESS;
120 120
 	case warning_skipped_special:
121 121
 	    if (msg == scandata->toplevel_path)
... ...
@@ -118,10 +118,10 @@ static void scanner_thread(void *arg)
118 118
 
119 119
     if (conn->filename)
120 120
 	free(conn->filename);
121
-    logg("*SCANTH: finished\n");
121
+    logg("$Finished scanthread\n");
122 122
     if (thrmgr_group_finished(conn->group, virus ? EXIT_OTHER :
123 123
 			      errors ? EXIT_ERROR : EXIT_OK)) {
124
-	logg("*SCANTH: connection shut down\n");
124
+	logg("$Scanthread: connection shut down\n");
125 125
 	/* close connection if we were last in group */
126 126
 	shutdown(conn->sd, 2);
127 127
 	closesocket(conn->sd);
... ...
@@ -848,17 +848,19 @@ int recvloop_th(int *socketds, unsigned nsockets, struct cl_engine *engine, unsi
848 848
 
849 849
 	    if (buf->got_newdata == -1) {
850 850
 		if (buf->mode == MODE_WAITREPLY) {
851
-		    logg("*RECVTH: mode WAIT_REPLY -> closed\n");
851
+		    logg("$mode WAIT_REPLY -> closed\n");
852 852
 		    buf->fd = -1;
853
+		    thrmgr_group_terminate(buf->group);
854
+		    thrmgr_group_finished(buf->group, EXIT_ERROR);
853 855
 		    continue;
854 856
 		} else {
855
-		    logg("*RECVTH: client read error or EOF on read\n");
857
+		    logg("$client read error or EOF on read\n");
856 858
 		    error = 1;
857 859
 		}
858 860
 	    }
859 861
 
860 862
 	    if (buf->fd != -1 && buf->got_newdata == -2) {
861
-		logg("*RECVTH: client read timed out\n");
863
+		logg("$Client read timed out\n");
862 864
 		mdprintf(buf->fd, "COMMAND READ TIMED OUT\n");
863 865
 		error = 1;
864 866
 	    }
... ...
@@ -866,7 +868,7 @@ int recvloop_th(int *socketds, unsigned nsockets, struct cl_engine *engine, unsi
866 866
 	    rr_last = i;
867 867
 	    if (buf->mode == MODE_WAITANCILL) {
868 868
 		buf->mode = MODE_COMMAND;
869
-		logg("*RECVTH: mode -> MODE_COMMAND\n");
869
+		logg("$mode -> MODE_COMMAND\n");
870 870
 	    }
871 871
 	    while (!error && buf->fd != -1 && buf->buffer && pos < buf->off &&
872 872
 		   buf->mode != MODE_WAITANCILL) {
... ...
@@ -896,7 +898,7 @@ int recvloop_th(int *socketds, unsigned nsockets, struct cl_engine *engine, unsi
896 896
 		       (cmd = get_cmd(buf, pos, &cmdlen, &term)) != NULL) {
897 897
 		    const char *argument;
898 898
 		    enum commands cmdtype = parse_command(cmd, &argument);
899
-		    logg("*RECVTH: got command %s (%u, %u), argument: %s\n",
899
+		    logg("$got command %s (%u, %u), argument: %s\n",
900 900
 			 cmd, (unsigned)cmdlen, (unsigned)cmdtype, argument ? argument : "");
901 901
 		    if (cmdtype == COMMAND_FILDES) {
902 902
 			if (buf->buffer + buf->off <= cmd + strlen("FILDES\n")) {
... ...
@@ -906,12 +908,12 @@ int recvloop_th(int *socketds, unsigned nsockets, struct cl_engine *engine, unsi
906 906
 			    /* put term back */
907 907
 			    buf->buffer[pos + cmdlen] = term;
908 908
 			    cmdlen = 0;
909
-			    logg("*RECVTH: mode -> MODE_WAITANCILL\n");
909
+			    logg("$RECVTH: mode -> MODE_WAITANCILL\n");
910 910
 			    break;
911 911
 			}
912 912
 			/* eat extra \0 for controlmsg */
913 913
 			cmdlen++;
914
-			logg("*RECVTH: FILDES command complete\n");
914
+			logg("$RECVTH: FILDES command complete\n");
915 915
 		    }
916 916
 
917 917
 		    conn.term = term;
... ...
@@ -927,20 +929,20 @@ int recvloop_th(int *socketds, unsigned nsockets, struct cl_engine *engine, unsi
927 927
 			error = 1;
928 928
 		    }
929 929
 		    if (thrmgr_group_need_terminate(conn.group)) {
930
-			logg("*RECVTH: have to terminate group\n");
930
+			logg("$Receive thread: have to terminate group\n");
931 931
 			error = CL_ETIMEOUT;
932 932
 			break;
933 933
 		    }
934 934
 		    if (error || !conn.group || rc) {
935 935
 			if (rc && thrmgr_group_finished(conn.group, EXIT_OK)) {
936
-			    logg("*RECVTH: closing conn, group finished\n");
936
+			    logg("$Receive thread: closing conn, group finished\n");
937 937
 			    /* if there are no more active jobs */
938 938
 			    shutdown(conn.sd, 2);
939 939
 			    closesocket(conn.sd);
940 940
 			    buf->fd = -1;
941 941
 			    conn.group = NULL;
942 942
 			} else if (conn.mode != MODE_STREAM) {
943
-			    logg("*RECVTH: mode -> MODE_WAITREPLY\n");
943
+			    logg("$mode -> MODE_WAITREPLY\n");
944 944
 			    /* no more commands are accepted */
945 945
 			    conn.mode = MODE_WAITREPLY;
946 946
 			    /* Stop monitoring this FD, it will be closed either
... ...
@@ -978,26 +980,26 @@ int recvloop_th(int *socketds, unsigned nsockets, struct cl_engine *engine, unsi
978 978
 			/* TODO: this doesn't belong here */
979 979
 			buf->dumpname = conn.filename;
980 980
 			buf->dumpfd = conn.scanfd;
981
-			logg("*RECVTH: STREAM: %s fd %u\n", buf->dumpname, buf->dumpfd);
981
+			logg("$Receive thread: INSTREAM: %s fd %u\n", buf->dumpname, buf->dumpfd);
982 982
 		    }
983 983
 		    if (conn.mode != MODE_COMMAND) {
984
-			logg("*RECVTH: breaking command loop, mode is no longer MODE_COMMAND\n");
984
+			logg("$Breaking command loop, mode is no longer MODE_COMMAND\n");
985 985
 			break;
986 986
 		    }
987 987
 		    conn.id++;
988 988
 		}
989
+		buf->mode = conn.mode;
990
+		buf->id = conn.id;
991
+		buf->group = conn.group;
992
+		buf->quota = conn.quota;
989 993
 		if (conn.scanfd != -1 && conn.scanfd != buf->dumpfd) {
990
-		    logg("*Unclaimed file descriptor received, closing: %d\n", conn.scanfd);
994
+		    logg("$Unclaimed file descriptor received, closing: %d\n", conn.scanfd);
991 995
 		    close(conn.scanfd);
992 996
 		    /* protocol error */
993 997
 		    conn_reply_error(&conn, "PROTOCOL ERROR: ancillary data sent without FILDES.");
994 998
 		    error = 1;
995 999
 		    break;
996 1000
 		}
997
-		buf->mode = conn.mode;
998
-		buf->id = conn.id;
999
-		buf->group = conn.group;
1000
-		buf->quota = conn.quota;
1001 1001
 		if (!error) {
1002 1002
 		    /* move partial command to beginning of buffer */
1003 1003
 		    if (pos < buf->off) {
... ...
@@ -1006,9 +1008,9 @@ int recvloop_th(int *socketds, unsigned nsockets, struct cl_engine *engine, unsi
1006 1006
 		    } else
1007 1007
 			buf->off = 0;
1008 1008
 		    if (buf->off)
1009
-			logg("*RECVTH: moved partial command: %lu\n", (unsigned long)buf->off);
1009
+			logg("$Moved partial command: %lu\n", (unsigned long)buf->off);
1010 1010
 		    else
1011
-			logg("*RECVTH: consumed entire command\n");
1011
+			logg("$Consumed entire command\n");
1012 1012
 		}
1013 1013
 		if (conn.mode == MODE_COMMAND && !cmd)
1014 1014
 		    break;
... ...
@@ -1016,24 +1018,24 @@ int recvloop_th(int *socketds, unsigned nsockets, struct cl_engine *engine, unsi
1016 1016
 		    /* Client is not supposed to send anything more */
1017 1017
 		    logg("^Client sent garbage after last command: %lu bytes\n", (unsigned long)buf->off);
1018 1018
 		    buf->buffer[buf->off] = '\0';
1019
-		    logg("*RECVTH: garbage: %s\n", buf->buffer);
1019
+		    logg("$Garbage: %s\n", buf->buffer);
1020 1020
 		    error = 1;
1021 1021
 		}
1022 1022
 		if (!error && buf->mode == MODE_STREAM) {
1023
-		    logg("*RECVTH: mode == MODE_STREAM\n");
1023
+		    logg("$mode == MODE_STREAM\n");
1024 1024
 		    if (!buf->chunksize) {
1025 1025
 			/* read chunksize */
1026 1026
 			if (buf->off >= 4) {
1027 1027
 			    uint32_t cs = *(uint32_t*)buf->buffer;
1028 1028
 			    buf->chunksize = ntohl(cs);
1029
-			    logg("*RECVTH: chunksize: %u\n", buf->chunksize);
1029
+			    logg("$Got chunksize: %u\n", buf->chunksize);
1030 1030
 			    if (!buf->chunksize) {
1031 1031
 				/* chunksize 0 marks end of stream */
1032 1032
 				conn.scanfd = buf->dumpfd;
1033 1033
 				conn.term = buf->term;
1034 1034
 				buf->dumpfd = -1;
1035 1035
 				buf->mode = buf->group ? MODE_COMMAND : MODE_WAITREPLY;
1036
-				logg("*RECVTH: chunks complete\n");
1036
+				logg("$Chunks complete\n");
1037 1037
 				buf->dumpname = NULL;
1038 1038
 				if ((rc = execute_or_dispatch_command(&conn, COMMAND_INSTREAMSCAN, NULL)) < 0) {
1039 1039
 				    logg("!Command dispatch failed\n");
... ...
@@ -1061,7 +1063,7 @@ int recvloop_th(int *socketds, unsigned nsockets, struct cl_engine *engine, unsi
1061 1061
 			    } else {
1062 1062
 				buf->quota -= buf->chunksize;
1063 1063
 			    }
1064
-			    logg("*RECVTH: quota: %lu\n", buf->quota);
1064
+			    logg("$Quota: %lu\n", buf->quota);
1065 1065
 			    pos = 4;
1066 1066
 			} else
1067 1067
 			    break;
... ...
@@ -1077,7 +1079,7 @@ int recvloop_th(int *socketds, unsigned nsockets, struct cl_engine *engine, unsi
1077 1077
 			logg("!INSTREAM: Can't write to temporary file.\n");
1078 1078
 			error = 1;
1079 1079
 		    }
1080
-		    logg("*RECVTH: processed %lu bytes of chunkdata\n", cmdlen);
1080
+		    logg("$Processed %lu bytes of chunkdata\n", cmdlen);
1081 1081
 		    pos += cmdlen;
1082 1082
 		    if (pos == buf->off) {
1083 1083
 			buf->off = 0;
... ...
@@ -1098,11 +1100,11 @@ int recvloop_th(int *socketds, unsigned nsockets, struct cl_engine *engine, unsi
1098 1098
 		}
1099 1099
 		thrmgr_group_terminate(buf->group);
1100 1100
 		if (thrmgr_group_finished(buf->group, EXIT_ERROR)) {
1101
-		    logg("*RECVTH: shutting down socket after error\n");
1101
+		    logg("$Shutting down socket after error\n");
1102 1102
 		    shutdown(buf->fd, 2);
1103 1103
 		    closesocket(buf->fd);
1104 1104
 		} else
1105
-		    logg("*RECVTH: socket not shut down due to active tasks\n");
1105
+		    logg("$Socket not shut down due to active tasks\n");
1106 1106
 		buf->fd = -1;
1107 1107
 	    }
1108 1108
 	}
... ...
@@ -98,13 +98,13 @@ enum commands parse_command(const char *cmd, const char **argument)
98 98
 	    const char *arg = cmd + len;
99 99
 	    if (commands[i].need_arg) {
100 100
 		if (!*arg) {/* missing argument */
101
-		    logg("*Command %s missing argument!\n", commands[i].cmd);
101
+		    logg("$Command %s missing argument!\n", commands[i].cmd);
102 102
 		    return COMMAND_UNKNOWN;
103 103
 		}
104 104
 		*argument = arg+1;
105 105
 	    } else {
106 106
 		if (*arg) {/* extra stuff after command */
107
-		    logg("*Command %s has trailing garbage!\n", commands[i].cmd);
107
+		    logg("$Command %s has trailing garbage!\n", commands[i].cmd);
108 108
 		    return COMMAND_UNKNOWN;
109 109
 		}
110 110
 		*argument = NULL;
... ...
@@ -183,7 +183,7 @@ int command(client_conn_t *conn, int *virus)
183 183
     jobgroup_t *group = NULL;
184 184
 
185 185
     if (thrmgr_group_need_terminate(conn->group)) {
186
-	logg("*Client disconnected while command was active\n");
186
+	logg("$Client disconnected while command was active\n");
187 187
 	if (conn->scanfd != -1)
188 188
 	    close(conn->scanfd);
189 189
 	return 1;
... ...
@@ -246,7 +246,7 @@ int command(client_conn_t *conn, int *virus)
246 246
 		} else
247 247
 		    ret = 0;
248 248
 	    }
249
-	    logg("*SESSION: closed fd %d\n", conn->scanfd);
249
+	    logg("$Closed fd %d\n", conn->scanfd);
250 250
 	    close(conn->scanfd);
251 251
 	    return ret;
252 252
 #else
... ...
@@ -409,7 +409,7 @@ int execute_or_dispatch_command(client_conn_t *conn, enum commands cmd, const ch
409 409
 	    default:
410 410
 		/* these commands are not recognized inside an IDSESSION */
411 411
 		conn_reply_error(conn, "Command invalid inside IDSESSION.");
412
-		logg("*SESSION: command is not valid inside IDSESSION: %d\n", cmd);
412
+		logg("$SESSION: command is not valid inside IDSESSION: %d\n", cmd);
413 413
 		conn->group = NULL;
414 414
 		return 1;
415 415
 	}
... ...
@@ -577,7 +577,7 @@ static void *thrmgr_pop(threadpool_t *pool)
577 577
     }
578 578
 
579 579
     if (!thrmgr_contended(pool)) {
580
-	logg("*THRMGR: queue crossed low threshold -> signaling\n");
580
+	logg("$THRMGR: queue crossed low threshold -> signaling\n");
581 581
 	pthread_cond_signal(&pool->queueable_cond);
582 582
     }
583 583
 
... ...
@@ -682,9 +682,9 @@ static int thrmgr_dispatch_internal(threadpool_t *threadpool, void *user_data, i
682 682
 		queue = threadpool->single_queue;
683 683
 
684 684
 	    while (thrmgr_contended(threadpool)) {
685
-		logg("*THRMGR: contended, sleeping\n");
685
+		logg("$THRMGR: contended, sleeping\n");
686 686
 		pthread_cond_wait(&threadpool->queueable_cond, &threadpool->pool_mutex);
687
-		logg("*THRMGR: contended, woken\n");
687
+		logg("$THRMGR: contended, woken\n");
688 688
 	    }
689 689
 
690 690
 	    if (!work_queue_add(queue, user_data)) {
... ...
@@ -725,11 +725,13 @@ int thrmgr_group_dispatch(threadpool_t *threadpool, jobgroup_t *group, void *use
725 725
     if (group) {
726 726
 	pthread_mutex_lock(&group->mutex);
727 727
 	group->jobs++;
728
+	logg("$THRMGR: active jobs for %p: %d\n", group, group->jobs);
728 729
 	pthread_mutex_unlock(&group->mutex);
729 730
     }
730 731
     if (!(ret = thrmgr_dispatch_internal(threadpool, user_data, 1)) && group) {
731 732
 	pthread_mutex_lock(&group->mutex);
732 733
 	group->jobs--;
734
+	logg("$THRMGR: active jobs for %p: %d\n", group, group->jobs);
733 735
 	pthread_mutex_unlock(&group->mutex);
734 736
     }
735 737
     return ret;
... ...
@@ -747,7 +749,7 @@ int thrmgr_group_finished(jobgroup_t *group, enum thrmgr_exit exitc)
747 747
 	return 1;
748 748
     }
749 749
     pthread_mutex_lock(&group->mutex);
750
-    logg("*THRMGR: group_finished: %p, %d\n", group, group->jobs);
750
+    logg("$THRMGR: group_finished: %p, %d\n", group, group->jobs);
751 751
     group->exit_total++;
752 752
     switch (exitc) {
753 753
 	case EXIT_OK:
... ...
@@ -760,13 +762,14 @@ int thrmgr_group_finished(jobgroup_t *group, enum thrmgr_exit exitc)
760 760
     if (group->jobs) {
761 761
 	if (!--group->jobs) {
762 762
 	    ret = 1;
763
-	}
763
+	} else
764
+	    logg("$THRMGR: active jobs for %p: %d\n", group, group->jobs);
764 765
 	if (group->jobs == 1)
765 766
 	    pthread_cond_signal(&group->only);
766 767
     }
767 768
     pthread_mutex_unlock(&group->mutex);
768 769
     if (ret) {
769
-	logg("*THRMGR: group_finished: freeing %p\n", group);
770
+	logg("$THRMGR: group_finished: freeing %p\n", group);
770 771
 	free(group);
771 772
     }
772 773
     return ret;
... ...
@@ -793,9 +796,11 @@ void thrmgr_group_waitforall(jobgroup_t *group, unsigned *ok, unsigned *error, u
793 793
     *total = group->exit_total;
794 794
     if(!--group->jobs)
795 795
 	needfree = 1;
796
+    else
797
+	logg("$THRMGR: active jobs for %p: %d\n", group, group->jobs);
796 798
     pthread_mutex_unlock(&group->mutex);
797 799
     if (needfree) {
798
-	logg("*THRMGR: freeing %p\n", group);
800
+	logg("$THRMGR: group finished freeing %p\n", group);
799 801
 	free(group);
800 802
     }
801 803
 }
... ...
@@ -810,6 +815,7 @@ jobgroup_t *thrmgr_group_new(void)
810 810
     if (!group)
811 811
 	return NULL;
812 812
     memcpy(group, &dummy, sizeof(dummy));
813
+    logg("$THRMGR: new group: %p\n", group);
813 814
     return group;
814 815
 }
815 816
 
... ...
@@ -189,7 +189,7 @@ const struct clam_option clam_options[] = {
189 189
 
190 190
     { "CommandReadTimeout", NULL, 0, TYPE_NUMBER, MATCH_NUMBER, 5, NULL, 0, OPT_CLAMD, "This option specifies the time (in seconds) after which clamd should\ntimeout if a client doesn't provide any initial command after connecting.", "5" },
191 191
 
192
-    { "SendBufTimeout", NULL, 0, TYPE_NUMBER, MATCH_NUMBER, 200, NULL, 0, OPT_CLAMD, "This option specifies how long to wait (in miliseconds) if the send buffer is full. Keep this value to prevent clamd hanging\n", "200"},
192
+    { "SendBufTimeout", NULL, 0, TYPE_NUMBER, MATCH_NUMBER, 500, NULL, 0, OPT_CLAMD, "This option specifies how long to wait (in miliseconds) if the send buffer is full. Keep this value to prevent clamd hanging\n", "200"},
193 193
 
194 194
     { "ReadTimeout", NULL, 0, TYPE_NUMBER, MATCH_NUMBER, 120, NULL, 0, OPT_MILTER, "Waiting for data from clamd will timeout after this time (seconds).\nValue of 0 disables the timeout.", "300" },
195 195
 
... ...
@@ -223,6 +223,9 @@ int logg(const char *str, ...)
223 223
 	mode_t old_umask;
224 224
 	int len;
225 225
 
226
+    if ((*str == '$' && logg_verbose < 2) ||
227
+	(*str == '*' && !logg_verbose))
228
+	return 0;
226 229
 
227 230
     ARGLEN(args, str, len);
228 231
     if(len <= sizeof(buffer)) {
... ...
@@ -306,8 +309,7 @@ int logg(const char *str, ...)
306 306
 	    } else if(*buff == '^') {
307 307
 		if(!logg_nowarn)
308 308
 		    fprintf(logg_fp, "WARNING: %s", buff + 1);
309
-	    } else if(*buff == '*') {
310
-		if(logg_verbose)
309
+	    } else if(*buff == '*' || *buff == '$') {
311 310
 		    fprintf(logg_fp, "%s", buff + 1);
312 311
 	    } else if(*buff == '#' || *buff == '~') {
313 312
 		fprintf(logg_fp, "%s", buff + 1);
... ...
@@ -325,10 +327,8 @@ int logg(const char *str, ...)
325 325
 	} else if(buff[0] == '^') {
326 326
 	    if(!logg_nowarn)
327 327
 		syslog(LOG_WARNING, "%s", buff + 1);
328
-	} else if(buff[0] == '*') {
329
-	    if(logg_verbose) {
330
-		syslog(LOG_DEBUG, "%s", buff + 1);
331
-	    }
328
+	} else if(buff[0] == '*' || buff[0] == '$') {
329
+	    syslog(LOG_DEBUG, "%s", buff + 1);
332 330
 	} else if(buff[0] == '#' || buff[0] == '~') {
333 331
 	    syslog(LOG_INFO, "%s", buff + 1);
334 332
 	} else syslog(LOG_INFO, "%s", buff);
... ...
@@ -51,13 +51,13 @@ scan_failed() {
51 51
 
52 52
 start_clamd()
53 53
 {
54
-	rm -f clamd-test.log
55
-	$LTEXEC $CLAMD_WRAPPER $TOP/clamd/clamd -c $1 --help >clamd-test.log || 
56
-		{ error "Failed to start clamd --help!"; die 1; }
54
+	rm -f clamd-test.log clamd-test1.log clamd-test2.log
55
+	$LTEXEC $CLAMD_WRAPPER $TOP/clamd/clamd -c $1 --help >clamd-test.log 2>&1 || 
56
+		{ error "Failed to start clamd --help!"; cat clamd-test.log; die 1; }
57 57
 	grep "Clam AntiVirus Daemon" clamd-test.log >/dev/null ||
58 58
 		{ error "Wrong --help reply from clamd!"; die 1; }
59
-	$LTEXEC $CLAMD_WRAPPER $TOP/clamd/clamd -c $1 || 
60
-		{ error "Failed to start clamd!"; die 1; }
59
+	$LTEXEC $CLAMD_WRAPPER $TOP/clamd/clamd -c $1 >clamd-test.log 2>&1 || 
60
+		{ error "Failed to start clamd!"; cat clamd-test.log; die 1; }
61 61
 }
62 62
 
63 63
 run_clamdscan_fileonly() {
... ...
@@ -1,6 +1,8 @@
1 1
 # script will fill in CWD and X
2
-LogFile CWD/clamd-test.log
2
+LogFile CWD/clamd-testX.log
3
+LogFileMaxSize 0
3 4
 LogTime yes
5
+Debug yes
4 6
 LogClean yes
5 7
 LogVerbose yes
6 8
 PidFile CWD/clamd-test.pid