[CI Problem] CI has logging errors even when successful

[driazati]

We should look into these and clean them up so they don't happen since its mostly just confusing if its an actual error or not (usually not)

ex: https://ci.tlcpack.ai/blue/organizations/jenkins/tvm/detail/PR-10516/9/pipeline/#step-838-log-1604

[2022-04-21T20:12:47.105Z] Error in atexit._run_exitfuncs:
[2022-04-21T20:12:47.105Z] Traceback (most recent call last):
[2022-04-21T20:12:47.105Z]   File "/usr/lib/python3.7/logging/__init__.py", line 2034, in shutdown
[2022-04-21T20:12:47.105Z]     h.close()
[2022-04-21T20:12:47.105Z]   File "/usr/local/lib/python3.7/dist-packages/absl/logging/__init__.py", line 951, in close
[2022-04-21T20:12:47.105Z]     self.stream.close()
[2022-04-21T20:12:47.105Z] AttributeError: 'LoggingTee' object has no attribute 'close'
[2022-04-21T20:12:52.369Z] Makefile:110: recipe for target 'html' failed
[2022-04-21T20:12:52.369Z] make: *** [html] Error 2

[guberti]

This issue is causing me quite a headache, as it is blocking me from merging #10921. I think I've figured it out though - it's caused by an interaction between sphinx-gallery and absl (imported by tensorflow). Here's what happens:

1. sphinx-gallery wants to capture the output of code blocks as it runs them (this is one of its main features). To do this, it uses a custom LoggingTee object to replace sys.stdout and sys.stderr:

class _LoggingTee(object):
    """A tee object to redirect streams to the logger."""
   ...

    def set_std_and_reset_position(self):
        if not isinstance(sys.stdout, _LoggingTee):
            self.origs = (sys.stdout, sys.stderr)
        sys.stdout = sys.stderr = self

2. tensorflow wants to have nice logging features, so it imports logging from absl. Hence, an absl PythonHandler, which is a subclass of Python's StreamHandler, is created.
3. When a StreamHandler is created, it creates a pointer to sys.stderr. However, since sphinx-gallery replaced sys.stderr with LoggingTee earlier, a LoggingTee is instead inserted here:

class StreamHandler(Handler):
    def __init__(self, stream=None):
        """
        Initialize the handler.

        If stream is not specified, sys.stderr is used.
        """
        Handler.__init__(self)
        if stream is None:
            stream = sys.stderr
        self.stream = stream

4. The error does not happen until sphinx-gallery finishes executing the code block. When this occurs, sphinx-gallery attempts to switch stderr and stdout back to their original values. However, it does not know that StreamHandler has a pointer to the LoggingTee object, and is unable to fix it. Hence, stdout and stderr go back to their original values, but self.stream in StreamHandler has the LoggingTee.

    def restore_std(self):
        sys.stdout.flush()
        sys.stderr.flush()
        sys.stdout, sys.stderr = self.origs

5. When it is time to close the log with absl, the close function is called:

  def close(self):
    """Closes the stream to which we are writing."""
    self.acquire()
    try:
      self.flush()
      try:
        # Do not close the stream if it's sys.stderr|stdout. They may be
        # redirected or overridden to files, which should be managed by users
        # explicitly.
        user_managed = sys.stderr, sys.stdout, sys.__stderr__, sys.__stdout__
        if self.stream not in user_managed and (
            not hasattr(self.stream, 'isatty') or not self.stream.isatty()):
          self.stream.close()
      except ValueError:
        # A ValueError is thrown if we try to run isatty() on a closed file.
        pass
      super(PythonHandler, self).close()
    finally:
      self.release()

We should not call close if we are writing to stderr or stdout, and absl knows this. Hence it checks whether self.stream is equal to either sys.stderr or sys.stdout. However, since self.stream is the LoggingTee object, it sees that it is not equal, and assumes the stream is a file that needs closing.
6. close() is then called on LoggingTee, which does not have a close() method. This yields the AttributeError found above.

[guberti]

I've got a PR out to fix this - sphinx-gallery/sphinx-gallery#961.

[guberti]

Sphinx-gallery PR has been merged - this issue will be fixed when sphinx-gallery is updated (which will be done by #10921).

[guberti]

#10921 has been merged, which brings the sphinx-gallery change mentioned above into TVM. This fixes the issue, so I believe we should close it (the warning is no longer occurring on main). If it occurs again for some reason, we should reopen this though.