masqmail-0.2
changeset 114:a80ebfa16cd5
better debugging output (thanks to Paolo)
| author | meillo@marmaro.de |
|---|---|
| date | Wed, 30 Jun 2010 15:00:59 +0200 |
| parents | c93023f58cc7 |
| children | 315773f814f7 |
| files | src/alias.c src/conf.c src/connect.c src/deliver.c src/local.c src/parse.c src/queue.c src/route.c src/smtp_out.c src/spool.c |
| diffstat | 10 files changed, 64 insertions(+), 40 deletions(-) [+] |
line diff
1.1 --- a/src/alias.c Wed Jun 30 13:23:49 2010 +0200 1.2 +++ b/src/alias.c Wed Jun 30 15:00:59 2010 +0200 1.3 @@ -32,6 +32,8 @@ 1.4 if (fnmatch(dom_node->data, addr->domain, FNM_CASEFOLD) == 0) { 1.5 foreach(conf.not_local_addresses, addr_node) { 1.6 a = create_address_qualified(addr_node->data, TRUE, conf.host_name); 1.7 + DEBUG(6) debugf("not_local_addresses: addr_node->data=%s a->address=%s\n", 1.8 + addr_node->data, a->address); 1.9 if (addr_isequal(a, addr)) { 1.10 destroy_address(a); 1.11 return FALSE; 1.12 @@ -43,6 +45,8 @@ 1.13 } 1.14 foreach(conf.local_addresses, addr_node) { 1.15 a = create_address_qualified(addr_node->data, TRUE, conf.host_name); 1.16 + DEBUG(6) debugf("local_addresses: addr_node->data=%s a->address=%s\n", 1.17 + addr_node->data, a->address); 1.18 if (addr_isequal(a, addr)) { 1.19 destroy_address(a); 1.20 return TRUE;
2.1 --- a/src/conf.c Wed Jun 30 13:23:49 2010 +0200 2.2 +++ b/src/conf.c Wed Jun 30 15:00:59 2010 +0200 2.3 @@ -99,6 +99,7 @@ 2.4 fgets(buf, 255, fptr); 2.5 if (buf[0] && (buf[0] != '#') && (buf[0] != '\n')) { 2.6 g_strchomp(buf); 2.7 + DEBUG(6) fprintf(stderr,"parse_list_file: item = %s\n", buf); 2.8 list = g_list_append(list, g_strdup(buf)); 2.9 } 2.10 } 2.11 @@ -115,7 +116,7 @@ 2.12 gchar buf[256]; 2.13 gchar *p, *q; 2.14 2.15 - DEBUG(6) fprintf(stderr, "parsing list %s\n", line); 2.16 + DEBUG(6) fprintf(stderr, "parsing list %s, file?:%d\n", line, read_file); 2.17 2.18 p = line; 2.19 while (*p != '\0') { 2.20 @@ -132,7 +133,7 @@ 2.21 /* just a normal item */ 2.22 list = g_list_append(list, g_strdup(buf)); 2.23 2.24 - DEBUG(6) printf("item = %s\n", buf); 2.25 + DEBUG(6) fprintf(stderr, "item = %s\n", buf); 2.26 2.27 if (*p) 2.28 p++; 2.29 @@ -214,6 +215,7 @@ 2.30 iface->port = atoi(p); 2.31 } else 2.32 iface->port = def_port; 2.33 + DEBUG(6) fprintf(stderr,"rval=%s, address:port=%s:%i\n",line, iface->address, iface->port); 2.34 2.35 return iface; 2.36 } 2.37 @@ -401,19 +403,18 @@ 2.38 if (!eat_comments(in)) 2.39 return FALSE; 2.40 2.41 - DEBUG(6) fprintf(stderr, "read_statement() 1\n"); 2.42 - 2.43 if (!read_lval(in, lval, lsize)) { 2.44 return FALSE; 2.45 } 2.46 2.47 - DEBUG(6) fprintf(stderr, "lval = %s\n", lval); 2.48 + DEBUG(6) fprintf(stderr, " lval = %s\n", lval); 2.49 if ((c = fgetc(in) == '=')) { 2.50 if (read_rval(in, rval, rsize)) { 2.51 - DEBUG(6) fprintf(stderr, "rval = %s\n", rval); 2.52 + DEBUG(6) fprintf(stderr, " rval = %s\n", rval); 2.53 return TRUE; 2.54 } 2.55 } else { 2.56 + DEBUG(6) fprintf(stderr," '=' expected after %s, char was '%c'\n", lval, c); 2.57 fprintf(stderr, "'=' expected after %s, char was '%c'\n", lval, c); 2.58 } 2.59 return FALSE; 2.60 @@ -437,6 +438,7 @@ 2.61 2.62 gchar lval[256], rval[2048]; 2.63 while (read_statement(in, lval, 256, rval, 2048)) { 2.64 + DEBUG(6) fprintf(stderr,"read_conf(): lval=%s\n", lval); 2.65 if (strcmp(lval, "debug_level") == 0) 2.66 conf.debug_level = atoi(rval); 2.67 else if (strcmp(lval, "run_as_user") == 0) {
3.1 --- a/src/connect.c Wed Jun 30 13:23:49 2010 +0200 3.2 +++ b/src/connect.c Wed Jun 30 15:00:59 2010 +0200 3.3 @@ -53,9 +53,9 @@ 3.4 3.5 /* clumsy, but makes compiler happy: */ 3.6 saddr.sin_addr = *(struct in_addr *) (&(addr->ip)); 3.7 - DEBUG(5) debugf("trying ip %s port %d\n", inet_ntoa(saddr.sin_addr), port); 3.8 + DEBUG(5) debugf(" trying ip %s port %d\n", inet_ntoa(saddr.sin_addr), port); 3.9 if (connect(*psockfd, (struct sockaddr *) (&saddr), sizeof(saddr)) == 0) { 3.10 - DEBUG(5) debugf("connected to %s\n", inet_ntoa(saddr.sin_addr)); 3.11 + DEBUG(5) debugf(" connected to %s\n", inet_ntoa(saddr.sin_addr)); 3.12 return addr; 3.13 } else { 3.14 int saved_errno = errno; 3.15 @@ -115,7 +115,7 @@ 3.16 3.17 foreach(res_func_list, res_node) { 3.18 resolve_func res_func; 3.19 - DEBUG(6) debugf("connect_resolvelist 1a\n"); 3.20 + DEBUG(6) debugf(" foreach() body\n"); 3.21 res_func = (resolve_func) (res_node->data); 3.22 3.23 if (res_func == NULL) {
4.1 --- a/src/deliver.c Wed Jun 30 13:23:49 2010 +0200 4.2 +++ b/src/deliver.c Wed Jun 30 15:00:59 2010 +0200 4.3 @@ -693,8 +693,11 @@ 4.4 GList *localnet_rcpt_list = NULL; 4.5 GList *other_rcpt_list; 4.6 4.7 - if (!spool_lock(msgout->msg->uid)) 4.8 + if (!spool_lock(msgout->msg->uid)) { 4.9 + DEBUG(5) debugf("spool_lock(%s) failed.\n", msgout->msg->uid); 4.10 continue; 4.11 + } 4.12 + DEBUG(5) debugf("spool_lock(%s)\n", msgout->msg->uid); 4.13 4.14 rcpt_list = g_list_copy(msgout->msg->rcpt_list); 4.15 if (conf.log_user) { 4.16 @@ -751,6 +754,7 @@ 4.17 4.18 /* actual delivery */ 4.19 if (local_msgout_list != NULL) { 4.20 + DEBUG(5) debugf("local_msgout_list\n"); 4.21 foreach(local_msgout_list, msgout_node) { 4.22 msg_out *msgout = (msg_out *) (msgout_node->data); 4.23 if (!deliver_local(msgout)) 4.24 @@ -763,6 +767,7 @@ 4.25 GList *route_list = NULL; 4.26 GList *route_node; 4.27 4.28 + DEBUG(5) debugf("localnet_msgout_list\n"); 4.29 if (conf.local_net_routes) 4.30 route_list = read_route_list(conf.local_net_routes, TRUE); 4.31 else 4.32 @@ -778,6 +783,7 @@ 4.33 } 4.34 4.35 if (other_msgout_list != NULL) { 4.36 + DEBUG(5) debugf("other_msgout_list\n"); 4.37 if (!deliver_msgout_list_online(other_msgout_list)) 4.38 ok = FALSE; 4.39 destroy_msg_out_list(other_msgout_list); 4.40 @@ -785,7 +791,12 @@ 4.41 4.42 foreach(msgout_list, msgout_node) { 4.43 msg_out *msgout = (msg_out *) (msgout_node->data); 4.44 - spool_unlock(msgout->msg->uid); 4.45 + if (spool_unlock(msgout->msg->uid)) { 4.46 + DEBUG(5) debugf("spool_unlock(%s)\n", msgout->msg->uid); 4.47 + } else { 4.48 + DEBUG(5) debugf("spool_unlock(%s) failed.\n", msgout->msg->uid); 4.49 + } 4.50 + 4.51 } 4.52 4.53 destroy_msg_out_list(msgout_list);
5.1 --- a/src/local.c Wed Jun 30 13:23:49 2010 +0200 5.2 +++ b/src/local.c Wed Jun 30 15:00:59 2010 +0200 5.3 @@ -70,8 +70,7 @@ 5.4 } 5.5 } 5.6 5.7 - DEBUG(5) debugf("running as euid %d\n", geteuid()); 5.8 - DEBUG(5) debugf("running as egid %d\n", getegid()); 5.9 + DEBUG(5) debugf("running as euid %d, egid %d\n", geteuid(), getegid()); 5.10 5.11 if (uid_ok && gid_ok) { 5.12 gchar *filename; 5.13 @@ -168,15 +167,14 @@ 5.14 } 5.15 } 5.16 5.17 - DEBUG(5) debugf("running as euid %d\n", geteuid()); 5.18 - DEBUG(5) debugf("running as egid %d\n", getegid()); 5.19 + DEBUG(5) debugf("running as euid %d, egid %d\n", geteuid(), getegid()); 5.20 5.21 if (uid_ok && gid_ok) { 5.22 char *path = g_strdup_printf("%s/Maildir", pw->pw_dir); 5.23 struct stat statbuf; 5.24 int ret; 5.25 5.26 - DEBUG(5) debugf("path = %s\n", path); 5.27 + DEBUG(5) debugf(" path = %s\n", path); 5.28 5.29 ok = TRUE; 5.30 ret = stat(path, &statbuf);
6.1 --- a/src/parse.c Wed Jun 30 13:23:49 2010 +0200 6.2 +++ b/src/parse.c Wed Jun 30 15:00:59 2010 +0200 6.3 @@ -349,7 +349,7 @@ 6.4 /* 6.5 allocate address, reading from string. 6.6 On failure, returns NULL. 6.7 - after call, end contatins a pointer to the end of the parsed string 6.8 + after call, end contains a pointer to the end of the parsed string 6.9 end may be NULL, if we are not interested. 6.10 6.11 parses both rfc 821 and rfc 822 addresses, depending on flag is_rfc821
7.1 --- a/src/queue.c Wed Jun 30 13:23:49 2010 +0200 7.2 +++ b/src/queue.c Wed Jun 30 15:00:59 2010 +0200 7.3 @@ -97,6 +97,7 @@ 7.4 if (msg_list != NULL) { 7.5 ok = deliver_msg_list(msg_list, DLVR_ALL); 7.6 destroy_msg_list(msg_list); 7.7 + logwrite(LOG_NOTICE, " deliver_msg_list()=%d.\n", ok); 7.8 } 7.9 logwrite(LOG_NOTICE, "Finished queue run.\n"); 7.10
8.1 --- a/src/route.c Wed Jun 30 13:23:49 2010 +0200 8.2 +++ b/src/route.c Wed Jun 30 15:00:59 2010 +0200 8.3 @@ -321,7 +321,8 @@ 8.4 debugf("rcpts for routed delivery, route = %s, id = %s\n", route->name, msg->uid); 8.5 foreach(rcpt_list, node) { 8.6 address *rcpt = (address *) (node->data); 8.7 - debugf("rcpt for routed delivery: <%s@%s>\n", rcpt->local_part, rcpt->domain); 8.8 + debugf(" rcpt for routed delivery: <%s@%s>\n", 8.9 + rcpt->local_part, rcpt->domain); 8.10 } 8.11 } 8.12
9.1 --- a/src/smtp_out.c Wed Jun 30 13:23:49 2010 +0200 9.2 +++ b/src/smtp_out.c Wed Jun 30 15:00:59 2010 +0200 9.3 @@ -262,8 +262,9 @@ 9.4 9.5 DEBUG(4) { 9.6 gint i = 0; 9.7 + debugf("in check_helo_response()\n"); 9.8 while (psb->auth_names[i]) { 9.9 - debugf("offered AUTH %s\n", psb->auth_names[i]); 9.10 + debugf(" offered AUTH %s\n", psb->auth_names[i]); 9.11 i++; 9.12 } 9.13 } 9.14 @@ -277,9 +278,9 @@ 9.15 } 9.16 9.17 DEBUG(4) { 9.18 - debugf(psb->use_size ? "uses SIZE\n" : "no size\n"); 9.19 - debugf(psb->use_pipelining ? "uses PIPELINING\n" : "no pipelining\n"); 9.20 - debugf(psb->use_auth ? "uses AUTH\n" : "no auth\n"); 9.21 + debugf(" %s\n", psb->use_size ? "uses SIZE" : "no size"); 9.22 + debugf(" %s\n", psb->use_pipelining ? "uses PIPELINING" : "no pipelining"); 9.23 + debugf(" %s\n", psb->use_auth ? "uses AUTH" : "no auth"); 9.24 } 9.25 9.26 return TRUE; 9.27 @@ -555,10 +556,10 @@ 9.28 unsigned int digest_len; 9.29 #endif 9.30 9.31 - DEBUG(5) debugf("encoded challenge = %s\n", chall64); 9.32 - DEBUG(5) debugf("decoded challenge = %s, size = %d\n", chall, chall_size); 9.33 - 9.34 - DEBUG(5) debugf("secret = %s\n", psb->auth_secret); 9.35 + DEBUG(5) debugf("smtp_out_auth_cram_md5():\n"); 9.36 + DEBUG(5) debugf(" encoded challenge = %s\n", chall64); 9.37 + DEBUG(5) debugf(" decoded challenge = %s, size = %d\n", chall, chall_size); 9.38 + DEBUG(5) debugf(" secret = %s\n", psb->auth_secret); 9.39 9.40 #ifdef USE_LIB_CRYPTO 9.41 HMAC(EVP_md5(), psb->auth_secret, strlen(psb->auth_secret), chall, chall_size, digest, &digest_len); 9.42 @@ -570,17 +571,17 @@ 9.43 sprintf(&(digest_string[i + i]), "%02x", (unsigned int) (digest[i])); 9.44 digest_string[32] = '\0'; 9.45 9.46 - DEBUG(5) debugf("digest = %s\n", digest_string); 9.47 + DEBUG(5) debugf(" digest = %s\n", digest_string); 9.48 9.49 reply = g_strdup_printf("%s %s", psb->auth_login, digest_string); 9.50 - DEBUG(5) debugf("unencoded reply = %s\n", reply); 9.51 + DEBUG(5) debugf(" unencoded reply = %s\n", reply); 9.52 9.53 reply64 = base64_encode(reply, strlen(reply)); 9.54 - DEBUG(5) debugf("encoded reply = %s\n", reply64); 9.55 + DEBUG(5) debugf(" encoded reply = %s\n", reply64); 9.56 9.57 fprintf(psb->out, "%s\r\n", reply64); 9.58 fflush(psb->out); 9.59 - DEBUG(4) debugf("%s\n", reply64); 9.60 + DEBUG(4) debugf(" reply64 = %s\n", reply64); 9.61 9.62 if ((ok = read_response(psb, SMTP_CMD_TIMEOUT))) 9.63 ok = check_response(psb, FALSE); 9.64 @@ -607,11 +608,12 @@ 9.65 gint resp_size; 9.66 gchar *reply64; 9.67 9.68 + DEBUG(5) debugf("smtp_out_auth_login():\n"); 9.69 resp64 = get_response_arg(&(psb->buffer[4])); 9.70 - DEBUG(5) debugf("encoded response = %s\n", resp64); 9.71 + DEBUG(5) debugf(" encoded response = %s\n", resp64); 9.72 resp = base64_decode(resp64, &resp_size); 9.73 g_free(resp64); 9.74 - DEBUG(5) debugf("decoded response = %s, size = %d\n", resp, resp_size); 9.75 + DEBUG(5) debugf(" decoded response = %s, size = %d\n", resp, resp_size); 9.76 g_free(resp); 9.77 reply64 = base64_encode(psb->auth_login, strlen(psb->auth_login)); 9.78 fprintf(psb->out, "%s\r\n", reply64); 9.79 @@ -620,10 +622,10 @@ 9.80 if ((ok = read_response(psb, SMTP_CMD_TIMEOUT))) { 9.81 if ((ok = check_response(psb, TRUE))) { 9.82 resp64 = get_response_arg(&(psb->buffer[4])); 9.83 - DEBUG(5) debugf("encoded response = %s\n", resp64); 9.84 + DEBUG(5) debugf(" encoded response = %s\n", resp64); 9.85 resp = base64_decode(resp64, &resp_size); 9.86 g_free(resp64); 9.87 - DEBUG(5) debugf("decoded response = %s, size = %d\n", resp, resp_size); 9.88 + DEBUG(5) debugf(" decoded response = %s, size = %d\n", resp, resp_size); 9.89 g_free(resp); 9.90 reply64 = base64_encode(psb->auth_secret, strlen(psb->auth_secret)); 9.91 fprintf(psb->out, "%s\r\n", reply64); 9.92 @@ -712,7 +714,8 @@ 9.93 9.94 /* respect maximum size given by server: */ 9.95 if ((psb->max_size > 0) && (size > psb->max_size)) { 9.96 - logwrite(LOG_WARNING, "%s == host=%s message size (%d) > fixed maximum message size of server (%d)", 9.97 + logwrite(LOG_WARNING, "%s == host=%s message size (%d) > " 9.98 + "fixed maximum message size of server (%d)", 9.99 msg->uid, psb->remote_host, size, psb->max_size); 9.100 psb->error = smtp_cancel; 9.101 ok = FALSE; 9.102 @@ -747,7 +750,7 @@ 9.103 ok = FALSE; 9.104 break; 9.105 } else { 9.106 - logwrite(LOG_NOTICE, "%s == %s host=%s failed: %s", 9.107 + logwrite(LOG_NOTICE, "%s == %s host=%s failed: %s\n", 9.108 msg->uid, addr_string(rcpt), psb->remote_host, psb->buffer); 9.109 if (psb->error == smtp_trylater) { 9.110 addr_mark_defered(rcpt); 9.111 @@ -798,7 +801,7 @@ 9.112 ok = FALSE; 9.113 break; 9.114 } else { 9.115 - logwrite(LOG_NOTICE, "%s == %s host=%s failed: %s", msg->uid, 9.116 + logwrite(LOG_NOTICE, "%s == %s host=%s failed: %s\n", msg->uid, 9.117 addr_string(rcpt), psb->remote_host, psb->buffer); 9.118 if (psb->error == smtp_trylater) { 9.119 addr_mark_defered(rcpt); 9.120 @@ -840,9 +843,10 @@ 9.121 } 9.122 9.123 DEBUG(5) { 9.124 - debugf("psb->error = %d\n", psb->error); 9.125 - debugf("ok = %d\n", ok); 9.126 - debugf("rcpt_accept = %d\n", rcpt_accept); 9.127 + debugf("smtp_out_msg():\n"); 9.128 + debugf(" psb->error = %d\n", psb->error); 9.129 + debugf(" ok = %d\n", ok); 9.130 + debugf(" rcpt_accept = %d\n", rcpt_accept); 9.131 } 9.132 9.133 if (psb->error == smtp_ok) {
10.1 --- a/src/spool.c Wed Jun 30 13:23:49 2010 +0200 10.2 +++ b/src/spool.c Wed Jun 30 15:00:59 2010 +0200 10.3 @@ -206,11 +206,14 @@ 10.4 msg = create_message(); 10.5 msg->uid = g_strdup(uid); 10.6 10.7 + DEBUG(4) debugf("msg_spool_read():\n"); 10.8 /* header spool: */ 10.9 ok = spool_read_header(msg); 10.10 + DEBUG(4) debugf(" spool_read_header()=%d, do_readdata=%d\n", ok, do_readdata); 10.11 if (ok && do_readdata) { 10.12 /* data spool: */ 10.13 ok = spool_read_data(msg); 10.14 + DEBUG(4) debugf(" spool_read_data()=%d\n", ok); 10.15 } 10.16 return msg; 10.17 }