RPA - Logging is your best friend

This is about a 5 minute read.

Why post about something so boring and trivial, like logging, that every one does? Because i have found not a lot of people do it much or perhaps use it at a minimum level. This post is probably more aimed at those starting out or people who have come to RPA from a non-programming background. It is only an opinion, but it might be useful for some, and will likely save hours of frustration when your bot is not doing what you want it to.

The Basic premise is: log a LOT; log a LOT of info and make your logging multi level i.e. levels of verbosity

TL;DR

The proposal is that if one is pedantic and detailed about logging in bots, instead of perhaps finding it a bore to add in once the bot is written, it will save considerable time, effort and be the most effective debugging tool anyone needs. It will also make your bots more maintainable. So, if you are interested in the possibilities, read on.

Is the above an obvious statement? Yup, but time and time again when I have viewed logs from bots, they have been practically pointless or useless.

For this post I am going to focus on what is often called the event log i.e. the continuing log of stuff happening in the bot. Error logs etc are pretty self-explanatory (or should be :-) ).

Why do this?

Consider the following scenarios (there are many more):

• You are asked to optimise a bot you didn't write which as many (lets say 20) workflows (.xamls) or sub tasks. How do you get to understand what the bot is up to apart from reading the code and how do you quickly identify the big items to focus in on to optimise?
• You are writing a fairly complex Bot against a legacy windows application, with a tricky UI element (e.g. a non-standard drop down with a custom tree control underneath it - which none of the RPA tools can introspect effectively) and it requires some tricky working out of specific co-ordinates to click and sometimes it works and other times it doesn't.
• You have a complex bot with MANY modules (.xaml or sub task) where data is being interchanged between them perhaps involving retrieving data from multiple APIs and/or databases. Everything has been good in development and system test, but in UAT (with more data) there is an intermittent exception which you don't really know is a data problem (i.e. the API's didn't return specific data in this case) or there is a defect in the bot code.

Are there benefits ? (some examples)

• In these cases, the odd message box is handy, but it's annoying to remove them all (even when the bot goes to production, some can be left in) and in the case of automating UI's, can remove the focus from the element you are automating. So using Message boxes may not always help you. The RPA platform's debugging is useful too but can be a pain in a complex bot.
• If you are in UAT and trying to establish whether it is a defect or the Bot is OK and it's the API or database, it isn't really possible to start adding loads of message boxes to try and diagnose it because the code should be unmodified in UAT.
• Things can change in other systems after the bot is put in production, so it is kinda handy to have the ability to diagnose without modifying the bot. This is standard practise in diagnosing a problem in many systems, by turning on more verbose logging to see where the problem is. A bot should have this too
• The best way to optimise a bot's performance is to use detailed logs to spot slow actions and prioritise and address them. Your logs can give you all that, down to the millisecond
• Many times I have had technical stakeholders claim that having X, Y and Z as separate modules is adding an unwanted speed overhead or some other speed related issue - a quick look in the logs soon dispels that.
• Finally if you hand a bot over to a team who then run and manage it, it is much easier to give them a bunch of steps to take if there is an exception before they call you suggesting the bot has a bug. In my personal experience you get less calls because often the diagnosis is there in the log and often (not always) there is a problem outside of the bot.

So, in summary, if we insert logging as we write (and we make it really easy to do), it is no effort and will pay back countless times. Seems like a no-brainer to me. I am often curious why people don't and apply logging (and commenting) after writing the module - which I personally find to be a real bore.

Some suggestions on approach

1. You can't log enough (logging levels)

Some would argue this is a silly statement as your logs become crammed with thousands of lines of unintelligible data AND in production the logs will chew up a lot of disk space over time. Here is the proposition:

1. Use logging levels like debug, info, warn, error, fatal in your logging and have this as a column. In UiPath this structure exists (debug is called trace).
2. Make your Bot only log the levels you need depending on whether you are in Development, UAT or Prod - usually via the config file. With this set you can log as much as you like to help with developing and debugging the bot knowing there is no need to change code later to remove such logging. In UiPath the logging framework is pretty much set (if you use it correctly) in others you can build a standard logging module that you can re-use

2. Have a really good format and very informative columns

So many times I have seen something like:

(19/09/2021 06:45:00) Some arbitrary text which may have some insight in it or not

This is usually because someone has just done a LOG TO FILE "Some arbitrary text which may have some insight in it", with perhaps "APPEND DATE & TIME" set as an option. In my humble opinion this is of no help, try the following

Have some really good columns e.g.

Date, Time, Logging Level, Process (e.g. overall Bot name), Module (e.g. , workflow etc. in UiPath [i.e. the .xaml name] or task file name in AA), Machine, Type (an arbitrary class of the log entry), System (e.g. the system being automated), Item (the unique item being processed e.g. an Invoice number or PDF file etc.), Message (the log message), Extra Data and anything else you need that is specific to the RPA platform which would be useful

Use a decent file format

Straight text is all very well and good but pretty useless if you are analysing logs, so a delimited format would be better. I find CSV difficult to read when scrolling through so I favour Tab delimited as the columns are separated better when viewed in an editor

Both CSV and TSV can then be viewed in anything as raw text or even loaded into excel so it can be filtered, analysed etc. Allowing flexibility of viewing tool makes things so convenient.

A log file should be viewable in just about anything, minimum being notepad. What I love to use is VS Code with the Rainbow CSV plugin which colour codes each column and will allow column view (each a column is aligned) or normal. As a side note I try not to use excel to view CSV files anyway because what you see is not necessarily what is in the file. VS Code also allows tailing of the log (auto scroll to end) and has the file open without a conflict with the bot writing to it. I am sure these things exist in all the other text editors.

Allow plenty of detail

As an example, I prefer to include milliseconds in the time. The only reason is that I like to optimise the bot's speed and have also often been challenged on the performance implications of breaking a bot up into lots of re-usable .xamls or sub tasks.

I also try to make the message as descriptive as possible, in natural language instead of tech and possibly include data to assist.

2. Build your own re-usable logging component (if necessary)

In UiPath there is a very sophisticated logging framework which should also upload to Orchestrator. You may also wish to supplement this, but at least ensure that you are using all the levels and fields appropriately. You may still want to write a small logging module which makes sure all fields are added and it is simple to log. This will give you standardisation across your bots

If you are not using UiPath and your RPA Platform doesn't have a specific logging framework, that is not necessarily a bad thing. The simple answer is to build your own logging module that deals with all parts of logging and then you can be in the happy place of copy and paste every time you need to log. Seems obvious, but many times I have seen bots with the same repeated custom lines of log to file, which are murder to change throughout all the modules.

While you are at it, make the logging module standalone so it will create a file if not there, add to a file if there and deal with how you want to organise your logs. You could have one file per day and even have an archive folder which it moves old ones into. Also think ahead for the scenarios where your bot may run on a device pool (i.e. run on any bot runner in that pool), so create a directory structure that ensures that bots don't overwrite other bots' logs. I go a bit over the top with [Process Name]\[Production Mode (Dev, UAT, Prod)]\Machine Name, as it can help if your bot also copies logs to a shared drive, i.e. no files get overwritten.

As a personal choice I try and avoid having a year\month\day logging folder structure as I find it tedious to navigate through, but it seems to be a very popular approach. I tend to favour a log file with a time stamp in the name (i.e. one per day) then an archive folder below that.

Mixing Events and Errors in the event log

The Automation Anywhere best practise document suggests having an event log and a separate Error log. This is sensible as it is quicker to read through the Error log if there is a problem. I personally choose to log the error to the event log too as it then gives you context for when the Error occurs i.e. what the bot did before and after.

3. Make a standard approach part of your coding standards

Peer review of code is an important part of a bot deployment process. It will help a great deal to ensure that all bot writers stick to those standards and log to the degree which enables better maintenance and problem diagnosis.

4. Have standard a diagnosis approach for when a bot is in production and problems occur

This will depend on your RPA platform, e.g. in UiPath you can go to Orchestrator and start drilling down. If you have built your own logging module then the process may include changing config to turn on a more verbose logging level and re-running the bot. This means the Bot operations team can gather all the diagnosing information, fix things if the problem is outside of a bot or raise the problem to the right owner (i.e. the bot developer or application/data owner)

It is also important to have a very good error handler module which takes care of logging as much info as possible about the error, whether it is an error or business (data etc.) exception, what the bot does etc., depending on whether the error is fatal/critical or just for one transaction etc.

Summary

So, there you have it, the pedantic view of how to use logging in your bot. I have no idea whether this post is informative or patronising but if it helps someone then all is good. In Summary

1. Log frequently
2. Log with different levels
3. Log a LOT of information
4. Make it a standard approach

Perhaps I should have posted just the above bullets, but I promise it will save you time and effort.