Logging for v1.35

[jeffsf]

The availability of logs during the lead-up to v1.35 has been very valuable to identify issues, be they with the code, the directions, the operator, or even the machine.

These commits assign priorities to hundreds of the previous msg command to make them "filterable" both for developers as well as for users and support-team members, properly provide 64 kB buffering to respect the concerns around flash wear, and enable logging for all users. Stable users will run "INFO" by default, with "DEBUG" available through a plug-in (or future skin modifications). Users on pre-Stable branches will log at the "DEBUG" level.

The "default" settings page has been modified to reflect that logging is on. This will help reduce confusion from experienced users expecting to see an option there, as well as less-experienced ones following outdated instructions.

These are "interim" severity assignments.

The eventual objective is that at the NOTICE level one gets a "quick sketch" of the operation of the machine. At the INFO level, there are enough details to determine, for example, when the scale tare was done, without overwhelming a non-technical users.

There's still a lot of "doubling" with both de1_comms and bluetorh reporting the same event. My plan in the future is to be able to report at the higher level (de1_comms) with a moderate log level and the lower level at a lower level. Users at the INFO level would then only see one of the pair of log messages.

Making the messages "denser" in content and eliminating non-printable "binary" seems needed to be able to achieve these objectives, as well as making it easier to select the "important enough" logging points for the NOTICE level and those that should be pushed down to the DEBUG level.

Thanks to @Mimoja and #90 for the contributions.

Many attempts to set bluetooth devices are done before the device is known to be connected. These, contrary to my instincts demanding checking before they are called, are presently logged as DEBUG, though they arguably should be logged as a WARNING or ERROR in logic that let the call be made at all. Resolving that would require a rework of bluetooth.tcl.

No significant work around changing the content of the messages is in this PR for v1.35. There has been significant work past this to reduce the size of the messages, eliminate "binary" data, and to make the messages more meaningful for a non-expert in that section of code. As these sometimes involve processing of the messages, especially within bluetooth.tcl, changes of this type are planned to be deferred to after the v1.35 release.

[decentjohn]

This is all great stuff. Can I ask you that you copy this documentation stuff in the manual, at a chapter/section where you feel it's appropriate? Otherwise it'll get lost here.

That goes for a lot of the other big sets of documentation you've written.

Feel free to create a page as needed, and I'll edit the table of contents to include a ref to it.

[jeffsf]

Change in commit message 4941b57 to reflect that the name of the method is ::logging::flush_log

[jeffsf]

Rebased due changes on main

Added severity to binary, machine, plugins, updater, utils, vars

Replaced and relocated previously non-functional close_log_file calls

Updated log_debug plugin

Based on discussion with @decentjohn , removed obsolete check_for_multiple_listbox_events_bug

Local work on de1_comms and bluetooth continues. Though seemingly solid here, that these now call other procs for formatting the binary data makes them too risky for inclusion in an imminent v1.35

[jeffsf]

Before

de1plus]$ egrep 'msg [^-]' *.tcl | cut -d ":" -f 1 | wc -l
     559
de1plus]$ egrep 'puts ' *.tcl | cut -d ":" -f 1 | wc -l
     233

de1plus]$ egrep 'msg [^-]' *.tcl | cut -d ":" -f 1 | sort | uniq -c
   1 autopair_with_de1.tcl
   8 binary.tcl
 195 bluetooth.tcl
 136 de1_comms.tcl
   2 event.tcl
  55 gui.tcl
   1 logging.tcl
  29 machine.tcl
   6 plugins.tcl
   1 profile.tcl
  22 updater.tcl
  39 utils.tcl
  64 vars.tcl

de1plus]$ egrep 'puts ' *.tcl | cut -d ":" -f 1 | sort | uniq -c
   2 autopair_with_de1.tcl
  11 binary.tcl
   1 de1_comms.tcl
  67 gui.tcl
   2 logging.tcl
  11 misc.tcl
  25 updater.tcl
  64 utils.tcl
  50 vars.tcl

After
(most are due to use of "msg" as a variable or files like misc.tcl that haven't been reviewed):

de1plus]$ egrep 'msg [^-]' *.tcl | cut -d ":" -f 1 | sort | uniq -c
   1 autopair_with_de1.tcl
   1 bluetooth.tcl
   1 de1_comms.tcl
   2 event.tcl
   7 gui.tcl
   1 logging.tcl
   1 profile.tcl
   3 vars.tcl

de1plus]$ egrep 'puts ' *.tcl | cut -d ":" -f 1 | sort | uniq -c
   2 autopair_with_de1.tcl
   2 logging.tcl
  11 misc.tcl
   2 updater.tcl
   5 utils.tcl

[jeffsf]

Resolved Tk rendering of an inactive, yet selected checkbox in commit 41d00ec

Modified log_uploader plugin to ignore the "placebo" log_enabled setting in commit bdbdab0 (squashed a commit around using::logging::flush_log as that is part of the PR, so can be included without dependency on another PR)

[jeffsf]

Rebased on current upstream HEAD; commit dac1635 (upstream/main, upstream/HEAD)