System Logs With ms Accuracy - Solved

[William Busby]

For years I've waited for SNOW to provide better logging that shows actions taken in linear sequence to no avail. I recently inherited an app built by a true code monkey with a single script include of 4000 lines. When ran it generates approx 800 lines in the system log. Since it runs within a second or two the log becomes useless given that sequential actions can be logged dozens of lines away from prev/next actions.

This is my solution to log down to the ms (and I can attest it works on large script includes 

 ). You can either add this in your own script include and call it remotely or add it to any Bravo Alpha script include but the heart of the solution is a function like this:

    timestamp: function(){

        return new GlideDateTime().getNumericValue();

    },

Then, anyplace you log using gs.info/warn/error just invoke it as:

gs.info(this.timestamp() + <remainder of your message>); // if the function is in the same si

or

gs.info(new <si_name>().timestamp() + <remainder of your message>);  // if the function is in a remote si

Now you can examine your logs by sorting on the Message field to see things happen in the correct sequence.

[Shane J]

One of our Devs went an alternate route.

Write to the log with an array instead.

Here is an example for Unused Notifications:

checkNotifications();
function checkNotifications() {
	var List = [],count=0;
	var Notification = new GlideRecord('sysevent_email_action');
	Notification.addEncodedQuery('active=true');
	Notification.setLimit(10);
	Notification.query();
	while (Notification.next()) {
		var NoteID = Notification.getValue('sys_id');
		var LOG = new GlideRecord('sys_email_log');
		LOG.addEncodedQuery('notification='+NoteID);
		LOG.setLimit(1);
		if (!LOG.next()) {
			List.push(NoteID);
			count++;
		}
	}
	gs.info("Unused Notifications: \n"+count+'\n'+List.join(','));
}

[Andy-L]

Hi, ServiceNow appear to have added an undocumented(?) sequence field to syslog - here.