Logging: add commands to runtime view/enable/disable logging
[citadel.git] / citadel / modules / network / serv_networkclient.c
index 190121a9867f9269406b40bbf91652b7f82b740d..1a027ea2384e8ed481398cec9f6104e895118c6b 100644 (file)
@@ -91,22 +91,26 @@ struct CitContext networker_client_CC;
 #define NODE ChrPtr(((AsyncNetworker*)IO->Data)->node)
 #define N ((AsyncNetworker*)IO->Data)->n
 
+int NetworkClientDebugEnabled = 0;
+
+#define DBGLOG(LEVEL) if ((LEVEL != LOG_DEBUG) || (NetworkClientDebugEnabled != 0))
+
 #define EVN_syslog(LEVEL, FORMAT, ...) \
-       syslog(LEVEL, \
+       DBGLOG(LEVEL) syslog(LEVEL, \
               "IO[%ld]CC[%d]NW[%s][%ld]" FORMAT, \
               IO->ID, CCID, NODE, N, __VA_ARGS__)
 
 #define EVNM_syslog(LEVEL, FORMAT) \
-       syslog(LEVEL, \
+       DBGLOG(LEVEL) syslog(LEVEL, \
               "IO[%ld]CC[%d]NW[%s][%ld]" FORMAT, \
               IO->ID, CCID, NODE, N)
 
 #define EVNCS_syslog(LEVEL, FORMAT, ...) \
-       syslog(LEVEL, "IO[%ld]NW[%s][%ld]" FORMAT, \
+       DBGLOG(LEVEL) syslog(LEVEL, "IO[%ld]NW[%s][%ld]" FORMAT, \
               IO->ID, NODE, N, __VA_ARGS__)
 
 #define EVNCSM_syslog(LEVEL, FORMAT) \
-       syslog(LEVEL, "IO[%ld]NW[%s][%ld]" FORMAT, \
+       DBGLOG(LEVEL) syslog(LEVEL, "IO[%ld]NW[%s][%ld]" FORMAT, \
               IO->ID, NODE, N)
 
 
@@ -157,7 +161,12 @@ void DeleteNetworker(void *vptr)
        FreeStrBuf(&NW->port);
        FreeStrBuf(&NW->secret);
        FreeStrBuf(&NW->Url);
+       FreeStrBuf(&NW->IO.ErrMsg);
        FreeAsyncIOContents(&NW->IO);
+       if (NW->HostLookup.VParsedDNSReply != NULL) {
+               NW->HostLookup.DNSReplyFree(NW->HostLookup.VParsedDNSReply);
+               NW->HostLookup.VParsedDNSReply = NULL;
+       }
        free(NW);
 }
 
@@ -185,6 +194,8 @@ eNextState NWC_ReadGreeting(AsyncNetworker *NW)
        extract_token (connected_to, ChrPtr(NW->IO.IOBuf), 1, ' ', sizeof connected_to);
        if (strcmp(connected_to, ChrPtr(NW->node)) != 0)
        {
+               if (NW->IO.ErrMsg == NULL)
+                       NW->IO.ErrMsg = NewStrBuf();
                StrBufPrintf(NW->IO.ErrMsg,
                             "Connected to node \"%s\" but I was expecting to connect to node \"%s\".",
                             connected_to, ChrPtr(NW->node));
@@ -216,6 +227,8 @@ eNextState NWC_ReadAuthReply(AsyncNetworker *NW)
        }
        else
        {
+               if (NW->IO.ErrMsg == NULL)
+                       NW->IO.ErrMsg = NewStrBuf();
                StrBufPrintf(NW->IO.ErrMsg,
                             "Connected to node \"%s\" but my secret wasn't accurate.",
                             ChrPtr(NW->node));
@@ -231,19 +244,20 @@ eNextState NWC_SendNDOP(AsyncNetworker *NW)
        AsyncIO *IO = &NW->IO;
        NW->tempFileName = NewStrBuf();
        NW->SpoolFileName = NewStrBuf();
-       StrBufPrintf(NW->tempFileName, 
+       StrBufPrintf(NW->SpoolFileName,
                     "%s/%s.%lx%x",
                     ctdl_netin_dir,
                     ChrPtr(NW->node),
                     time(NULL),// TODO: get time from libev
                     rand());
-       StrBufPrintf(NW->SpoolFileName, 
+       StrBufStripSlashes(NW->SpoolFileName, 1);
+       StrBufPrintf(NW->tempFileName, 
                     "%s/%s.%lx%x",
                     ctdl_nettmp_dir,
                     ChrPtr(NW->node),
                     time(NULL),// TODO: get time from libev
                     rand());
-
+       StrBufStripSlashes(NW->tempFileName, 1);
        /* We're talking to the correct node.  Now identify ourselves. */
        StrBufPlain(NW->IO.SendBuf.Buf, HKEY("NDOP\n"));
        NWC_DBG_SEND();
@@ -266,14 +280,14 @@ eNextState NWC_ReadNDOPReply(AsyncNetworker *NW)
                }
                else {
                        int fd;
-                       fd = open(ChrPtr(NW->SpoolFileName), 
+                       fd = open(ChrPtr(NW->tempFileName), 
                                  O_EXCL|O_CREAT|O_NONBLOCK|O_WRONLY, 
                                  S_IRUSR|S_IWUSR);
                        if (fd < 0)
                        {
                                EVN_syslog(LOG_CRIT,
                                       "cannot open %s: %s\n", 
-                                      ChrPtr(NW->SpoolFileName), 
+                                      ChrPtr(NW->tempFileName), 
                                       strerror(errno));
 
                                NW->State = eQUIT - 1;
@@ -343,6 +357,7 @@ eNextState NWC_ReadREADState(AsyncNetworker *NW)
 eNextState NWC_ReadREADBlobDone(AsyncNetworker *NW);
 eNextState NWC_ReadREADBlob(AsyncNetworker *NW)
 {
+       eNextState rc;
        AsyncIO *IO = &NW->IO;
        NWC_DBG_READ();
        if (NW->IO.IOB.TotalSendSize == NW->IO.IOB.TotalSentAlready)
@@ -350,8 +365,8 @@ eNextState NWC_ReadREADBlob(AsyncNetworker *NW)
                NW->State ++;
 
                FDIOBufferDelete(&NW->IO.IOB);
-               
-               if (link(ChrPtr(NW->SpoolFileName), ChrPtr(NW->tempFileName)) != 0) {
+
+               if (link(ChrPtr(NW->tempFileName), ChrPtr(NW->SpoolFileName)) != 0) {
                        EVN_syslog(LOG_ALERT, 
                               "Could not link %s to %s: %s\n",
                               ChrPtr(NW->tempFileName), 
@@ -360,26 +375,29 @@ eNextState NWC_ReadREADBlob(AsyncNetworker *NW)
                }
        
                unlink(ChrPtr(NW->tempFileName));
-               return NWC_DispatchWriteDone(&NW->IO);
+               rc = NWC_DispatchWriteDone(&NW->IO);
+               NW->State --;
+               return rc;
        }
        else {
                NW->State --;
                NW->IO.IOB.ChunkSendRemain = NW->IO.IOB.ChunkSize;
-               return NWC_DispatchWriteDone(&NW->IO);
+               return eSendReply; //NWC_DispatchWriteDone(&NW->IO);
        }
 }
 
 eNextState NWC_ReadREADBlobDone(AsyncNetworker *NW)
 {
+       eNextState rc;
        AsyncIO *IO = &NW->IO;
-       NWC_DBG_READ();
+/* we don't have any data to debug print here. */
        if (NW->IO.IOB.TotalSendSize == NW->IO.IOB.TotalSentAlready)
        {
                NW->State ++;
 
                FDIOBufferDelete(&NW->IO.IOB);
-               
-               if (link(ChrPtr(NW->SpoolFileName), ChrPtr(NW->tempFileName)) != 0) {
+
+               if (link(ChrPtr(NW->tempFileName), ChrPtr(NW->SpoolFileName)) != 0) {
                        EVN_syslog(LOG_ALERT, 
                               "Could not link %s to %s: %s\n",
                               ChrPtr(NW->tempFileName), 
@@ -388,7 +406,9 @@ eNextState NWC_ReadREADBlobDone(AsyncNetworker *NW)
                }
        
                unlink(ChrPtr(NW->tempFileName));
-               return NWC_DispatchWriteDone(&NW->IO);
+               rc = NWC_DispatchWriteDone(&NW->IO);
+               NW->State --;
+               return rc;
        }
        else {
                NW->State --;
@@ -422,26 +442,29 @@ eNextState NWC_SendNUOP(AsyncNetworker *NW)
        struct stat statbuf;
        int fd;
 
-       StrBufPrintf(NW->tempFileName,
+       StrBufPrintf(NW->SpoolFileName,
                     "%s/%s",
                     ctdl_netout_dir,
                     ChrPtr(NW->node));
-       fd = open(ChrPtr(NW->tempFileName), O_RDONLY);
+       StrBufStripSlashes(NW->SpoolFileName, 1);
+
+       fd = open(ChrPtr(NW->SpoolFileName), O_RDONLY);
        if (fd < 0) {
                if (errno != ENOENT) {
                        EVN_syslog(LOG_CRIT,
                               "cannot open %s: %s\n", 
-                              ChrPtr(NW->tempFileName), 
+                              ChrPtr(NW->SpoolFileName), 
                               strerror(errno));
                }
                NW->State = eQUIT;
                rc = NWC_SendQUIT(NW);
                NWC_DBG_SEND();
+               return rc;
        }
 
        if (fstat(fd, &statbuf) == -1) {
                EVN_syslog(LOG_CRIT, "FSTAT FAILED %s [%s]--\n", 
-                          ChrPtr(NW->tempFileName), 
+                          ChrPtr(NW->SpoolFileName), 
                           strerror(errno));
                if (fd > 0) close(fd);
                return eAbort;
@@ -509,7 +532,9 @@ eNextState NWC_SendBlobDone(AsyncNetworker *NW)
        else {
                NW->State --;
                IO->IOB.ChunkSendRemain = IO->IOB.ChunkSize;
-               return NWC_DispatchWriteDone(IO);
+               rc = NWC_DispatchWriteDone(IO);
+               NW->State --;
+               return rc;
        }
 }
 
@@ -528,8 +553,8 @@ eNextState NWC_ReadUCLS(AsyncNetworker *NW)
 
        EVN_syslog(LOG_NOTICE, "Sent %ld octets to <%s>\n", NW->IO.IOB.ChunkSize, ChrPtr(NW->node));
        if (ChrPtr(NW->IO.IOBuf)[0] == '2') {
-               EVN_syslog(LOG_DEBUG, "Removing <%s>\n", ChrPtr(NW->tempFileName));
-               unlink(ChrPtr(NW->tempFileName));
+               EVN_syslog(LOG_DEBUG, "Removing <%s>\n", ChrPtr(NW->SpoolFileName));
+               unlink(ChrPtr(NW->SpoolFileName));
        }
        return eSendReply;
 }
@@ -723,7 +748,7 @@ void NWC_SetTimeout(eNextState NextTCPState, AsyncNetworker *NW)
        AsyncIO *IO = &NW->IO;
        double Timeout = 0.0;
 
-       EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
+       EVN_syslog(LOG_DEBUG, "%s - %d\n", __FUNCTION__, NextTCPState);
 
        switch (NextTCPState) {
        case eSendReply:
@@ -748,7 +773,14 @@ void NWC_SetTimeout(eNextState NextTCPState, AsyncNetworker *NW)
        case eReadMore://// TODO
                return;
        }
-       SetNextTimeout(&NW->IO, Timeout);
+       if (Timeout > 0) {
+               EVN_syslog(LOG_DEBUG, 
+                          "%s - %d %f\n",
+                          __FUNCTION__,
+                          NextTCPState,
+                          Timeout);
+               SetNextTimeout(&NW->IO, Timeout*100);
+       }
 }
 
 
@@ -785,32 +817,48 @@ eNextState NWC_Terminate(AsyncIO *IO)
        return eAbort;
 }
 
+eNextState NWC_TerminateDB(AsyncIO *IO)
+{
+       EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
+       FinalizeNetworker(IO);
+       return eAbort;
+}
+
 eNextState NWC_Timeout(AsyncIO *IO)
 {
+       AsyncNetworker *NW = IO->Data;
        EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
 
+       if (NW->IO.ErrMsg == NULL)
+               NW->IO.ErrMsg = NewStrBuf();
+       StrBufPrintf(NW->IO.ErrMsg, "Timeout while talking to %s \r\n", ChrPtr(NW->host));
        return NWC_FailNetworkConnection(IO);
 }
 eNextState NWC_ConnFail(AsyncIO *IO)
 {
-///    AsyncNetworker *NW = IO->Data;
+       AsyncNetworker *NW = IO->Data;
 
        EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
-////   StrBufPlain(IO->ErrMsg, CKEY(POP3C_ReadErrors[pMsg->State])); todo
+       if (NW->IO.ErrMsg == NULL)
+               NW->IO.ErrMsg = NewStrBuf();
+       StrBufPrintf(NW->IO.ErrMsg, "failed to connect %s \r\n", ChrPtr(NW->host));
+
        return NWC_FailNetworkConnection(IO);
 }
 eNextState NWC_DNSFail(AsyncIO *IO)
 {
-///    AsyncNetworker *NW = IO->Data;
+       AsyncNetworker *NW = IO->Data;
 
        EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
-////   StrBufPlain(IO->ErrMsg, CKEY(POP3C_ReadErrors[pMsg->State])); todo
+       if (NW->IO.ErrMsg == NULL)
+               NW->IO.ErrMsg = NewStrBuf();
+       StrBufPrintf(NW->IO.ErrMsg, "failed to look up %s \r\n", ChrPtr(NW->host));
+
        return NWC_FailNetworkConnection(IO);
 }
 eNextState NWC_Shutdown(AsyncIO *IO)
 {
        EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
-////   pop3aggr *pMsg = IO->Data;
 
        FinalizeNetworker(IO);
        return eAbort;
@@ -836,8 +884,6 @@ eNextState nwc_connect_ip(AsyncIO *IO)
 static int NetworkerCount = 0;
 void RunNetworker(AsyncNetworker *NW)
 {
-       AsyncIO *IO = &NW->IO;
-
        NW->n = NetworkerCount++;
        network_talking_to(SKEY(NW->node), NTT_ADD);
        syslog(LOG_DEBUG, "NW[%s][%ld]: polling\n", ChrPtr(NW->node), NW->n);
@@ -851,6 +897,7 @@ void RunNetworker(AsyncNetworker *NW)
                     NWC_DispatchWriteDone,
                     NWC_DispatchReadDone,
                     NWC_Terminate,
+                    NWC_TerminateDB,
                     NWC_ConnFail,
                     NWC_Timeout,
                     NWC_Shutdown);
@@ -879,6 +926,7 @@ void network_poll_other_citadel_nodes(int full_poll, char *working_ignetcfg)
        AsyncNetworker *NW;
        StrBuf *CfgData;
        StrBuf *Line;
+       StrBuf *SpoolFileName;
        const char *lptr;
        const char *CfgPtr;
        int Done;
@@ -892,6 +940,7 @@ void network_poll_other_citadel_nodes(int full_poll, char *working_ignetcfg)
        become_session(&networker_client_CC);
 
        CfgData = NewStrBufPlain(working_ignetcfg, -1);
+       SpoolFileName = NewStrBufPlain(ctdl_netout_dir, -1);
        Line = NewStrBufPlain(NULL, StrLength(CfgData));
        Done = 0;
        CfgPtr = NULL;
@@ -926,10 +975,11 @@ void network_poll_other_citadel_nodes(int full_poll, char *working_ignetcfg)
                                poll = full_poll;
                                if (poll == 0)
                                {
-                                       NW->SpoolFileName = NewStrBufPlain(ctdl_netout_dir, -1);
-                                       StrBufAppendBufPlain(NW->SpoolFileName, HKEY("/"), 0);
-                                       StrBufAppendBuf(NW->SpoolFileName, NW->node, 0);
-                                       if (access(ChrPtr(NW->SpoolFileName), R_OK) == 0) {
+                                       StrBufAppendBufPlain(SpoolFileName, HKEY("/"), 0);
+                                       StrBufAppendBuf(SpoolFileName, NW->node, 0);
+                                       StrBufStripSlashes(SpoolFileName, 1);
+
+                                       if (access(ChrPtr(SpoolFileName), R_OK) == 0) {
                                                poll = 1;
                                        }
                                }
@@ -952,6 +1002,7 @@ void network_poll_other_citadel_nodes(int full_poll, char *working_ignetcfg)
                        DeleteNetworker(NW);
                }
        }
+       FreeStrBuf(&SpoolFileName);
        FreeStrBuf(&CfgData);
        FreeStrBuf(&Line);
 
@@ -986,8 +1037,10 @@ void network_do_clientqueue(void)
                free(working_ignetcfg);
 }
 
-
-
+void LogDebugEnableNetworkClient(const int n)
+{
+       NetworkClientDebugEnabled = n;
+}
 /*
  * Module entry point
  */
@@ -998,6 +1051,8 @@ CTDL_MODULE_INIT(network_client)
                CtdlFillSystemContext(&networker_client_CC, "CitNetworker");
                
                CtdlRegisterSessionHook(network_do_clientqueue, EVT_TIMER);
+               CtdlRegisterDebugFlagHook(HKEY("networkclient"), LogDebugEnableNetworkClient, &NetworkClientDebugEnabled);
+
        }
-       return "network_client";
+       return "networkclient";
 }