What happened to my print jobs?

We had a long-standing customer contact us recently to ask why some jobs print once, some print twice, and whether a particular job printed at all.

The answer is that you can find all that information in the RPM Remote Print Manager® (“RPM”) message log.

Viewing the message log—basic

You can launch a viewer program for the message log by going to the user interface, then Log / Launch Log Viewer:

However, this information does not show us all the useful information available because there are too many columns for some screens.

Viewing the message log— detail

To see jobs which have printed in the past, we need to export the message log and look at that directly.

To do that, in the user interface, go to Log / Export Log and then select a filename. I generally use “msglog-” followed by the date, for instance, “msglog-0103”, which creates the file msglog-0103.csv in the folder I selected.

Opening the message log

It’s best to view the message log export as a table, for instance as a spreadsheet in Excel. If you have Excel installed, double click on the file you just created. The file should be plain text and therefore safe to load into Excel. The only exception should be job names or queue names which might be UTF-8.

Alternatively, if you have a Google Drive account, you could upload the CSV file into Drive and open it as a Google Sheet.

Explaining the message log layout

Opening my message log file in Excel, this is what I see: 

I've listed just the first few lines. Let's focus on two columns, labeled Job and Description. We will be looking at these to track down past jobs.

Now, let’s search for jobs. Click on the column that lists “Job” at the top. In my copy of Excel, it’s column E. All log records created with a job ID will appear in the log with the ID. If the job still exists when the UI exports the log, it includes the job name. Otherwise, the job name still appears in some of the log records.

Since I”m just “looking around” I’ll scroll down until I see a job ID in the Jobs column:

Even without being an expert on everything RPM does, it shouldn’t be difficult t decipher that RPM created this job in the queue “archive2” and the job ID is 170810.

Now let’s use the search function to find more records for this job. I usually use the Ctrl+F shortcut. Type in the job number and let’s see where it takes us.

To save time and explanation, I’ll list the descriptions that appear with the remaining instances of this particular job in my log:

• Job '170810' name 'aa-audit.8' starts process with action 'SaveFolder' in queue 'archive2'
• Init successful action 'SaveFolder' job 'aa-audit.8', 'bytes=1104'
• Remove job '170810'.
• Close successful action 'SaveFolder' job 'aa-audit.8', 'bytes=1104'
• Job '170810' name aa-audit.8 completes process with action 'SaveFolder' in queue 'archive2'

My summary of these events is as follows: RPM received the job, created it, processed it, the job completed, and RPM removed it. The fact that RPM logs that it removes the job ahead of closing the job is not a concern to me. I sent 785 jobs, and all the jobs appeared in the target directory with the correct size.

If you care to know when these events happen, the timestamp is to the left of the description. Going back to the record “Create job name,” Excel displays the time value as “11:43.5” because “display as number” is the default. When I click on the date cell it shows the date and time as “1/2/2019 2:11:43 PM” RPM stores the actual time with milliseconds, so we have a much more precise value to work with, should that be useful.

More observations on the message log

1. The message log is useful to us as a record of "what" happened, but not "why." For instance, looking at another log, I saw a series of jobs that had only “create” and “remove” records. It took me a moment to remember that I sent jobs to a suspended queue and then purged that queue.
2. The message log does not stand alone. We have two other logs which at times we need access to so we can better understand a situation. Please don’t call support based on a single entry in the message log. No matter what you read in this article, we’re the ones who work with the technology and understand it better than anyone. Ultimately it’s the developers' call to request logs.
3. Logging at high detail no longer slows RPM down. It used to be that you could visibly watch progress slow to a crawl. Since we added message log buffering, this is no longer a problem.
4. If you turn off logging, you get no logging. We have added many other performance improvements to RPM over the past months, so if your job mix was too much to handle, take a look at the newer versions of RPM.