Fix logging call in rulematching (#2802)

When enabling debug logging we can end up with:

balrogpub_1    | --- Logging error ---
balrogpub_1    | Traceback (most recent call last):
balrogpub_1    |   File "/usr/local/lib/python3.9/logging/__init__.py", line 434, in format
balrogpub_1    |     return self._format(record)
balrogpub_1    |   File "/usr/local/lib/python3.9/logging/__init__.py", line 430, in _format
balrogpub_1    |     return self._fmt % record.__dict__
balrogpub_1    | KeyError: 'requestid'
balrogpub_1    |
balrogpub_1    | During handling of the above exception, another exception occurred:
balrogpub_1    |
balrogpub_1    | Traceback (most recent call last):
balrogpub_1    |   File "/usr/local/lib/python3.9/logging/__init__.py", line 1083, in emit
balrogpub_1    |     msg = self.format(record)
balrogpub_1    |   File "/usr/local/lib/python3.9/logging/__init__.py", line 927, in format
balrogpub_1    |     return fmt.format(record)
balrogpub_1    |   File "/usr/local/lib/python3.9/logging/__init__.py", line 666, in format
balrogpub_1    |     s = self.formatMessage(record)
balrogpub_1    |   File "/usr/local/lib/python3.9/logging/__init__.py", line 635, in formatMessage
balrogpub_1    |     return self._style.format(record)
balrogpub_1    |   File "/usr/local/lib/python3.9/logging/__init__.py", line 436, in format
balrogpub_1    |     raise ValueError('Formatting field not found in record: %s' % e)
balrogpub_1    | ValueError: Formatting field not found in record: 'requestid'
balrogpub_1    | Call stack:
balrogpub_1    |   File "/usr/local/lib/python3.9/site-packages/flask/app.py", line 2548, in __call__
balrogpub_1    |     return self.wsgi_app(environ, start_response)
balrogpub_1    |   File "/usr/local/lib/python3.9/site-packages/flask/app.py", line 2525, in wsgi_app
balrogpub_1    |     response = self.full_dispatch_request()
balrogpub_1    |   File "/usr/local/lib/python3.9/site-packages/flask/app.py", line 1820, in full_dispatch_request
balrogpub_1    |     rv = self.dispatch_request()
balrogpub_1    |   File "/usr/local/lib/python3.9/site-packages/flask/app.py", line 1796, in dispatch_request
balrogpub_1    |     return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args)
balrogpub_1    |   File "/usr/local/lib/python3.9/site-packages/connexion/decorators/decorator.py", line 68, in wrapper
balrogpub_1    |     response = function(request)
balrogpub_1    |   File "/usr/local/lib/python3.9/site-packages/connexion/decorators/uri_parsing.py", line 149, in wrapper
balrogpub_1    |     response = function(request)
balrogpub_1    |   File "/usr/local/lib/python3.9/site-packages/connexion/decorators/validation.py", line 399, in wrapper
balrogpub_1    |     return function(request)
balrogpub_1    |   File "/usr/local/lib/python3.9/site-packages/connexion/decorators/produces.py", line 41, in wrapper
balrogpub_1    |     response = function(request)
balrogpub_1    |   File "/usr/local/lib/python3.9/site-packages/connexion/decorators/parameter.py", line 120, in wrapper
balrogpub_1    |     return function(**kwargs)
balrogpub_1    |   File "/app/src/auslib/web/public/helpers.py", line 17, in wrapper
balrogpub_1    |     return f(*args, transaction=transaction, **kwargs)
balrogpub_1    |   File "/app/src/auslib/web/public/client.py", line 154, in get_update_blob
balrogpub_1    |     release, update_type, eval_metadata = AUS.evaluateRules(query, transaction=transaction)
balrogpub_1    |   File "/app/src/auslib/AUS.py", line 87, in evaluateRules
balrogpub_1    |     rules = dbo.rules.getRulesMatchingQuery(updateQuery, fallbackChannel=getFallbackChannel(updateQuery["channel"]), transaction=transaction)
balrogpub_1    |   File "/app/src/auslib/db.py", line 1916, in getRulesMatchingQuery
balrogpub_1    |     if not matchVersion(rule["version"], updateQuery["version"], get_version_class(updateQuery["product"])):
balrogpub_1    |   File "/app/src/auslib/util/rulematching.py", line 101, in matchVersion
balrogpub_1    |     logging.debug("ruleVersion: %s, queryVersion: %s", ruleVersion, queryVersion)
balrogpub_1    | Message: 'ruleVersion: %s, queryVersion: %s'
balrogpub_1    | Arguments: (None, '111.0a1')

Going through getLogger makes it so our wrapper is used and can set requestid.

src/auslib/util/rulematching.py

@@ -4,6 +4,8 @@
 from auslib.util.comparison import int_compare, string_compare, version_compare
 from auslib.util.versions import MozillaVersion
 
+log = logging.getLogger(__name__)
+
 
 def matchRegex(foo, bar):
     # Expand wildcards and use ^/$ to make sure we don't succeed on partial
@@ -98,7 +100,7 @@ def matchVersion(ruleVersion, queryVersion, versionClass=MozillaVersion):
     """Decides whether a version from the rules matches an incoming version.
     If the ruleVersion is null, we match any queryVersion. If it's not
     null, we must either match exactly, or match a comparison operator."""
-    logging.debug("ruleVersion: %s, queryVersion: %s", ruleVersion, queryVersion)
+    log.debug("ruleVersion: %s, queryVersion: %s", ruleVersion, queryVersion)
     if ruleVersion is None:
         return True
     rulesVersionList = ruleVersion.split(",")