Log Refactor

[hecon5]

This is the first part of #507

First to demonstrate the log speed (this new one is FAST), and to maintain the functionality of the existing code (a whole-system refactor is not super duper desirable), and to incorporate the remaining elements of the log tool.

Remaining elements:

• clsOptions
  • Log Level (currently natively part of the new log class, but is not implemented in options) (Added to options)
  • DisplayLogLevel
  • Add Upgrade Options for ShowDebug
  • [-] Remove ShowDebug as an option.
    • [-] ShowDebug is used 32 times. Suggest setting those use cases to an event level of eelDebugTrace, eelDebugEvent, or eelDebugInfo
    • Alternately: could just create an option that is If Options.DisplayLogLevel < eelNoError Then Options.ShowDebug = True (this seems the easiest way to handle it, actually)
  • Set LogLevel and DisplayLogLevel after Options are loaded
  • Whether logs are persistent or transient (per export) (default to not persistent)
    • Replicated existing method
  • What fields are logged (meta data)
    • Username
    • Computer name
    • Operation and operation state
    • others?-
    • Current operation and operation state
    • Current file being built
    • Addin Path?
  • Add persistence mode (defaults to off).
  • Determine how to parse the XML to a human readable output.
    • Do we need to save the color/HTML the console displays?
    • Can this be easily parsed to MarkDown?
• frmOptions:
  • Change Show Debug Checkbox to dropdown option for DisplayLogLevel.
  • add dropdown for LogLevel
  • Add option for persistent log (future). Current operation method will make this perform the same as currently happens (non-persistent logs).
• Get connection to the addin corrected; currently will only call the local program, but getting a connection to the addin shouldn't be too bad.
• Log persistence; the current tool exports the log to an xml file; need to implement a tool to pick that log back up into the log from the last exports; once you close the addin (from the built database) the addin resets to the previous state. To make the log persistent, we need to either reimport the previous values OR append them to the previous export.
  • It turns out the log is persistent when a table in the addin is used.
• Ensure backwards compatibility with previous log
• Determine how to handle "Private" log information that would be very valuable to a internal dev team, but should not be sent out. These would be especially informative for projects that share a dev space, and / or have a runner that's triggered by merge events.
  • Username
  • Computer Name
  • others?
  • Use a command SQL statement to select only relevant columns (aka don't export the sensitive columns where desired)
• Auto-build the temp file and external log (to avoid bloat on Addin file directly).
• Build cleanup for temp file and external log file (ACCDU).

This first PR is to build out others, create discussion, and have some review before we go forth. I've implemented it here as a ridealong to demonstrate feasibility and speed impacts (in my testing, it did not impact speed of export or build at all) and provided a ton more information and time stamp detail than I had.

The log also allows us to set the log level and thus keep the log a lot cleaner when users don't need ultragranular detail. For instance, if you're troubleshooting an export, you can set the log to log everything, even Debug Tracing. If you're in production, and you just want to know if warnings or more happen, you set it to warning.

Let me know what you all think!

If this initial implementation looks ok, I will refactor the rest of the clsLog2 class into the new one, but wanted to start off by showing a proof of concept.

@joyfullservice @josef-poetzl @bclothier anyone else?

[josef-poetzl]

eelLoggingOff ... should error level and LogOn/Off be separated so that the error level can be retained?

[hecon5]

The LogLevel and ErrorLevel are not retained the same; the Log.LogLevel is stored in the Log class, and the ErrorLevel is stored in clsOperation Operation.ErrorLevel; this way we can reuse the enum for both. If an error level is set but not logged, it's still retained in the Operation.ErrorLevel (despite not being logged) if this makes sense.

[hecon5]

I updated the error handling to show this in Log2.Error

[josef-poetzl]

I would not name this class clsErrorInfo but clsErrorLevel or similar.
Unlike my clsErrorInfo (#652), it only provides the ErrorLevel data.

When designing the clsErrorInfo, I encapsulated the complete error information - i.e. including the error message.
This enables the delegation of an ErrorInfo instance to the logger class.
This means that the composition of the text can be implemented in this class and the logger class can concentrate on the task of generating log entries.

Just a thought:
In principle, you could use 3 (or more?) classes:

1. class with the error data (clsErrorInfo)
2. class for formatting and output this data (here perhaps even several classes, depending on the output type)
3. class to control above: clsLog

clsLog:
RaiseEvent LogError(eInfo as clsErrorInfo)

clsLogOutputToFile, clsLogOutputToTexbox, ..
listen to event clsLog.LogError

This would allow you to switch log output classes on/off at will.

Similar (AccUnitLoader):
DebugPrintTestResultReporter.cls
LogFileTestResultReporter.cls
MsAccessVcsTestResultReporter.cls

/edit:
https://github.com/josef-poetzl/msaccess-vcs-addin/tree/dev-refactor-log
This would make it possible to attach any logger.

[hecon5]

Hmm, these are good points.

I think for the purposes of this addin, while being able to have an extensible log would be nice, having a consistent entrypoint and keeping it easier would be better in this case. Especially since most of the log entries should hopefully be simply notifications of state and process notes, not errors.

Also, I am not sure having extra classes to handle errors helps more than the cost of carry. To me, having the clsErrorInfo (or whatever we end up calling it) is really only there to help with consistently handling the warning/color notes as presented to users, not to format the error message. To me, that's the job of the calling function. I don't know we want to have the same error message type presented to the user if we expect an error and just need to make sure they're good with continuing vs an unexpected critical error (where they will probably need more information to debug it), and the best place for that would be the calling function, which would know if you want to use Log.Error, Log.Prompt, or Log.AddEntry and skip presenting the user with info entirely.

[josef-poetzl]

... I am not sure having extra classes to handle errors ...

Only extra classes to present or save the log.
For example: I personally do not need a permanently saved log. Then I simply do not activate this “listener” and the rest continues to run without any changes.

Or: Automated export via PowerShell ... then you could create an extra logger for this, which outputs to the shell console etc.

[hecon5]

I went ahead and made the functionality of the existing log export the same as before; this ensures the operation stays the same until we determine if more extensibility is needed (or wanted).

[hecon5]

@josef-poetzl I have this just about finished up; though, I'm having trouble getting Application.ExportXML to export the Addin's log. It seems that even if I do CodeProject.Application.ExportXML whatever project you're working on is exported, not the AddinLogs.

I did discover that the LogTable in the addin (when the addin is loaded as an addin) DOES keep the data from operation to operation, which is a neat thing, but I can't seem to get the thing exported correctly.

I even went so far as to use the RunInAddin but even then, it only seems to export the table from the exported file, not the addin log, and I am stuck.

[josef-poetzl]

Maybe use a querydef (in the FE) that accesses the table in the add-in?
select * from [Path to add-in].TabName
Or temporarily link the table in the FE.

The ADODB XML export is probably not an alternative, is it?

By the way: don't forget that the data is gone when you update the add-in.
Possibly write to an “add-in data” file instead of the add-in (Version Control.accdu).

[hecon5]

By the way: don't forget that the data is gone when you update the add-in.

Correct, it's actually desired; in actuality, I'm not sure I even wanted it to persist between sessions (to keep it lightweight), but that's another discussion. I don't know if we want the log to be muddied between different files being built/export, keeping the log to a single project is probably ok long term though.

Depending on how long it takes to import/[do operation]/export to project log it may end up being more efficient to simply keep a per-operation log like is done now.

The ADODB XML export is probably not an alternative, is it?

Hmm, I'll give that a shot; I was hoping to use a consistent XML export routine in case we ended up needing to sanitize it like we do with the tables; this gives the advantage of using the same XML parsing tools used by the addin for the built db and therefore a consistent XML look.

[hecon5]

Figured it out!

https://learn.microsoft.com/en-us/office/client-developer/access/desktop-database-reference/streams-and-persistence

was what I needed; it's also stupid fast; exporting about 900 records in a half second.

I'm going to tidy it up and push up the finished up code; this first version will export the log, clear out the log after each operation so it's not persisted (as is the case now).

If this works well I'll add some options to allow the log to be appended to the existing XML file or simply continue as-is (the current system).

If that works well, the next step will be to expose the new log class externally via the API (so that the pre/post called functions can log their state if desired).

[hecon5]

half a second

this is guestimation; I haven't timed it, I suspect it's faster than that, I just wanted to point out that this operation doesn't take any more time than the current log saving mechanism.

[hecon5]

ooh, unintended upside: because this class now relies on a table in the addin, if you somehow crash the addin/MS Access the log table remains and it will export next time you run an operation. This has been nice when I've caused a bug and needed to force close but don't know what went wrong during the export.

[josef-poetzl]

I tested this version: works fine.

One minor issue:
“Exporting xxx...” and “[n] xxx exported” appear at the same time. This makes it difficult to see which area the progress bar is currently running for.

Personally, I prefer the more compact display of 4.1.
But perhaps you will display other information such as "[m] failed".

I would move the log table to an external file (accdu extension is a good choice) so that the add-in file does not keep getting bigger, as you probably won't compress the add-in file regularly.
Furthermore, I feel that no data should be stored in an add-in file. :)

[hecon5]

Thanks for the review!

“Exporting xxx...” and “[n] xxx exported” appear at the same time. This makes it difficult to see which area the progress bar is currently running for.

This is due to how the Log.Flush runs; to speed up the export (causing a DoEvents slows things down a lot) the data may not show up instantly. Tuning how often a Log.Flush happens could improve that. Personally, I think the ProgressBar should have a simple caption outlining the task at hand, but that increases complexity and separates focus from the task at hand.

Personally, I prefer the more compact display of 4.1.
But perhaps you will display other information such as "[m] failed".

Fair point! Because I didn't want to refactor the rest of the code (yet) to accommodate the log levels, I set the Log.Add to , ErrorLevelIn:=IIf(blnPrint, eelNoError, eelDebugTrace) _, which has the unintended side effect of potentially displaying more information than desired.

Refactoring to instead use Log.AddEntry will allow us to set the eErrorLevel and therefore tune what is / isn't being displayed via preference.

an example I'm working on which would allow us to set the type of log information (and therefore how much/little is being displayed)

' In "ExportSource"

        .AddEntry T("Beginning Export of Source Files"), FunctionName, eelDebugInfo
        .AddEntry CurrentProject.Name, FunctionName, eelNoError
        .AddEntry T("VCS Version {0}", var0:=GetVCSVersion), FunctionName, eelNoError
        .AddEntry T("Full Path: {0}", var0:=CurrentProject.FullName), FunctionName, eelDebugInfo
        .AddEntry T("Export Folder: {0}", var0:=Options.GetExportFolder), FunctionName, eelDebugInfo
        .AddEntry IIf(blnFullExport, T("Performing Full Export"), T("Using Fast Save")), FunctionName, eelNoError
        .AddEntry "Time: " & ISO8601TimeStamp(False, True), FunctionName, eelNoError

would move the log table to an external file (accdu extension is a good choice) so that the add-in file does not keep getting bigger, as you probably won't compress the add-in file regularly.

Hmm, I'll do some testing on this. my goal to start with is that it is just as fast as the original log class and has additional features; I didn't want to create additional dependencies without careful consideration.

We could just have the file auto-compress on close/unload which (in my testing) doesn't impact it much. I'll do some testing on this.

Furthermore, I feel that no data should be stored in an add-in file. :)

Agreed; any log persistence would be a result of storing the logs in the source files, not the addin.

[josef-poetzl]

I think the ProgressBar should have a simple caption

Very good idea!
Without this text, you can only ever show the result. The text before the “...” then has no added value.
If something takes longer, I want to know what's going on.

We could just have the file auto-compress on close/unload which (in my testing) doesn't impact it much. I'll do some testing on this.

Please don't. :)

[hecon5]

Please don't. :)

🤣

[josef-poetzl]

Hmm, I'll do some testing on this. my goal to start with is that it is just as fast as the original log class and has additional features; I didn't want to create additional dependencies without careful consideration.

I don't see any particular dependency. If necessary, you can simply (re)create the file in the add-in directory.
As long as no data is to be saved, even a temp file would do the job.
A file stored in the add-in directory would have the advantage, as you have shown above, that the entries are retained in the event of a crash.

[hecon5]

I don't see any particular dependency.

Less of a class dependency, more of a "external file" dependency that has to be managed. Not insurmountable, but I didn't want to begin by creating a ton of complexity.

As long as no data is to be saved, even a temp file would do the job.

Good idea; I'll test that out; I think that may be the best way to do it.

[josef-poetzl]

Tested "Build from Source": Console log is empty.

BTW:
Please do not replace the original log exports with the xml export so that the content remains readable.
The XML is good for the data, but not for the eye ;)

[hecon5]

Tested "Build from Source": Console log is empty.

Huh. I'll take another look and see if I didn't commit a fix on accident.

BTW: Please do not replace the original log exports with the xml export so that the content remains readable. The XML is good for the data, but not for the eye ;)

I agree, I think I may export the data column and strip the HTML out of it may be easiest.

Lastly, I am having some trouble generating a temp ACCDU file. Connecting to it is no problem, and it seems fast enough when it's connected, but my simpleton lines aren't able to build the file. I will try and get those pushed today and maybe you have some ideas.

[josef-poetzl]

An example from one of my add-ins:
https://github.com/AccessCodeLib/ACLibImportWizard/blob/main/source/modules/ACLibConfiguration.cls (procedures: CheckConfigTableDef, ACLibConfigDatabaseFile)

[hecon5]

Made some progress; thanks for the tip! Worked a treat. Will hopefully get this tidied up and pushed up today.