Event Logger

[jashot7]

@gliechtenstein and I had a brief chat about this today.

There should be a Jasonette logger that fires events for common actions, such as the ones below:

• Network Requests
• Network Responses
• Timer Creation/Start
• Timer Triggering Actions

I currently have an implementation of a very basic/simple version of this that simply logs these events to the xCode console using NSLog, but ideally a great implementation for Jasonette would include logging everything over Wifi without the need for xCode (node server) and ties into common analytics engines (Google Analytics, etc.).

Also, this implementation will need to be cross-platform and my simple example I provide is iOS only at the moment.

Example Log Calls:

 // Example of a log call before a network request is made in JasonNetworkAction.m
 [JasonetteLogger logNetworkRequest:method withUrl:url withData:self.options[@"data"] ];

// Example of a log call for a network response in JasonNetworkAction.m
[JasonetteLogger logNetworkResponse:method withUrl:url withDataType:dataType
withResponseObject:responseObject ];

Example JasonetteLogger:

//  JasonetteLogger.m
//  Very simple logger using NSLog to log app events.
//
//  To turn off logging, set DEBUG to false in the xCode project file.
//
//
#import "JasonetteLogger.h"

@implementation JasonetteLogger

+ (void)logNetworkRequest: (NSString*)method withUrl: (NSString*)url withData:(NSDictionary*)data {
#if DEBUG
    NSLog(@"🔵 Network Request: %@ 🔵", (method == NULL ? @"GET" : [method uppercaseString]));
    NSLog(@"URL: %@", url);
    if (method != NULL) {
        NSLog(@"\n Data: %@ ", data);
    }
#endif
}

+ (void)logNetworkResponse: (NSString*)method withUrl: (NSString*)url
          withDataType: (NSDictionary*)dataType withResponseObject: (NSData*)responseObject {
#if DEBUG
    NSLog(@"🔷 Network Response: %@ 🔷", (method == NULL ? @"GET" : [method uppercaseString]));
    NSLog(@"DataType: %@", dataType);
    NSLog(@"ResponseObject: \n %@", responseObject);
#endif
}

+ (void)logTimerStart: (NSString*)name isRepeating: (BOOL)repeating
         withInterval: (NSTimeInterval)interval {
#if DEBUG
    NSLog(@"⏱ Started %@Timer '%@' with interval '%d'⏱", repeating ? @"REPEATING " : @"",
          name, (int)interval);
#endif
}

+ (void)logTimerActionTriggered: (NSString *)action{
#if DEBUG
    NSLog(@"⏱ Timer Triggered Action:⏱");
    NSLog(@"\n%@", action);
#endif
}
@end

[gliechtenstein]

One random idea i just had:

maybe we can create a protocol for all actions to support debugging to console. For example, we introduce an additional attribute called debug

{
  "type": "$network.request",
  "options": {
  },
  "success": {
    ...
  },
  "error": {
    ..
  },
  "debug": "true"
}

Note that this debug is a top level attribute on the same level as type, options, success, and error.

All actions are free to implement this additional attribute debug, and each action can behave whichever way it needs to. In this case the default action would be to log to console. Implementation-wise, the code would be the same, except that:

1. instead of explicitly calling [JasonetteLogger logNetworkRequest:method withUrl:url withData:self.options[@"data"] ]; based on #if DEBUG condition, we would trigger this with JSON.
2. instead of implementing a separate JasonetteLogger class, each action will implement its own custom way to handle debugging. So in this case, logNetworkRequest and logNetworkResponse will be added to JasonNetworkAction.

The benefit of this approach would be:

1. we don't need to add the #if DEBUG lines
2. Since it's a protocol that any action can implement, we can take advantage of it for all actions
3. Users can turn it on and off easily by simply attaching and removing the "debug": "true" option (and it won't be visible to end users), which means this is not hardcoded into the app, which means you can switch between debug and release modes in production just by updating the JSON.

---

Expanding on this idea, potentially we could allow the debug attribute to trigger another action, for example analytics (as @jashot7 mentioned).

In fact I have written an extension for sending analytics to segment.io, which is a great example to demonstrate why this debug attribute may be useful. Let me explain.

One constraint with Jasonette is there is only a single action call chain and currently it doesn't support multithreaded actions. This is by design for now because handling multithreading is not a trivial matter both for implementation and for usage (from user's point of view), so it's good to keep it simple for now.

The way JasonSEGAnalyticsAction is implemented, it treats the action the same as any other action like $network.request. Here's an example:

{
	"type": "$network.request",
	"options": {
		"url": "https://www.jasonbase.com/things/n3s.json"
	},
	"success": {
		"type": "$segment.track",
		"options": {
			"event": "response",
		  	"properties": {
				"json": "{{$jason}}"
			}
		},
		"success": {
			"type": "$render"
		}
	}
}

While it works for this case, this approach cannot cover all analytics use cases. For example you may want to send events to segment.io BEFORE sending the network.request, or maybe even during the action.

In this case we could utilize the debug attribute to pass another payload (instead of just passing true). Maybe something like this:

{
  "type": "$network.request",
  "options": {
    "url": "https://www.jasonbase.com/things/n3s.json"
  },
  "success": {
    "type": "$render"
  },
  "debug": {
    "action": {
      "type": "$segment.track",
      "options": {
        "event": "response",
        "properties": {
          "json": "{{$jason}}"
        }
      }
    }
  }
}

Actually, i'm now even wondering this debug can be even further generalized to support a mini-multithread within an action.

That said, I don't want this to be an architecture astronaut thread, and I'm not saying we should implement all these features from the beginning.

It's just a dump of an idea i just had, hope to hear what you think.

[maks]

@gliechtenstein 💯 !!!
I think this idea is an excellent idea to add a debug action!
Please lets decide on the details and implement asap :-) (I'm happy to build the Android side)
My 2c:

• please lets have a global debug property as well in the head to have the option to turning on debug for everything as well, as I could see myself wanting to sometimes do that rather than going through and having to enable it on every action
• would be nice to have a second property log or analytics or some name, as analytics is such a widely used thing, it would be better not to conflate it with debugging. Please lets add both as it would be annoying having to disable analytics everytime you wanted to do some custom debugging.
• I know we have {{ console.debug() }} etc already but it would be nice to add a dedicated $console action, then using it as the debug action in you above proposal seems to go nicely.

Again I'm really keen to implement this, so maybe break up the debug vs analytics into separate issues to get them implemented more quickly?

[clsource]

Some ideas 👍

I think having a logger property on the head can be used for configuration a logger server. And then every logger call will send the logs using this info.

{
  "$jason": {
    "head" : {
      "title" : "Logger Test",
      "loggers" : {
        "localhost" : {
          "url" : "http://logger.example.com",
          "level" : "trace|debug|info|warning|error|fatal",
          "default" : "true",
          "method" : "post",
          "header": {
            "X-Auth-Token": "abc1234",
          }
        }
      }
    }
  }
}

As you can see it's similar to $network.request action but with level and default properties.

level

defines what kind of messages will be sent to the logger server. If set to debug will send all debug and superior priority messages. If set to info will ignore debug messages and sent info or superior priority messages and so on.

More info
http://commons.apache.org/proper/commons-logging/guide.html

default
Only one logger could have this property, tells which logger use for different enviroments. If just one logger is defined it will be considered as default.

Usage

Using the debug syntax, but with the logger as type. Uses the default logger unless otherwise specified with the class property.

"debug": {
   "level" : "info",
    "action": {
      "type": "$logger",
      "options": {
        "class" : "analytics",
        "event": "response",
        "data": {
          "json": "{{$jason}}"
        }
      }
    }
  }

Logging internal Jasonette

For improving debug, Jasonette needs to log things as they go.
Example: Parsing a property and does not found a valid value, it must log what happended.

For this to work then you have to specify the 'jasonette' logger. It will log every event that triggers when parsing jasonette files by the app on runtime.

"loggers" : {
        "jasonette" : {
          "url" : "http://logger.example.com",
          "level" : "trace|debug|info|warning|error|fatal",
          "method" : "post",
          "header": {
            "X-Auth-Token": "abc1234",
          }

What do you think?
:)

[gliechtenstein]

---

Re @clsource :

First I want to make sure I'm understanding correctly. Are we talking about a custom Jasonette log server that's able to log the result? Or is this about any analytics service (such as google analytics, segment, mixpanel, etc.)? I think it would be great to have a node.js server that can be set up either locally or remotely to do custom logging for Jasonette.

As for the JSON syntax proposal, I hope that we can come up with a way to do this without a new addition to the ever-growing schema we already have.

Actually I have a feeling this and the custom events issues are somewhat related and maybe there's a way to implement this idea using the "register and call later" pattern somehow?

Could you take a look at the custom events issue and let me know if that is something that may make sense for us to use to implement your idea?

Overall I'm a fan of the idea, but it would be desirable if we can come up with an implementation that doesn't introduce new concepts if possible.

---

Re @maks :

please lets have a global debug property as well in the head to have the option to turning on debug for everything as well, as I could see myself wanting to sometimes do that rather than going through and having to enable it on every action

I agree this would be nice. But let's break this down to another issue and decide on an actual implementation AFTER the basic feature (attaching debug on actions) is rolled out and have been in use for a bit. I find that it's best to design APIs based on actual usage or otherwise we end up with a syntax that's not really optimal for actual use cases. A lot of times I found that if I don't do it this way i ended up inventing new syntax that's totally unnecessary and could have been handled with existing schema in some clever way.

would be nice to have a second property log or analytics or some name, as analytics is such a widely used thing, it would be better not to conflate it with debugging. Please lets add both as it would be annoying having to disable analytics everytime you wanted to do some custom debugging.

This one is much more complex than simply logging to console because there are many different analytic services out there each with their own API, which is why I think analytics are best implemented as extensions. But again, this may not be true and we may be able to come up with a uniform interface to handling this, but this should only be based on actual usage.

I know we have {{ console.debug() }} etc already but it would be nice to add a dedicated $console action, then using it as the debug action in you above proposal seems to go nicely.

how would a $console action work as you're envisioning it? There is an extension I worked on called JasonConsoleAction https://github.com/gliechtenstein/JasonConsoleAction which displays the current stack, but I think there can other ways as well. Curious what you're envisioning.

---

Overall, I think we should really break this down to pieces and implement incrementally. Otherwise we can get into analysis paralysis mode easily. Here's a suggestion:

1. Implement the original feature @jashot7 suggested, but using the approach I suggested (unless there's a good reason not to), on both iOS and Android.
2. After this is rolled out and have been in use for a bit, think of a way to implement analytics and the server based console logging

I think step 1 is pretty straight-forward as @jashot7 is already using this in his fork and it's working fine. All we need to do is just come to a conclusion on whether we will adopt the approach I suggested (include debug option inside an action and control it via JSON instead of hardcoding)

Let me know what you think, and we can get this going!

[clsource]

@gliechtenstein sure I will look into custom events and think a way to create a logger for jasonette events using existing sintax 👍

[gliechtenstein]

I just made a PR Jasonette/JASONETTE-iOS#258 based on @jashot7 's original code. Made a little change to log not just the body but also header.

It's just a basic logging feature that turns on and off based on options.debug's existence. A bit different from my original proposal where debug was on the same level as type, options, success, and error because I realized there can be other additional features going forward (we are already talking about analytics, but I'm sure there will be many other features that are common across actions) and it won't be scalable if we keep adding attributes to the top level every time.

Any suggestions? Otherwise i think we can implement the same thing for JasonTimerAction and other actions, as well as implement on Android.

[jashot7]

Awesome, @gliechtenstein. In order for this to replace what I'm currently doing for logging, it has to be something that I can turn on and off app-wide quickly and easily.

Implementing this for JasonTimerAction and other actions would be super as well. In particular, logging the requests made with Require would be really useful and I'm adding that next to our logger.

[clsource]

How about this for global debug mode on

$debug.on and $debug.off
Default class is debug.

"head" : {
  "actions" : {
   "global_debug" : {
       "type" : "$debug.on",
       "options" : 
        { 
            "class"  : "trace|debug|info|warning|error|fatal"
        }
    }
  }
}

Then activate the global debug in the $load event with trigger:global_debug