Use Python's logging framework for INFO diagnostic messages (fixes #353)

fire/core.py

@@ -52,6 +52,7 @@ def main(argv):
 import asyncio
 import inspect
 import json
+import logging
 import os
 import re
 import shlex
@@ -70,6 +71,51 @@ def main(argv):
 from fire.console import console_io
 
 
+class _LazyStderrStreamHandler(logging.StreamHandler):
+  """A StreamHandler that resolves sys.stderr dynamically at emit time.
+
+  The standard StreamHandler captures a reference to the stream object at
+  construction time. This subclass overrides that behaviour so that it always
+  writes to whatever sys.stderr currently refers to. This is important for
+  test code that replaces sys.stderr with an in-memory buffer via
+  unittest.mock.patch.object(sys, 'stderr', ...).
+  """
+
+  @property
+  def stream(self):
+    return sys.stderr
+
+  @stream.setter
+  def stream(self, value):
+    pass  # Always use sys.stderr; ignore any value stored at construction time.
+
+
+# Fire's internal logger.  By default it writes INFO-level messages to stderr,
+# preserving the behaviour that existed before this logging integration was
+# added.  Callers that want to suppress or redirect these messages can
+# configure the 'fire' or 'fire.core' logger, e.g.:
+#
+#   import logging
+#   logging.getLogger('fire').setLevel(logging.WARNING)  # suppress INFO msgs
+#
+_logger = logging.getLogger(__name__)
+if not _logger.handlers:
+  _handler = _LazyStderrStreamHandler()
+  _handler.setFormatter(logging.Formatter('%(levelname)s: %(message)s'))
+  _logger.addHandler(_handler)
+  _logger.propagate = False
+
+# Set INFO on the parent 'fire' logger (not on fire.core itself) so that
+# the effective level for fire.core is inherited from the hierarchy.  This
+# lets users suppress all fire messages by adjusting the 'fire' logger:
+#   logging.getLogger('fire').setLevel(logging.WARNING)
+# or target just this module with:
+#   logging.getLogger('fire.core').setLevel(logging.WARNING)
+_fire_parent_logger = logging.getLogger('fire')
+if _fire_parent_logger.level == logging.NOTSET:
+  _fire_parent_logger.setLevel(logging.INFO)
+
+
 def Fire(component=None, command=None, name=None, serialize=None):
   """This function, Fire, is the main entrypoint for Python Fire.
 
@@ -231,8 +277,7 @@ def _IsHelpShortcut(component_trace, remaining_args):
   if show_help:
     component_trace.show_help = True
     command = f'{component_trace.GetCommand()} -- --help'
-    print(f'INFO: Showing help with the command {shlex.quote(command)}.\n',
-          file=sys.stderr)
+    _logger.info('Showing help with the command %s.\n', shlex.quote(command))
   return show_help
 
 
@@ -287,8 +332,7 @@ def _DisplayError(component_trace):
 
   if show_help:
     command = f'{component_trace.GetCommand()} -- --help'
-    print(f'INFO: Showing help with the command {shlex.quote(command)}.\n',
-          file=sys.stderr)
+    _logger.info('Showing help with the command %s.\n', shlex.quote(command))
     help_text = helptext.HelpText(result, trace=component_trace,
                                   verbose=component_trace.verbose)
     output.append(help_text)

fire/core_test.py

@@ -14,6 +14,9 @@
 
 """Tests for the core module."""
 
+import io
+import logging
+import sys
 from unittest import mock
 
 from fire import core
@@ -224,5 +227,70 @@ def testLruCacheDecorator(self):
                   command=['foo']), 'foo')
 
 
+class LoggingTest(testutils.BaseTestCase):
+  """Tests that INFO messages use the Python logging framework (issue #353)."""
+
+  def testInfoMessageAppearsOnStderrByDefault(self):
+    """The 'Showing help' INFO line must appear in stderr without any logging config."""
+    with self.assertRaisesFireExit(0, r'INFO:.*Showing help'):
+      core.Fire(tc.InstanceVars, command=['--help'])
+
+  def testInfoMessageUsesFireLogger(self):
+    """core._logger must be a Logger named 'fire.core'."""
+    self.assertIsInstance(core._logger, logging.Logger)  # pylint: disable=protected-access
+    self.assertEqual(core._logger.name, 'fire.core')  # pylint: disable=protected-access
+
+  def testInfoCanBeSuppressedViaLogging(self):
+    """Users can suppress the INFO line by raising the fire.core logger level."""
+    fire_logger = logging.getLogger('fire.core')
+    original_level = fire_logger.level
+    try:
+      fire_logger.setLevel(logging.WARNING)
+      stderr_fp = io.StringIO()
+      with mock.patch.object(sys, 'stderr', stderr_fp):
+        with self.assertRaises(core.FireExit):
+          core.Fire(tc.InstanceVars, command=['--help'])
+      self.assertNotIn('INFO:', stderr_fp.getvalue())
+    finally:
+      fire_logger.setLevel(original_level)
+
+  def testInfoCanBeSuppressedViaParentLogger(self):
+    """Users can suppress the INFO line by raising the parent 'fire' logger level."""
+    fire_logger = logging.getLogger('fire')
+    original_level = fire_logger.level
+    try:
+      fire_logger.setLevel(logging.WARNING)
+      stderr_fp = io.StringIO()
+      with mock.patch.object(sys, 'stderr', stderr_fp):
+        with self.assertRaises(core.FireExit):
+          core.Fire(tc.InstanceVars, command=['--help'])
+      self.assertNotIn('INFO:', stderr_fp.getvalue())
+    finally:
+      fire_logger.setLevel(original_level)
+
+  def testInfoCanBeRedirectedViaCustomHandler(self):
+    """Users can capture fire's log output by adding their own handler."""
+    fire_logger = logging.getLogger('fire.core')
+    custom_stream = io.StringIO()
+    custom_handler = logging.StreamHandler(custom_stream)
+    custom_handler.setFormatter(logging.Formatter('%(levelname)s: %(message)s'))
+
+    # Remove the default handler, add a custom one to redirect to custom_stream.
+    original_handlers = fire_logger.handlers[:]
+    original_propagate = fire_logger.propagate
+    fire_logger.handlers = [custom_handler]
+    try:
+      stderr_fp = io.StringIO()
+      with mock.patch.object(sys, 'stderr', stderr_fp):
+        with self.assertRaises(core.FireExit):
+          core.Fire(tc.InstanceVars, command=['--help'])
+      # INFO message should appear in our custom stream, not stderr.
+      self.assertIn('INFO:', custom_stream.getvalue())
+      self.assertNotIn('INFO:', stderr_fp.getvalue())
+    finally:
+      fire_logger.handlers = original_handlers
+      fire_logger.propagate = original_propagate
+
+
 if __name__ == '__main__':
   testutils.main()