[mkgmap-dev] logging improvements

Wed Apr 7 00:23:18 BST 2021

Hi Gerd,

Please find attached small patches to 3 modules that improve their error
handling, plus the patch to remove commented out System.err.println
statements, which has no code changes.

In GmapiBuilder, the print stack trace calls have been replaced with
throwing ExitExceptions as in the other combiners, so that program execution
correctly stops.

In FileInfo, the thrown ReadFailedException has been replaced with a
MapFailedException, so that it is correctly picked up.

In TypSaver, there is an extra check for an empty file as this was not
handled properly.

Regarding the removal of duplicate messages in StyledConverter, I may be
being naively simplistic, but thought that as the data in the static list of
already logged messages has no effect on the actual generation of a map,
that any race condition would not really matter. If two threads attempt to
update at the same time and only one succeeds, the only impact will be that
it is possible that a duplicate message will later be output (assuming the
two threads are reporting different problems). If they are both reporting
the same message (which is most likely) then there will be no impact at all.
If two threads read that a message has not been displayed and then both
successfully manage to add to the list then the only result will be that
there is a duplicate entry in the list, which should have no impact as the
code is only checking for existence of an entry. Regarding the combinations
of styles and settings, I just need to combine both the  style name and the
option setting before adding to the list. Let me know if you think there is
any other problem I haven’t considered.

I don't at present have a fix for the unit test. Possibly creating a
separate process to run mkgmap when stderr/out needs to be read, rather than
directly calling it might work. Do you have any other suggestions?

Cheers,
Mike

-----Original Message-----
From: Gerd Petermann [mailto:gpetermann_muenchen at hotmail.com] 
Sent: 06 April 2021 09:21
To: Development list for mkgmap <mkgmap-dev at lists.mkgmap.org.uk>
Subject: Re: [mkgmap-dev] logging improvements

Hi Mike,

I can live with the codepage problems if we document the workaround (at
least in the svn commit message)

Reg. the changes in StyledConverter: I thought about this as well but found
it too much work to handle the case that a user can use multiple styles or
different combinations of styles and style-option settings. Did you consider
this? Remember that we have multiple instances of StyledConverter, possibly
using different settings regarding these options. I wonder why I see no code
that handles concurrent updates of the static lists.

Yes, I think it would be good to split the patch. I'd start with a patch
that fixes the unit tests (if you have an idea) and the other errors that
you found so far. I prefer to have a few smaller commits with clear commit
messages.

Gerd

________________________________________
Von: mkgmap-dev <mkgmap-dev-bounces at lists.mkgmap.org.uk> im Auftrag von Mike
Baggaley <mike at tvage.co.uk>
Gesendet: Dienstag, 6. April 2021 02:20
An: 'Development list for mkgmap'
Betreff: Re: [mkgmap-dev] logging improvements

Hi Gerd,

I have updated the patch with the following changes:

The --version option now outputs 2 lines, the first containing "mkgmap
version <version>", the second just <version>.

The log output now starts with " mkgmap version <version>" as its first line
before the start time.

I have replaced the use of logging Level.ALL with 3 custom levels
LogLevel.DIAGNOSTIC, LogLevel.ECHO and LogLevel.OVERRIDE (used by functions
log.diagnostic, log.echo and log.write respectively). The first is used to
display messages from the diagnostic options, the second is used for echo
and echotags and the last is used for general message that are required to
be included, such as the start time. The default output does not display
these prefixes, but if you use a logging.config file, they will be visible
to it.

I have replaced the calls to explicitly write stack traces with calls to
log.error, making sure they all have an error message, and passing the
exception as a  parameter. The default action for these is for the logger to
display a stack trace, which can be disabled in a logging.config file if you
don't want to see it.

In GmapiBuilder, the print stack trace calls have been replaced with
throwing ExitExceptions as in the other combiners, so that program execution
correctly stops.

In FileInfo, the thrown ReadFailedException has been replaced with a
MapFailedException, so that it is correctly picked up.

In TypSaver, I have added a check for an empty file as this was not handled
properly.

In O5mBinHandler a thrown IOException has been replaced with a
FormatException which is better handler.

I have added some code to StyledConvertor to prevent the duplication of
messages about style options.

The "roundabout has reversed way" messages are only displayed if
checkroundabouts is enabled.

I have looked into the code page issue and on Windows, the java environment
defaults to setting its code page to the system default, which on most
Windows machines will be 1252 as used by Windows applications. However, the
command prompt generally has a different code page - it is 850 on my
machine. It appears to be very tricky to change the code page within a Java
application, however, you can specify -Dfile.encoding=850 as a Java argument
or use chcp 1252 before running mkgmap. As 1252 contains more useful
characters than 850, chcp 1252 is likely to be a better solution. It only
seems to be an issue when actually displaying the output in a console
window. When directed to a file it doesn't seem to be a problem, so in
practice it probably isn't much of an issue, as I would think that if people
are displaying messages about road names etc, then there are likely to be
too many to view directly in the console. I'm assuming that the Java
environment doesn't know whether you are running a console program or a
Windows application and hence chooses the code page of the latter.

I have also looked further into the problem in the test suite and it appears
that the redirect of stderr and stdout in the Outputs function does not
capture anything that has gone through ConsoleHandler, even though its
output is directed to stderr. I assume there must be some creation of
separate streams by ConsoleHandler - it can't internally use System.err, as
it is not thread safe, unlike ConsoleHandler. Although only one test is
failing, this actually means a few other tests don't work properly, as they
are checking for an empty stderr output and they will never get anything
else.

I'm now thinking my original suggestion that command line argument errors
should go to stdout was possibly not the best option and these would also be
better going through the logging system. If you have specified a
logging.config file, it would make sense for these messages also to be under
its control. Not all command line argument errors are detected before
processing of input files starts anyway. What is your view?

If you think the patch is getting too big, I could split off the changes
that result in either new or different exceptions being thrown and the
removal of duplicated messages into a separate patch to be introduced first.

Cheers,
Mike

-----Original Message-----
From: Gerd Petermann [mailto:gpetermann_muenchen at hotmail.com]
Sent: 30 March 2021 20:01
To: Development list for mkgmap <mkgmap-dev at lists.mkgmap.org.uk>
Subject: Re: [mkgmap-dev] logging improvements

Hi Mike,

I agree that it would be good to have the version in the output.
I have no idea how users handle the different output files. I guess they do
anything that works somehow.

Gerd

________________________________________
Von: mkgmap-dev <mkgmap-dev-bounces at lists.mkgmap.org.uk> im Auftrag von Mike
Baggaley <mike at tvage.co.uk>
Gesendet: Montag, 29. März 2021 21:57
An: 'Development list for mkgmap'
Betreff: Re: [mkgmap-dev] logging improvements

Hi Gerd,

If the changes to the logging are applied without also changing the handling
of --check-routing-island-len, users who are using the option to remove
routing islands but do not have Level=INFO enabled (i.e. don't want to see
the messages) are likely to get a lot of unexpected messages. Similarly, if
the --report-dead-ends change is not also implemented at the same time,
users who do not specify --report-dead-ends and do not have Level=WARNING
enabled will start to get a lot of unwanted messages because
--report-dead-ends is on by default.

For --version, how about we output the following:
Version <version>
<version>
and give notice that at some point the second line will be removed? I'm not
entirely sure whether the link you passed was referring to --version or
$MKGMAP_VERSION$. There seems little point in using a script to extract the
version so that you can write it to the license file when you can specify it
directly anyway.

I also think it would be useful to write the version number to the log file
along with the start date and time. Does that sound reasonable to you?

I would have thought most people would be using 2>&1 to redirect both stdout
and stderr to the same file. I certainly don't want messages arbitrarily
going to different places. That and the problems with multiple threads were
my motivation for the patch. I will have a look at your codepage issue - I
use a Microsoft msbuild script to run the various programs involved in
building my maps and normally my logfile correctly displays non-Latin
characters, but occasionally they are corrupted and I think it may be when
mkgmap is the only program that needs to run, so it may be that there is a
problem if mkgmap creates the file, but it works if it appending to an
existing file.

I'll have a look at your config file. Mine seems to work OK; I see that we
are both using SimpleFormatter rather than UsefulFormatter.

I've attached a patch for the parts that were just removing commented out
System.out.println and System.err.println statements (so that they don't get
found when using search on the source). We can at least get those out of the
way...

Cheers,
Mike

-----Original Message-----
From: Gerd Petermann [mailto:gpetermann_muenchen at hotmail.com]
Sent: 29 March 2021 08:03
To: Development list for mkgmap <mkgmap-dev at lists.mkgmap.org.uk>
Subject: Re: [mkgmap-dev] logging improvements

Hi Mike,

I do not yet understand why we can't do the logging changes without changing
the meaning of options.
Anyway, a few observations:
- I think we have to be careful regarding the output of --version. Those who
extract the version number with a script probably expect two lines. See
http://gis.19327.n8.nabble.com/version-numbers-tp5734654p5734862.html

- style functions echo and echotags are now writing to the logger instead of
stderr, this looks like a major change. There also seems to be a difference
reg. codepages, I tried with a lines file containing just highway=*
{echotags "hw"} and the german road names with umlauts are unreadable.
Output of chcp command:
D:\mkgmap>chcp
Aktive Codepage: 850.

- the changes are not compatible with my existing config file for logging
which expects a prefix like WARNING, INFO or SEVERE (see attachment), not a
show stopper but others may face this problem as well. See attached file.

Gerd

________________________________________
Von: mkgmap-dev <mkgmap-dev-bounces at lists.mkgmap.org.uk> im Auftrag von Mike
Baggaley <mike at tvage.co.uk>
Gesendet: Sonntag, 28. März 2021 16:43
An: 'Development list for mkgmap'
Betreff: Re: [mkgmap-dev] logging improvements

Hi Gerd,

To assist with examining the patch, most of the source files have very small
changes. Here is a breakdown:

RouteArc - remove commented System.out.println
ExtTypeAttribues - remove commented System.err.println
TypElement - remove commented System.out.println
ImgHeader - - remove commented System.out.println
Locator - - remove commented System.out.println

FileBackedImgFileWriter - replace one System.err.println
MdxFile - replace one System.err.println
MdrFile - replace one System.err.println
NumberStyle - replace one System.err.println
EchoAction - replace one System.err.println
EchoTagsAction - replace one System.err.println
AbstractOp - replace one System.err.println
HousenumberGenerator - replace one System.err.println
OsmXlmHandler - replace one System.err.println
RestrictionHelper - replace one System.err.println
LblFileReader - replace one dubious System.err.println("Map has tide
prediction, please implement! ")
OverviewBuilder - replace System.out.println (2) + remove commented one
CommandArgs - replace System.out.println and System.err.println (2)

TdbBuilder - remove unneeded error message
ImgFS - fix duplicated file name in error message

Utils - write stacktrace to log
FileInfo - write stacktrace to log
HGTReader- write stacktrace to log
CoastlineFileLoader- write stacktrace to log
O5mBinHandler - write stacktrace to log
OsmMapDataSource - write stacktrace to log
SeaGenerator - write stacktrace to log
PrecompSeaGenerator - write stacktrace to log
PrecompSeaSaver - write stacktrace to log
PrecompSeaMerger - write stacktrace to log (2)
HGTList - write stacktrace to log (2)
GmapiBuilder - write stacktrace to log (2)
NsisBuilder - write stacktrace to log (4)
LocatorConfig - write stacktrace to log + replace System.out.println

These last few have slightly more changes:

RoadNetwork - changes for --check-routing-island-len plus fix spelling
mistakes
RoutreNode - changes for displaying the output of roundabout, flare and
similar arc checks
Logger - changes to logging interface
UsefulFormatter - changes to logging interface
GmapsuppBuilder - several message changes
CommandArgsReader - minor change to facilitate not writing date and time if
not processing a file
Main - various improvements to logging
MapMaker - several replacements of System.err.println and log.err
StyledConverter - change to --report-dead-ends default + several
replacements of System.err.println and log.warn
StyleImpl - several replacements of System.err.println and log.err

Cheers,
Mike

-----Original Message-----
From: Gerd Petermann [mailto:gpetermann_muenchen at hotmail.com]
Sent: 28 March 2021 10:17
To: Development list for mkgmap <mkgmap-dev at lists.mkgmap.org.uk>
Subject: Re: [mkgmap-dev] logging improvements

Hi Mike,

again: Please separate the changes regarding --check-routing-island-len from
those changes reg. logging.
It's a huge patch and I don't see a reason to mix the two things.

Gerd

________________________________________
Von: mkgmap-dev <mkgmap-dev-bounces at lists.mkgmap.org.uk> im Auftrag von Mike
Baggaley <mike at tvage.co.uk>
Gesendet: Donnerstag, 25. März 2021 11:15
An: 'Development list for mkgmap'
Betreff: Re: [mkgmap-dev] logging improvements

Hi Gerd,

Please find attached an updated patch.
Regarding your points:
1. I have been unable to fix the unit test. The patched version writes the
message to stdout when not using a logging.config file, but changing the
test from checkError to checkOutput does not fix the problem. Running the
test under the debugger, it appears that the test harness has nothing in
either the stdout or stderr stream, though the Eclipse console window
clearly shows output. This will need someone who understands the unit test
system better to fix the test.
2. Message fixed
3. Capitalisation fixed
4. Level.OFF is the correct value. The documentation refers to filtering
messages but does not mention use as a message severity.  Level.OFF is
Integer.MAX_VALUE and level.ALL is Integer.MIN_VALUE. Filtering works by
allowing messages of the filter value or higher. Hence using Level.OFF as a
message severity causes it to be always written, and Level.ALL will never be
written unless the filter level is also Level.All. I have added a comment to
the code to clarify this.
5.I have fixed a couple of SonarLint issues in the logging module, however
most of what it comes up with is of no consequence (there are hundreds of
warnings of dubious value).

I have also rethought the way error and warning messages that are unrelated
to input files are logged. Rather than using a write function using
Level.OFF as in the first version, I have added a global logger so that the
standard logging interface can be used. By default this global logger allows
errors and warnings though, whereas the other loggers only allow errors.
This means that program warnings can be displayed without having to display
OSM data warnings as well.

Cheers,
Mike

-----Original Message-----
From: Mike Baggaley [mailto:mike at tvage.co.uk]
Sent: 20 March 2021 12:55
To: 'Development list for mkgmap' <mkgmap-dev at lists.mkgmap.org.uk>
Subject: RE: [mkgmap-dev] logging improvements

HI Gerd, thanks for the reply

The new static method Logger.Write does not output any input file name and
is designed to output the same text as would have been output by
System.err.println. I may have used log.error rather than Logger.Write as a
replacement for System.err.println in a few places where I couldn't see a
reason why it hadn't been used - I'll have a look at these again.

1) Can you let me know how to run the unit tests?
2) I will change the message to correctly display -- report-routing-islands
(I initially started with --check-reporting-islands but decided report was
better, I must have omitted to change this message).
3) I am used to using capital letters for static functions -  I am happy to
change these to lower case.
4) I will look at using Level.ALL instead.
5) I will look into installing Sonarlint. I do get thirty-odd compiler
warnings, but none of these are related to the patch.

Cheers,
Mike

-----Original Message-----
From: Gerd Petermann [mailto:gpetermann_muenchen at hotmail.com]
Sent: 20 March 2021 08:28
To: Development list for mkgmap <mkgmap-dev at lists.mkgmap.org.uk>
Subject: Re: [mkgmap-dev] logging improvements

Hi Mike,

I agree in many points.
One reason to use System.err.println() instead of log.error() is that some
messages are not related to a specific input file and thus should not show
any input file name. Typically this is true in the combiners. I did not try
if your changes reflect this, but I think they don't?
The stacktraces help to indentify possible causes when users report
problems. I see no reason to remove them.

Please review,

1) unit test testWarningOnMismatchedCodePages fails.
2) The use of e.g. check-routing-island-len=1 gives message
"The --check-routing-island-len option is deprecated. Please use
--check-routing-islands and/or max-routing-island-len"
but --check-routing-islands is not a valid option. If possible, please
create a separate patch for the changes regarding options.
3) the new method names like Logger.Write or Logger.WriteStackTrace do not
comply with naming conventions, method names should not start with upper
case characters
4) The use of Level.OFF is confusing. My understanding is that the constant
is meant to disable logging?
5) Sonarlint complains about "Preconditions" and logging arguments should
not require evaluation (java:S2629) but that's not new with your patch.

Gerd

________________________________________
Von: mkgmap-dev <mkgmap-dev-bounces at lists.mkgmap.org.uk> im Auftrag von Mike
Baggaley <mike at tvage.co.uk>
Gesendet: Samstag, 20. März 2021 00:52
An: 'mkgmap development'
Betreff: [mkgmap-dev] logging improvements

Dear all,

Please find attached a first stab at improving the way error and other
messages are written, which at present is an ad hoc mixture of writing to
stderr, stdout and using Java logging, with no apparent logical structure.
Writing to stderr or stdout is not thread safe and causes problems when
max_jobs is greater than 1. When stderr is redirected to a file and threads
simultaneously attempt to write to it, you end up with extra numbered log
files containing a few lines that you would expect to be in the named log
file. As mkgmap supports a configuration file that defines how messages
should be logged, it doesn't make much sense writing a significant number of
messages to stderr which is not under logging control.

There are several diagnostic options that write their output using warning
as the severity, but as this is not enabled by default in the logging, they
appear to do nothing unless a logging configuration file is also used, which
is not intuitive. The --check-routing-island-len option seems somewhat
confused as it attempts to combine both reporting and fixing depending on
the value supplied. It also requires info level of logging which would
include a lot of other not necessarily wanted messages. If you are using it
to fix, you don't necessarily also want any messages.

In my view the way messages should be handled is as follows:

If the message is an informational message about the program itself and is
unrelated to processing any data then write it to stdout - this would apply
to the output of --version and --help.
If the message is an error message about an invalid parameter in the command
line, write it to stderr.
Once the command line has been processed sufficiently that a file is to be
processed then write messages using logging.
If a diagnostic option is enabled, the program should automatically log the
requested diagnostic messages. This would apply to --check-roundabouts,
--check-roundabout-flares, --report-similar-arcs, --check-routing-island-len
and --report-dead-ends.

The attached patch enhances the existing logging interface by providing the
following:
A mechanism for writing messages without any formatting getting added and
that always get written whatever level of logging is enabled.
A mechanism for writing stack trace information to the log file (I don't
believe stack traces really have any place in released code but have not
attempted to replace any of these).
Mostly directs messages as per my above proposal, though there is the
occasional place where the best option is not quite obvious to me, as I
think some of the code is not part of the main mkgmap program (there are
several main functions and some of the code is for testing purposes).
Only logs the start and finish times if files are being processed.
Outputs requested diagnostic messages regardless of enabled logging levels
Changes --report-dead-ends to be off by default, with the value of 1 being
the default if --report-dead-ends is specified without a value.
Filters duplicated --report-similar-arcs messages and ignores synthesised
arcs so that it can be used together with --make-opposite-cycleways.
Deprecates --check-routing-island-len, replacing it with
--report-routing-islands to handle reporting and --max-routing-island-len to
handle fixing.

I expect there will be the odd place where others may disagree with the
logging level for a message, but no doubt we can come to a consensus.
The patch touches quite a few source files, but there are only a few changes
that are anything more than altering the message outputting mechanism. There
is no change to any map outputs.

Cheers,
Mike

_______________________________________________
mkgmap-dev mailing list
mkgmap-dev at lists.mkgmap.org.uk
http://www.mkgmap.org.uk/mailman/listinfo/mkgmap-dev

-------------- next part --------------
A non-text attachment was scrubbed...
Name: FileInfoException.patch
Type: application/octet-stream
Size: 839 bytes
Desc: not available
URL: <http://www.mkgmap.org.uk/pipermail/mkgmap-dev/attachments/20210407/8d5a8d20/attachment-0004.obj>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: GmapiBuilderException.patch
Type: application/octet-stream
Size: 630 bytes
Desc: not available
URL: <http://www.mkgmap.org.uk/pipermail/mkgmap-dev/attachments/20210407/8d5a8d20/attachment-0005.obj>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: TypSaverException.patch
Type: application/octet-stream
Size: 559 bytes
Desc: not available
URL: <http://www.mkgmap.org.uk/pipermail/mkgmap-dev/attachments/20210407/8d5a8d20/attachment-0006.obj>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: comments.patch
Type: application/octet-stream
Size: 3095 bytes
Desc: not available
URL: <http://www.mkgmap.org.uk/pipermail/mkgmap-dev/attachments/20210407/8d5a8d20/attachment-0007.obj>