From 6feb0482ac3a005360430ff10acf0372c10618ef Mon Sep 17 00:00:00 2001 From: Wilfried Goesgens Date: Thu, 3 May 2012 23:55:30 +0200 Subject: [PATCH] IMAP: make debug logging configurable. --- citadel/modules/imap/imap_fetch.c | 49 +++++++------- citadel/modules/imap/imap_list.c | 5 +- citadel/modules/imap/imap_misc.c | 5 +- citadel/modules/imap/imap_tools.c | 11 ++-- citadel/modules/imap/serv_imap.c | 102 +++++++++++++++++------------- citadel/modules/imap/serv_imap.h | 14 ++++ 6 files changed, 108 insertions(+), 78 deletions(-) diff --git a/citadel/modules/imap/imap_fetch.c b/citadel/modules/imap/imap_fetch.c index aa9a3dfc0..38de324e6 100644 --- a/citadel/modules/imap/imap_fetch.c +++ b/citadel/modules/imap/imap_fetch.c @@ -132,14 +132,14 @@ void imap_fetch_internaldate(struct CtdlMessage *msg) { * "RFC822.TEXT" body only (without leading blank line) */ void imap_fetch_rfc822(long msgnum, const char *whichfmt) { - citimap *Imap = IMAP; + CitContext *CCC = CC; + citimap *Imap = CCCIMAP; const char *ptr = NULL; size_t headers_size, text_size, total_size; size_t bytes_to_send = 0; struct MetaData smi; int need_to_rewrite_metadata = 0; int need_body = 0; - CitContext *CCC = CC; /* Determine whether this particular fetch operation requires * us to fetch the message body from disk. If not, we can save @@ -240,11 +240,11 @@ void imap_fetch_rfc822(long msgnum, const char *whichfmt) { text_size = 0; } - syslog(LOG_DEBUG, - "RFC822: headers=" SIZE_T_FMT - ", text=" SIZE_T_FMT - ", total=" SIZE_T_FMT, - headers_size, text_size, total_size); + IMAP_syslog(LOG_DEBUG, + "RFC822: headers=" SIZE_T_FMT + ", text=" SIZE_T_FMT + ", total=" SIZE_T_FMT, + headers_size, text_size, total_size); if (!strcasecmp(whichfmt, "RFC822.SIZE")) { IAPrintf("RFC822.SIZE " SIZE_T_FMT, total_size); @@ -284,14 +284,15 @@ void imap_load_part(char *name, char *filename, char *partnum, char *disp, void *content, char *cbtype, char *cbcharset, size_t length, char *encoding, char *cbid, void *cbuserdata) { + struct CitContext *CCC = CC; char mimebuf2[SIZ]; StrBuf *desired_section; desired_section = (StrBuf *)cbuserdata; - syslog(LOG_DEBUG, "imap_load_part() looking for %s, found %s", - ChrPtr(desired_section), - partnum - ); + IMAP_syslog(LOG_DEBUG, "imap_load_part() looking for %s, found %s", + ChrPtr(desired_section), + partnum + ); if (!strcasecmp(partnum, ChrPtr(desired_section))) { client_write(content, length); @@ -663,7 +664,7 @@ void imap_fetch_body(long msgnum, ConstStr item, int is_peek) { int need_body = 1; int burn_the_cache = 0; CitContext *CCC = CC; - citimap *Imap = IMAP; + citimap *Imap = CCCIMAP; /* extract section */ section = NewStrBufPlain(CKEY(item)); @@ -671,8 +672,8 @@ void imap_fetch_body(long msgnum, ConstStr item, int is_peek) { if (strchr(ChrPtr(section), '[') != NULL) { StrBufStripAllBut(section, '[', ']'); } - syslog(LOG_DEBUG, "Section is: [%s]", - (StrLength(section) == 0) ? "(empty)" : ChrPtr(section) + IMAP_syslog(LOG_DEBUG, "Section is: [%s]", + (StrLength(section) == 0) ? "(empty)" : ChrPtr(section) ); /* Burn the cache if we don't have the same section of the @@ -705,7 +706,7 @@ void imap_fetch_body(long msgnum, ConstStr item, int is_peek) { is_partial = 1; } if ( (is_partial == 1) && (StrLength(partial) > 0) ) { - syslog(LOG_DEBUG, "Partial is <%s>", ChrPtr(partial)); + IMAP_syslog(LOG_DEBUG, "Partial is <%s>", ChrPtr(partial)); } if (Imap->cached_body == NULL) { @@ -1133,18 +1134,18 @@ void imap_do_fetch(citimap_command *Cmd) { /* debug output the parsed vector */ { int i; - syslog(LOG_DEBUG, "----- %ld params", Cmd->num_parms); + IMAP_syslog(LOG_DEBUG, "----- %ld params", Cmd->num_parms); for (i=0; i < Cmd->num_parms; i++) { if (Cmd->Params[i].len != strlen(Cmd->Params[i].Key)) - syslog(LOG_DEBUG, "*********** %ld != %ld : %s", - Cmd->Params[i].len, - strlen(Cmd->Params[i].Key), - Cmd->Params[i].Key); + IMAP_syslog(LOG_DEBUG, "*********** %ld != %ld : %s", + Cmd->Params[i].len, + strlen(Cmd->Params[i].Key), + Cmd->Params[i].Key); else - syslog(LOG_DEBUG, "%ld : %s", - Cmd->Params[i].len, - Cmd->Params[i].Key); + IMAP_syslog(LOG_DEBUG, "%ld : %s", + Cmd->Params[i].len, + Cmd->Params[i].Key); }} #endif @@ -1465,7 +1466,7 @@ void imap_uidfetch(int num_parms, ConstStr *Params) { MakeStringOf(Cmd.CmdBuf, 4); #if 0 - syslog(LOG_DEBUG, "-------%s--------", ChrPtr(Cmd.CmdBuf)); + IMAP_syslog(LOG_DEBUG, "-------%s--------", ChrPtr(Cmd.CmdBuf)); #endif num_items = imap_extract_data_items(&Cmd); if (num_items < 1) { diff --git a/citadel/modules/imap/imap_list.c b/citadel/modules/imap/imap_list.c index 6dbbe6ebb..17e41062b 100644 --- a/citadel/modules/imap/imap_list.c +++ b/citadel/modules/imap/imap_list.c @@ -189,7 +189,8 @@ void imap_listroom(struct ctdlroom *qrbuf, void *data) */ void imap_list(int num_parms, ConstStr *Params) { - citimap *Imap = IMAP; + struct CitContext *CCC = CC; + citimap *Imap = CCCIMAP; int i, j, paren_nest; ImapRoomListFilter ImapFilter; int selection_left = (-1); @@ -376,7 +377,7 @@ void imap_list(int num_parms, ConstStr *Params) &Params[i], 1); - syslog(LOG_DEBUG, "evaluating <%s>", Params[i].Key); + IMAP_syslog(LOG_DEBUG, "evaluating <%s>", Params[i].Key); if (!strcasecmp(Params[i].Key, "SUBSCRIBED")) { ImapFilter.return_subscribed = 1; diff --git a/citadel/modules/imap/imap_misc.c b/citadel/modules/imap/imap_misc.c index 3ccd46367..e7b3d69fe 100644 --- a/citadel/modules/imap/imap_misc.c +++ b/citadel/modules/imap/imap_misc.c @@ -280,6 +280,7 @@ void imap_do_append_flags(long new_msgnum, char *new_message_flags) { * This function is called by the main command loop. */ void imap_append(int num_parms, ConstStr *Params) { + struct CitContext *CCC = CC; long literal_length; struct CtdlMessage *msg = NULL; long new_msgnum = (-1L); @@ -353,10 +354,10 @@ void imap_append(int num_parms, ConstStr *Params) { client_getln(dummy, sizeof dummy); /* Convert RFC822 newlines (CRLF) to Unix newlines (LF) */ - syslog(LOG_DEBUG, "Converting CRLF to LF"); + IMAPM_syslog(LOG_DEBUG, "Converting CRLF to LF"); StrBufToUnixLF(Imap->TransmittedMessage); - syslog(LOG_DEBUG, "Converting message format"); + IMAPM_syslog(LOG_DEBUG, "Converting message format"); msg = convert_internet_message_buf(&Imap->TransmittedMessage); ret = imap_grabroom(roomname, Params[2].Key, 1); diff --git a/citadel/modules/imap/imap_tools.c b/citadel/modules/imap/imap_tools.c index 67cd1bcc5..d1c5d9580 100644 --- a/citadel/modules/imap/imap_tools.c +++ b/citadel/modules/imap/imap_tools.c @@ -225,7 +225,7 @@ static char* toimap(char* destp, char* destend, char* src) *destp = 0; string_init(&dest, destp, destend-destp); - /* syslog(LOG_DEBUG, "toimap %s", src); */ + /* IMAP_syslog(LOG_DEBUG, "toimap %s", src); */ for (;;) { @@ -291,7 +291,7 @@ static char* toimap(char* destp, char* destend, char* src) if (state == 1) utf7_closeb64(&dest, v, i); - /* syslog(LOG_DEBUG, " -> %s", destp); */ + /* IMAP_syslog(LOG_DEBUG, " -> %s", destp); */ return string_end(&dest); } @@ -309,7 +309,7 @@ static char* fromimap(char* destp, char* destend, const char* src) *destp = 0; string_init(&dest, destp, destend-destp); - /* syslog(LOG_DEBUG, "fromimap %s", src); */ + /* IMAP_syslog(LOG_DEBUG, "fromimap %s", src); */ do { c = *p++; @@ -367,7 +367,7 @@ static char* fromimap(char* destp, char* destend, const char* src) } } while (c != '\0'); - /* syslog(LOG_DEBUG, " -> %s", destp); */ + /* IMAP_syslog(LOG_DEBUG, " -> %s", destp); */ return string_end(&dest); } @@ -604,6 +604,7 @@ void imap_mailboxname(char *buf, int bufsize, struct ctdlroom *qrbuf) int imap_roomname(char *rbuf, int bufsize, const char *foldername) { + struct CitContext *CCC = CC; int levels; char floorname[ROOMNAMELEN*2]; char roomname[ROOMNAMELEN]; @@ -680,7 +681,7 @@ int imap_roomname(char *rbuf, int bufsize, const char *foldername) ret = (0 | IR_MAILBOX); exit: - syslog(LOG_DEBUG, "(That translates to \"%s\")", rbuf); + IMAP_syslog(LOG_DEBUG, "(That translates to \"%s\")", rbuf); return(ret); } diff --git a/citadel/modules/imap/serv_imap.c b/citadel/modules/imap/serv_imap.c index eca14eb05..46a6ba7d9 100644 --- a/citadel/modules/imap/serv_imap.c +++ b/citadel/modules/imap/serv_imap.c @@ -69,7 +69,7 @@ #include "imap_misc.h" #include "ctdl_module.h" - +int IMAPDebugEnabled = 0; HashList *ImapCmds = NULL; void registerImapCMD(const char *First, long FLen, const char *Second, long SLen, @@ -102,8 +102,9 @@ void imap_cleanup(void) const imap_handler_hook *imap_lookup(int num_parms, ConstStr *Params) { + struct CitContext *CCC = CC; void *v; - citimap *Imap = IMAP; + citimap *Imap = CCCIMAP; if (num_parms < 1) return NULL; @@ -112,33 +113,33 @@ const imap_handler_hook *imap_lookup(int num_parms, ConstStr *Params) StrBufPlain(Imap->Reply, CKEY(Params[1])); StrBufUpCase(Imap->Reply); - syslog(LOG_DEBUG, "---- Looking up [%s] -----", + IMAP_syslog(LOG_DEBUG, "---- Looking up [%s] -----", ChrPtr(Imap->Reply)); if (GetHash(ImapCmds, SKEY(Imap->Reply), &v)) { - syslog(LOG_DEBUG, "Found."); + IMAPM_syslog(LOG_DEBUG, "Found."); FlushStrBuf(Imap->Reply); return (imap_handler_hook *) v; } if (num_parms == 1) { - syslog(LOG_DEBUG, "NOT Found."); + IMAPM_syslog(LOG_DEBUG, "NOT Found."); FlushStrBuf(Imap->Reply); return NULL; } - syslog(LOG_DEBUG, "---- Looking up [%s] -----", + IMAP_syslog(LOG_DEBUG, "---- Looking up [%s] -----", ChrPtr(Imap->Reply)); StrBufAppendBufPlain(Imap->Reply, CKEY(Params[2]), 0); StrBufUpCase(Imap->Reply); if (GetHash(ImapCmds, SKEY(Imap->Reply), &v)) { - syslog(LOG_DEBUG, "Found."); + IMAPM_syslog(LOG_DEBUG, "Found."); FlushStrBuf(Imap->Reply); return (imap_handler_hook *) v; } - syslog(LOG_DEBUG, "NOT Found."); + IMAPM_syslog(LOG_DEBUG, "NOT Found."); FlushStrBuf(Imap->Reply); return NULL; } @@ -305,11 +306,12 @@ void imap_add_single_msgid(long msgnum, void *userdata) */ void imap_load_msgids(void) { + struct CitContext *CCC = CC; struct cdbdata *cdbfr; - citimap *Imap = IMAP; + citimap *Imap = CCCIMAP; if (Imap->selected == 0) { - syslog(LOG_ERR, "imap_load_msgids() can't run; no room selected"); + IMAPM_syslog(LOG_ERR, "imap_load_msgids() can't run; no room selected"); return; } @@ -339,7 +341,8 @@ void imap_load_msgids(void) */ void imap_rescan_msgids(void) { - citimap *Imap = IMAP; + struct CitContext *CCC = CC; + citimap *Imap = CCCIMAP; int original_num_msgs = 0; long original_highest = 0L; int i, j, jstart; @@ -350,7 +353,7 @@ void imap_rescan_msgids(void) int num_recent = 0; if (Imap->selected == 0) { - syslog(LOG_ERR, "imap_load_msgids() can't run; no room selected"); + IMAPM_syslog(LOG_ERR, "imap_load_msgids() can't run; no room selected"); return; } @@ -370,7 +373,7 @@ void imap_rescan_msgids(void) if (cdbfr != NULL) { msglist = malloc(cdbfr->len + 1); if (msglist == NULL) { - syslog(LOG_CRIT, "IMAP: malloc() failed"); + IMAPM_syslog(LOG_CRIT, "malloc() failed"); CC->kill_me = KILLME_MALLOC_FAILED; return; } @@ -475,7 +478,8 @@ void imap_rescan_msgids(void) */ void imap_cleanup_function(void) { - citimap *Imap = IMAP; + struct CitContext *CCC = CC; + citimap *Imap = CCCIMAP; /* Don't do this stuff if this is not a Imap session! */ if (CC->h_command_function != imap_command_loop) @@ -486,7 +490,7 @@ void imap_cleanup_function(void) imap_do_expunge(); } - syslog(LOG_DEBUG, "Performing IMAP cleanup hook"); + IMAPM_syslog(LOG_DEBUG, "Performing IMAP cleanup hook"); imap_free_msgids(); imap_free_transmitted_message(); @@ -506,7 +510,7 @@ void imap_cleanup_function(void) FreeStrBuf(&Imap->Reply); if (Imap->Cmd.Params != NULL) free(Imap->Cmd.Params); free(Imap); - syslog(LOG_DEBUG, "Finished IMAP cleanup hook"); + IMAPM_syslog(LOG_DEBUG, "Finished IMAP cleanup hook"); } @@ -911,13 +915,14 @@ void imap_select(int num_parms, ConstStr *Params) */ int imap_do_expunge(void) { - citimap *Imap = IMAP; + struct CitContext *CCC = CC; + citimap *Imap = CCCIMAP; int i; int num_expunged = 0; long *delmsgs = NULL; int num_delmsgs = 0; - syslog(LOG_DEBUG, "imap_do_expunge() called"); + IMAPM_syslog(LOG_DEBUG, "imap_do_expunge() called"); if (Imap->selected == 0) { return (0); } @@ -940,7 +945,7 @@ int imap_do_expunge(void) imap_rescan_msgids(); } - syslog(LOG_DEBUG, "Expunged %d messages from <%s>", num_expunged, CC->room.QRname); + IMAP_syslog(LOG_DEBUG, "Expunged %d messages from <%s>", num_expunged, CC->room.QRname); return (num_expunged); } @@ -1020,6 +1025,7 @@ void imap_namespace(int num_parms, ConstStr *Params) */ void imap_create(int num_parms, ConstStr *Params) { + struct CitContext *CCC = CC; int ret; char roomname[ROOMNAMELEN]; int floornum; @@ -1035,14 +1041,14 @@ void imap_create(int num_parms, ConstStr *Params) if (strchr(Params[2].Key, '\\') != NULL) { IReply("NO Invalid character in folder name"); - syslog(LOG_DEBUG, "invalid character in folder name"); + IMAPM_syslog(LOG_ERR, "invalid character in folder name"); return; } ret = imap_roomname(roomname, sizeof roomname, Params[2].Key); if (ret < 0) { IReply("NO Invalid mailbox name or location"); - syslog(LOG_DEBUG, "invalid mailbox name or location"); + IMAPM_syslog(LOG_ERR, "invalid mailbox name or location"); return; } floornum = (ret & 0x00ff); /* lower 8 bits = floor number */ @@ -1051,7 +1057,7 @@ void imap_create(int num_parms, ConstStr *Params) if (flags & IR_MAILBOX) { if (strncasecmp(Params[2].Key, "INBOX/", 6)) { IReply("NO Personal folders must be created under INBOX"); - syslog(LOG_DEBUG, "not subordinate to inbox"); + IMAPM_syslog(LOG_ERR, "not subordinate to inbox"); return; } } @@ -1064,8 +1070,8 @@ void imap_create(int num_parms, ConstStr *Params) newroomview = VIEW_BBS; } - syslog(LOG_INFO, "IMAP: Create new room <%s> on floor <%d> with type <%d>", - roomname, floornum, newroomtype); + IMAP_syslog(LOG_INFO, "Create new room <%s> on floor <%d> with type <%d>", + roomname, floornum, newroomtype); ret = CtdlCreateRoom(roomname, newroomtype, "", floornum, 1, 0, newroomview); if (ret == 0) { @@ -1086,7 +1092,7 @@ void imap_create(int num_parms, ConstStr *Params) CtdlAideMessage(notification_message, "Room Creation Message"); free(notification_message); } - syslog(LOG_DEBUG, "imap_create() completed"); + IMAPM_syslog(LOG_DEBUG, "imap_create() completed"); } @@ -1450,8 +1456,9 @@ void imap_rename(int num_parms, ConstStr *Params) irl->irl_newroom, irl->irl_newfloor); if (r != crr_ok) { + struct CitContext *CCC = CC; /* FIXME handle error returns better */ - syslog(LOG_ERR, "IMAP: CtdlRenameRoom() error %d", r); + IMAP_syslog(LOG_ERR, "CtdlRenameRoom() error %d", r); } irlp = irl; irl = irl->next; @@ -1475,6 +1482,7 @@ void imap_rename(int num_parms, ConstStr *Params) */ void imap_command_loop(void) { + struct CitContext *CCC = CC; struct timeval tv1, tv2; suseconds_t total_time = 0; citimap *Imap; @@ -1482,8 +1490,8 @@ void imap_command_loop(void) const imap_handler_hook *h; gettimeofday(&tv1, NULL); - CC->lastcmd = time(NULL); - Imap = IMAP; + CCC->lastcmd = time(NULL); + Imap = CCCIMAP; flush_output(); if (Imap->Cmd.CmdBuf == NULL) @@ -1492,23 +1500,23 @@ void imap_command_loop(void) FlushStrBuf(Imap->Cmd.CmdBuf); if (CtdlClientGetLine(Imap->Cmd.CmdBuf) < 1) { - syslog(LOG_ERR, "IMAP: client disconnected: ending session."); + IMAPM_syslog(LOG_ERR, "client disconnected: ending session."); CC->kill_me = KILLME_CLIENT_DISCONNECTED; return; } if (Imap->authstate == imap_as_expecting_password) { - syslog(LOG_INFO, "IMAP: "); + IMAPM_syslog(LOG_INFO, ""); } else if (Imap->authstate == imap_as_expecting_plainauth) { - syslog(LOG_INFO, "IMAP: "); + IMAPM_syslog(LOG_INFO, ""); } else if ((Imap->authstate == imap_as_expecting_multilineusername) || cbmstrcasestr(ChrPtr(Imap->Cmd.CmdBuf), " LOGIN ")) { - syslog(LOG_INFO, "IMAP: LOGIN..."); + IMAPM_syslog(LOG_INFO, "LOGIN..."); } else { - syslog(LOG_INFO, "IMAP: %s", ChrPtr(Imap->Cmd.CmdBuf)); + IMAP_syslog(LOG_DEBUG, "%s", ChrPtr(Imap->Cmd.CmdBuf)); } pchs = ChrPtr(Imap->Cmd.CmdBuf); @@ -1560,18 +1568,18 @@ void imap_command_loop(void) /* debug output the parsed vector */ { int i; - syslog(LOG_DEBUG, "----- %ld params", Imap->Cmd.num_parms); + IMAP_syslog(LOG_DEBUG, "----- %ld params", Imap->Cmd.num_parms); for (i=0; i < Imap->Cmd.num_parms; i++) { if (Imap->Cmd.Params[i].len != strlen(Imap->Cmd.Params[i].Key)) - syslog(LOG_DEBUG, "*********** %ld != %ld : %s", - Imap->Cmd.Params[i].len, - strlen(Imap->Cmd.Params[i].Key), + IMAP_syslog(LOG_DEBUG, "*********** %ld != %ld : %s", + Imap->Cmd.Params[i].len, + strlen(Imap->Cmd.Params[i].Key), Imap->Cmd.Params[i].Key); else - syslog(LOG_DEBUG, "%ld : %s", - Imap->Cmd.Params[i].len, - Imap->Cmd.Params[i].Key); + IMAP_syslog(LOG_DEBUG, "%ld : %s", + Imap->Cmd.Params[i].len, + Imap->Cmd.Params[i].Key); }} #endif @@ -1622,10 +1630,10 @@ BAIL: gettimeofday(&tv2, NULL); total_time = (tv2.tv_usec + (tv2.tv_sec * 1000000)) - (tv1.tv_usec + (tv1.tv_sec * 1000000)); - syslog(LOG_DEBUG, "IMAP command completed in %ld.%ld seconds", - (total_time / 1000000), - (total_time % 1000000) - ); + IMAP_syslog(LOG_DEBUG, "IMAP command completed in %ld.%ld seconds", + (total_time / 1000000), + (total_time % 1000000) + ); } void imap_noop (int num_parms, ConstStr *Params) @@ -1647,7 +1655,10 @@ void imap_logout(int num_parms, ConstStr *Params) const char *CitadelServiceIMAP="IMAP"; const char *CitadelServiceIMAPS="IMAPS"; - +void SetIMAPDebugEnabled(const int n) +{ + IMAPDebugEnabled = n; +} /* * This function is called to register the IMAP extension with Citadel. */ @@ -1703,6 +1714,7 @@ CTDL_MODULE_INIT(imap) if (!threading) { + CtdlRegisterDebugFlagHook(HKEY("imapsrv"), SetIMAPDebugEnabled, &IMAPDebugEnabled); CtdlRegisterServiceHook(config.c_imap_port, NULL, imap_greeting, imap_command_loop, NULL, CitadelServiceIMAP); #ifdef HAVE_OPENSSL diff --git a/citadel/modules/imap/serv_imap.h b/citadel/modules/imap/serv_imap.h index 8113f675b..371dbeb2e 100644 --- a/citadel/modules/imap/serv_imap.h +++ b/citadel/modules/imap/serv_imap.h @@ -101,8 +101,22 @@ enum { #define FDELIM '\\' +extern int IMAPDebugEnabled; #define IMAP ((citimap *)CC->session_specific_data) +#define CCCIMAP ((citimap *)CCC->session_specific_data) + +#define IMAPDBGLOG(LEVEL) if ((LEVEL != LOG_DEBUG) || (IMAPDebugEnabled != 0)) +#define CCCID CCC->cs_pid +#define IMAP_syslog(LEVEL, FORMAT, ...) \ + IMAPDBGLOG(LEVEL) syslog(LEVEL, \ + "IMAPCC[%d] " FORMAT, \ + CCCID, __VA_ARGS__) + +#define IMAPM_syslog(LEVEL, FORMAT) \ + IMAPDBGLOG(LEVEL) syslog(LEVEL, \ + "IMAPCC[%d] " FORMAT, \ + CCCID) #define I_FLAG_NONE (0) #define I_FLAG_LOGGED_IN (1<<0) -- 2.30.2