HumanCellAtlas / data-store

Design specs and prototypes for the HCA Data Storage System (DSS, "blue box")
https://dss.staging.data.humancellatlas.org/
Other
40 stars 6 forks source link

Logging functions using f-strings can cause exceptions if % are substituted into f-string. #427

Closed Bento007 closed 7 years ago

Bento007 commented 7 years ago

check over f-strings in logs to avoid substituting a variable that includes a %. This may cause the logging expression to interpret the % as a variable substitution. This was observed when integrating the google could support for indexer.

from file dss/events/handlers/index.py line 42. Erroneous example: logger.error(f"Exception occurred while processing GS event: {ex} Event: %s", json.dumps(event, indent=4))

after the f-string is evaluation this string is created:

Exception occurred while processing GS event: 403 GET https://www.googleapis.com/storage/v1/b/fake/o/bundles%2F1e7366fb-3634-4d8d-8bf6-2a0aaf1868a8.2017-09-07T222143.145620Z: tsmith12@human-cell-atlas-mbaumann-dev.iam.gserviceaccount.com does not have storage.objects.get access to fake/bundles/1e7366fb-3634-4d8d-8bf6-2a0aaf1868a8.2017-09-07T222143.145620Z.

The %2F in the url is evaluated as a variable substitution by logger which results in an exception being thrown because the incorrect number or type of parameters was provided. Here is how to avoid it.

Fixed Example: logger.error("Exception occurred while processing GS event: %s Event: %s", ex, json.dumps(event, indent=4))

run test_indexer.TestGCPIndexer.test_debug_message_logged_when_indexing_an_invalid_bundle_name to see fix.

ttung commented 7 years ago

So another possibility we could do is:

logger.error("%s", f"abcabcabc")

This standardizes us on the f-string formatting operations, which we are trending towards.

The downside is that we do the string formatting operation regardless of whether the logging is enabled.