Confusion with errors and logging

Please can any module maintainer or other expert comment on whether they think the suggested resolution is the right way to go? I don't mind creating a patch, but I'd like to get a consensus first on the correct approach.

OK, I needed to get my site working, so here is an attempt at a patch.

• The comment for geocoder_cache_get indicates that the intention is to use FALSE for no result. Fixed all plugins to conform. This should fix "no results" to work in all cases: value is cached and no watchdog. This is a change to behaviour, but there are the 2 related issues that indicate a consensus in the community that watchdog errors are not wanted for "no result". This is particularly important for geocoding from user data e.g. on a views filter "show your nearest XXX".
• Fix widget not to cache exceptions - these are temporary errors such as network failure, and not a problem with the specific data that is being geocoded. NB existing sites may have caches polluted with temporary failures. Some valid data will fail to geocode until the cache is cleared if it was attempted during a temporary failure (especially likely: Google API limit hit?).
• Fix watchdog severity to WARNING which seemed to be the majority case and no clear reason to make things more complex.
• Fixed all plugins to throw exception for errors which calling code handles (calls watchdog and converts to a NULL). This means all watchdog logs are consistent.
• NB lots of whitespace changes from removing try/catch in the plugins - sorry that's a bit harder to review but it doesn't really seem right to leave the text badly aligned.

Tested on google so far.

Sorry, well spotted, version is 1.x.

So it looks like I am going in the right direction - need to fix all plug-ins to distinguish between error (exception) and no result (return NULL/FALSE).

@rudiedirkx Would you be willing to provide a detailed review please?

Thanks for the reply.

The matter of "API change" or "bug fix" could be a matter of debate - if the existing behaviour is sufficiently inconsistent and unhelpful you would call it a bug. In this case it is highly inconsistent - for example Google geocoder does not log for geocode failure in the specific case that there was a result but it was then rejected because of the setting in $options['reject_results'].

I believe the latest stable release changed the API in similar ways and there doesn't appear to have been any outcry.

• If geocode failures are being cached, then there now isn't a log when fetching from cache. So the log for geocode failure no longer occurs in a way that can be relied upon.
• Changed the severity of log generated for errors: geocoder_widget_get_field_value explicitly sets WARNING whereas the default from before was ERROR.
• If your geocoder is failing because of temporary error such as API limit, there is now one log per location if multi-valued (even though the failure isn't specific to a location), but before there was just one log.

Given this history of API change and that you can't really rely on the logs at present anyway, it's hard to see that anyone wants the logging to stay exactly how it is right now. I recommend that one more change to make everything consistent and simple.

I guess one possibility is a config option whether to generate errors for geocode failures? Of course whatever value we pick as default it won't reproduce the previous behaviour of inconsistent logging:-) If we go this way, we probably ought to generate the same error also when retrieving from cache.

@rudiedirkx Thanks. Your questions have prompted me to explain my thoughts more clearly, and in doing so, I feel the right path has become clearer to me. So here is an updated attempt to explain as clearly as I can.

Geocoding has 3 different possible cases:

• SUCCESS
• ZERO RESULTS (I have been calling this geocode failure before, but that's possibly ambiguous)
• ERROR (typically transient such as API limit reached)

In terms of watchdog logging, we currently have:

• SUCCESS: no log
• ZERO RESULTS: inconsistent whether to log (depends on plug-in, cache state and various other factors)
• ERROR: log

The latest release has added a new factor: caching. The intended behaviour as I understand it is:

• SUCCESS: cache
• ZERO RESULTS: configurable whether to cache
• ERROR: no cache

However there is a bug and in fact ERROR is being cached. It's easy to fix ERROR not to be cached. But at that point it becomes inconsistent whether ZERO RESULTS is cached (same as per logging - depends on plug-in etc). To fix this bug properly, we need to make sure that all plug-ins distinguish between "error" and "zero results". This is the "fixing the API" and I agree it is not an option - we have to do it or caching is broken which seems a pretty serious bug.

Once we do that, we automatically fix the inconsistency in logging as well. But what is the correct behaviour for logging ZERO RESULTS? In my patch, I don't log. But having thought about it more, I think the answer is that different site admins may have different views. So my new proposal is:

• SUCCESS: no log
• ZERO RESULTS: configurable whether to log (but should be notice not error)
• ERROR: log

The benefit of this is:

1. It minimises the impact on existing sites because each site can choose whether to log (we would need to make sure the release note made it clear that site owners should set this new setting as per their needs).
2. It offers the same behaviour for logging and caching

If you and @Pol are in agreement with my proposal then I will fix the patch accordingly.

With my final sentence in #8 I mean that if logging for ZERO RESULTS is enabled, then I think we have to make the log 100% of the time, including the case where ZERO RESULTS has been retrieved from cache. I will make sure that my patch does this by moving that log in the code.

Sorry, you are right, I got that last bit wrong. I have edited it. I agree no log, not even a config option.

@Pol thanks for your trust.

@rudiedirkx The log for no results is proving problematic. The log would be fairly useless without logging the geocode source value $data, which is present in the Google geocoder log in the current code. However for a field, $data is a complex structure that is converted into a string within the plugin field_callback, so the string value is not accessible to the main module code to use for logging.

Do you think we can just drop the idea of a log for no results. It is currently only present for Google?

===

The alternative I guess is to allow the main module code to see the data string. This seems a bit scary, but maybe it could work, something like this.

The implementations of field_callback seem to fall into two sets. The "service" plugins accept text, address_field, location and taxonomy ref. The "static" plugins (latlon, json, kml, wkt, gpx) accept text or file. In almost every case, it looks as if whenever a particular field is converted, there is a "standard conversion" the same way - only exception I see so far is that KML has extra code to accept zip files.

So allow field_callback to be NULL in the plugin array. If so, perform a "standard conversion" to text (and store this value in a variable in case we need to log it). Pass the result to the main callback, which does have code to make a log for zero results.

For a custom plug-in where field_callback is still set, then there will be no log for zero results - but then there presumably isn't one now either.

This is becoming a bigger and riskier change and seems a lot of work and quite complex just for one log. However I guess it would remove the duplication of the same field conversion code over and over in the existing plugins.

===

What do the experts think?

Actually I don't think the alternative in my previous comment works so well. In the case where ZERO RESULTS has been cached, there is no practical way to know the data string value to log it.

In fact with the current version right now, ZERO RESULTS retrieved from cache already has no log and no one seems to have raised an issue about it.

So are you OK with dropping the idea of a configurable log for ZERO RESULTS? I guess if someone objects and raises an issue then we can rethink strategies.

If so, I would like to go back to the patch I submitted - except I plan to make one small change to it to safeguard the plug-in return value for ZERO RESULTS slightly better.

OK, I think I have figured it out. Sorry for the previous negative post - I'm gradually learning about geocoder.

The solution I came up with is

• In the main geocoder function, we do have a string value for $data.
• In the widget, we don't have a string, but we can put a link to the entity into the log message.

Here's a new patch that matches #10. Same as last time, best viewed ignoring whitespace changes.

@Pol done, thanks for the heads-up

@rudiedirkx Yes I see what you mean, that is entirely a reasonable suggestion. However it would mean quite a lot more changes to all plugins which I'm not really in a position to test very well.

The current solution does also provide logging of input data, and it is a simpler diff that I have now coded and tested. Please can you have a review of it as is, and see if you think it is suitable for commit?

Someone who has the time could always add the enhanced exceptions at a later date.

@rudiedirkx Thanks and good job for spotting bugs. Sorry for the messed up merge of #19 - I'm still quite new to git!

Return from plug-in is:

• SUCCESS: a valid Geometry
• ERROR: throw Exception
• ZERO RESULTS: NULL, FALSE, array() or anything else that == FALSE in PHP. geocoder_cache_set converts to explicit FALSE before storing in cache.

It would be useful to document this, but I don't know where to put it as I can't see anywhere documenting the plugin API.

My first patch tried to convert all the "return NULL" to FALSE but I dropped that idea for the second patch. I also realised the issue with custom plugins (plus there are a lot of 'hidden' return NULLs when there is a missing return value or missing return statement).

Just had a thought: I think custom plugins would also be a problem for your idea of requiring an exception for ZERO RESULTS.

Your specific comments:

1) Fixed. This was another recent change from Pol that got lost when I was merging.
2) As above, Yandex is allowed to return NULL. I have fixed geocoder to remove the === test.
3) Done.

Great, thanks for the review

@Pol You kindly said

About this patch, let me know if this patch is ok, so I can commit it, I'm trusting you all on this one.

rudiedirkx has set to RTBC so I believe we are ready for commit, thanks.

Thanks Pol!