I gather that Thor (aka Peter Rodgers) approves of my Back To The Beginning series. Let me tell you, it is hard going and not a post goes by without me making a couple more assumptions than I wanted and creating a couple more loose ends that I need to tie up. It is mostly context, ROC/NetKernel is what I have been breathing in the past six years. When I look at other evolutions in the IT field (yes, I do) they look as alien to me as ROC/NetKernel might look to you. It's all a matter of point-of-view, of context.
This brings me to a question I got about my last post. Actually, two questions.
The first one was : "Why are you not showing a lot more code ? Things remain at the child's play stage without it, a real application has a lot more code !". While I disagree with the statement, that is a good observation that deserves an answer.
I'm not easily offended and I had a very good email discussion with the person that made the observation. Feel free to contact me if you have questions too !
ROC development is not code-centric. It is about constructing small components (endpoints) that you can compose together and constrain as needed. If you know about shell scripting, you are already familiar with this concept. A lot of components (for example, I used an XSLT transformation in an earlier post) are already available.
The components should be made such that they do one task, one task only. For myself I use the following rule-of-thumb ... if a component requires more than 200 lines of source code, comments and logging included, I have not been thinking things through enough.
Tony Butterfield gave me the following thought exercise to come to grips with it. Would the Linux ls command be a good candidate for a ROC component ? The answer is ... no. The core of the command (directory listing) is fine but it has too many formatting and filtering options. By putting those options in the same component you would take away the chance for the ROC system to optimize them. They should have been in different components.
So the reason there hasn't been a lot of code in this series shows the reality of developing in ROC/NetKernel, it is not me trying to avoid complexity.
The second question was : "What is this aContext-thingie in your Java code ?". Ah, right, oops, I didn't actually discuss coding in the ROC world at all yet, did I ?
Well, to start, if it runs in the JVM, you can potentially use it to ROC code in. In practice, I find that a combination of Java and Groovy is ideal. Note that I wasn't formally trained in either. Note that I am pretty proficient in Python (and Jython is an option in NetKernel). However, if 200 lines are all I'm going to write for a given component, I'm not going to require wizardry in any language, right ? So I decided to use Java for writing new components (since NetKernel was developed in it, it is closest to the metal) and I use Groovy as my composition language.
I am quite serious, I can't stand up to any seasoned J2EE developer in a "pure" Java coding challenge and I have great respect for their skills. However, if I'm allowed to use ROC/NetKernel to solve the problem I will go toe to toe with the best.
Writing a new component always follows these four steps :
- What have I promised that I will provide ?
- What do I need in order deliver my promise ?
- Add value (the thing that makes this special).
- Return a response.
When a request of an endpoint is made, you are handed the context of that request to take those steps. This context allows you to pull in the arguments to the request, for example :
String theargument = context.source("arg:theargument",String.class);
It allows you to create new (sub)requests in order to add value, for example :
INKFRequest subrequest = context.createRequest("active:somecomponent");
subrequest.addArgumentByValue("theargument", theargument);
String theresult = (String)context.issueRequest(subrequest);
And finally it allows you to return a response :
context.createResponseFrom(theresult);
When using Java you are given slightly more control over things, however the HelloWorldAccessor with the onSource method from the introduction module is a good starting point, we'll discuss different types of endpoints and verbs in a later post (loose ends again, I know). The same thing in Groovy would look like this :
import org.netkernel.layer0.nkf.*;
import org.netkernel.layer0.representation.*
import org.netkernel.layer0.representation.impl.*;
// context
INKFRequestContext aContext = (INKFRequestContext)context;
//
aContext.createResponseFrom("Hello World");
Due to the way a Groovy program is instantiated you are dropped straight into the equivalent of the onSource method in a Java accessor. Also, the assignment of context to aContext is strictly speaking not necessary, it is a coding practice that allows me to see things correctly in my editor (Eclipse). In any of the available scripting languages you'll always have context available.
So ... why are these two (the Java accessor in the introduction module and the Groovy program above) good starting points but actually bad components ? Because they don't add value, the response is a static string, I could just as well - and did in the introduction module - define a literal resource.
Food for thought, no ?
In the second half of the 1990s I was an IDMS database administrator for Belgium's biggest retailer. When our resident guru almost got killed by the job I got most of the main databases in my care ... and I must admit I ruled supreme. If you've never heard of the BOFH, check him out here and here. I don't know if any of those stories are based on reality, but they are nothing compared to some of the stuff I pulled off.
I hated logging.
Let me place that statement in the correct context. PL/I did not allow asynchronous actions, logging ate processing time. Also, disk storage was not cheap, the estimated costs of storage could and would often kill a project before it even started. Database storage was even more expensive. Migration to tape was an option but it made consultation afterwards very impractical.
This brings me to the why of logging. Opinions may differ but I see only two reasons :
- Audit
- Bug fixing by means of postmortem analysis
Audit. You want to know what was requested and - if you're a security auditor - who requested it. This is a - and in my view the only - legitimate reason for logging. However, even back then tools existed that allowed auditing without having to put it in the code. A fellow database administrator that was a bit too curious about the wages of the others and looked them up on the database found that out the hard way.
Bug fixing by means of postmortem analysis. You want to know what the state of the system was at the time of an error. This requires excessive amounts of logging. It did back then and it does today. And let me tell you something ... it's never enough.
You might say I'm an old fart that's not up to speed with the current state of technology. Storage is very cheap, asynchronous logging has become the standard ... and doesn't everybody say that you should log everything because it can be big stash of useful data itself ?
As a matter of fact, they - whoever they are - don't. They mean audit data collected on the edges of your system, not the things you'd typically put in a put skip list or System.out.println.
I still hate logging. And therefore I was very happy that when NetKernel 4 was released, it contained a back-in-time machine. Such was the power that 1060 Research also released a backport for NetKernel 3. This time machine is also known as the Visualizer. When running, it captures the complete (!) state of any request in the NetKernel system. Anybody that has worked with it agrees that it is sheer magic, for you can pinpoint any error almost immediately. Such a powerful tool warrants its own blogpost, so that's for next time.
All personal opinion aside, how does one log in NetKernel then ? Well, lets see how we can add some to our introduction module. First I want to have some audit of the incoming requests. We could write our own transparent overlay - another topic for a future blogpost - for this, but as it happens the HTTP Jetty Fulcrums have everything that's needed.
Open [installationdirectory]/modules/urn.org.netkernel.fulcrum.frontend-1.7.12/etc/HTTPServerConfig.xml in your favorite text/xml editor.
Remove the
<!--Uncomment for NCSA Logging
and the matching
-->
line. You can also change the settings and/or the name of the logfile. Restart NetKernel (this change is not picked up dynamically). You should now find a new logfile under [installationdirectory]/log.
Now try http://localhost:8080/introduction/helloworld-file in your browser. Open up the logfile and you should see something like this (given date, locale and browser differences) :
0:0:0:0:0:0:0:1 - - [03/jan/2014:09:42:35 +0000] "GET /introduction/helloworld-file HTTP/1.1" 200 0 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0"
That's audit taken care of. Do I have to mention the fact that this logfile can easily be picked up by tools like Splunk and Logstash ?
If you need help with integrations like that, feel free to contact me. I've been there and done that.
Maybe you think I'm full of shit in my rant above or maybe you just have to comply with the rules and regulations of a customer. If so, yes, you can also do explicit logging in NetKernel.
Since the HelloWorldAccessor is the only piece of code we have, it's in there that we'll add it. The onSource method looks like this :
public void onSource(INKFRequestContext aContext) throws Exception {
aContext.createResponseFrom("Hello World");
}
Adding logging is as simple as :
public void onSource(INKFRequestContext aContext) throws Exception {
aContext.logRaw(INKFLocale.LEVEL_INFO,"Logging from HelloWorldAccessor");
aContext.createResponseFrom("Hello World");
}
You'll notice the logging appears in two places. Firstly in the standard output of the NetKernel process :
I 11:00:34 HelloWorldAc~ Logging from HelloWorldAccessor
Secondly in [installationdirectory]/log/netkernel-0.log :
<record>
<date>2014-01-03T11:00:34</date>
<millis>1388743234821</millis>
<sequence>278</sequence>
<logger>NetKernel</logger>
<level>INFO</level>
<class>HelloWorldAccessor</class>
<thread>167</thread>
<message>Logging from HelloWorldAccessor</message>
</record>
Why is this ? Well, the log methods look for a configuration resource. Either you pass this resource in the method, or the resource res:/etc/system/LogConfig.xml is used (if it can be found), or - as a final resort - [installationdirectory]/etc/KernelLogConfig.xml is used. Check it out, it has two handlers.
So, to preempt a couple of questions, if you want a different log for each application, you can. If you want a JSON formatted log, no problem. Another common request these days (for yes, I am up to speed) is that the log messages themselves have to be formatted.
In order to do that, your module requires a res:/etc/messages.properties file resource. An actual file yes, logging is provided at such a low level that not all the resource abstractions are in place yet. The file can contain things like :
AUDIT_BEGIN={"timestamp":"%1","component":"%2", "verb":"%3", "type": "AUDIT_BEGIN"}
AUDIT_END={"timestamp":"%1","component":"%2", "verb":"%3", "type": "AUDIT_END"}
In your code you can then write :
aContext.logFormatted(INKFLocale.LEVEL_INFO,"AUDIT_BEGIN", System.currentTimeMillis(), "HelloWorldAccessor" , "SOURCE");
And the results look like this :
I 11:42:03 HelloWorldAc~{"timestamp":"1388745723359","component":"HelloWorldAccessor", "verb":"SOURCE", "type": "AUDIT_BEGIN"}
and :
<record>
<date>2014-01-03T11:42:03</date>
<millis>1388745723360</millis>
<sequence>263</sequence>
<logger>NetKernel</logger>
<level>INFO</level>
<class>HelloWorldAccessor</class>
<thread>176</thread>
<message>{"timestamp":"1388745723359","component":"HelloWorldAccessor", "verb":"SOURCE", "type": "AUDIT_BEGIN"}</message>
</record>
Again I'll mention the fact that these logfiles can easily be picked up by tools like Splunk and Logstash. And there you have it, a complete - and customizable - logging system. To close my post I'm going to talk about the loglevels for a moment, NetKernel provides :
- INKFLocale.LEVEL_DEBUG
- INKFLocale.LEVEL_FINEST
- INKFLocale.LEVEL_FINER
- INKFLocale.LEVEL_INFO
- INKFLocale.LEVEL_WARNING
- INKFLocale.LEVEL_SEVERE
Not only can these be easily matched to ITIL aware operations systems, you can also turn them off and on in NetKernel itself. This will allow you to safe quite a bit of storage ... you never know when that might come in handy ;-).
