Flogger - the advanced logging node!

Share Your Nodes
21

I have now published version 1.1.0. Following is done:
Timeformat consistency,
Now using typeInput for selecting what to log,
Msg pass through added,
Your loglevels are now available,
Log level override is now possible.
JSON output formatting added,
Send to debug sidebar added.

I would be happy if you would test if everything works. I updated the manual, so everything should be documented.

I will be thinking a little more about mustache formatting and syslog. Maybe syslog should be implemented in a completely separate node?

2 Likes
22

wow, quick work.

I will update and test / feedback as soon as i can.

23

Hi so far...

On updating, I get error ReferenceError: outLogstamp is not defined in the side-bar

  • I had to update the config node (no defaults were set for timestamp)

Minor ramble - skip if you wish...
Whenever I change something in my own nodes - i always try to consider what happens when a user upgrades to latest version and attempt to have my code handle it by setting defaults or interpreting their original node settings & coercing it into the new setting.. i.e. you could have had the node read that the original "timestamp" flag was set & update the variable to the new corresponding option value - it would have avoided this. Its no biggie but if a user has lots of flogger nodes on lots of systems, they are gonna have to open and update everyone of them. Same thing goes for the next point (if what to log is empty (i.e. "complete msg" in previous version) then set the typed input to "Complete Message" automatically - kinda like an in-place upgrade :slight_smile:

After updating the config node & setting an option in the timestamp dropdown, I was getting no output in the log. I suspect that is because there is no option for "complete msg" (msg. was set but field was empty). After entering payload it works - however the problem is I want "complete msg"

Please consider adding a custom option "complete msg"

Off the top of my head, it is something like this...

var opts = {default: "msg", typeField: $myTypeField};
opts.types = ["msg","flow","global",{  value:"complete",  label:"Complete msg",  hasValue: true }];
$myTypedInput.typedInput(opts);

On another node (after updating config node & selecting an option for timestamp), I was getting 2019/06/28 15:59:07 WRN [msg.payload] [CHECK-AGE] Error in setup of flogger node - not sure why but suspect something else not set by default. I forget what sorry

When opening another existing flogger node, I noted thatno option was set for debug level dropdown
(dropdown is blank & likely due to my original flow having debug level set to "WRN" - which isnt an option now). Sure enough, the output to debug log was WRN. After selecting WARN from the drop down - the log correctly reports WARN. Again, no real hardship but I would consider checking the users current setting. If it == "WRN", override it to be "WARN". If it == "DBG", override it to be "DEBUG". If it is empty or something else, set it to "INFO" or some other default so that the dropdown has something to display.

Other stuff...
timestamp is now ISO format (yyyy/dd/mm) - thanks.
output to debug side panel - excellent
ouput JSON - working great

Thats all I have time for right now.

Keep up the good work - I think this is gonna be one I use.

1 Like
24

Hi Steve,

Thank you for your careful review. Sorry about the glitches that came from all the code-change. While you were reviewing, I made the moustache-option available in version 1.1.1.
Unfortunately it changed the code quite much. I would recommend you to delete your nodes and the configs. I know this is anoying for the standard-user. But here in the beginning where I make huge changes, It would be a lot of code to keep it "updateable".

25

I understand & you're right, it is early doors so no major concern. I did think that too but thought it worth mentioning as (built in upgrade) is often overlooked.

I won't get a chance to check it out your update for some time now so just a question....
How did you implement the mustache format? Did you add "str" type on the typedinput?

I hope you don't mind all the feedback. I personally find others feedback too few and too far between - so hope I've been more of a help than a nuisance :slight_smile:

1 Like
26

Hi Steve.

I really appreciate all the feedback. Keep doing that. It gives me a lot of ideas I didn't think about.

I implemented the moustache by creating a HTML select with three options. 1 full message object. 2 selectable object and 3 moustache.

Depending on the selection I show different input fields to the user.

From a user standpoint I think this is the most easy to understand instead of explaining to use a standard text field.

27

I have done some final polishing and testing most corner cases... It's at version 1.1.4 now.
It should be pretty much ready for production.

28

I did manage to have a play today and did install 1.1.4 and gave it a quick whirl. All good except when I sent an object to mustache, it didn't strigify very well however when using complete object, it did strigify nicely.

Can't remember why or what the object was or the part that didn't strigify nicely (may have been a property that was buffer or array - I think the mustache strigified it as unicode or escape characters or something) (ps, that was with config set as JSON output)

Other than that, very nice. Excellent work.

Oh, sorry no, one more thing, would you consider permitting the filename to be set by msg.filename if the form property is left blank? Useful for users to dynamically decide what log to write to.

Cheers, Steve.

Ok, can't help myself - did you have any thoughts about log rotation? Perhaps an additional node that manages log rotation on a folder/filename/wildcard? You don't necessarily need to manage rotation timers (node red had an abundance of triggers/timers) but just perform the rotation operations with options comparable with the excellent Linux logrotate application. Of course I realise for Linux users this is not really a "need" but windows users don't have these luxuries.

1 Like
29

I found the funky stringify. it was the mustache library I used that did some html escaping by default - it should be corrected now. I also added the filename override - seems like another good idea.

I submitted 1.1.5 via npm - it should be available soon.

I think logrotation is a little out of scope. If I get too big logs, I might reconsider :wink:

2 Likes
30

Hi again.

So I had an odd issue on a flow with 2 flogger nodes (one set for DEBUG, one set for ERROR - both using the same config node [i.e. same path]). The DEBUG node wrote to its debug.log file but the ERROR node failed to write to error.log with "Cant write file!"
image

I havent managed to reproduce it yet to see why flogger failed to write to one file but not another - however I did note you do not raise an error event in node-red so all detail is lost.
(one clue to the failed to write was that the debug.log file already existed, the error.log file did not)

It would be most beneficial if you add node.error(...) so that it can be caught by a catch node & so we can gain access to the err reason in console output and node-red debug pan.

e.g...

if (filename) {
	path = node.logconfig.logdir + "/" + filename
	fs.appendFile(path, logline, (err) => {  
		if (err) {
			node.status({shape: "ring", fill: "red", text: "Cant write file!"})
			node.error(err, msg); /* <<<  This would permit us to determine the problem as a console log and node-red debug pane log would get generated. */
		} else {
			nowstrstatus = now.toLocaleString()
			node.status({shape: "ring", fill: "green", text: nowstrstatus})
		}
	})
} else {
	node.status({shape: "ring", fill: "red", text: "Missing filename!"})
	/* ***  maybe consider adding something here too (maybe node.warn instead? not really an internal error!) *** */
}
31

So I have found * my * issue with my flows ERROR flogger node declaring "cannot write file".

The object being caught by a catch node has a "filename" property in msg. This is then sent to a flogger node and it seems you implemented the msg.filename override unconditionally causing flogger to try and log to (for example) c:\logs\c:\file.txt. (msg.filename was set to "c:\file.txt" by an upstream object - I never intended in using a dynamic filename in this instance - I had intentially hard coded the log file filename into the flogger node property editor)

I had hoped like may other nodes do (and how it was requested - reference below) that msg.filename would override if left blank.

There is good reason why most nodes handle this situation like that. In the case of flogger...

  • Everywhere I use flogger I will have to add a change node or function node immediately prior to the flogger node to clear out msg.filename just in case another node or operation prior to the flogger node added filename into the msg object.
  • On a *nix system, you could potentially overwrite a wrong file (the middle colon in this windows example caused a path error)

Would you be kind enough to NOT unconditionally override filename please?

what I did temporarily to get past this...

// if (msg.filename) filename = msg.filename // Filename override via msg object
if (!filename) filename = msg.filename // Filename override via msg object IF filename was left blank only.  NOTE: final filename will be checked below so no need to ensure msg.filename has something - just do the assignment.
32

Hi Steve,

Thank you for your input and for your debugging. To me this seems more like a naming collision because of the use of a quite common name "filename". What if I used the name "logfile" instead? Wouldn't that solve it?

I kind of prefer the idea that I can configure a filename on the node and then later override it with a message property if I want.

33

That is of course your prerogative however many node that permit override only do so if it's left blank.

Perhaps some thought on this matter is needed? Perhaps a switch that permits/prevents override is an acceptable halfway house?

34

Hi (jumping in) - the preferred modus operandi for nodes is if a parameter is left blank in the node then it can be provided by the msg. If specified by the user then it can't be overridden, (as presumably they set it for a reason).

1 Like
35

Hi Steve

I prefer to comply with the normal node-red behavior.
I submitted 1.1.6 that does like you want.

5 Likes
36

I have a few minor issues with the way date/time is formatted by flogger. These may depend on locale and browser, so YMMV.

First, with the configuration set to Timestamp = Local, the node status.text appears as "2019-7-10 11:01:30", but the time logged to the file is "2019/07/10 11:01:30". Without being an ISO 8601 purist, I think leading zeros are a good idea, and the use of slashes should be avoided. In any case, the formats should be consistent.

When the timestamp is set to UTC, the status.text is still in local time. This not unreasonable, but the user then has no indication that time is being logged to the file as UTC. More seriously, the timestamp in the file lacks a "Z" designator, so when using the information at a later date there is no way to know whether times are UTC or local.

37

This makes sense in most cases, but I think that flogger, like a number of contributed nodes I use or have written, ought to be an exception. Sometimes, the reason for setting a parameter in the edit dialog is to provide a default or fallback in case the incoming message does not provide a valid input. This is how flogger handles the msg.loglevel parameter, so now there is an inconsistency between how msg.filename and msg.loglevel behave.

As an example of how things can go wrong, suppose no filename is provided in the configuration. If the incoming message also lacks a filename, the node reports an error and logs nothing. Fortunately, in this case the incoming message is passed through, and if the user had the foresight to enable a debug node on the output, it might be possible to track down the source of the bad input. On the other hand, if the user does not have write permission for the logfile, the node reports the error and logs nothing but apparently does not pass the message through. I think these issues are important, since flogger is likely to be used to log messages from multiple sources that are intermittent and not entirely under the user's control.

38

At the end of the day it is up the author. As long as it is clear (maybe via info docs) what the behaviour is for the user. We can only suggest.

39

Tbh, I disagree with permitting a msg property to override an explicitly entered property.

Example, say a catch node is attached to a flogger node and the catch node catches such nodes as file. The object sent to flogger will have a filename property that will cause an unusable (or worse, an usable random path) and potentially modify a random or important file.

Perhaps it would be better and less open to interpretation if the file name was a typedInput and JSONata was an option, you could use filename ? filename : 'log.log'

40

Exactly :smiley: . All the more reason to think through the not-so-edge cases and provide good documentation.