Example of using LogProbe() for Remote logging

[nevf]

I've installed Node Monitor and it looks pretty amazing so far. I want use Remote application log monitoring but can't work out how to use LogProbe() which from what I can work out is required, otherwise Log output goes to console. I've never used Backbone which probably doesn't help.

Can someone give me a example please.

[lorenwest]

The key to understanding monitor-dashboard is understanding the monitor package. In the context of logging, your application does something like this:

var Monitor = require('monitor');
var logger = Monitor.getLogger('MyModule');
...
logger.info('place.in.my.module', 'Something happened here.');

And when you run your application, you should see this log statement in your console. The difference with this log statement is that it's a nodejs event - meaning you can watch for these events. In particular, a probe running in one process can be monitored by another process.

The monitor-dashboard allows you to visualize these remote probes in a dashboard. In your case, you place a log component on your dashboard, connect it to your process (in the setting screen), and you should see that log statement in your browser.

That was a high level overview. At this stage of monitor and dashboard, there are far too few examples. Something about writing the code always gets in the way of writing about the code that has been written...

[nevf]

@lorenwest This is how I have it setup. I'm seeing the log output in the console, but I only see logging output from monitor itself. ex.

11:38:21.336 [info] Connection.676.emit [{"0":"probe:change:06c3a0a5-82d0-059f-292f-9388182b2c97","1":{"sequence":6,"bundle":[["2014-03-03T00:38:20.749Z","info","Connection","676.emit",{"0":"probe:change:cc52ea1d-f194-bd24-702d-73e28df0221d","1":"[Object]"}]]}}]
11:38:21.765 [info] Connection.676.emit [{"0":"probe:change:cc52ea1d-f194-bd24-702d-73e28df0221d","1":{"uptime":156411.9015852001,"heapUsed":19758816,"cpus":[{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":35405328,"nice":0,"sys":37076984,"idle":670454375,"irq":725906}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":16514515,"nice":0,"sys":15493437,"idle":710928609,"irq":284953}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":27918562,"nice":0,"sys":20456546,"idle":694561453,"irq":243609}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":18460796,"nice":0,"sys":14277000,"idle":710198750,"irq":230375}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":29488406,"nice":0,"sys":21119000,"idle":692329140,"irq":252171}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":18016843,"nice":0,"sys":13665906,"idle":711253796,"irq":197500}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":27798656,"nice":0,"sys":20590609,"idle":694547281,"irq":222312}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":19323328,"nice":0,"sys":15902312,"idle":707710906,"irq":210656}}],"freemem":10185871360,"loadavg":[0,0,0],"osUptime":1351534.8299296}}]
11:38:22.340 [info] Connection.676.emit [{"0":"probe:change:06c3a0a5-82d0-059f-292f-9388182b2c97","1":{"sequence":7,"bundle":[["2014-03-03T00:38:21.765Z","info","Connection","676.emit",{"0":"probe:change:cc52ea1d-f194-bd24-702d-73e28df0221d","1":"[Object]"}]]}}]
11:38:22.777 [info] Connection.676.emit [{"0":"probe:change:cc52ea1d-f194-bd24-702d-73e28df0221d","1":{"uptime":156412.91583680012,"heapUsed":19860768,"cpus":[{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":35405375,"nice":0,"sys":37077000,"idle":670455328,"irq":725906}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":16514562,"nice":0,"sys":15493453,"idle":710929562,"irq":284953}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":27918609,"nice":0,"sys":20456593,"idle":694562375,"irq":243609}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":18460796,"nice":0,"sys":14277046,"idle":710199718,"irq":230375}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":29488578,"nice":0,"sys":21119046,"idle":692329937,"irq":252171}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":18016859,"nice":0,"sys":13665921,"idle":711254781,"irq":197500}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":27798671,"nice":0,"sys":20590718,"idle":694548171,"irq":222312}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":19323343,"nice":0,"sys":15902359,"idle":707711859,"irq":210656}}],"freemem":10185875456,"loadavg":[0,0,0],"osUptime":1351535.8451832}}]
11:38:23.351 [info] Connection.676.emit [{"0":"probe:change:06c3a0a5-82d0-059f-292f-9388182b2c97","1":{"sequence":8,"bundle":[["2014-03-03T00:38:22.777Z","info","Connection","676.emit",{"0":"probe:change:cc52ea1d-f194-bd24-702d-73e28df0221d","1":"[Object]"}]]}}]
11:38:23.797 [info] Connection.676.emit [{"0":"probe:change:cc52ea1d-f194-bd24-702d-73e28df0221d","1":{"uptime":156413.93264520005,"heapUsed":19961864,"cpus":[{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":35405390,"nice":0,"sys":37077031,"idle":670456296,"irq":725906}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":16514562,"nice":0,"sys":15493468,"idle":710930562,"irq":284953}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":27918640,"nice":0,"sys":20456640,"idle":694563312,"irq":243609}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":18460859,"nice":0,"sys":14277062,"idle":710200656,"irq":230375}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":29488687,"nice":0,"sys":21119125,"idle":692330765,"irq":252187}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":18016859,"nice":0,"sys":13665937,"idle":711255781,"irq":197500}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":27798750,"nice":0,"sys":20590812,"idle":694549015,"irq":222312}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":19323359,"nice":0,"sys":15902390,"idle":707712828,"irq":210656}}],"freemem":10186137600,"loadavg":[0,0,0],"osUptime":1351536.858988}}]
11

I've tried everything I can think of to no avail.

[lorenwest]

@nevf If you can explain how you have it set up, I will help getting this going for you. These items will help troubleshooting:

• Include the lines of code in your app that send the log statement to the console
• Copy the log output you are seeing on the console
• Is monitor-dashboard running on the same machine as your app server? If not, what is the name of the app server machine?
• Describe the settings screen options of the logger in the dashboard (click on the title to get the settings screen)

The settings screen should show the host name your application is running on. It can also include filters to show just the logs you care to see. You can filter on log type (info, debug, error, etc) as well as log module name, and place within the module.

Thank you for your patience during this period of few example docs. If you'd want to blog about your experience, this will help others with the same issue.

[nevf]

@lorenwest ok.

var Monitor = require('monitor');
var mon_log = Monitor.getLogger('Clibu');

I have a Logger function I call which does:

   logger function( msg ){
        mon_log.trace( msg ); 
    }

I've also tried: mon_log.trace( 'Clibu', msg );

Console output:

[2014-03-03T00:33:36.651Z] [TRACE] Clibu - 1) In clibu_db._updateArticle(), Elapsed time: 0s
[2014-03-03T00:33:36.654Z] [TRACE] Clibu - 3) In clibu_db._updateArticle() -> cArticles.update() callback() - !error && && _value, Elapsed time: 0.003s
[2014-03-03T00:33:36.655Z] [TRACE] Clibu - 1) In clibu_db.update_fts(), Elapsed time: 0s

FYI. mon_log.info() doesn't output anything as info doesn't match the regex.test in your log code.

The app is running on the same Windows 8 PC as the monitor-dashboard.

For Log settings match pattern is the default:

{trace,debug,info,warn,error,fatal}.*

I've also tried:

{trace,debug,info,warn,error,fatal}Clibu.*

Server is: Neville-RED:MonitorDashBoard:2 I've also seen: Neville-RED:MonitorDashBoard:1 in addition to :2

Hope that helps.

[lorenwest]

You've gotten very far - congratulations! A few things to point out that may make this easier:

• The logger name when using Monitor.getLogger(name) is one part of the log key
• The second part of the log key is passed in the first argument to mon_log.trace()

• Together, these form the key to the actual log statement. Example:

  var mon_log = Monitor.getLogger('Clibu.db'); ... mon_log.trace('updateArticle', 'Trace message');

This will create a log output like this:

[date] [TRACE] Clibu.db.updateArticle - Trace message

The reason I bring this up is so you can filter your log output by all Clibu logs, just the db logs, or just the updateArticle log statement. With that said, your filter setting can be something like this:

*.Clibu.db.*

The {trace,info,debug,... part could be used as well as the wildcard in that first slot.

So far it looks like you're set up well. Do you have a Monitor.start(); line in your app server? Assuming you do, the fact that you're connecting to Neville-RED vs. localhost may be a problem. Unless configured to allow external connections, node-monitor only allows localhost connections. This is a security setting so you don't accidentally open node-monitor to the world without considering your network security.

Let me know how things are working.

[nevf]

require('monitor').start(); is the first line of code in the main app js file, which is a different file/module to where the logger code is. If I remove require('monitor').start(); I no longer see TRACE messages in the console.

I've changed the filter to: {trace,debug,info,warn,error,fatal}.*Clibu.*

Still can't see anything.

I don't see localhost in the Server list. Neville-RED is the name of the local PC.

[lorenwest]

The server picker on the options screen needs some work. It doesn't include localhost, and it doesn't allow you to enter servers that it doesn't yet know about.

At the bottom of the options form there's a 'view source' button. Push it, and edit the JSON to change the name from Neville-RED to localhost. I'm not sure that will resolve the issue, but am curious if you see any changes.

[nevf]

Edited and changed to localhost and made no difference. Could this be a Windows issue?

[lorenwest]

It could possibly be a windows issue, but monitor-dashboard is tested under windows, and it's more likely something we're both not seeing.

I see in your original log outputs, you're connecting to a Process probe (sending heapUsed, etc). Do you know if that process probe is connected to the monitor-dashboard server, or to your app server?

11:38:21.765 [info] Connection.676.emit [{"0":"probe:change:cc52ea1d-f194-bd24-702d-73e28df0221d","1":{"uptime":156411.9015852001,"heapUsed":19758816,"cpus":[{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":35405328,"nice":0,"sys":37076984,"idle":670454375,"irq":725906}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":16514515,"nice":0,"sys":15493437,"idle":710928609,"irq":284953}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":27918562,"nice":0,"sys":20456546,"idle":694561453,"irq":243609}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":18460796,"nice":0,"sys":14277000,"idle":710198750,"irq":230375}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":29488406,"nice":0,"sys":21119000,"idle":692329140,"irq":252171}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":18016843,"nice":0,"sys":13665906,"idle":711253796,"irq":197500}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":27798656,"nice":0,"sys":20590609,"idle":694547281,"irq":222312}},{"model":"Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz","speed":3399,"times":{"user":19323328,"nice":0,"sys":15902312,"idle":707710906,"irq":210656}}],"freemem":10185871360,"loadavg":[0,0,0],"osUptime":1351534.8299296}}]
11:38:22.340 [info] Connection.676.emit [{"0":"probe:change:06c3a0a5-82d0-059f-292f-9388182b2c97","1":{"sequence":7,"bundle":[["2014-03-03T00:38:21.765Z","info","Connection","676.emit",{"0":"probe:change:cc52ea1d-f194-bd24-702d-73e28df0221d","1":"[Object]"}]]}}]

I'm just wondering if we're getting anything from your app server, or if it's all coming from the monitor-dashboard server.

If you don't mind emailing me the source to your page (Menu / Page Settings / View Source), I'd be happy to see if there's anything in there that may be preventing you from seeing logs from your app server.

You can send to opensource@lorenwest.com

[nevf]

Sent.

[nevf]

@lorenwest Thanks for you help getting logging working. The doc's need updating to help folks in future.

I am seeing the following error now:

[2014-03-03T19:54:25.956Z] [TRACE] Clibu.Logger - Error writing c:\webapps\clibu\server/config/runtime.json { [Error: ENOENT, open 'c:\webapps\clibu\server\config\runtime.json.tmp-229912900']
  errno: 34,
  code: 'ENOENT',
  path: 'c:\\webapps\\clibu\\server\\config\\runtime.json.tmp-229912900' }
Error writing c:\webapps\clibu\server/config/runtime.json { [Error: ENOENT, open 'c:\webapps\clibu\server\config\runtime.json.tmp-229912900']
  errno: 34,
  code: 'ENOENT',
  path: 'c:\\webapps\\clibu\\server\\config\\runtime.json.tmp-229912900' }

Unfortunately there is an issue which prevents me from using monitor. I need to override console.log et.all. and send it's output to my remote logger. Monitor sends it's output to console.log so when I override console.log we get into an endless loop: console.log -> monitor.info -> console.log.

The ability for Monitor to capture & remotely log console.log itself would resolve this, but this may not be possible given how it works.

[lorenwest]

The console log listener monitors log events, sending them to the console. To disable the console log listener, put the following after var Monitor = require('monitor');

Monitor.Config.Monitor.consoleLogListener.pattern = '';

That should disable monitor events from going out to the console.log. Then you can re-route your console log to node-monitor.

Again, apologies for the lack of documentation.

[nevf]

Thanks I'll try that when I get a chance.