Networker Increase logging on startup

[citadel.git] / citadel / modules / network / serv_networkclient.c

diff --git a/citadel/modules/network/serv_networkclient.c b/citadel/modules/network/serv_networkclient.c
index 647ec6ed634fee8cb1e5ef6af863253d4a14a068..82b3920a03890f0d9af4461add425c0c6c49f022 100644 (file)
--- a/citadel/modules/network/serv_networkclient.c
+++ b/citadel/modules/network/serv_networkclient.c
@@ -88,6 +88,28 @@
 
 struct CitContext networker_client_CC;
 
+#define NODE ChrPtr(((AsyncNetworker*)IO->Data)->node)
+#define N ((AsyncNetworker*)IO->Data)->n
+
+#define EVN_syslog(LEVEL, FORMAT, ...) \
+       syslog(LEVEL, \
+              "IO[%ld]CC[%d]NW[%s][%ld]" FORMAT, \
+              IO->ID, CCID, NODE, N, __VA_ARGS__)
+
+#define EVNM_syslog(LEVEL, FORMAT) \
+       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, \
+              IO->ID, NODE, N, __VA_ARGS__)
+
+#define EVNCSM_syslog(LEVEL, FORMAT) \
+       syslog(LEVEL, "IO[%ld]NW[%s][%ld]" FORMAT, \
+              IO->ID, NODE, N)
+
+
 typedef enum _eNWCState {
        eeGreating,
        eAuth,
@@ -135,16 +157,12 @@ void DeleteNetworker(void *vptr)
        FreeStrBuf(&NW->port);
        FreeStrBuf(&NW->secret);
        FreeStrBuf(&NW->Url);
-       if (NW->IO.CitContext != NULL) {
-               ((struct CitContext*)NW->IO.CitContext)->state = CON_IDLE;
-               ((struct CitContext*)NW->IO.CitContext)->kill_me = 1;
-       }
        FreeAsyncIOContents(&NW->IO);
        free(NW);
 }
 
-#define NWC_DBG_SEND() syslog(LOG_DEBUG, "NW client[%ld]: > %s", NW->n, ChrPtr(NW->IO.SendBuf.Buf))
-#define NWC_DBG_READ() syslog(LOG_DEBUG, "NW client[%ld]: < %s\n", NW->n, ChrPtr(NW->IO.IOBuf))
+#define NWC_DBG_SEND() EVN_syslog(LOG_DEBUG, ": > %s", ChrPtr(NW->IO.SendBuf.Buf))
+#define NWC_DBG_READ() EVN_syslog(LOG_DEBUG, ": < %s\n", ChrPtr(NW->IO.IOBuf))
 #define NWC_OK (strncasecmp(ChrPtr(NW->IO.IOBuf), "+OK", 3) == 0)
 
 eNextState FinalizeNetworker(AsyncIO *IO)
@@ -160,6 +178,7 @@ eNextState FinalizeNetworker(AsyncIO *IO)
 eNextState NWC_ReadGreeting(AsyncNetworker *NW)
 {
        char connected_to[SIZ];
+       AsyncIO *IO = &NW->IO;
        NWC_DBG_READ();
        /* Read the server greeting */
        /* Check that the remote is who we think it is and warn the Aide if not */
@@ -169,7 +188,7 @@ eNextState NWC_ReadGreeting(AsyncNetworker *NW)
                StrBufPrintf(NW->IO.ErrMsg,
                             "Connected to node \"%s\" but I was expecting to connect to node \"%s\".",
                             connected_to, ChrPtr(NW->node));
-               syslog(LOG_ERR, "%s\n", ChrPtr(NW->IO.ErrMsg));
+               EVN_syslog(LOG_ERR, "%s\n", ChrPtr(NW->IO.ErrMsg));
                CtdlAideMessage(ChrPtr(NW->IO.ErrMsg), "Network error");
                return eAbort;/// todo: aide message in anderer queue speichern
        }
@@ -178,6 +197,7 @@ eNextState NWC_ReadGreeting(AsyncNetworker *NW)
 
 eNextState NWC_SendAuth(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        /* We're talking to the correct node.  Now identify ourselves. */
        StrBufPrintf(NW->IO.SendBuf.Buf, "NETP %s|%s\n", 
                     config.c_nodename, 
@@ -188,6 +208,7 @@ eNextState NWC_SendAuth(AsyncNetworker *NW)
 
 eNextState NWC_ReadAuthReply(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        NWC_DBG_READ();
        if (ChrPtr(NW->IO.IOBuf)[0] == '2')
        {
@@ -198,7 +219,7 @@ eNextState NWC_ReadAuthReply(AsyncNetworker *NW)
                StrBufPrintf(NW->IO.ErrMsg,
                             "Connected to node \"%s\" but my secret wasn't accurate.",
                             ChrPtr(NW->node));
-               syslog(LOG_ERR, "%s\n", ChrPtr(NW->IO.ErrMsg));
+               EVN_syslog(LOG_ERR, "%s\n", ChrPtr(NW->IO.ErrMsg));
                CtdlAideMessage(ChrPtr(NW->IO.ErrMsg), "Network error");
                
                return eAbort;
@@ -207,6 +228,7 @@ eNextState NWC_ReadAuthReply(AsyncNetworker *NW)
 
 eNextState NWC_SendNDOP(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        NW->tempFileName = NewStrBuf();
        NW->SpoolFileName = NewStrBuf();
        StrBufPrintf(NW->tempFileName, 
@@ -230,6 +252,7 @@ eNextState NWC_SendNDOP(AsyncNetworker *NW)
 
 eNextState NWC_ReadNDOPReply(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        int TotalSendSize;
        NWC_DBG_READ();
        if (ChrPtr(NW->IO.IOBuf)[0] == '2')
@@ -237,7 +260,7 @@ eNextState NWC_ReadNDOPReply(AsyncNetworker *NW)
 
                NW->IO.IOB.TotalSentAlready = 0;
                TotalSendSize = atol (ChrPtr(NW->IO.IOBuf) + 4);
-               syslog(LOG_DEBUG, "Expecting to transfer %ld bytes\n", NW->IO.IOB.TotalSendSize);
+               EVN_syslog(LOG_DEBUG, "Expecting to transfer %ld bytes\n", NW->IO.IOB.TotalSendSize);
                if (TotalSendSize <= 0) {
                        NW->State = eNUOP - 1;
                }
@@ -248,7 +271,7 @@ eNextState NWC_ReadNDOPReply(AsyncNetworker *NW)
                                  S_IRUSR|S_IWUSR);
                        if (fd < 0)
                        {
-                               syslog(LOG_CRIT,
+                               EVN_syslog(LOG_CRIT,
                                       "cannot open %s: %s\n", 
                                       ChrPtr(NW->SpoolFileName), 
                                       strerror(errno));
@@ -268,6 +291,7 @@ eNextState NWC_ReadNDOPReply(AsyncNetworker *NW)
 
 eNextState NWC_SendREAD(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        eNextState rc;
 
        if (NW->IO.IOB.TotalSentAlready < NW->IO.IOB.TotalSendSize)
@@ -306,6 +330,7 @@ eNextState NWC_SendREAD(AsyncNetworker *NW)
 
 eNextState NWC_ReadREADState(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        NWC_DBG_READ();
        if (ChrPtr(NW->IO.IOBuf)[0] == '6')
        {
@@ -318,6 +343,7 @@ eNextState NWC_ReadREADState(AsyncNetworker *NW)
 eNextState NWC_ReadREADBlobDone(AsyncNetworker *NW);
 eNextState NWC_ReadREADBlob(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        NWC_DBG_READ();
        if (NW->IO.IOB.TotalSendSize == NW->IO.IOB.TotalSentAlready)
        {
@@ -326,7 +352,7 @@ eNextState NWC_ReadREADBlob(AsyncNetworker *NW)
                FDIOBufferDelete(&NW->IO.IOB);
                
                if (link(ChrPtr(NW->SpoolFileName), ChrPtr(NW->tempFileName)) != 0) {
-                       syslog(LOG_ALERT, 
+                       EVN_syslog(LOG_ALERT, 
                               "Could not link %s to %s: %s\n",
                               ChrPtr(NW->tempFileName), 
                               ChrPtr(NW->SpoolFileName), 
@@ -345,6 +371,7 @@ eNextState NWC_ReadREADBlob(AsyncNetworker *NW)
 
 eNextState NWC_ReadREADBlobDone(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        NWC_DBG_READ();
        if (NW->IO.IOB.TotalSendSize == NW->IO.IOB.TotalSentAlready)
        {
@@ -353,7 +380,7 @@ eNextState NWC_ReadREADBlobDone(AsyncNetworker *NW)
                FDIOBufferDelete(&NW->IO.IOB);
                
                if (link(ChrPtr(NW->SpoolFileName), ChrPtr(NW->tempFileName)) != 0) {
-                       syslog(LOG_ALERT, 
+                       EVN_syslog(LOG_ALERT, 
                               "Could not link %s to %s: %s\n",
                               ChrPtr(NW->tempFileName), 
                               ChrPtr(NW->SpoolFileName), 
@@ -371,6 +398,7 @@ eNextState NWC_ReadREADBlobDone(AsyncNetworker *NW)
 }
 eNextState NWC_SendCLOS(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        StrBufPlain(NW->IO.SendBuf.Buf, HKEY("CLOS\n"));
        NWC_DBG_SEND();
        return eSendReply;
@@ -378,6 +406,7 @@ eNextState NWC_SendCLOS(AsyncNetworker *NW)
 
 eNextState NWC_ReadCLOSReply(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        NWC_DBG_READ();
        if (ChrPtr(NW->IO.IOBuf)[0] != '2')
                return eTerminateConnection;
@@ -387,6 +416,7 @@ eNextState NWC_ReadCLOSReply(AsyncNetworker *NW)
 
 eNextState NWC_SendNUOP(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        eNextState rc;
        long TotalSendSize;
        struct stat statbuf;
@@ -399,7 +429,7 @@ eNextState NWC_SendNUOP(AsyncNetworker *NW)
        fd = open(ChrPtr(NW->tempFileName), O_RDONLY);
        if (fd < 0) {
                if (errno != ENOENT) {
-                       syslog(LOG_CRIT,
+                       EVN_syslog(LOG_CRIT,
                               "cannot open %s: %s\n", 
                               ChrPtr(NW->tempFileName), 
                               strerror(errno));
@@ -410,15 +440,15 @@ eNextState NWC_SendNUOP(AsyncNetworker *NW)
        }
 
        if (fstat(fd, &statbuf) == -1) {
-               syslog(9, "FSTAT FAILED %s [%s]--\n", 
-                      ChrPtr(NW->tempFileName), 
-                      strerror(errno));
+               EVN_syslog(LOG_CRIT, "FSTAT FAILED %s [%s]--\n", 
+                          ChrPtr(NW->tempFileName), 
+                          strerror(errno));
                if (fd > 0) close(fd);
                return eAbort;
        }
        TotalSendSize = statbuf.st_size;
        if (TotalSendSize == 0) {
-               syslog(LOG_DEBUG,
+               EVNM_syslog(LOG_DEBUG,
                       "Nothing to send.\n");
                NW->State = eQUIT;
                rc = NWC_SendQUIT(NW);
@@ -434,6 +464,7 @@ eNextState NWC_SendNUOP(AsyncNetworker *NW)
 }
 eNextState NWC_ReadNUOPReply(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        NWC_DBG_READ();
        if (ChrPtr(NW->IO.IOBuf)[0] != '2')
                return eAbort;
@@ -442,6 +473,7 @@ eNextState NWC_ReadNUOPReply(AsyncNetworker *NW)
 
 eNextState NWC_SendWRIT(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        StrBufPrintf(NW->IO.SendBuf.Buf, "WRIT %ld\n", 
                     NW->IO.IOB.TotalSendSize - NW->IO.IOB.TotalSentAlready);
        NWC_DBG_SEND();
@@ -449,6 +481,7 @@ eNextState NWC_SendWRIT(AsyncNetworker *NW)
 }
 eNextState NWC_ReadWRITReply(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        NWC_DBG_READ();
        if (ChrPtr(NW->IO.IOBuf)[0] != '7')
        {
@@ -462,6 +495,7 @@ eNextState NWC_ReadWRITReply(AsyncNetworker *NW)
 
 eNextState NWC_SendBlobDone(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        eNextState rc;
        if (NW->IO.IOB.TotalSendSize == NW->IO.IOB.TotalSentAlready)
        {
@@ -481,6 +515,7 @@ eNextState NWC_SendBlobDone(AsyncNetworker *NW)
 
 eNextState NWC_SendUCLS(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        StrBufPlain(NW->IO.SendBuf.Buf, HKEY("UCLS 1\n"));
        NWC_DBG_SEND();
        return eSendReply;
@@ -488,11 +523,12 @@ eNextState NWC_SendUCLS(AsyncNetworker *NW)
 }
 eNextState NWC_ReadUCLS(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        NWC_DBG_READ();
 
-       syslog(LOG_NOTICE, "Sent %ld octets to <%s>\n", NW->IO.IOB.ChunkSize, ChrPtr(NW->node));
+       EVN_syslog(LOG_NOTICE, "Sent %ld octets to <%s>\n", NW->IO.IOB.ChunkSize, ChrPtr(NW->node));
        if (ChrPtr(NW->IO.IOBuf)[0] == '2') {
-               syslog(LOG_DEBUG, "Removing <%s>\n", ChrPtr(NW->tempFileName));
+               EVN_syslog(LOG_DEBUG, "Removing <%s>\n", ChrPtr(NW->tempFileName));
                unlink(ChrPtr(NW->tempFileName));
        }
        return eSendReply;
@@ -500,6 +536,7 @@ eNextState NWC_ReadUCLS(AsyncNetworker *NW)
 
 eNextState NWC_SendQUIT(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        StrBufPlain(NW->IO.SendBuf.Buf, HKEY("QUIT\n"));
 
        NWC_DBG_SEND();
@@ -508,6 +545,7 @@ eNextState NWC_SendQUIT(AsyncNetworker *NW)
 
 eNextState NWC_ReadQUIT(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        NWC_DBG_READ();
 
        return eAbort;
@@ -625,16 +663,14 @@ eNextState nwc_get_one_host_ip(AsyncIO *IO)
         * here we start with the lookup of one host.
         */ 
 
-       InitC_ares_dns(IO);
-
-       syslog(LOG_DEBUG, "NWC: %s\n", __FUNCTION__);
+       EVN_syslog(LOG_DEBUG, "NWC: %s\n", __FUNCTION__);
 
-       syslog(LOG_DEBUG, 
-                     "NWC client[%ld]: looking up %s-Record %s : %d ...\n", 
-                     NW->n, 
-                     (NW->IO.ConnectMe->IPv6)? "aaaa": "a",
-                     NW->IO.ConnectMe->Host, 
-                     NW->IO.ConnectMe->Port);
+       EVN_syslog(LOG_DEBUG, 
+                  "NWC client[%ld]: looking up %s-Record %s : %d ...\n", 
+                  NW->n, 
+                  (NW->IO.ConnectMe->IPv6)? "aaaa": "a",
+                  NW->IO.ConnectMe->Host, 
+                  NW->IO.ConnectMe->Port);
 
        QueueQuery((NW->IO.ConnectMe->IPv6)? ns_t_aaaa : ns_t_a, 
                   NW->IO.ConnectMe->Host, 
@@ -684,9 +720,10 @@ eNextState NWC_FailNetworkConnection(AsyncIO *IO)
 
 void NWC_SetTimeout(eNextState NextTCPState, AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
        double Timeout = 0.0;
 
-       syslog(LOG_DEBUG, "NWC3: %s\n", __FUNCTION__);
+       EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
 
        switch (NextTCPState) {
        case eSendReply:
@@ -717,7 +754,7 @@ void NWC_SetTimeout(eNextState NextTCPState, AsyncNetworker *NW)
 
 eNextState NWC_DispatchReadDone(AsyncIO *IO)
 {
-       syslog(LOG_DEBUG, "NWC: %s\n", __FUNCTION__);
+       EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
        AsyncNetworker *NW = IO->Data;
        eNextState rc;
 
@@ -729,7 +766,7 @@ eNextState NWC_DispatchReadDone(AsyncIO *IO)
 }
 eNextState NWC_DispatchWriteDone(AsyncIO *IO)
 {
-       syslog(LOG_DEBUG, "NWC: %s\n", __FUNCTION__);
+       EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
        AsyncNetworker *NW = IO->Data;
        eNextState rc;
 
@@ -743,14 +780,14 @@ eNextState NWC_DispatchWriteDone(AsyncIO *IO)
 /*****************************************************************************/
 eNextState NWC_Terminate(AsyncIO *IO)
 {
-       syslog(LOG_DEBUG, "Nw: %s\n", __FUNCTION__);
+       EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
        FinalizeNetworker(IO);
        return eAbort;
 }
 
 eNextState NWC_Timeout(AsyncIO *IO)
 {
-       syslog(LOG_DEBUG, "NW: %s\n", __FUNCTION__);
+       EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
 
        return NWC_FailNetworkConnection(IO);
 }
@@ -758,7 +795,7 @@ eNextState NWC_ConnFail(AsyncIO *IO)
 {
 ///    AsyncNetworker *NW = IO->Data;
 
-       syslog(LOG_DEBUG, "NW: %s\n", __FUNCTION__);
+       EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
 ////   StrBufPlain(IO->ErrMsg, CKEY(POP3C_ReadErrors[pMsg->State])); todo
        return NWC_FailNetworkConnection(IO);
 }
@@ -766,13 +803,13 @@ eNextState NWC_DNSFail(AsyncIO *IO)
 {
 ///    AsyncNetworker *NW = IO->Data;
 
-       syslog(LOG_DEBUG, "NW: %s\n", __FUNCTION__);
+       EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
 ////   StrBufPlain(IO->ErrMsg, CKEY(POP3C_ReadErrors[pMsg->State])); todo
        return NWC_FailNetworkConnection(IO);
 }
 eNextState NWC_Shutdown(AsyncIO *IO)
 {
-       syslog(LOG_DEBUG, "NW: %s\n", __FUNCTION__);
+       EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
 ////   pop3aggr *pMsg = IO->Data;
 
        FinalizeNetworker(IO);
@@ -784,12 +821,11 @@ eNextState nwc_connect_ip(AsyncIO *IO)
 {
        AsyncNetworker *NW = IO->Data;
 
-       syslog(LOG_DEBUG, "NW: %s\n", __FUNCTION__);
-       syslog(LOG_DEBUG, "network: polling <%s>\n", ChrPtr(NW->node));
-       syslog(LOG_NOTICE, "Connecting to <%s> at %s:%s\n", 
-              ChrPtr(NW->node), 
-              ChrPtr(NW->host),
-              ChrPtr(NW->port));
+       EVN_syslog(LOG_DEBUG, "%s\n", __FUNCTION__);
+       EVN_syslog(LOG_NOTICE, "Connecting to <%s> at %s:%s\n", 
+                  ChrPtr(NW->node), 
+                  ChrPtr(NW->host),
+                  ChrPtr(NW->port));
        
        return EvConnectSock(IO,
                             NWC_ConnTimeout,
@@ -797,8 +833,14 @@ eNextState nwc_connect_ip(AsyncIO *IO)
                             1);
 }
 
+static int NetworkerCount = 0;
 void RunNetworker(AsyncNetworker *NW)
 {
+       AsyncIO *IO = &NW->IO;
+
+       NW->n = NetworkerCount++;
+       network_talking_to(SKEY(NW->node), NTT_ADD);
+       EVN_syslog(LOG_DEBUG, "network: polling <%s>\n", ChrPtr(NW->node));
        ParseURL(&NW->IO.ConnectMe, NW->Url, 504);
 
        InitIOStruct(&NW->IO,
@@ -892,7 +934,8 @@ void network_poll_other_citadel_nodes(int full_poll, char *working_ignetcfg)
                                        }
                                }
                        }
-                       if (poll) {
+                       if (poll && (StrLength (NW->host) > 0) && (!strcmp(ChrPtr(NW->host), "0.0.0.0")))
+                       {
                                NW->Url = NewStrBufPlain(NULL, StrLength(Line));
                                StrBufPrintf(NW->Url, "citadel://:%s@%s:%s", 
                                             ChrPtr(NW->secret),
@@ -900,7 +943,6 @@ void network_poll_other_citadel_nodes(int full_poll, char *working_ignetcfg)
                                             ChrPtr(NW->port));
                                if (!network_talking_to(SKEY(NW->node), NTT_CHECK))
                                {
-                                       network_talking_to(SKEY(NW->node), NTT_ADD);
                                        RunNetworker(NW);
                                        continue;
                                }