Indents are 8 characters wide and are expressed as a tab character.
[citadel.git] / citadel / modules / eventclient / serv_eventclient.c
index 79b0eeb303d15dbba8bb2e6c17572574b8f9d308..520ae7fc8704270ac7149fbaad31d6db1f4665e6 100644 (file)
@@ -1,19 +1,13 @@
 /*
- * Copyright (c) 1998-2012 by the citadel.org team
+ * Copyright (c) 1998-2015 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 version 3.
- *  
- *  
+ * This program is open source software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License version 3.
  *
- *  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.
- *
- *  
- *  
- *  
+ * 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.
  */
 
 #include "sysdep.h"
@@ -53,9 +47,8 @@
 #include "server.h"
 #include "citserver.h"
 #include "support.h"
-
 #include "ctdl_module.h"
-
+#include "config.h"
 #include "event_client.h"
 #include "serv_curl.h"
 
@@ -63,32 +56,18 @@ ev_loop *event_base;
 int DebugEventLoop = 0;
 int DebugEventLoopBacktrace = 0;
 int DebugCurl = 0;
+pthread_key_t evConKey;
 
 long EvIDSource = 1;
 /*****************************************************************************
  *                   libevent / curl integration                             *
  *****************************************************************************/
-#define DBGLOG(LEVEL) if ((LEVEL != LOG_DEBUG) || (DebugCurl != 0))
-
-#define EVCURL_syslog(LEVEL, FORMAT, ...)                              \
-       DBGLOG (LEVEL) syslog(LEVEL, "EVCURL:IO[%ld]CC[%d] " FORMAT,    \
-                             IO->ID, CCID, __VA_ARGS__)
-
-#define EVCURLM_syslog(LEVEL, FORMAT)                                  \
-       DBGLOG (LEVEL) syslog(LEVEL, "EVCURL:IO[%ld]CC[%d] " FORMAT,    \
-                             IO->ID, CCID)
-
-#define CURL_syslog(LEVEL, FORMAT, ...)                                        \
-       DBGLOG (LEVEL) syslog(LEVEL, "CURL: " FORMAT, __VA_ARGS__)
-
-#define CURLM_syslog(LEVEL, FORMAT)                    \
-       DBGLOG (LEVEL) syslog(LEVEL, "CURL: " FORMAT)
 
 #define MOPT(s, v)                                                     \
        do {                                                            \
                sta = curl_multi_setopt(mhnd, (CURLMOPT_##s), (v));     \
                if (sta) {                                              \
-                       EVQ_syslog(LOG_ERR, "error setting option "     \
+                       syslog(LOG_ERR, "error setting option " \
                               #s " on curl multi handle: %s\n",        \
                               curl_easy_strerror(sta));                \
                        exit (1);                                       \
@@ -106,6 +85,8 @@ typedef struct _evcurl_global_data {
 ev_async WakeupCurl;
 evcurl_global_data global;
 
+eNextState QueueAnDBOperation(AsyncIO *IO);
+
 static void
 gotstatus(int nnrun)
 {
@@ -114,16 +95,16 @@ gotstatus(int nnrun)
 
        global.nrun = nnrun;
 
-       CURLM_syslog(LOG_DEBUG,
+       syslog(LOG_DEBUG,
                     "gotstatus(): about to call curl_multi_info_read\n");
        while ((msg = curl_multi_info_read(global.mhnd, &nmsg))) {
-               CURL_syslog(LOG_DEBUG,
+               syslog(LOG_DEBUG,
                            "got curl multi_info message msg=%d\n",
                            msg->msg);
 
                if (CURLMSG_DONE == msg->msg) {
                        CURL *chnd;
-                       char *chandle = NULL;
+                       void *chandle = NULL;
                        CURLcode sta;
                        CURLMcode msta;
                        AsyncIO*IO;
@@ -142,27 +123,27 @@ gotstatus(int nnrun)
                        }
                        IO = (AsyncIO *)chandle;
                        if (IO->ID == 0) {
-                               EVCURL_syslog(LOG_ERR,
+                               syslog(LOG_ERR,
                                              "Error, invalid IO context %p\n",
                                              IO);
                                continue;
                        }
                        SetEVState(IO, eCurlGotStatus);
 
-                       EVCURLM_syslog(LOG_DEBUG, "request complete\n");
+                       syslog(LOG_DEBUG, "request complete\n");
 
-                       IO->Now = ev_now(event_base);
+                       IO->CitContext->lastcmd = IO->Now = ev_now(event_base);
 
                        ev_io_stop(event_base, &IO->recv_event);
                        ev_io_stop(event_base, &IO->send_event);
 
                        sta = msg->data.result;
                        if (sta) {
-                               EVCURL_syslog(LOG_ERR,
+                               syslog(LOG_ERR,
                                              "error description: %s\n",
                                              IO->HttpReq.errdesc);
                                IO->HttpReq.CurlError = curl_easy_strerror(sta);
-                               EVCURL_syslog(LOG_ERR,
+                               syslog(LOG_ERR,
                                              "error performing request: %s\n",
                                              IO->HttpReq.CurlError);
                                if (sta == CURLE_OPERATION_TIMEDOUT)
@@ -175,19 +156,20 @@ gotstatus(int nnrun)
                                                CURLINFO_RESPONSE_CODE,
                                                &IO->HttpReq.httpcode);
                        if (sta)
-                               EVCURL_syslog(LOG_ERR,
+                               syslog(LOG_ERR,
                                              "error asking curl for "
                                              "response code from request: %s\n",
                                              curl_easy_strerror(sta));
-                       EVCURL_syslog(LOG_DEBUG,
+                       syslog(LOG_DEBUG,
                                      "http response code was %ld\n",
                                      (long)IO->HttpReq.httpcode);
 
 
                        curl_slist_free_all(IO->HttpReq.headers);
+                       IO->HttpReq.headers = NULL;
                        msta = curl_multi_remove_handle(global.mhnd, chnd);
                        if (msta)
-                               EVCURL_syslog(LOG_ERR,
+                               syslog(LOG_ERR,
                                              "warning problem detaching "
                                              "completed handle from curl multi: "
                                              "%s\n",
@@ -199,6 +181,9 @@ gotstatus(int nnrun)
                        switch(IO->SendDone(IO))
                        {
                        case eDBQuery:
+                               FreeURL(&IO->ConnectMe);
+                               QueueAnDBOperation(IO);
+                               break;
                        case eSendDNSQuery:
                        case eReadDNSReply:
                        case eConnect:
@@ -234,9 +219,9 @@ stepmulti(void *data, curl_socket_t fd, int which)
                                        which,
                                        &running_handles);
 
-       CURLM_syslog(LOG_DEBUG, "stepmulti(): calling gotstatus()\n");
+       syslog(LOG_DEBUG, "stepmulti(): calling gotstatus()\n");
        if (msta)
-               CURL_syslog(LOG_ERR,
+               syslog(LOG_ERR,
                            "error in curl processing events"
                            "on multi handle, fd %d: %s\n",
                            (int)fd,
@@ -249,14 +234,14 @@ stepmulti(void *data, curl_socket_t fd, int which)
 static void
 gottime(struct ev_loop *loop, ev_timer *timeev, int events)
 {
-       CURLM_syslog(LOG_DEBUG, "EVCURL: waking up curl for timeout\n");
+       syslog(LOG_DEBUG, "EVCURL: waking up curl for timeout\n");
        stepmulti(NULL, CURL_SOCKET_TIMEOUT, 0);
 }
 
 static void
 got_in(struct ev_loop *loop, ev_io *ioev, int events)
 {
-       CURL_syslog(LOG_DEBUG,
+       syslog(LOG_DEBUG,
                    "EVCURL: waking up curl for io on fd %d\n",
                    (int)ioev->fd);
 
@@ -266,7 +251,7 @@ got_in(struct ev_loop *loop, ev_io *ioev, int events)
 static void
 got_out(struct ev_loop *loop, ev_io *ioev, int events)
 {
-       CURL_syslog(LOG_DEBUG,
+       syslog(LOG_DEBUG,
                    "waking up curl for io on fd %d\n",
                    (int)ioev->fd);
 
@@ -283,7 +268,7 @@ gotdata(void *data, size_t size, size_t nmemb, void *cglobal)
        {
                IO->HttpReq.ReplyData = NewStrBufPlain(NULL, SIZ);
        }
-       IO->Now = ev_now(event_base);
+       IO->CitContext->lastcmd = IO->Now = ev_now(event_base);
        return CurlFillStrBuf_callback(data,
                                       size,
                                       nmemb,
@@ -292,7 +277,7 @@ gotdata(void *data, size_t size, size_t nmemb, void *cglobal)
 
 static int
 gotwatchtime(CURLM *multi, long tblock_ms, void *cglobal) {
-       CURL_syslog(LOG_DEBUG, "EVCURL: gotwatchtime called %ld ms\n", tblock_ms);
+       syslog(LOG_DEBUG, "EVCURL: gotwatchtime called %ld ms\n", tblock_ms);
        evcurl_global_data *global = cglobal;
        ev_timer_stop(EV_DEFAULT, &global->timeev);
        if (tblock_ms < 0 || 14000 < tblock_ms)
@@ -312,7 +297,7 @@ gotwatchsock(CURL *easy,
 {
        evcurl_global_data *global = cglobal;
        CURLM *mhnd = global->mhnd;
-       char *f;
+       void *f;
        AsyncIO *IO = (AsyncIO*) vIO;
        CURLcode sta;
        const char *Action;
@@ -320,7 +305,7 @@ gotwatchsock(CURL *easy,
        if (IO == NULL) {
                sta = curl_easy_getinfo(easy, CURLINFO_PRIVATE, &f);
                if (sta) {
-                       CURL_syslog(LOG_ERR,
+                       syslog(LOG_ERR,
                                    "EVCURL: error asking curl for private "
                                    "cookie of curl handle: %s\n",
                                    curl_easy_strerror(sta));
@@ -328,7 +313,7 @@ gotwatchsock(CURL *easy,
                }
                IO = (AsyncIO *) f;
                SetEVState(IO, eCurlNewIO);
-               EVCURL_syslog(LOG_DEBUG,
+               syslog(LOG_DEBUG,
                              "EVCURL: got socket for URL: %s\n",
                              IO->ConnectMe->PlainUrl);
 
@@ -344,7 +329,7 @@ gotwatchsock(CURL *easy,
        }
 
        SetEVState(IO, eCurlGotIO);
-       IO->Now = ev_now(event_base);
+       IO->CitContext->lastcmd = IO->Now = ev_now(event_base);
 
        Action = "";
        switch (action)
@@ -367,19 +352,19 @@ gotwatchsock(CURL *easy,
        }
 
 
-       EVCURL_syslog(LOG_DEBUG,
+       syslog(LOG_DEBUG,
                      "EVCURL: gotwatchsock called fd=%d action=%s[%d]\n",
                      (int)fd, Action, action);
 
        switch (action)
        {
        case CURL_POLL_NONE:
-               EVCURLM_syslog(LOG_DEBUG,
+               syslog(LOG_DEBUG,
                               "called first time "
                               "to register this sockwatcker\n");
                break;
        case CURL_POLL_REMOVE:
-               EVCURLM_syslog(LOG_DEBUG,
+               syslog(LOG_DEBUG,
                               "called last time to unregister "
                               "this sockwatcher\n");
                ev_io_stop(event_base, &IO->recv_event);
@@ -412,7 +397,7 @@ void curl_init_connectionpool(void)
 
        if (sta)
        {
-               CURL_syslog(LOG_ERR,
+               syslog(LOG_ERR,
                            "error initializing curl library: %s\n",
                            curl_easy_strerror(sta));
 
@@ -421,7 +406,7 @@ void curl_init_connectionpool(void)
        mhnd = global.mhnd = curl_multi_init();
        if (!mhnd)
        {
-               CURLM_syslog(LOG_ERR,
+               syslog(LOG_ERR,
                             "error initializing curl multi handle\n");
                exit(3);
        }
@@ -439,12 +424,12 @@ int evcurl_init(AsyncIO *IO)
        CURLcode sta;
        CURL *chnd;
 
-       EVCURLM_syslog(LOG_DEBUG, "EVCURL: evcurl_init called ms\n");
+       syslog(LOG_DEBUG, "EVCURL: evcurl_init called ms\n");
        IO->HttpReq.attached = 0;
        chnd = IO->HttpReq.chnd = curl_easy_init();
        if (!chnd)
        {
-               EVCURLM_syslog(LOG_ERR, "EVCURL: error initializing curl handle\n");
+               syslog(LOG_ERR, "EVCURL: error initializing curl handle\n");
                return 0;
        }
 
@@ -471,13 +456,13 @@ int evcurl_init(AsyncIO *IO)
        OPT(WRITEDATA, (void *)IO);
        OPT(ERRORBUFFER, IO->HttpReq.errdesc);
 
-       if ((!IsEmptyStr(config.c_ip_addr))
-               && (strcmp(config.c_ip_addr, "*"))
-               && (strcmp(config.c_ip_addr, "::"))
-               && (strcmp(config.c_ip_addr, "0.0.0.0"))
+       if ((!IsEmptyStr(CtdlGetConfigStr("c_ip_addr")))
+               && (strcmp(CtdlGetConfigStr("c_ip_addr"), "*"))
+               && (strcmp(CtdlGetConfigStr("c_ip_addr"), "::"))
+               && (strcmp(CtdlGetConfigStr("c_ip_addr"), "0.0.0.0"))
                )
        {
-               OPT(INTERFACE, config.c_ip_addr);
+               OPT(INTERFACE, CtdlGetConfigStr("c_ip_addr"));
        }
 
 #ifdef CURLOPT_HTTP_CONTENT_DECODING
@@ -503,14 +488,15 @@ static void IOcurl_abort_shutdown_callback(struct ev_loop *loop,
                return;
 
        SetEVState(IO, eCurlShutdown);
-       IO->Now = ev_now(event_base);
-       EVCURL_syslog(LOG_DEBUG, "EVENT Curl: %s\n", __FUNCTION__);
+       IO->CitContext->lastcmd = IO->Now = ev_now(event_base);
+       syslog(LOG_DEBUG, "EVENT Curl: %s\n", __FUNCTION__);
 
        curl_slist_free_all(IO->HttpReq.headers);
+       IO->HttpReq.headers = NULL;
        msta = curl_multi_remove_handle(global.mhnd, IO->HttpReq.chnd);
        if (msta)
        {
-               EVCURL_syslog(LOG_ERR,
+               syslog(LOG_ERR,
                              "EVCURL: warning problem detaching completed handle "
                              "from curl multi: %s\n",
                              curl_multi_strerror(msta));
@@ -524,6 +510,7 @@ static void IOcurl_abort_shutdown_callback(struct ev_loop *loop,
        assert(IO->ShutdownAbort);
        IO->ShutdownAbort(IO);
 }
+
 eNextState
 evcurl_handle_start(AsyncIO *IO)
 {
@@ -533,7 +520,7 @@ evcurl_handle_start(AsyncIO *IO)
 
        SetEVState(IO, eCurlStart);
        chnd = IO->HttpReq.chnd;
-       EVCURL_syslog(LOG_DEBUG,
+       syslog(LOG_DEBUG,
                  "EVCURL: Loading URL: %s\n", IO->ConnectMe->PlainUrl);
        OPT(URL, IO->ConnectMe->PlainUrl);
        if (StrLength(IO->ConnectMe->CurlCreds))
@@ -556,11 +543,11 @@ evcurl_handle_start(AsyncIO *IO)
        OPT(HTTPHEADER, IO->HttpReq.headers);
 
        IO->NextState = eConnect;
-       EVCURLM_syslog(LOG_DEBUG, "EVCURL: attaching to curl multi handle\n");
+       syslog(LOG_DEBUG, "EVCURL: attaching to curl multi handle\n");
        msta = curl_multi_add_handle(global.mhnd, IO->HttpReq.chnd);
        if (msta)
        {
-               EVCURL_syslog(LOG_ERR,
+               syslog(LOG_ERR,
                          "EVCURL: error attaching to curl multi handle: %s\n",
                          curl_multi_strerror(msta));
        }
@@ -578,7 +565,7 @@ evcurl_handle_start(AsyncIO *IO)
 
 static void WakeupCurlCallback(EV_P_ ev_async *w, int revents)
 {
-       CURLM_syslog(LOG_DEBUG, "waking up curl multi handle\n");
+       syslog(LOG_DEBUG, "waking up curl multi handle\n");
 
        curl_multi_perform(&global, CURL_POLL_NONE);
 }
@@ -587,7 +574,7 @@ static void evcurl_shutdown (void)
 {
        curl_global_cleanup();
        curl_multi_cleanup(global.mhnd);
-       CURLM_syslog(LOG_DEBUG, "exiting\n");
+       syslog(LOG_DEBUG, "exiting\n");
 }
 /*****************************************************************************
  *                       libevent integration                                *
@@ -610,6 +597,8 @@ ev_async ExitEventLoop;
 static void QueueEventAddCallback(EV_P_ ev_async *w, int revents)
 {
        CitContext *Ctx;
+       long IOID = -1;
+       long count = 0;
        ev_tstamp Now;
        HashList *q;
        void *v;
@@ -634,9 +623,11 @@ static void QueueEventAddCallback(EV_P_ ev_async *w, int revents)
        while (GetNextHashPos(q, It, &len, &Key, &v))
        {
                IOAddHandler *h = v;
+               count ++;
                if (h->IO->ID == 0) {
                        h->IO->ID = EvIDSource++;
                }
+               IOID = h->IO->ID;
                if (h->IO->StartIO == 0.0)
                        h->IO->StartIO = Now;
 
@@ -645,7 +636,7 @@ static void QueueEventAddCallback(EV_P_ ev_async *w, int revents)
                Ctx = h->IO->CitContext;
                become_session(Ctx);
 
-               h->IO->Now = Now;
+               h->IO->CitContext->lastcmd = h->IO->Now = Now;
                switch (h->EvAttch(h->IO))
                {
                case eReadMore:
@@ -668,7 +659,7 @@ static void QueueEventAddCallback(EV_P_ ev_async *w, int revents)
        }
        DeleteHashPos(&It);
        DeleteHashContent(&q);
-       EVQM_syslog(LOG_DEBUG, "EVENT Q Add done.\n");
+       syslog(LOG_DEBUG, "%s CC[%ld] EVENT Q Add %ld  done.", IOSTR, IOID, count);
 }
 
 
@@ -676,7 +667,7 @@ static void EventExitCallback(EV_P_ ev_async *w, int revents)
 {
        ev_break(event_base, EVBREAK_ALL);
 
-       EVQM_syslog(LOG_DEBUG, "EVENT Q exiting.\n");
+       syslog(LOG_DEBUG, "EVENT Q exiting.\n");
 }
 
 
@@ -694,6 +685,7 @@ void InitEventQueue(void)
 extern void CtdlDestroyEVCleanupHooks(void);
 
 extern int EVQShutDown;
+const char *IOLog = "IO";
 /*
  * this thread operates the select() etc. via libev.
  */
@@ -702,8 +694,10 @@ void *client_event_thread(void *arg)
        struct CitContext libev_client_CC;
 
        CtdlFillSystemContext(&libev_client_CC, "LibEv Thread");
-//     citthread_setspecific(MyConKey, (void *)&smtp_queue_CC);
-       EVQM_syslog(LOG_DEBUG, "client_event_thread() initializing\n");
+
+       pthread_setspecific(evConKey, IOLog);
+
+       syslog(LOG_DEBUG, "client_event_thread() initializing\n");
 
        event_base = ev_default_loop (EVFLAG_AUTO);
        ev_async_init(&AddJob, QueueEventAddCallback);
@@ -717,7 +711,7 @@ void *client_event_thread(void *arg)
 
        ev_run (event_base, 0);
 
-       EVQM_syslog(LOG_DEBUG, "client_event_thread() exiting\n");
+       syslog(LOG_DEBUG, "client_event_thread() exiting\n");
 
 ///what todo here?     CtdlClearSystemContext();
        pthread_mutex_lock(&EventExitQueueMutex);
@@ -758,6 +752,8 @@ extern void ShutDownDBCLient(AsyncIO *IO);
 static void DBQueueEventAddCallback(EV_P_ ev_async *w, int revents)
 {
        CitContext *Ctx;
+       long IOID = -1;
+       long count = 0;;
        ev_tstamp Now;
        HashList *q;
        void *v;
@@ -784,11 +780,13 @@ static void DBQueueEventAddCallback(EV_P_ ev_async *w, int revents)
        {
                IOAddHandler *h = v;
                eNextState rc;
+               count ++;
                if (h->IO->ID == 0)
                        h->IO->ID = EvIDSource++;
+               IOID = h->IO->ID;
                if (h->IO->StartDB == 0.0)
                        h->IO->StartDB = Now;
-               h->IO->Now = Now;
+               h->IO->CitContext->lastcmd = h->IO->Now = Now;
 
                SetEVState(h->IO, eDBAttach);
                Ctx = h->IO->CitContext;
@@ -805,13 +803,13 @@ static void DBQueueEventAddCallback(EV_P_ ev_async *w, int revents)
        }
        DeleteHashPos(&It);
        DeleteHashContent(&q);
-       EVQM_syslog(LOG_DEBUG, "DBEVENT Q Add done.\n");
+       syslog(LOG_DEBUG, "%s CC[%ld] DBEVENT Q Add %ld done.", IOSTR, IOID, count);
 }
 
 
 static void DBEventExitCallback(EV_P_ ev_async *w, int revents)
 {
-       EVQM_syslog(LOG_DEBUG, "DB EVENT Q exiting.\n");
+       syslog(LOG_DEBUG, "DB EVENT Q exiting.\n");
        ev_break(event_db, EVBREAK_ALL);
 }
 
@@ -828,6 +826,8 @@ void DBInitEventQueue(void)
        DBInboundEventQueue = DBInboundEventQueues[0];
 }
 
+const char *DBLog = "BD";
+
 /*
  * this thread operates writing to the message database via libev.
  */
@@ -836,9 +836,11 @@ void *db_event_thread(void *arg)
        ev_loop *tmp;
        struct CitContext libev_msg_CC;
 
+       pthread_setspecific(evConKey, DBLog);
+
        CtdlFillSystemContext(&libev_msg_CC, "LibEv DB IO Thread");
 
-       EVQM_syslog(LOG_DEBUG, "dbevent_thread() initializing\n");
+       syslog(LOG_DEBUG, "dbevent_thread() initializing\n");
 
        tmp = event_db = ev_loop_new (EVFLAG_AUTO);
 
@@ -852,7 +854,7 @@ void *db_event_thread(void *arg)
        pthread_mutex_lock(&DBEventExitQueueMutex);
 
        event_db = NULL;
-       EVQM_syslog(LOG_INFO, "dbevent_thread() exiting\n");
+       syslog(LOG_INFO, "dbevent_thread() exiting\n");
 
        DeleteHash(&DBQueueEvents);
        DBInboundEventQueue = NULL;
@@ -868,7 +870,7 @@ void *db_event_thread(void *arg)
 
 void ShutDownEventQueues(void)
 {
-       EVQM_syslog(LOG_DEBUG, "EVENT Qs triggering exits.\n");
+       syslog(LOG_DEBUG, "EVENT Qs triggering exits.\n");
 
        pthread_mutex_lock(&DBEventQueueMutex);
        ev_async_send (event_db, &DBExitEventLoop);
@@ -893,10 +895,16 @@ void DebugCurlEnable(const int n)
        DebugCurl = n;
 }
 
+const char *WLog = "WX";
 CTDL_MODULE_INIT(event_client)
 {
        if (!threading)
        {
+               if (pthread_key_create(&evConKey, NULL) != 0) {
+                       syslog(LOG_CRIT, "Can't create TSD key: %s", strerror(errno));
+               }
+               pthread_setspecific(evConKey, WLog);
+
                CtdlRegisterDebugFlagHook(HKEY("eventloop"), DebugEventloopEnable, &DebugEventLoop);
                CtdlRegisterDebugFlagHook(HKEY("eventloopbacktrace"), DebugEventloopBacktraceEnable, &DebugEventLoopBacktrace);
                CtdlRegisterDebugFlagHook(HKEY("curl"), DebugCurlEnable, &DebugCurl);