Logging: add timestamps for eventdriven IO
[citadel.git] / citadel / modules / c-ares-dns / serv_c-ares-dns.c
index a97f5368d6cbbc15efe6684bbb952ab62d8cfa7a..d1b1a027e5f86d2ac33acdad19115058585d4b69 100644 (file)
@@ -1,19 +1,19 @@
 /*
- * Copyright (c) 1998-2009 by the citadel.org team
+ * Copyright (c) 1998-2012 by the citadel.org team
  *
- *  This program is free 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 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.
  *
- *  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
+ *  
+ *  
+ *  
  *
  *  Inspired by NodeJS.org; thanks for the MX-Parser ;-)
  */
@@ -64,195 +64,238 @@ void SockStateCb(void *data, int sock, int read, int write);
 
 
 static void HostByAddrCb(void *data,
-                         int status,
-                         int timeouts,
-                         struct hostent *hostent) 
+                        int status,
+                        int timeouts,
+                        struct hostent *hostent)
 {
        AsyncIO *IO = data;
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
+       EV_DNS_LOGT_STOP(DNS.timeout);
 #endif
-       IO->DNSQuery->DNSStatus = status;
+       ev_timer_stop (event_base, &IO->DNS.timeout);
+
+       IO->DNS.Query->DNSStatus = status;
        if  (status != ARES_SUCCESS) {
-//             ResolveError(*cb, status);
+               StrBufPlain(IO->ErrMsg, ares_strerror(status), -1);
                return;
        }
-       IO->DNSQuery->Data = hostent;
-/// TODO: howto free this??
+       IO->DNS.Query->Data = hostent;
 }
 
-static void ParseAnswerA(AsyncIO *IO, unsigned char* abuf, int alen) 
+static void ParseAnswerA(AsyncIO *IO, unsigned char* abuf, int alen)
 {
-       struct hostent* host;
+       struct hostent* host = NULL;
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
 #endif
 
-       if (IO->DNSQuery->VParsedDNSReply != NULL)
-               IO->DNSQuery->DNSReplyFree(IO->DNSQuery->VParsedDNSReply);
-       IO->DNSQuery->VParsedDNSReply = NULL;
-
-       IO->DNSQuery->DNSStatus = ares_parse_a_reply(abuf, alen, &host, NULL, NULL);
-       if (IO->DNSQuery->DNSStatus != ARES_SUCCESS) {
-//    ResolveError(arg->js_cb, status);
+       if (IO->DNS.Query->VParsedDNSReply != NULL)
+               IO->DNS.Query->DNSReplyFree(IO->DNS.Query->VParsedDNSReply);
+       IO->DNS.Query->VParsedDNSReply = NULL;
+
+       IO->DNS.Query->DNSStatus = ares_parse_a_reply(abuf,
+                                                     alen,
+                                                     &host,
+                                                     NULL,
+                                                     NULL);
+       if (IO->DNS.Query->DNSStatus != ARES_SUCCESS) {
+               if (host != NULL)
+                       ares_free_hostent(host);
+               StrBufPlain(IO->ErrMsg,
+                           ares_strerror(IO->DNS.Query->DNSStatus), -1);
                return;
        }
-       IO->DNSQuery->VParsedDNSReply = host;
-       IO->DNSQuery->DNSReplyFree = (FreeDNSReply) ares_free_hostent;
+       IO->DNS.Query->VParsedDNSReply = host;
+       IO->DNS.Query->DNSReplyFree = (FreeDNSReply) ares_free_hostent;
 }
 
 
-static void ParseAnswerAAAA(AsyncIO *IO, unsigned char* abuf, int alen) 
+static void ParseAnswerAAAA(AsyncIO *IO, unsigned char* abuf, int alen)
 {
-       struct hostent* host;
+       struct hostent* host = NULL;
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
 #endif
 
-       if (IO->DNSQuery->VParsedDNSReply != NULL)
-               IO->DNSQuery->DNSReplyFree(IO->DNSQuery->VParsedDNSReply);
-       IO->DNSQuery->VParsedDNSReply = NULL;
-
-       IO->DNSQuery->DNSStatus = ares_parse_aaaa_reply(abuf, alen, &host, NULL, NULL);
-       if (IO->DNSQuery->DNSStatus != ARES_SUCCESS) {
-//    ResolveError(arg->js_cb, status);
+       if (IO->DNS.Query->VParsedDNSReply != NULL)
+               IO->DNS.Query->DNSReplyFree(IO->DNS.Query->VParsedDNSReply);
+       IO->DNS.Query->VParsedDNSReply = NULL;
+
+       IO->DNS.Query->DNSStatus = ares_parse_aaaa_reply(abuf,
+                                                        alen,
+                                                        &host,
+                                                        NULL,
+                                                        NULL);
+       if (IO->DNS.Query->DNSStatus != ARES_SUCCESS) {
+               if (host != NULL)
+                       ares_free_hostent(host);
+               StrBufPlain(IO->ErrMsg,
+                           ares_strerror(IO->DNS.Query->DNSStatus), -1);
                return;
        }
-       IO->DNSQuery->VParsedDNSReply = host;
-       IO->DNSQuery->DNSReplyFree = (FreeDNSReply) ares_free_hostent;
+       IO->DNS.Query->VParsedDNSReply = host;
+       IO->DNS.Query->DNSReplyFree = (FreeDNSReply) ares_free_hostent;
 }
 
 
-static void ParseAnswerCNAME(AsyncIO *IO, unsigned char* abuf, int alen) 
+static void ParseAnswerCNAME(AsyncIO *IO, unsigned char* abuf, int alen)
 {
-       struct hostent* host;
+       struct hostent* host = NULL;
 
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
 #endif
 
-       if (IO->DNSQuery->VParsedDNSReply != NULL)
-               IO->DNSQuery->DNSReplyFree(IO->DNSQuery->VParsedDNSReply);
-       IO->DNSQuery->VParsedDNSReply = NULL;
-
-       IO->DNSQuery->DNSStatus = ares_parse_a_reply(abuf, alen, &host, NULL, NULL);
-       if (IO->DNSQuery->DNSStatus != ARES_SUCCESS) {
-//    ResolveError(arg->js_cb, status);
+       if (IO->DNS.Query->VParsedDNSReply != NULL)
+               IO->DNS.Query->DNSReplyFree(IO->DNS.Query->VParsedDNSReply);
+       IO->DNS.Query->VParsedDNSReply = NULL;
+
+       IO->DNS.Query->DNSStatus = ares_parse_a_reply(abuf,
+                                                     alen,
+                                                     &host,
+                                                     NULL,
+                                                     NULL);
+       if (IO->DNS.Query->DNSStatus != ARES_SUCCESS) {
+               if (host != NULL)
+                       ares_free_hostent(host);
+               StrBufPlain(IO->ErrMsg,
+                           ares_strerror(IO->DNS.Query->DNSStatus), -1);
                return;
        }
 
        // a CNAME lookup always returns a single record but
-       IO->DNSQuery->VParsedDNSReply = host;
-       IO->DNSQuery->DNSReplyFree = (FreeDNSReply) ares_free_hostent;
+       IO->DNS.Query->VParsedDNSReply = host;
+       IO->DNS.Query->DNSReplyFree = (FreeDNSReply) ares_free_hostent;
 }
 
 
-static void ParseAnswerMX(AsyncIO *IO, unsigned char* abuf, int alen) 
+static void ParseAnswerMX(AsyncIO *IO, unsigned char* abuf, int alen)
 {
-       struct ares_mx_reply *mx_out;
+       struct ares_mx_reply *mx_out = NULL;
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
 #endif
 
-       if (IO->DNSQuery->VParsedDNSReply != NULL)
-               IO->DNSQuery->DNSReplyFree(IO->DNSQuery->VParsedDNSReply);
-       IO->DNSQuery->VParsedDNSReply = NULL;
+       if (IO->DNS.Query->VParsedDNSReply != NULL)
+               IO->DNS.Query->DNSReplyFree(IO->DNS.Query->VParsedDNSReply);
+       IO->DNS.Query->VParsedDNSReply = NULL;
 
-       IO->DNSQuery->DNSStatus = ares_parse_mx_reply(abuf, alen, &mx_out);
-       if (IO->DNSQuery->DNSStatus != ARES_SUCCESS) {
-//    ResolveError(arg->js_cb, status);
+       IO->DNS.Query->DNSStatus = ares_parse_mx_reply(abuf, alen, &mx_out);
+       if (IO->DNS.Query->DNSStatus != ARES_SUCCESS) {
+               if (mx_out != NULL)
+                       ares_free_data(mx_out);
+               StrBufPlain(IO->ErrMsg,
+                           ares_strerror(IO->DNS.Query->DNSStatus), -1);
                return;
        }
 
-       IO->DNSQuery->VParsedDNSReply = mx_out;
-       IO->DNSQuery->DNSReplyFree = (FreeDNSReply) ares_free_data;
+       IO->DNS.Query->VParsedDNSReply = mx_out;
+       IO->DNS.Query->DNSReplyFree = (FreeDNSReply) ares_free_data;
 }
 
 
-static void ParseAnswerNS(AsyncIO *IO, unsigned char* abuf, int alen) 
+static void ParseAnswerNS(AsyncIO *IO, unsigned char* abuf, int alen)
 {
-       struct hostent* host;
+       struct hostent* host = NULL;
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
 #endif
 
-       if (IO->DNSQuery->VParsedDNSReply != NULL)
-               IO->DNSQuery->DNSReplyFree(IO->DNSQuery->VParsedDNSReply);
-       IO->DNSQuery->VParsedDNSReply = NULL;
+       if (IO->DNS.Query->VParsedDNSReply != NULL)
+               IO->DNS.Query->DNSReplyFree(IO->DNS.Query->VParsedDNSReply);
+       IO->DNS.Query->VParsedDNSReply = NULL;
 
-       IO->DNSQuery->DNSStatus = ares_parse_ns_reply(abuf, alen, &host);
-       if (IO->DNSQuery->DNSStatus != ARES_SUCCESS) {
-//    ResolveError(arg->js_cb, status);
+       IO->DNS.Query->DNSStatus = ares_parse_ns_reply(abuf, alen, &host);
+       if (IO->DNS.Query->DNSStatus != ARES_SUCCESS) {
+               if (host != NULL)
+                       ares_free_hostent(host);
+               StrBufPlain(IO->ErrMsg,
+                           ares_strerror(IO->DNS.Query->DNSStatus), -1);
                return;
        }
-       IO->DNSQuery->VParsedDNSReply = host;
-       IO->DNSQuery->DNSReplyFree = (FreeDNSReply) ares_free_hostent;
+       IO->DNS.Query->VParsedDNSReply = host;
+       IO->DNS.Query->DNSReplyFree = (FreeDNSReply) ares_free_hostent;
 }
 
 
-static void ParseAnswerSRV(AsyncIO *IO, unsigned char* abuf, int alen) 
+static void ParseAnswerSRV(AsyncIO *IO, unsigned char* abuf, int alen)
 {
-       struct ares_srv_reply *srv_out;
+       struct ares_srv_reply *srv_out = NULL;
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
 #endif
 
-       if (IO->DNSQuery->VParsedDNSReply != NULL)
-               IO->DNSQuery->DNSReplyFree(IO->DNSQuery->VParsedDNSReply);
-       IO->DNSQuery->VParsedDNSReply = NULL;
+       if (IO->DNS.Query->VParsedDNSReply != NULL)
+               IO->DNS.Query->DNSReplyFree(IO->DNS.Query->VParsedDNSReply);
+       IO->DNS.Query->VParsedDNSReply = NULL;
 
-       IO->DNSQuery->DNSStatus = ares_parse_srv_reply(abuf, alen, &srv_out);
-       if (IO->DNSQuery->DNSStatus != ARES_SUCCESS) {
-//    ResolveError(arg->js_cb, status);
+       IO->DNS.Query->DNSStatus = ares_parse_srv_reply(abuf, alen, &srv_out);
+       if (IO->DNS.Query->DNSStatus != ARES_SUCCESS) {
+               if (srv_out != NULL)
+                       ares_free_data(srv_out);
+               StrBufPlain(IO->ErrMsg,
+                           ares_strerror(IO->DNS.Query->DNSStatus), -1);
                return;
        }
 
-       IO->DNSQuery->VParsedDNSReply = srv_out;
-       IO->DNSQuery->DNSReplyFree = (FreeDNSReply) ares_free_data;
+       IO->DNS.Query->VParsedDNSReply = srv_out;
+       IO->DNS.Query->DNSReplyFree = (FreeDNSReply) ares_free_data;
 }
 
 
-static void ParseAnswerTXT(AsyncIO *IO, unsigned char* abuf, int alen) 
+static void ParseAnswerTXT(AsyncIO *IO, unsigned char* abuf, int alen)
 {
        struct ares_txt_reply *txt_out;
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
 #endif
 
-       if (IO->DNSQuery->VParsedDNSReply != NULL)
-               IO->DNSQuery->DNSReplyFree(IO->DNSQuery->VParsedDNSReply);
-       IO->DNSQuery->VParsedDNSReply = NULL;
+       if (IO->DNS.Query->VParsedDNSReply != NULL)
+               IO->DNS.Query->DNSReplyFree(IO->DNS.Query->VParsedDNSReply);
+       IO->DNS.Query->VParsedDNSReply = NULL;
 
-       IO->DNSQuery->DNSStatus = ares_parse_txt_reply(abuf, alen, &txt_out);
-       if (IO->DNSQuery->DNSStatus != ARES_SUCCESS) {
-//    ResolveError(arg->js_cb, status);
+       IO->DNS.Query->DNSStatus = ares_parse_txt_reply(abuf, alen, &txt_out);
+       if (IO->DNS.Query->DNSStatus != ARES_SUCCESS) {
+               if (txt_out != NULL)
+                       ares_free_data(txt_out);
+               StrBufPlain(IO->ErrMsg,
+                           ares_strerror(IO->DNS.Query->DNSStatus), -1);
                return;
        }
-       IO->DNSQuery->VParsedDNSReply = txt_out;
-       IO->DNSQuery->DNSReplyFree = (FreeDNSReply) ares_free_data;
+       IO->DNS.Query->VParsedDNSReply = txt_out;
+       IO->DNS.Query->DNSReplyFree = (FreeDNSReply) ares_free_data;
 }
 
 void QueryCb(void *arg,
             int status,
             int timeouts,
             unsigned char* abuf,
-            int alen) 
+            int alen)
 {
        AsyncIO *IO = arg;
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
+       EV_DNS_LOGT_STOP(DNS.timeout);
 #endif
+       ev_timer_stop (event_base, &IO->DNS.timeout);
 
-       IO->DNSQuery->DNSStatus = status;
+       IO->DNS.Query->DNSStatus = status;
        if (status == ARES_SUCCESS)
-               IO->DNSQuery->DNS_CB(arg, abuf, alen);
-       else
-               IO->DNSQuery->DNSStatus = status;
-///    ev_io_stop(event_base, &IO->DNSQuery->dns_io_event);
-       
+               IO->DNS.Query->DNS_CB(arg, abuf, alen);
+       else {
+               EV_syslog(LOG_DEBUG, "C-ARES: Failed by: %s error %s\n",
+                         __FUNCTION__,
+                         ares_strerror(status));
+               StrBufPlain(IO->ErrMsg, ares_strerror(status), -1);
+               IO->DNS.Query->DNSStatus = status;
+       }
+
        ev_idle_init(&IO->unwind_stack,
                     IO_postdns_callback);
        IO->unwind_stack.data = IO;
+       EV_DNS_LOGT_INIT(unwind_stack);
+       EV_DNS_LOGT_START(unwind_stack);
        ev_idle_start(event_base, &IO->unwind_stack);
 }
 
@@ -260,28 +303,71 @@ void QueryCbDone(AsyncIO *IO)
 {
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
+       EV_DNS_LOGT_STOP(DNS.timeout);
 #endif
 
        ev_idle_stop(event_base, &IO->unwind_stack);
 }
 
+void DestructCAres(AsyncIO *IO)
+{
+#ifdef DEBUG_CARES
+       EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
+       EV_DNS_LOGT_STOP(DNS.timeout);
+#endif
+       EV_DNS_LOG_STOP(DNS.recv_event);
+       ev_io_stop(event_base, &IO->DNS.recv_event);
+       EV_DNS_LOG_STOP(DNS.send_event);
+       ev_io_stop(event_base, &IO->DNS.send_event);
+       ev_timer_stop (event_base, &IO->DNS.timeout);
+       ev_idle_stop(event_base, &IO->unwind_stack);
+       ares_destroy_options(&IO->DNS.Options);
+}
+
 
 void InitC_ares_dns(AsyncIO *IO)
 {
        int optmask = 0;
 #ifdef DEBUG_CARES
-       EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
+       EV_syslog(LOG_DEBUG, "C-ARES: %s %p\n", __FUNCTION__, IO->DNS.Channel);
 #endif
 
-       if (IO->DNSChannel == NULL) {
+       if (IO->DNS.Channel == NULL) {
                optmask |= ARES_OPT_SOCK_STATE_CB;
-               IO->DNSOptions.sock_state_cb = SockStateCb;
-               IO->DNSOptions.sock_state_cb_data = IO;
-               ares_init_options(&IO->DNSChannel, &IO->DNSOptions, optmask);
+               IO->DNS.Options.sock_state_cb = SockStateCb;
+               IO->DNS.Options.sock_state_cb_data = IO;
+               ares_init_options(&IO->DNS.Channel, &IO->DNS.Options, optmask);
+       }
+       IO->DNS.Query->DNSStatus = 0;
+}
+
+static void
+DNStimeouttrigger_callback(struct ev_loop *loop, ev_timer *watcher, int revents)
+{
+       AsyncIO *IO = watcher->data;
+       struct timeval tv, MaxTV;
+       struct timeval *NextTV;
+
+       memset(&MaxTV, 0, sizeof(MaxTV));
+       memset(&tv, 0, sizeof(tv));
+       MaxTV.tv_sec = 30;
+       NextTV = ares_timeout(IO->DNS.Channel, &MaxTV, &tv);
+
+       if ((NextTV->tv_sec != MaxTV.tv_sec) ||
+           (NextTV->tv_usec != MaxTV.tv_usec))
+       {
+               fd_set readers, writers;
+#ifdef DEBUG_CARES
+               EV_syslog(LOG_DEBUG, "C-ARES: %s Timeout!\n", __FUNCTION__);
+#endif
+               FD_ZERO(&readers);
+               FD_ZERO(&writers);
+               ares_fds(IO->DNS.Channel, &readers, &writers);
+               ares_process(IO->DNS.Channel, &readers, &writers);
        }
 }
 
-void QueueGetHostByNameDone(void *Ctx, 
+void QueueGetHostByNameDone(void *Ctx,
                            int status,
                            int timeouts,
                            struct hostent *hostent)
@@ -291,71 +377,97 @@ void QueueGetHostByNameDone(void *Ctx,
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
 #endif
 
-       IO->DNSQuery->DNSStatus = status;
-       IO->DNSQuery->VParsedDNSReply = hostent;
-       IO->DNSQuery->DNSReplyFree = (FreeDNSReply) ares_free_hostent;
+       IO->DNS.Query->DNSStatus = status;
+       IO->DNS.Query->VParsedDNSReply = hostent;
+       IO->DNS.Query->DNSReplyFree = (FreeDNSReply) ares_free_hostent;
 
        ev_idle_init(&IO->unwind_stack,
                     IO_postdns_callback);
        IO->unwind_stack.data = IO;
+       EV_DNS_LOGT_INIT(unwind_stack);
+       EV_DNS_LOGT_START(unwind_stack);
        ev_idle_start(event_base, &IO->unwind_stack);
+       ev_timer_stop (event_base, &IO->DNS.timeout);
 }
 
-void QueueGetHostByName(AsyncIO *IO, const char *Hostname, DNSQueryParts *QueryParts, IO_CallBack PostDNS)
+void QueueGetHostByName(AsyncIO *IO,
+                       const char *Hostname,
+                       DNSQueryParts *QueryParts,
+                       IO_CallBack PostDNS)
 {
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
+       IO->DNS.SourcePort = 0;
 #endif
 
-       IO->DNSQuery = QueryParts;
-       IO->DNSQuery->PostDNS = PostDNS;
+       IO->DNS.Query = QueryParts;
+       IO->DNS.Query->PostDNS = PostDNS;
 
        InitC_ares_dns(IO);
 
-       ares_gethostbyname(IO->DNSChannel,
-                          Hostname,   
+       ev_timer_init(&IO->DNS.timeout, DNStimeouttrigger_callback, 10, 1);
+       EV_DNS_LOGT_INIT(DNS.timeout);
+       IO->DNS.timeout.data = IO;
+       ares_gethostbyname(IO->DNS.Channel,
+                          Hostname,
                           AF_INET6, /* it falls back to ipv4 in doubt... */
                           QueueGetHostByNameDone,
                           IO);
-//get_one_mx_host_ip_done);
+       EV_DNS_LOGT_START(DNS.timeout);
+       ev_timer_start(event_base, &IO->DNS.timeout);
+
 }
-int QueueQuery(ns_type Type, const char *name, AsyncIO *IO, DNSQueryParts *QueryParts, IO_CallBack PostDNS)
+
+int QueueQuery(ns_type Type,
+              const char *name,
+              AsyncIO *IO,
+              DNSQueryParts *QueryParts,
+              IO_CallBack PostDNS)
 {
        int length, family;
        char address_b[sizeof(struct in6_addr)];
 
-       IO->DNSQuery = QueryParts;
-       IO->DNSQuery->PostDNS = PostDNS;
+#ifdef DEBUG_CARES
+       IO->DNS.SourcePort = 0;
+#endif
+
+       IO->DNS.Query = QueryParts;
+       IO->DNS.Query->PostDNS = PostDNS;
+       IO->DNS.Start = IO->Now;
 
        InitC_ares_dns(IO);
 
+       ev_timer_init(&IO->DNS.timeout, DNStimeouttrigger_callback, 10, 1);
+       IO->DNS.timeout.data = IO;
+       EV_DNS_LOGT_INIT(DNS.timeout);
+
        switch(Type) {
        case ns_t_a:
-               IO->DNSQuery->DNS_CB = ParseAnswerA;
+               IO->DNS.Query->DNS_CB = ParseAnswerA;
                break;
 
        case ns_t_aaaa:
-               IO->DNSQuery->DNS_CB = ParseAnswerAAAA;
+               IO->DNS.Query->DNS_CB = ParseAnswerAAAA;
                break;
 
        case ns_t_mx:
-               IO->DNSQuery->DNS_CB = ParseAnswerMX;
+               IO->DNS.Query->DNS_CB = ParseAnswerMX;
                break;
 
        case ns_t_ns:
-               IO->DNSQuery->DNS_CB = ParseAnswerNS;
+               IO->DNS.Query->DNS_CB = ParseAnswerNS;
                break;
 
        case ns_t_txt:
-               IO->DNSQuery->DNS_CB = ParseAnswerTXT;
+               IO->DNS.Query->DNS_CB = ParseAnswerTXT;
                break;
 
        case ns_t_srv:
-               IO->DNSQuery->DNS_CB = ParseAnswerSRV;
+               IO->DNS.Query->DNS_CB = ParseAnswerSRV;
                break;
 
        case ns_t_cname:
-               IO->DNSQuery->DNS_CB = ParseAnswerCNAME;
+               IO->DNS.Query->DNS_CB = ParseAnswerCNAME;
                break;
 
        case ns_t_ptr:
@@ -371,8 +483,14 @@ int QueueQuery(ns_type Type, const char *name, AsyncIO *IO, DNSQueryParts *Query
                        return -1;
                }
 
-               ares_gethostbyaddr(IO->DNSChannel, address_b, length, family, HostByAddrCb, IO);
-
+               ares_gethostbyaddr(IO->DNS.Channel,
+                                  address_b,
+                                  length,
+                                  family,
+                                  HostByAddrCb,
+                                  IO);
+               EV_DNS_LOGT_START(DNS.timeout);
+               ev_timer_start(event_base, &IO->DNS.timeout);
 #ifdef DEBUG_CARES
                EV_syslog(LOG_DEBUG, "C-ARES: %s X1\n", __FUNCTION__);
 #endif
@@ -387,7 +505,9 @@ int QueueQuery(ns_type Type, const char *name, AsyncIO *IO, DNSQueryParts *Query
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
 #endif
-       ares_query(IO->DNSChannel, name, ns_c_in, Type, QueryCb, IO);
+       ares_query(IO->DNS.Channel, name, ns_c_in, Type, QueryCb, IO);
+       EV_DNS_LOGT_START(DNS.timeout);
+       ev_timer_start(event_base, &IO->DNS.timeout);
        return 1;
 }
 
@@ -396,90 +516,97 @@ int QueueQuery(ns_type Type, const char *name, AsyncIO *IO, DNSQueryParts *Query
 
 
 /*****************************************************************************
- *                   libevent / c-ares integration                           *
+ *                      libev / c-ares integration                           *
  *****************************************************************************/
 static void DNS_send_callback(struct ev_loop *loop, ev_io *watcher, int revents)
 {
        AsyncIO *IO = watcher->data;
-       
+
+       IO->Now = ev_now(event_base);
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
 #endif
 
-       ares_process_fd(IO->DNSChannel, ARES_SOCKET_BAD, IO->dns_send_event.fd);
+       ares_process_fd(IO->DNS.Channel,
+                       ARES_SOCKET_BAD,
+                       IO->DNS.send_event.fd);
 }
 static void DNS_recv_callback(struct ev_loop *loop, ev_io *watcher, int revents)
 {
        AsyncIO *IO = watcher->data;
-       
+
+       IO->Now = ev_now(event_base);
+
 #ifdef DEBUG_CARES
        EV_syslog(LOG_DEBUG, "C-ARES: %s\n", __FUNCTION__);
 #endif
 
-       ares_process_fd(IO->DNSChannel, IO->dns_recv_event.fd, ARES_SOCKET_BAD);
+       ares_process_fd(IO->DNS.Channel,
+                       IO->DNS.recv_event.fd,
+                       ARES_SOCKET_BAD);
 }
 
-void SockStateCb(void *data, int sock, int read, int write) 
+void SockStateCb(void *data, int sock, int read, int write)
 {
-       /*
-       struct timeval tvbuf, maxtv, *ret;
-       
-       int64_t time = 10;
-*/
        AsyncIO *IO = data;
 /* already inside of the event queue. */
 #ifdef DEBUG_CARES
 {
        struct sockaddr_in sin = {};
        socklen_t slen;
-       slen = sizeof(sin);     
-       if ((IO->DnsSourcePort == 0) && 
+       slen = sizeof(sin);
+       if ((IO->DNS.SourcePort == 0) &&
            (getsockname(sock, &sin, &slen) == 0))
        {
-               IO->DnsSourcePort = ntohs(sin.sin_port);
+               IO->DNS.SourcePort = ntohs(sin.sin_port);
        }
        EV_syslog(LOG_DEBUG, "C-ARES: %s %d|%d Sock %d port %hu\n",
                  __FUNCTION__,
                  read,
                  write,
                  sock,
-                 IO->DnsSourcePort);
+                 IO->DNS.SourcePort);
 }
 #endif
+       IO->Now = ev_now(event_base);
 
        if (read) {
-               if ((IO->dns_recv_event.fd != sock) &&
-                   (IO->dns_recv_event.fd != 0)) {
-                       ev_io_stop(event_base, &IO->dns_recv_event);
+               if ((IO->DNS.recv_event.fd != sock) &&
+                   (IO->DNS.recv_event.fd != 0)) {
+                       EV_DNS_LOG_STOP(DNS.recv_event);
+                       ev_io_stop(event_base, &IO->DNS.recv_event);
                }
-               IO->dns_recv_event.fd = sock;
-               ev_io_init(&IO->dns_recv_event, DNS_recv_callback, IO->dns_recv_event.fd, EV_READ);
-               IO->dns_recv_event.data = IO;
-               ev_io_start(event_base, &IO->dns_recv_event);
-       } 
+               IO->DNS.recv_event.fd = sock;
+               ev_io_init(&IO->DNS.recv_event,
+                          DNS_recv_callback,
+                          IO->DNS.recv_event.fd,
+                          EV_READ);
+               EV_DNS_LOG_INIT(DNS.recv_event);
+               IO->DNS.recv_event.data = IO;
+               EV_DNS_LOG_START(DNS.recv_event);
+               ev_io_start(event_base, &IO->DNS.recv_event);
+       }
        if (write) {
-               if ((IO->dns_send_event.fd != sock) &&
-                   (IO->dns_send_event.fd != 0)) {
-                       ev_io_stop(event_base, &IO->dns_send_event);
+               if ((IO->DNS.send_event.fd != sock) &&
+                   (IO->DNS.send_event.fd != 0)) {
+                       EV_DNS_LOG_STOP(DNS.send_event);
+                       ev_io_stop(event_base, &IO->DNS.send_event);
                }
-               IO->dns_send_event.fd = sock;
-               ev_io_init(&IO->dns_send_event, DNS_send_callback, IO->dns_send_event.fd, EV_WRITE);
-               IO->dns_send_event.data = IO;
-               ev_io_start(event_base, &IO->dns_send_event);
-       }
-/*
-
-               ev_io_start(event_base, &IO->dns_io_event);
-       
-               maxtv.tv_sec = time/1000;
-               maxtv.tv_usec = (time % 1000) * 1000;
-               
-               ret = ares_timeout(IO->DNSChannel, &maxtv, &tvbuf);
+               IO->DNS.send_event.fd = sock;
+               ev_io_init(&IO->DNS.send_event,
+                          DNS_send_callback,
+                          IO->DNS.send_event.fd,
+                          EV_WRITE);
+               IO->DNS.send_event.data = IO;
+               EV_DNS_LOG_INIT(DNS.send_event);
+               EV_DNS_LOG_START(DNS.send_event);
+               ev_io_start(event_base, &IO->DNS.send_event);
        }
-*/
        if ((read == 0) && (write == 0)) {
-               ev_io_stop(event_base, &IO->dns_recv_event);
-               ev_io_stop(event_base, &IO->dns_send_event);
+               EV_DNS_LOG_STOP(DNS.recv_event);
+               EV_DNS_LOG_STOP(DNS.send_event);
+               ev_io_stop(event_base, &IO->DNS.recv_event);
+               ev_io_stop(event_base, &IO->DNS.send_event);
        }
 }
 
@@ -489,9 +616,7 @@ CTDL_MODULE_INIT(c_ares_client)
        {
                int r = ares_library_init(ARES_LIB_INIT_ALL);
                if (0 != r) {
-                       // TODO
-                       // ThrowException(Exception::Error(String::New(ares_strerror(r))));
-////                   assert(r == 0);
+                       
                }
        }
        return "c-ares";