afb-trace: Restore microsecond time
[src/app-framework-binder.git] / src / afb-trace.c
index fb8cc19..5404a5a 100644 (file)
@@ -1,5 +1,5 @@
 /*
- * Copyright (C) 2016, 2017 "IoT.bzh"
+ * Copyright (C) 2016, 2017, 2018 "IoT.bzh"
  * Author José Bollo <jose.bollo@iot.bzh>
  *
  * Licensed under the Apache License, Version 2.0 (the "License");
@@ -27,6 +27,7 @@
 #include <pthread.h>
 
 #include <json-c/json.h>
+
 #define AFB_BINDING_VERSION 0
 #include <afb/afb-binding.h>
 
@@ -36,6 +37,7 @@
 #include "afb-xreq.h"
 #include "afb-export.h"
 #include "afb-evt.h"
+#include "afb-session.h"
 #include "afb-trace.h"
 
 #include "wrap-json.h"
@@ -76,10 +78,9 @@ struct event {
 };
 
 /* struct for sessions */
-struct session {
-       struct session *next;           /* link to the next session */
-       struct afb_session *session;    /* the session */
-       struct afb_trace *trace;        /* the tracer */
+struct cookie {
+       struct afb_session *session;    /* the session */
+       struct afb_trace *trace;        /* the tracer */
 };
 
 /* struct for recording hooks */
@@ -88,7 +89,7 @@ struct hook {
        void *handler;                  /* the handler of the hook */
        struct event *event;            /* the associated event */
        struct tag *tag;                /* the associated tag */
-       struct session *session;        /* the associated session */
+       struct afb_session *session;    /* the associated session */
 };
 
 /* types of hooks */
@@ -98,6 +99,7 @@ enum trace_type
        Trace_Type_Ditf,        /* export hooks */
        Trace_Type_Svc,         /* export hooks */
        Trace_Type_Evt,         /* evt hooks */
+       Trace_Type_Session,     /* session hooks */
        Trace_Type_Global,      /* global hooks */
        Trace_Type_Count        /* count of types of hooks */
 };
@@ -107,11 +109,10 @@ struct afb_trace
 {
        int refcount;                           /* reference count */
        pthread_mutex_t mutex;                  /* concurrency management */
-       struct afb_daemon *daemon;              /* daemon */
+       const char *apiname;                    /* api name for events */
        struct afb_session *bound;              /* bound to session */
        struct event *events;                   /* list of events */
        struct tag *tags;                       /* list of tags */
-       struct session *sessions;               /* list of tags */
        struct hook *hooks[Trace_Type_Count];   /* hooks */
 };
 
@@ -230,6 +231,7 @@ static struct flag xreq_flags[] = { /* must be sorted by names */
                { "fail",               afb_hook_flag_req_fail },
                { "get",                afb_hook_flag_req_get },
                { "get_application_id", afb_hook_flag_req_get_application_id },
+               { "get_uid",            afb_hook_flag_req_get_uid },
                { "has_permission",     afb_hook_flag_req_has_permission },
                { "json",               afb_hook_flag_req_json },
                { "life",               afb_hook_flags_req_life },
@@ -366,8 +368,8 @@ static void hook_xreq_subscribe(void *closure, const struct afb_hookid *hookid,
 {
        hook_xreq(closure, hookid, xreq, "subscribe", "{s{ss si} si}",
                                        "event",
-                                               "name", afb_evt_event_fullname(eventid),
-                                               "id", afb_evt_event_id(eventid),
+                                               "name", afb_evt_eventid_fullname(eventid),
+                                               "id", afb_evt_eventid_id(eventid),
                                        "result", result);
 }
 
@@ -375,8 +377,8 @@ static void hook_xreq_unsubscribe(void *closure, const struct afb_hookid *hookid
 {
        hook_xreq(closure, hookid, xreq, "unsubscribe", "{s{ss? si} si}",
                                        "event",
-                                               "name", afb_evt_event_fullname(eventid),
-                                               "id", afb_evt_event_id(eventid),
+                                               "name", afb_evt_eventid_fullname(eventid),
+                                               "id", afb_evt_eventid_id(eventid),
                                        "result", result);
 }
 
@@ -489,6 +491,12 @@ static void hook_xreq_context_make(void *closure, const struct afb_hookid *hooki
                                        "result", pr);
 }
 
+static void hook_xreq_get_uid(void *closure, const struct afb_hookid *hookid, const struct afb_xreq *xreq, int result)
+{
+       hook_xreq(closure, hookid, xreq, "get_uid", "{si}",
+                                       "result", result);
+}
+
 static struct afb_hook_xreq_itf hook_xreq_itf = {
        .hook_xreq_begin = hook_xreq_begin,
        .hook_xreq_end = hook_xreq_end,
@@ -515,7 +523,8 @@ static struct afb_hook_xreq_itf hook_xreq_itf = {
        .hook_xreq_subcall_req_result = hook_xreq_subcall_req_result,
        .hook_xreq_has_permission = hook_xreq_has_permission,
        .hook_xreq_get_application_id = hook_xreq_get_application_id,
-       .hook_xreq_context_make = hook_xreq_context_make
+       .hook_xreq_context_make = hook_xreq_context_make,
+       .hook_xreq_get_uid = hook_xreq_get_uid,
 };
 
 /*******************************************************************************/
@@ -615,7 +624,7 @@ static void hook_ditf_vverbose(void *closure, const struct afb_hookid *hookid, c
 static void hook_ditf_event_make(void *closure, const struct afb_hookid *hookid, const struct afb_export *export, const char *name, struct afb_eventid *result)
 {
        hook_ditf(closure, hookid, export, "event_make", "{ss ss si}",
-                       "name", name, "event", afb_evt_event_fullname(result), "id", afb_evt_event_id(result));
+                       "name", name, "event", afb_evt_eventid_fullname(result), "id", afb_evt_eventid_id(result));
 }
 
 static void hook_ditf_rootdir_get_fd(void *closure, const struct afb_hookid *hookid, const struct afb_export *export, int result)
@@ -863,6 +872,77 @@ static struct afb_hook_evt_itf hook_evt_itf = {
        .hook_evt_unref = hook_evt_unref
 };
 
+/*******************************************************************************/
+/*****  trace the sessions                                                 *****/
+/*******************************************************************************/
+
+static struct flag session_flags[] = { /* must be sorted by names */
+               { "addref",             afb_hook_flag_session_addref },
+               { "all",                afb_hook_flags_session_all },
+               { "close",              afb_hook_flag_session_close },
+               { "common",             afb_hook_flags_session_common },
+               { "create",             afb_hook_flag_session_create },
+               { "destroy",            afb_hook_flag_session_destroy },
+               { "renew",              afb_hook_flag_session_renew },
+               { "unref",              afb_hook_flag_session_unref },
+};
+
+/* get the session value for flag of 'name' */
+static int get_session_flag(const char *name)
+{
+       return get_flag(name, session_flags, (int)(sizeof session_flags / sizeof *session_flags));
+}
+
+static void hook_session(void *closure, const struct afb_hookid *hookid, struct afb_session *session, const char *action, const char *format, ...)
+{
+       va_list ap;
+
+       va_start(ap, format);
+       emit(closure, hookid, "session", "{ss ss}", format, ap,
+                                       "uuid", session,
+                                       "action", action);
+       va_end(ap);
+}
+
+static void hook_session_create(void *closure, const struct afb_hookid *hookid, struct afb_session *session)
+{
+       hook_session(closure, hookid, session, "create", "{ss}", "token", afb_session_token(session));
+}
+
+static void hook_session_close(void *closure, const struct afb_hookid *hookid, struct afb_session *session)
+{
+       hook_session(closure, hookid, session, "close", NULL);
+}
+
+static void hook_session_destroy(void *closure, const struct afb_hookid *hookid, struct afb_session *session)
+{
+       hook_session(closure, hookid, session, "destroy", NULL);
+}
+
+static void hook_session_renew(void *closure, const struct afb_hookid *hookid, struct afb_session *session)
+{
+       hook_session(closure, hookid, session, "renew", "{ss}", "token", afb_session_token(session));
+}
+
+static void hook_session_addref(void *closure, const struct afb_hookid *hookid, struct afb_session *session)
+{
+       hook_session(closure, hookid, session, "addref", NULL);
+}
+
+static void hook_session_unref(void *closure, const struct afb_hookid *hookid, struct afb_session *session)
+{
+       hook_session(closure, hookid, session, "unref", NULL);
+}
+
+static struct afb_hook_session_itf hook_session_itf = {
+       .hook_session_create = hook_session_create,
+       .hook_session_close = hook_session_close,
+       .hook_session_destroy = hook_session_destroy,
+       .hook_session_renew = hook_session_renew,
+       .hook_session_addref = hook_session_addref,
+       .hook_session_unref = hook_session_unref
+};
+
 /*******************************************************************************/
 /*****  trace the globals                                                  *****/
 /*******************************************************************************/
@@ -954,6 +1034,12 @@ abstracting[Trace_Type_Count] =
                .unref =  (void(*)(void*))afb_hook_unref_evt,
                .get_flag = get_evt_flag
        },
+       [Trace_Type_Session] =
+       {
+               .name = "session",
+               .unref =  (void(*)(void*))afb_hook_unref_session,
+               .get_flag = get_session_flag
+       },
        [Trace_Type_Global] =
        {
                .name = "global",
@@ -967,7 +1053,7 @@ abstracting[Trace_Type_Count] =
 /*******************************************************************************/
 
 /* drop hooks of 'trace' matching 'tag' and 'event' and 'session' */
-static void trace_unhook(struct afb_trace *trace, struct tag *tag, struct event *event, struct session *session)
+static void trace_unhook(struct afb_trace *trace, struct tag *tag, struct event *event, struct afb_session *session)
 {
        int i;
        struct hook *hook, **prev;
@@ -996,24 +1082,7 @@ static void trace_cleanup(struct afb_trace *trace)
        struct hook *hook;
        struct tag *tag, **ptag;
        struct event *event, **pevent;
-       struct session *session, **psession;
 
-       /* clean sessions */
-       psession = &trace->sessions;
-       while ((session = *psession)) {
-               /* search for session */
-               for (hook = NULL, i = 0 ; !hook && i < Trace_Type_Count ; i++)
-                       for (hook = trace->hooks[i] ; hook && hook->session != session ; hook = hook->next);
-               /* keep or free whether used or not */
-               if (hook)
-                       psession = &session->next;
-               else {
-                       *psession = session->next;
-                       if (__atomic_exchange_n(&session->trace, NULL, __ATOMIC_RELAXED))
-                               afb_session_set_cookie(session->session, session, NULL, NULL);
-                       free(session);
-               }
-       }
        /* clean tags */
        ptag = &trace->tags;
        while ((tag = *ptag)) {
@@ -1045,19 +1114,6 @@ static void trace_cleanup(struct afb_trace *trace)
        }
 }
 
-/* callback at end of traced session */
-static void free_session_cookie(void *cookie)
-{
-       struct session *session = cookie;
-       struct afb_trace *trace = __atomic_exchange_n(&session->trace, NULL, __ATOMIC_RELAXED);
-       if (trace) {
-               pthread_mutex_lock(&trace->mutex);
-               trace_unhook(trace, NULL, NULL, session);
-               trace_cleanup(trace);
-               pthread_mutex_unlock(&trace->mutex);
-       }
-}
-
 /*
  * Get the tag of 'name' within 'trace'.
  * If 'alloc' isn't zero, create the tag and add it.
@@ -1089,7 +1145,6 @@ static struct tag *trace_get_tag(struct afb_trace *trace, const char *name, int
  */
 static struct event *trace_get_event(struct afb_trace *trace, const char *name, int alloc)
 {
-       struct afb_event e;
        struct event *event;
 
        /* search the event */
@@ -1100,8 +1155,7 @@ static struct event *trace_get_event(struct afb_trace *trace, const char *name,
        if (!event && alloc) {
                event = malloc(sizeof * event);
                if (event) {
-                       e = afb_daemon_make_event_v1(*trace->daemon, name);
-                       event->evtid = afb_evt_to_evtid(afb_event_to_eventid(e));
+                       event->evtid = afb_evt_evtid_create2(trace->apiname, name);
                        if (event->evtid) {
                                event->next = trace->events;
                                trace->events = event;
@@ -1115,41 +1169,48 @@ static struct event *trace_get_event(struct afb_trace *trace, const char *name,
 }
 
 /*
- * Get the session of 'value' within 'trace'.
- * If 'alloc' isn't zero, create the session and add it.
+ * called on session closing
  */
-static struct session *trace_get_session(struct afb_trace *trace, struct afb_session *value, int alloc)
-{
-       struct session *session;
-
-       /* search the session */
-       session = trace->sessions;
-       while (session && session->session != value)
-               session = session->next;
-
-       if (!session && alloc) {
-               session = malloc(sizeof * session);
-               if (session) {
-                       session->session = value;
-                       session->trace = NULL;
-                       session->next = trace->sessions;
-                       trace->sessions = session;
-               }
-       }
-       return session;
+static void session_closed(void *item)
+{
+       struct cookie *cookie = item;
+
+       pthread_mutex_lock(&cookie->trace->mutex);
+       trace_unhook(cookie->trace, NULL, NULL, cookie->session);
+       pthread_mutex_unlock(&cookie->trace->mutex);
+       free(cookie);
+}
+
+/*
+ * records the cookie of session for tracking close
+ */
+static void *session_open(void *closure)
+{
+       struct cookie *param = closure, *cookie;
+       cookie = malloc(sizeof *cookie);
+       if (cookie)
+               *cookie = *param;
+       return cookie;
 }
 
 /*
  * Get the session of 'uuid' within 'trace'.
  * If 'alloc' isn't zero, create the session and add it.
  */
-static struct session *trace_get_session_by_uuid(struct afb_trace *trace, const char *uuid, int alloc)
+static struct afb_session *trace_get_session_by_uuid(struct afb_trace *trace, const char *uuid, int alloc)
 {
-       struct afb_session *session;
-       int created;
+       struct cookie cookie;
 
-       session = afb_session_get(uuid, alloc ? &created : NULL);
-       return session ? trace_get_session(trace, session, alloc) : NULL;
+       if (!alloc)
+               cookie.session = afb_session_search(uuid);
+       else {
+               cookie.session = afb_session_get(uuid, AFB_SESSION_TIMEOUT_DEFAULT, NULL);
+               if (cookie.session) {
+                       cookie.trace = trace;
+                       afb_session_cookie(cookie.session, cookie.trace, session_open, session_closed, &cookie, 0);
+               }
+       }
+       return cookie.session;
 }
 
 static struct hook *trace_make_detached_hook(struct afb_trace *trace, const char *event, const char *tag)
@@ -1170,13 +1231,8 @@ static struct hook *trace_make_detached_hook(struct afb_trace *trace, const char
 
 static void trace_attach_hook(struct afb_trace *trace, struct hook *hook, enum trace_type type)
 {
-       struct session *session = hook->session;
        hook->next = trace->hooks[type];
        trace->hooks[type] = hook;
-       if (session && !session->trace) {
-               session->trace = trace;
-               afb_session_set_cookie(session->session, session, session, free_session_cookie);
-       }
 }
 
 /*******************************************************************************/
@@ -1195,7 +1251,7 @@ struct desc
        struct context *context;
        const char *name;
        const char *tag;
-       const char *session;
+       const char *uuid;
        const char *api;
        const char *verb;
        const char *pattern;
@@ -1206,7 +1262,7 @@ struct desc
 static void addhook(struct desc *desc, enum trace_type type)
 {
        struct hook *hook;
-       struct session *session;
+       struct afb_session *session;
        struct afb_session *bind;
        struct afb_trace *trace = desc->context->trace;
 
@@ -1217,7 +1273,7 @@ static void addhook(struct desc *desc, enum trace_type type)
                        ctxt_error(&desc->context->errors, "tracing %s is forbidden", abstracting[type].name);
                        return;
                }
-               if (desc->session) {
+               if (desc->uuid) {
                        ctxt_error(&desc->context->errors, "setting session is forbidden");
                        return;
                }
@@ -1233,17 +1289,19 @@ static void addhook(struct desc *desc, enum trace_type type)
        /* create the hook handler */
        switch (type) {
        case Trace_Type_Xreq:
-               if (desc->session) {
-                       session = trace_get_session_by_uuid(trace, desc->session, 1);
+               if (!desc->uuid)
+                       session = afb_session_addref(bind);
+               else {
+                       session = trace_get_session_by_uuid(trace, desc->uuid, 1);
                        if (!session) {
                                ctxt_error(&desc->context->errors, "allocation of session failed");
                                free(hook);
                                return;
                        }
-                       bind = session->session;
                }
-               hook->handler = afb_hook_create_xreq(desc->api, desc->verb, bind,
+               hook->handler = afb_hook_create_xreq(desc->api, desc->verb, session,
                                desc->flags[type], &hook_xreq_itf, hook);
+               afb_session_unref(session);
                break;
        case Trace_Type_Ditf:
                hook->handler = afb_hook_create_ditf(desc->api, desc->flags[type], &hook_ditf_itf, hook);
@@ -1254,6 +1312,9 @@ static void addhook(struct desc *desc, enum trace_type type)
        case Trace_Type_Evt:
                hook->handler = afb_hook_create_evt(desc->pattern, desc->flags[type], &hook_evt_itf, hook);
                break;
+       case Trace_Type_Session:
+               hook->handler = afb_hook_create_session(desc->uuid, desc->flags[type], &hook_session_itf, hook);
+               break;
        case Trace_Type_Global:
                hook->handler = afb_hook_create_global(desc->flags[type], &hook_global_itf, hook);
                break;
@@ -1267,7 +1328,7 @@ static void addhook(struct desc *desc, enum trace_type type)
        }
 
        /* attach and activate the hook */
-       afb_req_subscribe(desc->context->req, afb_event_from_evtid(hook->event->evtid));
+       afb_req_subscribe(desc->context->req, afb_evt_event_from_evtid(hook->event->evtid));
        trace_attach_hook(trace, hook, type);
 }
 
@@ -1322,6 +1383,11 @@ static void add_evt_flags(void *closure, struct json_object *object)
        add_flags(closure, object, Trace_Type_Evt);
 }
 
+static void add_session_flags(void *closure, struct json_object *object)
+{
+       add_flags(closure, object, Trace_Type_Session);
+}
+
 static void add_global_flags(void *closure, struct json_object *object)
 {
        add_flags(closure, object, Trace_Type_Global);
@@ -1332,22 +1398,23 @@ static void add(void *closure, struct json_object *object)
 {
        int rc;
        struct desc desc;
-       struct json_object *request, *event, *daemon, *service, *sub, *global;
+       struct json_object *request, *event, *daemon, *service, *sub, *global, *session;
 
        memcpy (&desc, closure, sizeof desc);
-       request = event = daemon = service = sub = global = NULL;
+       request = event = daemon = service = sub = global = session = NULL;
 
        rc = wrap_json_unpack(object, "{s?s s?s s?s s?s s?s s?s s?o s?o s?o s?o s?o s?o}",
                        "name", &desc.name,
                        "tag", &desc.tag,
                        "api", &desc.api,
                        "verb", &desc.verb,
-                       "session", &desc.session,
+                       "uuid", &desc.uuid,
                        "pattern", &desc.pattern,
                        "request", &request,
                        "daemon", &daemon,
                        "service", &service,
                        "event", &event,
+                       "session", &session,
                        "global", &global,
                        "for", &sub);
 
@@ -1359,8 +1426,8 @@ static void add(void *closure, struct json_object *object)
                if (desc.verb && desc.verb[0] == '*' && !desc.verb[1])
                        desc.verb = NULL;
 
-               if (desc.session && desc.session[0] == '*' && !desc.session[1])
-                       desc.session = NULL;
+               if (desc.uuid && desc.uuid[0] == '*' && !desc.uuid[1])
+                       desc.uuid = NULL;
 
                /* get what is expected */
                if (request)
@@ -1375,6 +1442,9 @@ static void add(void *closure, struct json_object *object)
                if (event)
                        wrap_json_optarray_for_all(event, add_evt_flags, &desc);
 
+               if (session)
+                       wrap_json_optarray_for_all(event, add_session_flags, &desc);
+
                if (global)
                        wrap_json_optarray_for_all(global, add_global_flags, &desc);
 
@@ -1435,7 +1505,7 @@ static void drop_session(void *closure, struct json_object *object)
 {
        int rc;
        struct context *context = closure;
-       struct session *session;
+       struct afb_session *session;
        const char *uuid;
 
        rc = wrap_json_unpack(object, "s", &uuid);
@@ -1445,8 +1515,10 @@ static void drop_session(void *closure, struct json_object *object)
                session = trace_get_session_by_uuid(context->trace, uuid, 0);
                if (!session)
                        ctxt_error(&context->errors, "session %s not found", uuid);
-               else
+               else {
                        trace_unhook(context->trace, NULL, NULL, session);
+                       afb_session_unref(session);
+               }
        }
 }
 
@@ -1455,17 +1527,17 @@ static void drop_session(void *closure, struct json_object *object)
 /*******************************************************************************/
 
 /* allocates an afb_trace instance */
-struct afb_trace *afb_trace_create(struct afb_daemon *daemon, struct afb_session *bound)
+struct afb_trace *afb_trace_create(const char *apiname, struct afb_session *bound)
 {
        struct afb_trace *trace;
 
-       assert(daemon);
+       assert(apiname);
 
        trace = calloc(1, sizeof *trace);
        if (trace) {
                trace->refcount = 1;
                trace->bound = bound;
-               trace->daemon = daemon;
+               trace->apiname = apiname;
                pthread_mutex_init(&trace->mutex, NULL);
        }
        return trace;
@@ -1519,7 +1591,7 @@ extern int afb_trace_drop(struct afb_req req, struct json_object *args, struct a
 {
        int rc;
        struct context context;
-       struct json_object *tags, *events, *sessions;
+       struct json_object *tags, *events, *uuids;
 
        memset(&context, 0, sizeof context);
        context.trace = trace;
@@ -1536,13 +1608,13 @@ extern int afb_trace_drop(struct afb_req req, struct json_object *args, struct a
                return 0;
        }
 
-       tags = events = sessions = NULL;
+       tags = events = uuids = NULL;
        rc = wrap_json_unpack(args, "{s?o s?o s?o}",
                        "event", &events,
                        "tag", &tags,
-                       "session", &sessions);
+                       "uuid", &uuids);
 
-       if (rc < 0 || !(events || tags || sessions)) {
+       if (rc < 0 || !(events || tags || uuids)) {
                afb_req_fail(req, "error-detected", "bad drop arguments");
                return -1;
        }
@@ -1555,8 +1627,8 @@ extern int afb_trace_drop(struct afb_req req, struct json_object *args, struct a
        if (events)
                wrap_json_optarray_for_all(events, drop_event, &context);
 
-       if (sessions)
-               wrap_json_optarray_for_all(sessions, drop_session, &context);
+       if (uuids)
+               wrap_json_optarray_for_all(uuids, drop_session, &context);
 
        trace_cleanup(trace);
 
@@ -1569,4 +1641,3 @@ extern int afb_trace_drop(struct afb_req req, struct json_object *args, struct a
        free(context.errors);
        return -1;
 }
-