Logging Window or Tab

[vonnieda]

Suggestion from @TomKeddie:

We should have a logging window or tab that can be shown or hidden from the view menu. This will be very helpful for users setting up new machines and helping with debugging. It will also be very important for the scripting feature #282.

• Required: Add a new Log tab to the main tabs interface which shows the output from log4j.
• Required: Make sure all UI settings in this feature are saved to preferences.
• Required: Show stdout and stderr in log tab.
• Nice to have: Add checkboxes or a dropdown menu in the tab to turn on and off stdout, stderr and common logging situations, e.g. driver, vision, gcode, etc.
• Nice to have: Add a search box.
• Nice to have: Detach the tab to a floating window so the user can see the log messages while working in other tabs.
• Nice to have: Copy to clipboard/paste buffer.
• System output is getting extraneous newlines. See comment: Logging Window or Tab #288 (comment)

See #333 for potential changes to logging to make this work better.

[TomKeddie]

Thanks.

Nice to have: save to file.
Nice to have: copy to clipboard/paste buffer.

[vonnieda]

First pass at this is in.

[dzach]

Provide a way to clear the log widget (not the log file) and show only new entries from that point in time on. Could be a filter for time (i.e. filter out entries earlier than hh:mm:ss) with a button to set time to "now"

[pfried]

I already fiddled around with the logging on the weekend for some hours, but i had no luck in redirecting the output stream (stdout, stderr) to the Logger and keeping the output on the console. Can anyone give a hint on this or has a link to a working implementation of such a logger redirect?

[vonnieda]

@pfried
Pseudocode:
PrintStream originalOut = System.out;
LoggingPrintStream out = new LoggingPrintStream(originalOut);
System.setOut(out);

The basic idea is to make a new implementation of PrintStream that sends it's output both to the original System.out and to the Logger. The same can be done for err with setErr.

[pfried]

okay, same approach i had, but no luck. I cant remember the problem correctly since it was already some weeks ago. I will try again.

[pfried]

just wanted to leave a quick working notice

I started working on the features above, some things to note:

• I will replace the simple TextOutput by custom elements for each Logentry based on a JList
• Output of the Logging to stdout will be back by adding a ConsoleLogger similar to the Tinylog one but with fixed original output PrintStream

About the UI:

For the search box and also for filtering i think i will "live" filter the underlying LogEntry List. I am thinking about the same for the LogLevels. The LineLimit is a bit pointless then, i would rather remove the line limit and set it to a fixed number.

All other functionalities will happen on the filtered list e.g. save to file, copy to clipboard

[vonnieda]

@pfried Agree on all points, looking forward to seeing the results!

[pfried]

About the issue:

Nice to have: Add checkboxes or a dropdown menu in the tab to turn on and off stdout, stderr and common logging situations, e.g. driver, vision, gcode, etc.

I added one for the System.out, but not for others, additional checkboxes are very easy to add if necessary

Nice to have: Add a search box.

Done, searches whole LogEntry, so searching for class name is ease, also debug levels etc.

Nice to have: Click the class name of a log message to adjust the log level for that class.

I am not so sure if that makes sense, i did not do it because all the permanent settings are hard to display, you would need a list for all logging classes (or the relevant ones) with their corresponding log levels

Nice to have: Detach the tab to a floating window so the user can see the log messages while working in other tabs.

Acutally i do not know how to do this, maybe someone who did the multi window thing should take care of it.

Nice to have: Save to file.

Did not add as i think copying to clipboard is way easier and more helpful. Logs get saved anyway

Nice to have: Copy to clipboard/paste buffer.

Added a button for that

[vonnieda]

Agree on all points.

[vonnieda]

Example of output with extraneous newlines:

[vonnieda]

Many thanks to @pfried for finishing up many of the requested features!

[vonnieda]

Some of the features have been temporarily reverted due to a performance problem in #467.

[pfried]

i saw it, currently i am running a profile run, @vonnieda could you test disabling autoscroll and check if the problem persists?

[vonnieda]

@pfried Yes, disabling auto scroll seems to fix it.

[pfried]

About the general workflow, i think it would actually be nice if we had a more feature branch based workflow where features are in their own branch getting merged at a certain point. Of course there would need to be people who test the branches, but having to hotfix the develop branch is no solution either.

I now cherry picked the commits related to logging and reapplied them. The history now has a ton of entriesm

[vonnieda]

@pfried re: feature branches: this is how I do all of my work, and there's no reason that others can't, too. When I start a new feature I create a branch called feature/feature-name, do all the work and testing in that branch and then when I am happy with it I merge it to develop. Contributors can do the same by branching from develop and submitting a pull request from their branch. When you submit a pull request you are effectively asking me to merge the feature branch into the develop branch.

Typically, if a PR is found to contain a bug after the fact I would not revert it, but instead fix or wait for a fix. But this one created such a serious performance problem that I thought it was best to remove it entirely temporarily until the problem could be solved.

[pfried]

you are right, a bit unsatisfying that my commits caused that much trouble, i would have liked to fix it quickly, but your were so fast i had not enough time to provide a fix

[vonnieda]

It's nothing to worry about. Bugs creep in. I'll review the new PR tonight and get it merged.

[vonnieda]

Indeed, at first glance I'd say that the logger probably tries to send output to System.out or System.err when it encounters an error, which causes an infinite loop and stack overflow. @pfried, thoughts?

[pfried]

One of the writer must have an issue with writing to its stream, but this could be the Console logger or the File Logger. Seems that we need to do a check if the stream is writable, or we catch all the errors without an output to the console. I had Exceptions before (the double line issue) but never saw a behaviour like @cri-s

I will check if I can reproduce the behaviour by setting an invalid config

[pfried]

Cannot reproduce it, @cri-s Could you apply the path below and check if it might solve the problem, only a quickshot

Index: src/main/java/org/openpnp/logging/ConsoleWriter.java
IDEA additional info:
Subsystem: com.intellij.openapi.diff.impl.patch.CharsetEP
<+>UTF-8
===================================================================
--- src/main/java/org/openpnp/logging/ConsoleWriter.java	(date 1490578123000)
+++ src/main/java/org/openpnp/logging/ConsoleWriter.java	(revision )
@@ -36,7 +36,10 @@
 
     @Override
     public void write(final LogEntry logEntry) {
-        getPrintStream(logEntry.getLevel()).print(logEntry.getRenderedLogEntry());
+        PrintStream stream = getPrintStream(logEntry.getLevel());
+        if(!stream.checkError()) {
+            stream.print(logEntry.getRenderedLogEntry());
+        }
     }
 
     @Override

[vonnieda]

I may have reproduced this, or something quite like it. It only happens on Windows, because of another issue. When the OpenCV library shuts down it tries to delete a temporary file and gets an access denied. This causes an exception to be thrown, which the new logging stuff tries to log. This results (somehow) in a StackOverlowException. I can reproduce this simply by running OpenPnP on Windows and then exiting normally. I get a StackOverflowException in the console. Running under the debugger lets me see that this is happening somewhere in SystemLogger.

I think this may be related to #442

[vonnieda]

That registry error is common, I've been seeing that on Windows for years and it doesn't seem to be a problem. I'm not sure why you would be getting a stack overflow on startup. Have you tried backing up and removing machine.xml?

[vonnieda]

Okay, so it must be that the standalone editor is saving a value in the preferences (for the current directory) that somehow kills OpenPnP's reading of preferences. Can you please file this as a new issue?

[vonnieda]

I have temporarily removed system logging as it was causing a whole host of issues. See comments in be475a2

[pfried]

I want to provide a fix for it and also for the StackOverflow. I am pretty busy right now (also due to building my own PnP machine 🤓, will do a forum post on this later on). Expect the fixes within the next 2-3 weeks

[vonnieda]

Newline issue fixed in #579

[vonnieda]

I'm going to go ahead and close this as completed. All the major functionality has been added and there have no further requests for functionality. Future requests can be handled on a one by one basis.