[Python-checkins] logging issues: Re: r46027 - python/trunk/Lib/cookielib.py

Jim Jewett jimjjewett at gmail.com
Wed May 17 23:34:49 CEST 2006


(1)  I don't think logging should be removed from the stdlib.  At the
very least, the reasoning should be added to PEP 337, which says to
*add* logging to the standard library.
http://www.python.org/dev/peps/pep-0337/  (There will probably be a
Summer Of Code student funded to do this; if it is a problem, lets fix
the problem in the logging module.)

(2)  Logging isn't really as unstable as you seem to think Beta
implies; it is probably more stable than the newer cookielib, let
alone the combination of cookielib, urllib2, and Processors.  (John
Lee has been making long-overdue fixes to urllib2 -- and processors in
particular -- because he was the first to really understand it well
enough; these fixes are generally triggered by immediate problems and
may not be complete fixes.)

I will agree that it might make sense to remove the beta marker from
the version of logging that is distributed in the stdlib.

(3)  What else was shipped with those applications which caused this?
Which version of logging did you have?

Both tracebacks could be caused if the root logger were not a normal
logger (and its manager therefore not a normal manager).  Vinay has
taken some steps to allow 3rd party libraries to override the class of
even the root logger, but doing it *right* is fairly subtle.

Another possibility is that you got burned by threads allowing access
to half-constructed loggers or managers, or by broken
PlaceHolders/fixups in the manager.  Again, this can't happen unless
someone is doing at least two dangerous things, but ... it has
triggered a few of the changelog entries.

-jJ


On 5/17/06, georg.brandl <python-checkins at python.org> wrote:
> Author: georg.brandl
> Date: Wed May 17 16:45:06 2006
> New Revision: 46027
>
> Modified:
>    python/trunk/Lib/cookielib.py
> Log:
> Add global debug flag to cookielib to avoid heavy dependency on the logging module.
> Resolves #1484758.
>
>
>
> Modified: python/trunk/Lib/cookielib.py
> ==============================================================================
> --- python/trunk/Lib/cookielib.py       (original)
> +++ python/trunk/Lib/cookielib.py       Wed May 17 16:45:06 2006
> @@ -28,7 +28,7 @@
>  __all__ = ['Cookie', 'CookieJar', 'CookiePolicy', 'DefaultCookiePolicy',
>             'FileCookieJar', 'LWPCookieJar', 'LoadError', 'MozillaCookieJar']
>
> -import re, urlparse, copy, time, urllib, logging
> +import re, urlparse, copy, time, urllib
>  try:
>      import threading as _threading
>  except ImportError:
> @@ -36,7 +36,18 @@
>  import httplib  # only for the default HTTP port
>  from calendar import timegm
>
> -debug = logging.getLogger("cookielib").debug
> +debug = 0   # set to true to enable debugging via the logging module
> +logger = None
> +
> +def _debug(*args):
> +    global logger
> +    if not debug:
> +        return
> +    if not logger:
> +        import logging
> +        logger = logging.getLogger("cookielib")
> +    return logger.debug(*args)
> +
>
>  DEFAULT_HTTP_PORT = str(httplib.HTTP_PORT)
>  MISSING_FILENAME_TEXT = ("a filename was not supplied (nor was the CookieJar "
> @@ -611,7 +622,7 @@
>          try:
>              int(port)
>          except ValueError:
> -            debug("nonnumeric port: '%s'", port)
> +            _debug("nonnumeric port: '%s'", port)
>              return None
>      else:
>          port = DEFAULT_HTTP_PORT
> @@ -902,7 +913,7 @@
>          strict about which cookies to accept).
>
>          """
> -        debug(" - checking cookie %s=%s", cookie.name, cookie.value)
> +        _debug(" - checking cookie %s=%s", cookie.name, cookie.value)
>
>          assert cookie.name is not None
>
> @@ -918,25 +929,25 @@
>          if cookie.version is None:
>              # Version is always set to 0 by parse_ns_headers if it's a Netscape
>              # cookie, so this must be an invalid RFC 2965 cookie.
> -            debug("   Set-Cookie2 without version attribute (%s=%s)",
> -                  cookie.name, cookie.value)
> +            _debug("   Set-Cookie2 without version attribute (%s=%s)",
> +                   cookie.name, cookie.value)
>              return False
>          if cookie.version > 0 and not self.rfc2965:
> -            debug("   RFC 2965 cookies are switched off")
> +            _debug("   RFC 2965 cookies are switched off")
>              return False
>          elif cookie.version == 0 and not self.netscape:
> -            debug("   Netscape cookies are switched off")
> +            _debug("   Netscape cookies are switched off")
>              return False
>          return True
>
>      def set_ok_verifiability(self, cookie, request):
>          if request.is_unverifiable() and is_third_party(request):
>              if cookie.version > 0 and self.strict_rfc2965_unverifiable:
> -                debug("   third-party RFC 2965 cookie during "
> +                _debug("   third-party RFC 2965 cookie during "
>                               "unverifiable transaction")
>                  return False
>              elif cookie.version == 0 and self.strict_ns_unverifiable:
> -                debug("   third-party Netscape cookie during "
> +                _debug("   third-party Netscape cookie during "
>                               "unverifiable transaction")
>                  return False
>          return True
> @@ -946,7 +957,7 @@
>          # servers that know both V0 and V1 protocols.
>          if (cookie.version == 0 and self.strict_ns_set_initial_dollar and
>              cookie.name.startswith("$")):
> -            debug("   illegal name (starts with '$'): '%s'", cookie.name)
> +            _debug("   illegal name (starts with '$'): '%s'", cookie.name)
>              return False
>          return True
>
> @@ -956,17 +967,17 @@
>              if ((cookie.version > 0 or
>                   (cookie.version == 0 and self.strict_ns_set_path)) and
>                  not req_path.startswith(cookie.path)):
> -                debug("   path attribute %s is not a prefix of request "
> -                      "path %s", cookie.path, req_path)
> +                _debug("   path attribute %s is not a prefix of request "
> +                       "path %s", cookie.path, req_path)
>                  return False
>          return True
>
>      def set_ok_domain(self, cookie, request):
>          if self.is_blocked(cookie.domain):
> -            debug("   domain %s is in user block-list", cookie.domain)
> +            _debug("   domain %s is in user block-list", cookie.domain)
>              return False
>          if self.is_not_allowed(cookie.domain):
> -            debug("   domain %s is not in user allow-list", cookie.domain)
> +            _debug("   domain %s is not in user allow-list", cookie.domain)
>              return False
>          if cookie.domain_specified:
>              req_host, erhn = eff_request_host(request)
> @@ -985,7 +996,7 @@
>                         "info", "jobs", "mobi", "museum", "name", "pro",
>                         "travel", "eu") and len(tld) == 2:
>                          # domain like .co.uk
> -                        debug("   country-code second level domain %s", domain)
> +                        _debug("   country-code second level domain %s", domain)
>                          return False
>              if domain.startswith("."):
>                  undotted_domain = domain[1:]
> @@ -993,30 +1004,30 @@
>                  undotted_domain = domain
>              embedded_dots = (undotted_domain.find(".") >= 0)
>              if not embedded_dots and domain != ".local":
> -                debug("   non-local domain %s contains no embedded dot",
> -                      domain)
> +                _debug("   non-local domain %s contains no embedded dot",
> +                       domain)
>                  return False
>              if cookie.version == 0:
>                  if (not erhn.endswith(domain) and
>                      (not erhn.startswith(".") and
>                       not ("."+erhn).endswith(domain))):
> -                    debug("   effective request-host %s (even with added "
> -                          "initial dot) does not end end with %s",
> -                          erhn, domain)
> +                    _debug("   effective request-host %s (even with added "
> +                           "initial dot) does not end end with %s",
> +                           erhn, domain)
>                      return False
>              if (cookie.version > 0 or
>                  (self.strict_ns_domain & self.DomainRFC2965Match)):
>                  if not domain_match(erhn, domain):
> -                    debug("   effective request-host %s does not domain-match "
> -                          "%s", erhn, domain)
> +                    _debug("   effective request-host %s does not domain-match "
> +                           "%s", erhn, domain)
>                      return False
>              if (cookie.version > 0 or
>                  (self.strict_ns_domain & self.DomainStrictNoDots)):
>                  host_prefix = req_host[:-len(domain)]
>                  if (host_prefix.find(".") >= 0 and
>                      not IPV4_RE.search(req_host)):
> -                    debug("   host prefix %s for domain %s contains a dot",
> -                          host_prefix, domain)
> +                    _debug("   host prefix %s for domain %s contains a dot",
> +                           host_prefix, domain)
>                      return False
>          return True
>
> @@ -1031,13 +1042,13 @@
>                  try:
>                      int(p)
>                  except ValueError:
> -                    debug("   bad port %s (not numeric)", p)
> +                    _debug("   bad port %s (not numeric)", p)
>                      return False
>                  if p == req_port:
>                      break
>              else:
> -                debug("   request port (%s) not found in %s",
> -                      req_port, cookie.port)
> +                _debug("   request port (%s) not found in %s",
> +                       req_port, cookie.port)
>                  return False
>          return True
>
> @@ -1050,7 +1061,7 @@
>          """
>          # Path has already been checked by .path_return_ok(), and domain
>          # blocking done by .domain_return_ok().
> -        debug(" - checking cookie %s=%s", cookie.name, cookie.value)
> +        _debug(" - checking cookie %s=%s", cookie.name, cookie.value)
>
>          for n in "version", "verifiability", "secure", "expires", "port", "domain":
>              fn_name = "return_ok_"+n
> @@ -1061,34 +1072,34 @@
>
>      def return_ok_version(self, cookie, request):
>          if cookie.version > 0 and not self.rfc2965:
> -            debug("   RFC 2965 cookies are switched off")
> +            _debug("   RFC 2965 cookies are switched off")
>              return False
>          elif cookie.version == 0 and not self.netscape:
> -            debug("   Netscape cookies are switched off")
> +            _debug("   Netscape cookies are switched off")
>              return False
>          return True
>
>      def return_ok_verifiability(self, cookie, request):
>          if request.is_unverifiable() and is_third_party(request):
>              if cookie.version > 0 and self.strict_rfc2965_unverifiable:
> -                debug("   third-party RFC 2965 cookie during unverifiable "
> -                      "transaction")
> +                _debug("   third-party RFC 2965 cookie during unverifiable "
> +                       "transaction")
>                  return False
>              elif cookie.version == 0 and self.strict_ns_unverifiable:
> -                debug("   third-party Netscape cookie during unverifiable "
> -                      "transaction")
> +                _debug("   third-party Netscape cookie during unverifiable "
> +                       "transaction")
>                  return False
>          return True
>
>      def return_ok_secure(self, cookie, request):
>          if cookie.secure and request.get_type() != "https":
> -            debug("   secure cookie with non-secure request")
> +            _debug("   secure cookie with non-secure request")
>              return False
>          return True
>
>      def return_ok_expires(self, cookie, request):
>          if cookie.is_expired(self._now):
> -            debug("   cookie expired")
> +            _debug("   cookie expired")
>              return False
>          return True
>
> @@ -1101,8 +1112,8 @@
>                  if p == req_port:
>                      break
>              else:
> -                debug("   request port %s does not match cookie port %s",
> -                      req_port, cookie.port)
> +                _debug("   request port %s does not match cookie port %s",
> +                       req_port, cookie.port)
>                  return False
>          return True
>
> @@ -1114,17 +1125,17 @@
>          if (cookie.version == 0 and
>              (self.strict_ns_domain & self.DomainStrictNonDomain) and
>              not cookie.domain_specified and domain != erhn):
> -            debug("   cookie with unspecified domain does not string-compare "
> -                  "equal to request domain")
> +            _debug("   cookie with unspecified domain does not string-compare "
> +                   "equal to request domain")
>              return False
>
>          if cookie.version > 0 and not domain_match(erhn, domain):
> -            debug("   effective request-host name %s does not domain-match "
> -                  "RFC 2965 cookie domain %s", erhn, domain)
> +            _debug("   effective request-host name %s does not domain-match "
> +                   "RFC 2965 cookie domain %s", erhn, domain)
>              return False
>          if cookie.version == 0 and not ("."+erhn).endswith(domain):
> -            debug("   request-host %s does not match Netscape cookie domain "
> -                  "%s", req_host, domain)
> +            _debug("   request-host %s does not match Netscape cookie domain "
> +                   "%s", req_host, domain)
>              return False
>          return True
>
> @@ -1137,24 +1148,24 @@
>          if not erhn.startswith("."):
>              erhn = "."+erhn
>          if not (req_host.endswith(domain) or erhn.endswith(domain)):
> -            #debug("   request domain %s does not match cookie domain %s",
> -            #      req_host, domain)
> +            #_debug("   request domain %s does not match cookie domain %s",
> +            #       req_host, domain)
>              return False
>
>          if self.is_blocked(domain):
> -            debug("   domain %s is in user block-list", domain)
> +            _debug("   domain %s is in user block-list", domain)
>              return False
>          if self.is_not_allowed(domain):
> -            debug("   domain %s is not in user allow-list", domain)
> +            _debug("   domain %s is not in user allow-list", domain)
>              return False
>
>          return True
>
>      def path_return_ok(self, path, request):
> -        debug("- checking cookie path=%s", path)
> +        _debug("- checking cookie path=%s", path)
>          req_path = request_path(request)
>          if not req_path.startswith(path):
> -            debug("  %s does not path-match %s", req_path, path)
> +            _debug("  %s does not path-match %s", req_path, path)
>              return False
>          return True
>
> @@ -1216,7 +1227,7 @@
>          cookies = []
>          if not self._policy.domain_return_ok(domain, request):
>              return []
> -        debug("Checking %s for cookies to return", domain)
> +        _debug("Checking %s for cookies to return", domain)
>          cookies_by_path = self._cookies[domain]
>          for path in cookies_by_path.keys():
>              if not self._policy.path_return_ok(path, request):
> @@ -1224,9 +1235,9 @@
>              cookies_by_name = cookies_by_path[path]
>              for cookie in cookies_by_name.values():
>                  if not self._policy.return_ok(cookie, request):
> -                    debug("   not returning cookie")
> +                    _debug("   not returning cookie")
>                      continue
> -                debug("   it's a match")
> +                _debug("   it's a match")
>                  cookies.append(cookie)
>          return cookies
>
> @@ -1303,7 +1314,7 @@
>          The Cookie2 header is also added unless policy.hide_cookie2 is true.
>
>          """
> -        debug("add_cookie_header")
> +        _debug("add_cookie_header")
>          self._cookies_lock.acquire()
>
>          self._policy._now = self._now = int(time.time())
> @@ -1380,7 +1391,7 @@
>                      continue
>                  if k == "domain":
>                      if v is None:
> -                        debug("   missing value for domain attribute")
> +                        _debug("   missing value for domain attribute")
>                          bad_cookie = True
>                          break
>                      # RFC 2965 section 3.3.3
> @@ -1390,7 +1401,7 @@
>                          # Prefer max-age to expires (like Mozilla)
>                          continue
>                      if v is None:
> -                        debug("   missing or invalid value for expires "
> +                        _debug("   missing or invalid value for expires "
>                                "attribute: treating as session cookie")
>                          continue
>                  if k == "max-age":
> @@ -1398,7 +1409,7 @@
>                      try:
>                          v = int(v)
>                      except ValueError:
> -                        debug("   missing or invalid (non-numeric) value for "
> +                        _debug("   missing or invalid (non-numeric) value for "
>                                "max-age attribute")
>                          bad_cookie = True
>                          break
> @@ -1411,7 +1422,7 @@
>                  if (k in value_attrs) or (k in boolean_attrs):
>                      if (v is None and
>                          k not in ("port", "comment", "commenturl")):
> -                        debug("   missing value for %s attribute" % k)
> +                        _debug("   missing value for %s attribute" % k)
>                          bad_cookie = True
>                          break
>                      standard[k] = v
> @@ -1497,8 +1508,8 @@
>                  self.clear(domain, path, name)
>              except KeyError:
>                  pass
> -            debug("Expiring cookie, domain='%s', path='%s', name='%s'",
> -                  domain, path, name)
> +            _debug("Expiring cookie, domain='%s', path='%s', name='%s'",
> +                   domain, path, name)
>              return None
>
>          return Cookie(version,
> @@ -1613,13 +1624,13 @@
>
>      def extract_cookies(self, response, request):
>          """Extract cookies from response, where allowable given the request."""
> -        debug("extract_cookies: %s", response.info())
> +        _debug("extract_cookies: %s", response.info())
>          self._cookies_lock.acquire()
>          self._policy._now = self._now = int(time.time())
>
>          for cookie in self.make_cookies(response, request):
>              if self._policy.set_ok(cookie, request):
> -                debug(" setting cookie: %s", cookie)
> +                _debug(" setting cookie: %s", cookie)
>                  self.set_cookie(cookie)
>          self._cookies_lock.release()
>
> _______________________________________________
> Python-checkins mailing list
> Python-checkins at python.org
> http://mail.python.org/mailman/listinfo/python-checkins
>


More information about the Python-checkins mailing list