Skip to content

Extra logging to troubleshoot the EXIF caching issues

Erwan Rouchet requested to merge exif-log into main

This is yet another attempt at figuring out what is going on with EXIF metadata stored in the image information cache: when an error occurs, just dump the whole JSON payload into the logging message.

The current server logs return something like this:

15:56:41.275 [qtp361571968-11] WARN  e.i.l.c.c.InfoService - getOrReadInfo(): Field is missing value
 at [Source: (String)"{"exif":{"fields":[{"tag":274,"dataType":3,"value":6},{"tag":34665,"dataType":9,"value":{"parentTag":34665,"fields":[{"tag":40962,"dataType":4,"value":4032},{"tag":40963,"dataType":4,"test":[{"applicationVersion":"5.0.5","serializationVersion":4,"identifier":"3z6t7pSN45UYit2nwcJaTPon.png","mediaType":"image/jpeg","numResolutions":1,"images":[{"width":4032,"height":3024,"tileWidth":4032,"tileHeight":3024}],"metadata":{"exif":{"fields":[{"tag":274,"dataType":3,"value":6},{"tag":34665,"dataType":9,"[truncated 998 chars]; line: 1, column: 1488] (through reference chain: edu.illinois.library.cantaloupe.image.Metadata["exif"])

The [truncated 998 chars] at the end of the line is added by Jackson, the JSON parsing library that Cantaloupe uses, and there is no easy way to just turn it off, so changing the logging message is easier:

15:56:41.275 [qtp361571968-11] WARN  e.i.l.c.c.InfoService - getOrReadInfo(): Field Orientation (274) is missing value in {"parentTag":34665,"fields":[{"tag":40962,"dataType":4,"value":4032},{"tag":40963,"dataType":4,"test":[{"applicationVersion":"5.0.5","serializationVersion":4,"identifier":"3z6t7pSN45UYit2nwcJaTPon.png","mediaType":"image/jpeg","numResolutions":1,"images":[{"width":4032,"height":3024,"tileWidth":4032,"tileHeight":3024}],"metadata":{"exif":{"fields":[{"tag":274,"dataType":3,"value":6},{"tag":34665,"dataType":9,"value":{"parentTag":34665,"fields":[{"tag":40962,"dataType":4,"value":4032},{"tag":40963,"dataType":4}]}}]},"iptc":[]}},{"applicationVersion":"5.0.5","serializationVersion":4,"identifier":"3z6t7pSN45UYit2nwcJaTPon.png","mediaType":"image/jpeg","numResolutions":1,"images":[{"width":4032,"height":3024,"tileWidth":4032,"tileHeight":3024}],"metadata":{"exif":{"fields":[{"tag":274,"dataType":3,"value":6},{"tag":34665,"dataType":9,"value":{"parentTag":34665,"fields":[{"tag":40962,"dataType":4,"value":4032},{"tag":40963,"dataType":4}]}}]},"iptc":[]}},{"applicationVersion":"5.0.5","serializationVersion":4,"identifier":"3z6t7pSN45UYit2nwcJaTPon.png","mediaType":"image/jpeg","numResolutions":1,"images":[{"width":4032,"height":3024,"tileWidth":4032,"tileHeight":3024}],"metadata":{"exif":{"fields":[{"tag":274,"dataType":3,"value":6},{"tag":34665,"dataType":9,"value":{"parentTag":34665,"fields":[{"tag":40962,"dataType":4,"value":4032},{"tag":40963,"dataType":4}]}}]},"iptc":[]}}]}]}
 at [Source: (String)"{"exif":{"fields":[{"tag":274,"dataType":3,"value":6},{"tag":34665,"dataType":9,"value":{"parentTag":34665,"fields":[{"tag":40962,"dataType":4,"value":4032},{"tag":40963,"dataType":4,"test":[{"applicationVersion":"5.0.5","serializationVersion":4,"identifier":"3z6t7pSN45UYit2nwcJaTPon.png","mediaType":"image/jpeg","numResolutions":1,"images":[{"width":4032,"height":3024,"tileWidth":4032,"tileHeight":3024}],"metadata":{"exif":{"fields":[{"tag":274,"dataType":3,"value":6},{"tag":34665,"dataType":9,"[truncated 998 chars]; line: 1, column: 1488] (through reference chain: edu.illinois.library.cantaloupe.image.Metadata["exif"])

I tested this by editing a JSON file from the cache and removing a "value": "…" from one of the EXIF tags.

This will be visible in both the HTTP 500 error page and the logs. We can use that next time to get a full JSON payload and see if the "value" is truly missing, or if something else in the parsing is going wrong.

Merge request reports