5.10.2. Understanding and Interpretting ConsoleUser Log Files

ConsoleUser logs are structured as follows:

<date and time>::[<level>::]<message>

The defined levels are TRACE, DEBUG, WARNING, and ERROR.

Some messages are “normal” or “verbose” log messages and do not have a displayed level associated with them.

TRACE messages are intended to trace function calls through the execution. While some legacy functions may miss the ending message, TRACE pairs should have a message that begins with “starting” to show entering the function whose name follows “starting” and then an “ending” message with the same function name, and often the return value at the end of the function.

DEBUG messages are ones the developer thought could be useful when troubleshooting, but would not normally be of interest otherwise.

WARNING messages are a sign that something was potentially wrong, but it also might have been a normal, handled situation. For example, when loading images ConsoleUser searches many locations in a PATH-like structure. If the image is not found at one location, that may generate a warning as an attempted file load was not successful. The next location will be tried, so it may not really represent an error.

ERROR messages indicate something went wrong, though it may not indicate anything is going to derail other operations in ConsoleUser. Failing to find the icon to launch an application, for example, should produce an error, but the rest of the tasks ConsoleUser attempts may well still succeed.

5.10.2.1. How to Troubleshoot

Given that, ideally, each function has its enter and exit logged it’s straightforward, though messy at times, to follow the control flow of the execution. While it’s often good to look for error messages, knowing the path through the code is often helpful. This let’s us trace images being loaded to actions being taken resulting in different conditions being handled and ultimately getting to whatever error went wrong. There may well have been previous steps that we can trace to failures that sent us down paths we didn’t expect.

Presuming the ConsoleUser was stopped shortly after some error we want to diagnose, jump to the bottom of the log file. From there go up in the file to find the source of the problem. Often, this will either be an explicit ERROR message, or a message this is not intrinsically good or bad like:

Sun Jun 15 08:18:54 2025::DEBUG::matches has 0 prospective answers: [] (from /usr/local/tg/cu/ThresholdPatternMatcherImpl.py->match line 105)

In that message, there were no matches found for whatever text or image was being looked for. That isn’t a warning or an error, because the code could be looking to make sure something has disappeared (like a dialog window) where matching the image would be the error condition.

When something has gone wrong though, finding no matches for something near the bottom of the file will often be a clue. In this case we can look at the line before that message and see:

Sun Jun 15 08:18:53 2025::TRACE::Starting ThresholdPatternnMatcher.match for the haystack NumpyRegion wrapping Created from array and needle NumpyRegion wrapping images/qemu/chat/cinny/3.2/win/10/10586/default/usernameField.png and bounded by () with threshold 5

So that failure to match was trying to find the usernameField.png which is likely to be a problem for whatever action was being taken, as it is likely trying to find the login field to enter the username.

So that gives us our starting point for debugging. Ultimately, this user failed to login because it could not match the username field on the screen when ConsoleUser expected to find it there. We can then keep working back through the log to see if there were other errors that led to this situation, or if the image in the library (the png above) was wrong.

A first check for having the right image is to look at the full path that leads to the file. In this case we are expecting a QEMU compatible VNC server (the images/qemu portion of the path), so if we are using VMWare or xvnc we know we have the wrong config setting. Next, we are trying to use Cinny 3.2 on Windows 10 to do a chat action (the chat/cinny/3.2/win/10 portion). If we are not on Win 10 or expected to be using a different application, we know that part of the config is wrong. Next we see it’s using a region modifier of 10586 which corresponds to a particular Windows 10 update that changed some icons, and that it is using the default Windows theme (the 10586/default portion of the path). If the Windows theme has been changed, or a different patch level is being used, those are potentially contributing factors.

If all those path elements are as expected, the problem could be that this username field is being presented differently for some reason, which could happen if the server changed for example. It could also be the case that something in the display settings has changed, like the resolution changing or something similar.

It could also, of course, be that the expected region is just not on the screen when ConsoleUser looks for it. Perhaps an earlier step had failed, so we are not in fact at a login screen now. Maybe some Windows notification is blocking the part of the screen that has the username field we want. Often to troubleshoot steps like that a person needs to watch until the error happens. Since that’s cumbersome (and often boring) many spots that could result in failures are set to be able to save a screenshot of what ConsoleUser saw at the moment of a failure. That can be enabled by defining the config option saveScreenshots. If there is not already such an ability, we can use the ConsoleUser log file to find which file and method was closes to the failed call, and add a line that will vary from file to file but will look something like:

self.dekstop.get_region().save_as_png('/tmp/my_failed_screen.png')

Then using a tool like Gimp we can open both the saved screenshot and the image we were attempting to match to see if there are any obvious differences. Note, it’s important to use the above approach or to use the capture.py tool in the ConsoleUser tools directory to get the reference screenshot. Other techniques may not capture the same view as ConsoleUser has, and since this check involves pixel-level comparisons any deviation in the source could lead to false mismatches.

If we imagine for a moment that we’re having trouble logging into a different application, here using a browser to interact with a blogging site named Elgg. ConsoleUser is having trouble finding the username field in this example as well, so we added a line like above to capture the screen when it should be matching the login field. Below is the full desktop the user “sees” when attempting to match the login field.

And if we look specifically in the area around where the username field is on the screen it looks like (zoomed 800% to show more detail):

Then if we compare to the image ConsoleUesr is attempting to match, in this case using images/qemu/blog/elgg/windows/10/chrome/63/default we can see (zoomed 800% to show more detail):

We can see that the font is different between these images, and the highlighted border around the input field is missing. That explains why the match would fail. Before rushing to capture updated image(s) it will be worth investigating how this match has gone wrong. Is this a different version of Elgg? A different browser? A different theme? Any of those could trigger a missed match, but would potentially prompt different solutions.