From 4c7e6afb5ee568a8ae33f71d6079dcbc49c5f875 Mon Sep 17 00:00:00 2001 From: Wilfried Goesgens Date: Sun, 24 Jun 2012 12:31:24 +0200 Subject: [PATCH] NetQueue: make logging runtime configurable; add context. --- citadel/modules/network/serv_netmail.c | 75 +++++++++++++------------ citadel/modules/network/serv_netspool.c | 62 ++++++++++---------- citadel/modules/network/serv_network.c | 42 +++++++++----- citadel/modules/network/serv_network.h | 31 ++++++++++ 4 files changed, 133 insertions(+), 77 deletions(-) diff --git a/citadel/modules/network/serv_netmail.c b/citadel/modules/network/serv_netmail.c index 5b2a02524..4270009fa 100644 --- a/citadel/modules/network/serv_netmail.c +++ b/citadel/modules/network/serv_netmail.c @@ -97,6 +97,7 @@ * Deliver digest messages */ void network_deliver_digest(SpoolControl *sc) { + struct CitContext *CCC = CC; char buf[SIZ]; int i; struct CtdlMessage *msg = NULL; @@ -167,9 +168,9 @@ void network_deliver_digest(SpoolControl *sc) { recps = malloc(recps_len); if (recps == NULL) { - syslog(LOG_EMERG, - "Cannot allocate %ld bytes for recps...\n", - (long)recps_len); + QN_syslog(LOG_EMERG, + "Cannot allocate %ld bytes for recps...\n", + (long)recps_len); abort(); } @@ -203,7 +204,9 @@ void network_deliver_digest(SpoolControl *sc) { /* * Deliver list messages to everyone on the list ... efficiently */ -void network_deliver_list(struct CtdlMessage *msg, SpoolControl *sc, const char *RoomName) { +void network_deliver_list(struct CtdlMessage *msg, SpoolControl *sc, const char *RoomName) +{ + struct CitContext *CCC = CC; char *recps = NULL; size_t recps_len = SIZ; struct recptypes *valid; @@ -225,9 +228,9 @@ void network_deliver_list(struct CtdlMessage *msg, SpoolControl *sc, const char recps = malloc(recps_len); if (recps == NULL) { - syslog(LOG_EMERG, - "Cannot allocate %ld bytes for recps...\n", - (long)recps_len); + QN_syslog(LOG_EMERG, + "Cannot allocate %ld bytes for recps...\n", + (long)recps_len); abort(); } @@ -265,6 +268,7 @@ void network_deliver_list(struct CtdlMessage *msg, SpoolControl *sc, const char void network_spool_msg(long msgnum, void *userdata) { + struct CitContext *CCC = CC; StrBuf *Buf = NULL; SpoolControl *sc; int i; @@ -574,34 +578,35 @@ void network_spool_msg(long msgnum, sc->working_ignetcfg, sc->the_netmap) != 0) { - syslog(LOG_ERR, - "Invalid node <%s>\n", - mptr->remote_nodename); + QN_syslog(LOG_ERR, + "Invalid node <%s>\n", + mptr->remote_nodename); send = 0; } /* Check for split horizon */ - syslog(LOG_DEBUG, "Path is %s\n", msg->cm_fields['P']); + QN_syslog(LOG_DEBUG, "Path is %s\n", msg->cm_fields['P']); bang = num_tokens(msg->cm_fields['P'], '!'); - if (bang > 1) for (i=0; i<(bang-1); ++i) { - extract_token(buf, - msg->cm_fields['P'], - i, '!', - sizeof buf); - - syslog(LOG_DEBUG, "Compare <%s> to <%s>\n", - buf, mptr->remote_nodename) ; - if (!strcasecmp(buf, mptr->remote_nodename)) { - send = 0; - syslog(LOG_DEBUG, "Not sending to %s\n", - mptr->remote_nodename); - } - else { - syslog(LOG_DEBUG, - "Sending to %s\n", - mptr->remote_nodename); + if (bang > 1) { + for (i=0; i<(bang-1); ++i) { + extract_token(buf, + msg->cm_fields['P'], + i, '!', + sizeof buf); + + QN_syslog(LOG_DEBUG, "Compare <%s> to <%s>\n", + buf, mptr->remote_nodename) ; + if (!strcasecmp(buf, mptr->remote_nodename)) { + send = 0; + break; + } } + + QN_syslog(LOG_INFO, + "%sSending to %s\n", + (send)?"":"Not ", + mptr->remote_nodename); } /* Send the message */ @@ -638,9 +643,9 @@ void network_spool_msg(long msgnum, rand() ); - syslog(LOG_DEBUG, - "Appending to %s\n", - filename); + QN_syslog(LOG_DEBUG, + "Appending to %s\n", + filename); fp = fopen(filename, "ab"); if (fp != NULL) { @@ -649,10 +654,10 @@ void network_spool_msg(long msgnum, fclose(fp); } else { - syslog(LOG_ERR, - "%s: %s\n", - filename, - strerror(errno)); + QN_syslog(LOG_ERR, + "%s: %s\n", + filename, + strerror(errno)); } /* free the serialized version */ diff --git a/citadel/modules/network/serv_netspool.c b/citadel/modules/network/serv_netspool.c index 6c2acb162..944fe4b6d 100644 --- a/citadel/modules/network/serv_netspool.c +++ b/citadel/modules/network/serv_netspool.c @@ -424,6 +424,7 @@ void network_spoolout_room(RoomProcList *room_to_spool, */ void network_process_buffer(char *buffer, long size, HashList *working_ignetcfg, HashList *the_netmap, int *netmap_changed) { + struct CitContext *CCC = CC; StrBuf *Buf = NULL; struct CtdlMessage *msg = NULL; long pos; @@ -438,14 +439,14 @@ void network_process_buffer(char *buffer, long size, HashList *working_ignetcfg, unsigned char firstbyte; unsigned char lastbyte; - syslog(LOG_DEBUG, "network_process_buffer() processing %ld bytes\n", size); + QN_syslog(LOG_DEBUG, "network_process_buffer() processing %ld bytes\n", size); /* Validate just a little bit. First byte should be FF and * last byte should be 00. */ firstbyte = buffer[0]; lastbyte = buffer[size-1]; if ( (firstbyte != 255) || (lastbyte != 0) ) { - syslog(LOG_ERR, "Corrupt message ignored. Length=%ld, firstbyte = %d, lastbyte = %d\n", - size, firstbyte, lastbyte); + QN_syslog(LOG_ERR, "Corrupt message ignored. Length=%ld, firstbyte = %d, lastbyte = %d\n", + size, firstbyte, lastbyte); return; } @@ -506,14 +507,14 @@ void network_process_buffer(char *buffer, long size, HashList *working_ignetcfg, time(NULL), rand() ); - syslog(LOG_DEBUG, "Appending to %s\n", filename); + QN_syslog(LOG_DEBUG, "Appending to %s\n", filename); fp = fopen(filename, "ab"); if (fp != NULL) { fwrite(sermsg.ser, sermsg.len, 1, fp); fclose(fp); } else { - syslog(LOG_ERR, "%s: %s\n", filename, strerror(errno)); + QN_syslog(LOG_ERR, "%s: %s\n", filename, strerror(errno)); } free(sermsg.ser); CtdlFreeMessage(msg); @@ -569,7 +570,7 @@ void network_process_buffer(char *buffer, long size, HashList *working_ignetcfg, "Please check the address and try sending the message again.\n"); msg = NULL; free_recipients(recp); - syslog(LOG_DEBUG, "Bouncing message due to invalid recipient address.\n"); + QNM_syslog(LOG_DEBUG, "Bouncing message due to invalid recipient address.\n"); return; } strcpy(target_room, ""); /* no target room if mail */ @@ -643,6 +644,7 @@ void network_process_file(char *filename, HashList *the_netmap, int *netmap_changed) { + struct CitContext *CCC = CC; FILE *fp; long msgstart = (-1L); long msgend = (-1L); @@ -652,12 +654,12 @@ void network_process_file(char *filename, fp = fopen(filename, "rb"); if (fp == NULL) { - syslog(LOG_CRIT, "Error opening %s: %s\n", filename, strerror(errno)); + QN_syslog(LOG_CRIT, "Error opening %s: %s\n", filename, strerror(errno)); return; } fseek(fp, 0L, SEEK_END); - syslog(LOG_INFO, "network: processing %ld bytes from %s\n", ftell(fp), filename); + QN_syslog(LOG_INFO, "network: processing %ld bytes from %s\n", ftell(fp), filename); rewind(fp); /* Look for messages in the data stream and break them out */ @@ -699,6 +701,7 @@ void network_process_file(char *filename, */ void network_do_spoolin(HashList *working_ignetcfg, HashList *the_netmap, int *netmap_changed) { + struct CitContext *CCC = CC; DIR *dp; struct dirent *d; struct stat statbuf; @@ -711,11 +714,11 @@ void network_do_spoolin(HashList *working_ignetcfg, HashList *the_netmap, int *n */ if (stat(ctdl_netin_dir, &statbuf)) return; if (statbuf.st_mtime == last_spoolin_mtime) { - syslog(LOG_DEBUG, "network: nothing in inbound queue\n"); + QNM_syslog(LOG_DEBUG, "network: nothing in inbound queue\n"); return; } last_spoolin_mtime = statbuf.st_mtime; - syslog(LOG_DEBUG, "network: processing inbound queue\n"); + QNM_syslog(LOG_DEBUG, "network: processing inbound queue\n"); /* * Ok, there's something interesting in there, so scan it. @@ -747,6 +750,7 @@ void network_do_spoolin(HashList *working_ignetcfg, HashList *the_netmap, int *n */ void network_consolidate_spoolout(HashList *working_ignetcfg, HashList *the_netmap) { + struct CitContext *CCC = CC; IOBuffer IOB; FDIOBuffer FDIO; int d_namelen; @@ -826,12 +830,12 @@ void network_consolidate_spoolout(HashList *working_ignetcfg, HashList *the_netm ctdl_netout_dir, ChrPtr(NextHop)); - syslog(LOG_DEBUG, "Consolidate %s to %s\n", filename, ChrPtr(NextHop)); + QN_syslog(LOG_DEBUG, "Consolidate %s to %s\n", filename, ChrPtr(NextHop)); if (network_talking_to(SKEY(NextHop), NTT_CHECK)) { nFailed++; - syslog(LOG_DEBUG, - "Currently online with %s - skipping for now\n", - ChrPtr(NextHop) + QN_syslog(LOG_DEBUG, + "Currently online with %s - skipping for now\n", + ChrPtr(NextHop) ); } else { @@ -844,10 +848,10 @@ void network_consolidate_spoolout(HashList *working_ignetcfg, HashList *the_netm IOB.fd = open(filename, O_RDONLY); if (IOB.fd == -1) { nFailed++; - syslog(LOG_ERR, - "failed to open %s for reading due to %s; skipping.\n", - filename, strerror(errno) - ); + QN_syslog(LOG_ERR, + "failed to open %s for reading due to %s; skipping.\n", + filename, strerror(errno) + ); network_talking_to(SKEY(NextHop), NTT_REMOVE); continue; } @@ -863,10 +867,10 @@ void network_consolidate_spoolout(HashList *working_ignetcfg, HashList *the_netm } if (fd == -1) { nFailed++; - syslog(LOG_ERR, - "failed to open %s for reading due to %s; skipping.\n", - spooloutfilename, strerror(errno) - ); + QN_syslog(LOG_ERR, + "failed to open %s for reading due to %s; skipping.\n", + spooloutfilename, strerror(errno) + ); close(IOB.fd); network_talking_to(SKEY(NextHop), NTT_REMOVE); continue; @@ -884,10 +888,10 @@ void network_consolidate_spoolout(HashList *working_ignetcfg, HashList *the_netm } else { nFailed++; - syslog(LOG_ERR, - "failed to append to %s [%s]; rolling back..\n", - spooloutfilename, strerror(errno) - ); + QN_syslog(LOG_ERR, + "failed to append to %s [%s]; rolling back..\n", + spooloutfilename, strerror(errno) + ); /* whoops partial append?? truncate spooloutfilename again! */ ftruncate(fd, dsize); } @@ -901,9 +905,9 @@ void network_consolidate_spoolout(HashList *working_ignetcfg, HashList *the_netm if (nFailed > 0) { FreeStrBuf(&NextHop); - syslog(LOG_INFO, - "skipping Spoolcleanup because of %d files unprocessed.\n", - nFailed + QN_syslog(LOG_INFO, + "skipping Spoolcleanup because of %d files unprocessed.\n", + nFailed ); return; diff --git a/citadel/modules/network/serv_network.c b/citadel/modules/network/serv_network.c index 730c0452f..5dbb75f15 100644 --- a/citadel/modules/network/serv_network.c +++ b/citadel/modules/network/serv_network.c @@ -92,6 +92,9 @@ #include "netmail.h" #include "ctdl_module.h" +int NetQDebugEnabled = 0; +struct CitContext networker_spool_CC; + /* comes from lookup3.c from libcitadel... */ extern uint32_t hashlittle( const void *key, size_t length, uint32_t initval); @@ -147,8 +150,9 @@ int GetNetworkedRoomNumbers(const char *DirName, HashList *DirList) * message from being entered into the database multiple times if it happens * to arrive multiple times by accident. */ -int network_usetable(struct CtdlMessage *msg) { - +int network_usetable(struct CtdlMessage *msg) +{ + struct CitContext *CCC = CC; char msgid[SIZ]; struct cdbdata *cdbut; struct UseTable ut; @@ -179,7 +183,7 @@ int network_usetable(struct CtdlMessage *msg) { cdbut = cdb_fetch(CDB_USETABLE, msgid, strlen(msgid)); if (cdbut != NULL) { cdb_free(cdbut); - syslog(LOG_DEBUG, "network_usetable() : we already have %s\n", msgid); + QN_syslog(LOG_DEBUG, "network_usetable() : we already have %s\n", msgid); return(1); } @@ -206,6 +210,7 @@ int network_usetable(struct CtdlMessage *msg) { */ int network_sync_to(char *target_node, long len) { + struct CitContext *CCC = CC; SpoolControl sc; int num_spooled = 0; int found_node = 0; @@ -269,8 +274,8 @@ int network_sync_to(char *target_node, long len) DeleteHash(&sc.working_ignetcfg); DeleteHash(&sc.the_netmap); - syslog(LOG_NOTICE, "Synchronized %d messages to <%s>\n", - num_spooled, target_node); + QN_syslog(LOG_NOTICE, "Synchronized %d messages to <%s>\n", + num_spooled, target_node); return(num_spooled); } @@ -391,7 +396,9 @@ void destroy_network_queue_room_locked (void) /* * Bounce a message back to the sender */ -void network_bounce(struct CtdlMessage *msg, char *reason) { +void network_bounce(struct CtdlMessage *msg, char *reason) +{ + struct CitContext *CCC = CC; char *oldpath = NULL; char buf[SIZ]; char bouncesource[SIZ]; @@ -401,7 +408,7 @@ void network_bounce(struct CtdlMessage *msg, char *reason) { static int serialnum = 0; size_t size; - syslog(LOG_DEBUG, "entering network_bounce()\n"); + QNM_syslog(LOG_DEBUG, "entering network_bounce()\n"); if (msg == NULL) return; @@ -490,7 +497,7 @@ void network_bounce(struct CtdlMessage *msg, char *reason) { /* Clean up */ if (valid != NULL) free_recipients(valid); CtdlFreeMessage(msg); - syslog(LOG_DEBUG, "leaving network_bounce()\n"); + QNM_syslog(LOG_DEBUG, "leaving network_bounce()\n"); } @@ -504,7 +511,9 @@ void network_bounce(struct CtdlMessage *msg, char *reason) { * * Run through the rooms doing various types of network stuff. */ -void network_do_queue(void) { +void network_do_queue(void) +{ + struct CitContext *CCC = CC; static int doing_queue = 0; static time_t last_run = 0L; int full_processing = 1; @@ -520,7 +529,7 @@ void network_do_queue(void) { if ( (time(NULL) - last_run) < config.c_net_freq ) { full_processing = 0; syslog(LOG_DEBUG, "Network full processing in %ld seconds.\n", - config.c_net_freq - (time(NULL)- last_run) + config.c_net_freq - (time(NULL)- last_run) ); } @@ -535,6 +544,7 @@ void network_do_queue(void) { } doing_queue = 1; + become_session(&networker_spool_CC); begin_critical_section(S_RPLIST); RL.rplist = rplist; rplist = NULL; @@ -564,14 +574,14 @@ void network_do_queue(void) { * Go ahead and run the queue */ if (full_processing && !server_shutting_down) { - syslog(LOG_DEBUG, "network: loading outbound queue\n"); + QNM_syslog(LOG_DEBUG, "network: loading outbound queue"); CtdlForEachRoom(network_queue_interesting_rooms, &RL); } if ((RL.rplist != NULL) && (!server_shutting_down)) { RoomProcList *ptr, *cmp; ptr = RL.rplist; - syslog(LOG_DEBUG, "network: running outbound queue\n"); + QNM_syslog(LOG_DEBUG, "network: running outbound queue"); while (ptr != NULL && !server_shutting_down) { cmp = ptr->next; @@ -621,7 +631,7 @@ void network_do_queue(void) { DeleteHash(&working_ignetcfg); - syslog(LOG_DEBUG, "network: queue run completed\n"); + QNM_syslog(LOG_DEBUG, "network: queue run completed"); if (full_processing) { last_run = time(NULL); @@ -727,12 +737,18 @@ void SetNTTDebugEnabled(const int n) { NTTDebugEnabled = n; } +void SetNetQDebugEnabled(const int n) +{ + NetQDebugEnabled = n; +} CTDL_MODULE_INIT(network) { if (!threading) { + CtdlFillSystemContext(&networker_spool_CC, "CitNetSpool"); CtdlRegisterDebugFlagHook(HKEY("networktalkingto"), SetNTTDebugEnabled, &NTTDebugEnabled); + CtdlRegisterDebugFlagHook(HKEY("networkqueue"), SetNetQDebugEnabled, &NetQDebugEnabled); CtdlRegisterCleanupHook(cleanup_nttlist); CtdlRegisterSessionHook(network_cleanup_function, EVT_STOP, PRIO_STOP + 30); CtdlRegisterSessionHook(network_logout_hook, EVT_LOGOUT, PRIO_LOGOUT + 10); diff --git a/citadel/modules/network/serv_network.h b/citadel/modules/network/serv_network.h index d0cba74ef..c11a7f891 100644 --- a/citadel/modules/network/serv_network.h +++ b/citadel/modules/network/serv_network.h @@ -1,3 +1,34 @@ +/* + * Copyright (c) 2000-2012 by the citadel.org team + * + * This program is open source software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA + */ + +extern int NetQDebugEnabled; + +#define DBGLOG(LEVEL) if ((LEVEL != LOG_DEBUG) || (NetQDebugEnabled != 0)) + +#define QN_syslog(LEVEL, FORMAT, ...) \ + DBGLOG(LEVEL) syslog(LEVEL, \ + "CC[%d]" FORMAT, \ + CCC->cs_pid, __VA_ARGS__) + +#define QNM_syslog(LEVEL, FORMAT) \ + DBGLOG(LEVEL) syslog(LEVEL, \ + "CC[%d]" FORMAT, \ + CCC->cs_pid) typedef struct namelist namelist; -- 2.30.2