aboutsummaryrefslogtreecommitdiff
path: root/absl/logging/tests
diff options
context:
space:
mode:
authorYilei Yang <yileiyang@google.com>2017-09-19 14:25:01 -0700
committerYilei Yang <yileiyang@google.com>2017-09-19 14:25:01 -0700
commit1c6972eef4d4dc774fa50f29248f776fa6628e9e (patch)
tree49f251967b459d7ec3c72042d132b77adb7d1b1a /absl/logging/tests
downloadabsl-py-1c6972eef4d4dc774fa50f29248f776fa6628e9e.tar.gz
Initial commit: Abseil Python Common Libraries.
Diffstat (limited to 'absl/logging/tests')
-rw-r--r--absl/logging/tests/__init__.py13
-rw-r--r--absl/logging/tests/converter_test.py135
-rw-r--r--absl/logging/tests/log_before_import_test.py88
-rwxr-xr-xabsl/logging/tests/logging_functional_test.py762
-rwxr-xr-xabsl/logging/tests/logging_functional_test_helper.py302
-rw-r--r--absl/logging/tests/logging_test.py734
-rw-r--r--absl/logging/tests/verbosity_flag_test.py58
7 files changed, 2092 insertions, 0 deletions
diff --git a/absl/logging/tests/__init__.py b/absl/logging/tests/__init__.py
new file mode 100644
index 0000000..a3bd1cd
--- /dev/null
+++ b/absl/logging/tests/__init__.py
@@ -0,0 +1,13 @@
+# Copyright 2017 The Abseil Authors.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
diff --git a/absl/logging/tests/converter_test.py b/absl/logging/tests/converter_test.py
new file mode 100644
index 0000000..bdc893a
--- /dev/null
+++ b/absl/logging/tests/converter_test.py
@@ -0,0 +1,135 @@
+# Copyright 2017 The Abseil Authors.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+"""Tests for converter.py."""
+
+from __future__ import absolute_import
+from __future__ import division
+from __future__ import print_function
+
+import logging
+
+from absl import logging as absl_logging
+from absl.logging import converter
+from absl.testing import absltest
+
+
+class ConverterTest(absltest.TestCase):
+ """Tests the converter module."""
+
+ def test_absl_to_cpp(self):
+ self.assertEqual(0, converter.absl_to_cpp(absl_logging.DEBUG))
+ self.assertEqual(0, converter.absl_to_cpp(absl_logging.INFO))
+ self.assertEqual(1, converter.absl_to_cpp(absl_logging.WARN))
+ self.assertEqual(2, converter.absl_to_cpp(absl_logging.ERROR))
+ self.assertEqual(3, converter.absl_to_cpp(absl_logging.FATAL))
+
+ with self.assertRaises(TypeError):
+ converter.absl_to_cpp('')
+
+ def test_absl_to_standard(self):
+ self.assertEqual(
+ logging.DEBUG, converter.absl_to_standard(absl_logging.DEBUG))
+ self.assertEqual(
+ logging.INFO, converter.absl_to_standard(absl_logging.INFO))
+ self.assertEqual(
+ logging.WARNING, converter.absl_to_standard(absl_logging.WARN))
+ self.assertEqual(
+ logging.WARN, converter.absl_to_standard(absl_logging.WARN))
+ self.assertEqual(
+ logging.ERROR, converter.absl_to_standard(absl_logging.ERROR))
+ self.assertEqual(
+ logging.FATAL, converter.absl_to_standard(absl_logging.FATAL))
+ self.assertEqual(
+ logging.CRITICAL, converter.absl_to_standard(absl_logging.FATAL))
+ # vlog levels.
+ self.assertEqual(9, converter.absl_to_standard(2))
+ self.assertEqual(8, converter.absl_to_standard(3))
+
+ with self.assertRaises(TypeError):
+ converter.absl_to_standard('')
+
+ def test_standard_to_absl(self):
+ self.assertEqual(
+ absl_logging.DEBUG, converter.standard_to_absl(logging.DEBUG))
+ self.assertEqual(
+ absl_logging.INFO, converter.standard_to_absl(logging.INFO))
+ self.assertEqual(
+ absl_logging.WARN, converter.standard_to_absl(logging.WARN))
+ self.assertEqual(
+ absl_logging.WARN, converter.standard_to_absl(logging.WARNING))
+ self.assertEqual(
+ absl_logging.ERROR, converter.standard_to_absl(logging.ERROR))
+ self.assertEqual(
+ absl_logging.FATAL, converter.standard_to_absl(logging.FATAL))
+ self.assertEqual(
+ absl_logging.FATAL, converter.standard_to_absl(logging.CRITICAL))
+ # vlog levels.
+ self.assertEqual(2, converter.standard_to_absl(logging.DEBUG - 1))
+ self.assertEqual(3, converter.standard_to_absl(logging.DEBUG - 2))
+
+ with self.assertRaises(TypeError):
+ converter.standard_to_absl('')
+
+ def test_standard_to_cpp(self):
+ self.assertEqual(0, converter.standard_to_cpp(logging.DEBUG))
+ self.assertEqual(0, converter.standard_to_cpp(logging.INFO))
+ self.assertEqual(1, converter.standard_to_cpp(logging.WARN))
+ self.assertEqual(1, converter.standard_to_cpp(logging.WARNING))
+ self.assertEqual(2, converter.standard_to_cpp(logging.ERROR))
+ self.assertEqual(3, converter.standard_to_cpp(logging.FATAL))
+ self.assertEqual(3, converter.standard_to_cpp(logging.CRITICAL))
+
+ with self.assertRaises(TypeError):
+ converter.standard_to_cpp('')
+
+ def test_get_initial_for_level(self):
+ self.assertEqual('F', converter.get_initial_for_level(logging.CRITICAL))
+ self.assertEqual('E', converter.get_initial_for_level(logging.ERROR))
+ self.assertEqual('W', converter.get_initial_for_level(logging.WARNING))
+ self.assertEqual('I', converter.get_initial_for_level(logging.INFO))
+ self.assertEqual('I', converter.get_initial_for_level(logging.DEBUG))
+ self.assertEqual('I', converter.get_initial_for_level(logging.NOTSET))
+
+ self.assertEqual('F', converter.get_initial_for_level(51))
+ self.assertEqual('E', converter.get_initial_for_level(49))
+ self.assertEqual('E', converter.get_initial_for_level(41))
+ self.assertEqual('W', converter.get_initial_for_level(39))
+ self.assertEqual('W', converter.get_initial_for_level(31))
+ self.assertEqual('I', converter.get_initial_for_level(29))
+ self.assertEqual('I', converter.get_initial_for_level(21))
+ self.assertEqual('I', converter.get_initial_for_level(19))
+ self.assertEqual('I', converter.get_initial_for_level(11))
+ self.assertEqual('I', converter.get_initial_for_level(9))
+ self.assertEqual('I', converter.get_initial_for_level(1))
+ self.assertEqual('I', converter.get_initial_for_level(-1))
+
+ def test_string_to_standard(self):
+ self.assertEqual(logging.DEBUG, converter.string_to_standard('debug'))
+ self.assertEqual(logging.INFO, converter.string_to_standard('info'))
+ self.assertEqual(logging.WARNING, converter.string_to_standard('warn'))
+ self.assertEqual(logging.WARNING, converter.string_to_standard('warning'))
+ self.assertEqual(logging.ERROR, converter.string_to_standard('error'))
+ self.assertEqual(logging.CRITICAL, converter.string_to_standard('fatal'))
+
+ self.assertEqual(logging.DEBUG, converter.string_to_standard('DEBUG'))
+ self.assertEqual(logging.INFO, converter.string_to_standard('INFO'))
+ self.assertEqual(logging.WARNING, converter.string_to_standard('WARN'))
+ self.assertEqual(logging.WARNING, converter.string_to_standard('WARNING'))
+ self.assertEqual(logging.ERROR, converter.string_to_standard('ERROR'))
+ self.assertEqual(logging.CRITICAL, converter.string_to_standard('FATAL'))
+
+
+if __name__ == '__main__':
+ absltest.main()
diff --git a/absl/logging/tests/log_before_import_test.py b/absl/logging/tests/log_before_import_test.py
new file mode 100644
index 0000000..d1ae0a7
--- /dev/null
+++ b/absl/logging/tests/log_before_import_test.py
@@ -0,0 +1,88 @@
+# Copyright 2017 The Abseil Authors.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+"""Test of logging behavior before app.run(), aka flag and logging init()."""
+
+from __future__ import absolute_import
+from __future__ import division
+from __future__ import print_function
+
+import io
+import re
+
+from absl import logging
+from absl.testing import absltest
+import mock
+
+# We do this before our library imports in order to catch any Python stderr
+# output they may generate. We don't want them to; capture and check.
+fake_stderr_type = io.BytesIO if bytes is str else io.StringIO
+
+logging.get_verbosity() # Access --verbosity before flag parsing.
+# Access --logtostderr before flag parsing.
+logging.get_absl_handler().use_absl_log_file()
+
+
+class Error(Exception):
+ pass
+
+
+# Pre-initialization (aka "import" / __main__ time) test. Checked below.
+with mock.patch('sys.stderr', new=fake_stderr_type()) as pre_init_mock_stderr:
+ # Trigger the notice to stderr once. infos and above go to stderr.
+ logging.debug('Debug message at parse time.')
+ logging.info('Info message at parse time.')
+ logging.error('Error message at parse time.')
+ logging.warning('Warning message at parse time.')
+ try:
+ raise Error('Exception reason.')
+ except Error:
+ logging.exception('Exception message at parse time.')
+
+
+class LoggingInitWarningTest(absltest.TestCase):
+
+ def test_captured_pre_init_warnings(self):
+ captured_stderr = pre_init_mock_stderr.getvalue()
+ self.assertNotIn('Debug message at parse time.', captured_stderr)
+ self.assertNotIn('Info message at parse time.', captured_stderr)
+
+ traceback_re = re.compile(
+ r'\nTraceback \(most recent call last\):.*?Error: Exception reason.',
+ re.MULTILINE | re.DOTALL)
+ if not traceback_re.search(captured_stderr):
+ self.fail(
+ 'Cannot find traceback message from logging.exception '
+ 'in stderr:\n{}'.format(captured_stderr))
+ # Remove the traceback so the rest of the stderr is deterministic.
+ captured_stderr = traceback_re.sub('', captured_stderr)
+ captured_stderr_lines = captured_stderr.splitlines()
+ self.assertLen(captured_stderr_lines, 4)
+ self.assertIn('Logging before flag parsing goes to stderr',
+ captured_stderr_lines[0])
+ self.assertIn('Error message at parse time.', captured_stderr_lines[1])
+ self.assertIn('Warning message at parse time.', captured_stderr_lines[2])
+ self.assertIn('Exception message at parse time.', captured_stderr_lines[3])
+
+ def test_no_more_warnings(self):
+ with mock.patch('sys.stderr', new=fake_stderr_type()) as mock_stderr:
+ self.assertMultiLineEqual('', mock_stderr.getvalue())
+ logging.warning('Hello. hello. hello. Is there anybody out there?')
+ self.assertNotIn('Logging before flag parsing goes to stderr',
+ mock_stderr.getvalue())
+ logging.info('A major purpose of this executable is merely not to crash.')
+
+
+if __name__ == '__main__':
+ absltest.main() # This calls the app.run() init equivalent.
diff --git a/absl/logging/tests/logging_functional_test.py b/absl/logging/tests/logging_functional_test.py
new file mode 100755
index 0000000..af36d23
--- /dev/null
+++ b/absl/logging/tests/logging_functional_test.py
@@ -0,0 +1,762 @@
+# Copyright 2017 The Abseil Authors.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+"""Functional tests for absl.logging."""
+
+from __future__ import absolute_import
+from __future__ import division
+from __future__ import print_function
+
+import fnmatch
+import os
+import re
+import shutil
+import subprocess
+import sys
+import tempfile
+
+from absl import flags
+from absl import logging
+from absl.testing import _bazelize_command
+from absl.testing import absltest
+from absl.testing import parameterized
+import six
+
+
+FLAGS = flags.FLAGS
+
+
+_PY_VLOG3_LOG_MESSAGE = """\
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:62] This line is VLOG level 3
+"""
+
+_PY_VLOG2_LOG_MESSAGE = """\
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:64] This line is VLOG level 2
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:64] This line is log level 2
+"""
+
+# VLOG1 is the same as DEBUG logs.
+_PY_DEBUG_LOG_MESSAGE = """\
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:65] This line is VLOG level 1
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:65] This line is log level 1
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:66] This line is DEBUG
+"""
+
+_PY_INFO_LOG_MESSAGE = """\
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:65] This line is VLOG level 0
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:65] This line is log level 0
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:70] Interesting Stuff\0
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:71] Interesting Stuff with Arguments: 42
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:73] Interesting Stuff with Dictionary
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:76] Info first 1 of 2
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:77] Info 1 (every 3)
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:76] Info first 2 of 2
+I1231 23:59:59.000000 12345 logging_functional_test_helper.py:77] Info 4 (every 3)
+"""
+
+_PY_INFO_LOG_MESSAGE_NOPREFIX = """\
+This line is VLOG level 0
+This line is log level 0
+Interesting Stuff\0
+Interesting Stuff with Arguments: 42
+Interesting Stuff with Dictionary
+Info first 1 of 2
+Info 1 (every 3)
+Info first 2 of 2
+Info 4 (every 3)
+"""
+
+_PY_WARNING_LOG_MESSAGE = """\
+W1231 23:59:59.000000 12345 logging_functional_test_helper.py:65] This line is VLOG level -1
+W1231 23:59:59.000000 12345 logging_functional_test_helper.py:65] This line is log level -1
+W1231 23:59:59.000000 12345 logging_functional_test_helper.py:79] Worrying Stuff
+W0000 23:59:59.000000 12345 logging_functional_test_helper.py:81] Warn first 1 of 2
+W0000 23:59:59.000000 12345 logging_functional_test_helper.py:82] Warn 1 (every 3)
+W0000 23:59:59.000000 12345 logging_functional_test_helper.py:81] Warn first 2 of 2
+W0000 23:59:59.000000 12345 logging_functional_test_helper.py:82] Warn 4 (every 3)
+"""
+
+if sys.version_info[0:2] == (3, 4):
+ _FAKE_ERROR_EXTRA_MESSAGE = """\
+Traceback (most recent call last):
+ File "logging_functional_test_helper.py", line 456, in _test_do_logging
+ raise OSError('Fake Error')
+"""
+else:
+ _FAKE_ERROR_EXTRA_MESSAGE = ''
+
+_PY_ERROR_LOG_MESSAGE = """\
+E1231 23:59:59.000000 12345 logging_functional_test_helper.py:65] This line is VLOG level -2
+E1231 23:59:59.000000 12345 logging_functional_test_helper.py:65] This line is log level -2
+E1231 23:59:59.000000 12345 logging_functional_test_helper.py:87] An Exception %s
+Traceback (most recent call last):
+ File "logging_functional_test_helper.py", line 456, in _test_do_logging
+ raise OSError('Fake Error')
+OSError: Fake Error
+E0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] Once more, just because
+Traceback (most recent call last):
+ File "./logging_functional_test_helper.py", line 78, in _test_do_logging
+ raise OSError('Fake Error')
+OSError: Fake Error
+E0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] Exception 2 %s
+Traceback (most recent call last):
+ File "logging_functional_test_helper.py", line 456, in _test_do_logging
+ raise OSError('Fake Error')
+OSError: Fake Error
+E0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] Non-exception
+E0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] Exception 3
+Traceback (most recent call last):
+ File "logging_functional_test_helper.py", line 456, in _test_do_logging
+ raise OSError('Fake Error')
+OSError: Fake Error
+E0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] No traceback
+{fake_error_extra}OSError: Fake Error
+E1231 23:59:59.000000 12345 logging_functional_test_helper.py:90] Alarming Stuff
+E0000 23:59:59.000000 12345 logging_functional_test_helper.py:92] Error first 1 of 2
+E0000 23:59:59.000000 12345 logging_functional_test_helper.py:93] Error 1 (every 3)
+E0000 23:59:59.000000 12345 logging_functional_test_helper.py:92] Error first 2 of 2
+E0000 23:59:59.000000 12345 logging_functional_test_helper.py:93] Error 4 (every 3)
+""".format(fake_error_extra=_FAKE_ERROR_EXTRA_MESSAGE)
+
+
+_CRITICAL_DOWNGRADE_TO_ERROR_MESSAGE = """\
+E0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] CRITICAL - A critical message
+"""
+
+
+_VERBOSITY_FLAG_TEST_PARAMETERS = (
+ ('fatal', logging.FATAL),
+ ('error', logging.ERROR),
+ ('warning', logging.WARN),
+ ('info', logging.INFO),
+ ('debug', logging.DEBUG),
+ ('vlog1', 1),
+ ('vlog2', 2),
+ ('vlog3', 3))
+
+
+def _get_fatal_log_expectation(testcase, message, include_stacktrace):
+ """Returns the expectation for fatal logging tests.
+
+ Args:
+ testcase: The TestCase instance.
+ message: The extra fatal logging message.
+ include_stacktrace: Whether or not to include stacktrace.
+
+ Returns:
+ A callable, the expectation for fatal logging tests. It will be passed to
+ FunctionalTest._exec_test as third items in the expected_logs list.
+ See _exec_test's docstring for more information.
+ """
+ def assert_logs(logs):
+ if os.name == 'nt':
+ # On Windows, it also dumps extra information at the end, something like:
+ # This application has requested the Runtime to terminate it in an
+ # unusual way. Please contact the application's support team for more
+ # information.
+ logs = '\n'.join(logs.split('\n')[:-3])
+ format_string = (
+ 'F1231 23:59:59.000000 12345 logging_functional_test_helper.py:175] '
+ '%s message\n')
+ expected_logs = format_string % message
+ if include_stacktrace:
+ expected_logs += 'Stack trace:\n'
+ if six.PY3:
+ faulthandler_start = 'Fatal Python error: Aborted'
+ testcase.assertIn(faulthandler_start, logs)
+ log_message = logs.split(faulthandler_start)[0]
+ testcase.assertEqual(_munge_log(expected_logs), _munge_log(log_message))
+
+ return assert_logs
+
+
+def _munge_log(buf):
+ """Remove timestamps, thread ids, filenames and line numbers from logs."""
+
+ # Remove all messages produced before the output to be tested.
+ buf = re.sub(r'(?:.|\n)*START OF TEST HELPER LOGS: IGNORE PREVIOUS.\n',
+ r'',
+ buf)
+
+ # Greeting
+ buf = re.sub(r'(?m)^Log file created at: .*\n',
+ '',
+ buf)
+ buf = re.sub(r'(?m)^Running on machine: .*\n',
+ '',
+ buf)
+ buf = re.sub(r'(?m)^Binary: .*\n',
+ '',
+ buf)
+ buf = re.sub(r'(?m)^Log line format: .*\n',
+ '',
+ buf)
+
+ # Verify thread id is logged as a non-negative quantity.
+ matched = re.match(r'(?m)^(\w)(\d\d\d\d \d\d:\d\d:\d\d\.\d\d\d\d\d\d) '
+ r'([ ]*-?[0-9a-fA-f]+ )?([a-zA-Z<][\w._<>-]+):(\d+)',
+ buf)
+ if matched:
+ threadid = matched.group(3)
+ if int(threadid) < 0:
+ raise AssertionError("Negative threadid '%s' in '%s'" % (threadid, buf))
+
+ # Timestamp
+ buf = re.sub(r'(?m)' + logging.ABSL_LOGGING_PREFIX_REGEX,
+ r'\g<severity>0000 00:00:00.000000 12345 \g<filename>:123',
+ buf)
+
+ # Traceback
+ buf = re.sub(r'(?m)^ File "(.*/)?([^"/]+)", line (\d+),',
+ r' File "\g<2>", line 456,',
+ buf)
+
+ # Stack trace is too complicated for re, just assume it extends to end of
+ # output
+ buf = re.sub(r'(?sm)^Stack trace:\n.*',
+ r'Stack trace:\n',
+ buf)
+ buf = re.sub(r'(?sm)^\*\*\* Signal 6 received by PID.*\n.*',
+ r'Stack trace:\n',
+ buf)
+ buf = re.sub((r'(?sm)^\*\*\* ([A-Z]+) received by PID (\d+) '
+ r'\(TID 0x([0-9a-f]+)\)'
+ r'( from PID \d+)?; stack trace: \*\*\*\n.*'),
+ r'Stack trace:\n',
+ buf)
+ buf = re.sub(r'(?sm)^\*\*\* Check failure stack trace: \*\*\*\n.*',
+ r'Stack trace:\n',
+ buf)
+
+ if os.name == 'nt':
+ # On windows, we calls Python interpreter explicitly, so the file names
+ # include the full path. Strip them.
+ buf = re.sub(r'( File ").*(logging_functional_test_helper\.py", line )',
+ r'\1\2',
+ buf)
+
+ return buf
+
+
+def _verify_status(expected, actual, output):
+ if expected != actual:
+ raise AssertionError(
+ 'Test exited with unexpected status code %d (expected %d). '
+ 'Output was:\n%s' % (actual, expected, output))
+
+
+def _verify_ok(status, output):
+ """Check that helper exited with no errors."""
+ _verify_status(0, status, output)
+
+
+def _verify_fatal(status, output):
+ """Check that helper died as expected."""
+ # os.abort generates a SIGABRT signal (-6). On Windows, the process
+ # immediately returns an exit code of 3.
+ # See https://docs.python.org/3.6/library/os.html#os.abort.
+ expected_exit_code = 3 if os.name == 'nt' else -6
+ _verify_status(expected_exit_code, status, output)
+
+
+def _verify_assert(status, output):
+ """.Check that helper failed with assertion."""
+ _verify_status(1, status, output)
+
+
+class FunctionalTest(parameterized.TestCase):
+ """Functional tests using the logging_functional_test_helper script."""
+
+ def _get_helper(self):
+ return _bazelize_command.get_executable_path(
+ os.path.join(os.path.dirname(__file__),
+ 'logging_functional_test_helper'))
+ def _get_logs(self,
+ verbosity,
+ include_info_prefix=True):
+ logs = []
+ if verbosity >= 3:
+ logs.append(_PY_VLOG3_LOG_MESSAGE)
+ if verbosity >= 2:
+ logs.append(_PY_VLOG2_LOG_MESSAGE)
+ if verbosity >= logging.DEBUG:
+ logs.append(_PY_DEBUG_LOG_MESSAGE)
+
+ if verbosity >= logging.INFO:
+ if include_info_prefix:
+ logs.append(_PY_INFO_LOG_MESSAGE)
+ else:
+ logs.append(_PY_INFO_LOG_MESSAGE_NOPREFIX)
+ if verbosity >= logging.WARN:
+ logs.append(_PY_WARNING_LOG_MESSAGE)
+ if verbosity >= logging.ERROR:
+ logs.append(_PY_ERROR_LOG_MESSAGE)
+
+ expected_logs = ''.join(logs)
+ if six.PY3:
+ # In Python 3 class types are represented a bit differently
+ expected_logs = expected_logs.replace(
+ "<type 'exceptions.OSError'>", "<class 'OSError'>")
+ return expected_logs
+
+ def setUp(self):
+ self._log_dir = tempfile.mkdtemp(dir=FLAGS.test_tmpdir)
+
+ def tearDown(self):
+ shutil.rmtree(self._log_dir)
+
+ def _exec_test(self,
+ verify_exit_fn,
+ expected_logs,
+ test_name='do_logging',
+ pass_logtostderr=False,
+ use_absl_log_file=False,
+ show_info_prefix=1,
+ extra_args=()):
+ """Execute the helper script and verify its output.
+
+ Args:
+ verify_exit_fn: A function taking (status, output).
+ expected_logs: List of tuples, or None if output shouldn't be checked.
+ Tuple is (log prefix, log type, expected contents):
+ - log prefix: A program name, or 'stderr'.
+ - log type: 'INFO', 'ERROR', etc.
+ - expected: Can be the followings:
+ - A string
+ - A callable, called with the logs as a single argument
+ - None, means don't check contents of log file
+ test_name: Name to pass to helper.
+ pass_logtostderr: Pass --logtostderr to the helper script if True.
+ use_absl_log_file: If True, call
+ logging.get_absl_handler().use_absl_log_file() before test_fn in
+ logging_functional_test_helper.
+ show_info_prefix: --showprefixforinfo value passed to the helper script.
+ extra_args: Iterable of str (optional, defaults to ()) - extra arguments
+ to pass to the helper script.
+
+ Raises:
+ AssertionError: Assertion error when test fails.
+ """
+ args = ['--log_dir=%s' % self._log_dir]
+ if pass_logtostderr:
+ args.append('--logtostderr')
+ if not show_info_prefix:
+ args.append('--noshowprefixforinfo')
+ args += extra_args
+
+ # Execute helper in subprocess.
+ env = os.environ.copy()
+ env.update({
+ 'TEST_NAME': test_name,
+ 'USE_ABSL_LOG_FILE': '%d' % (use_absl_log_file,),
+ })
+ cmd = [self._get_helper()] + args
+
+ print('env: %s' % env, file=sys.stderr)
+ print('cmd: %s' % cmd, file=sys.stderr)
+ process = subprocess.Popen(
+ cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, env=env,
+ universal_newlines=True)
+ output, _ = process.communicate()
+ status = process.returncode
+
+ # Verify exit status.
+ verify_exit_fn(status, output)
+
+ # Check outputs?
+ if expected_logs is None:
+ return
+
+ # Get list of log files.
+ logs = os.listdir(self._log_dir)
+ logs = fnmatch.filter(logs, '*.log.*')
+ logs.append('stderr')
+
+ # Look for a log matching each expected pattern.
+ matched = []
+ unmatched = []
+ unexpected = logs[:]
+ for log_prefix, log_type, expected in expected_logs:
+ # What pattern?
+ if log_prefix == 'stderr':
+ assert log_type is None
+ pattern = 'stderr'
+ else:
+ pattern = r'%s[.].*[.]log[.]%s[.][\d.-]*$' % (log_prefix, log_type)
+
+ # Is it there
+ for basename in logs:
+ if re.match(pattern, basename):
+ matched.append([expected, basename])
+ unexpected.remove(basename)
+ break
+ else:
+ unmatched.append(pattern)
+
+ # Mismatch?
+ errors = ''
+ if unmatched:
+ errors += 'The following log files were expected but not found: %s' % (
+ '\n '.join(unmatched))
+ if unexpected:
+ if errors:
+ errors += '\n'
+ errors += 'The following log files were not expected: %s' % (
+ '\n '.join(unexpected))
+ if errors:
+ raise AssertionError(errors)
+
+ # Compare contents of matches.
+ for (expected, basename) in matched:
+ if expected is None:
+ continue
+
+ if basename == 'stderr':
+ actual = output
+ else:
+ path = os.path.join(self._log_dir, basename)
+ if six.PY2:
+ f = open(path)
+ else:
+ f = open(path, encoding='utf-8')
+ with f:
+ actual = f.read()
+
+ if callable(expected):
+ try:
+ expected(actual)
+ except AssertionError:
+ print('expected_logs assertion failed, actual {} log:\n{}'.format(
+ basename, actual), file=sys.stderr)
+ raise
+ elif isinstance(expected, str):
+ self.assertMultiLineEqual(_munge_log(expected), _munge_log(actual),
+ '%s differs' % basename)
+ else:
+ self.fail(
+ 'Invalid value found for expected logs: {}, type: {}'.format(
+ expected, type(expected)))
+
+ @parameterized.named_parameters(
+ ('', False),
+ ('logtostderr', True))
+ def test_py_logging(self, logtostderr):
+ # Python logging by default logs to stderr.
+ self._exec_test(
+ _verify_ok,
+ [['stderr', None, self._get_logs(logging.INFO)]],
+ pass_logtostderr=logtostderr)
+
+ def test_py_logging_use_absl_log_file(self):
+ # Python logging calling use_absl_log_file causes also log to files.
+ self._exec_test(
+ _verify_ok,
+ [['stderr', None, ''],
+ ['absl_log_file', 'INFO', self._get_logs(logging.INFO)]],
+ use_absl_log_file=True)
+
+ def test_py_logging_use_absl_log_file_logtostderr(self):
+ # Python logging asked to log to stderr even though use_absl_log_file
+ # is called.
+ self._exec_test(
+ _verify_ok,
+ [['stderr', None, self._get_logs(logging.INFO)]],
+ pass_logtostderr=True,
+ use_absl_log_file=True)
+
+ @parameterized.named_parameters(
+ ('', False),
+ ('logtostderr', True))
+ def test_py_logging_noshowprefixforinfo(self, logtostderr):
+ self._exec_test(
+ _verify_ok,
+ [['stderr', None, self._get_logs(logging.INFO,
+ include_info_prefix=False)]],
+ pass_logtostderr=logtostderr,
+ show_info_prefix=0)
+
+ def test_py_logging_noshowprefixforinfo_use_absl_log_file(self):
+ self._exec_test(
+ _verify_ok,
+ [['stderr', None, ''],
+ ['absl_log_file', 'INFO', self._get_logs(logging.INFO)]],
+ show_info_prefix=0,
+ use_absl_log_file=True)
+
+ def test_py_logging_noshowprefixforinfo_use_absl_log_file_logtostderr(self):
+ self._exec_test(
+ _verify_ok,
+ [['stderr', None, self._get_logs(logging.INFO,
+ include_info_prefix=False)]],
+ pass_logtostderr=True,
+ show_info_prefix=0,
+ use_absl_log_file=True)
+
+ def test_py_logging_noshowprefixforinfo_verbosity(self):
+ self._exec_test(
+ _verify_ok,
+ [['stderr', None, self._get_logs(logging.DEBUG)]],
+ pass_logtostderr=True,
+ show_info_prefix=0,
+ use_absl_log_file=True,
+ extra_args=['-v=1'])
+
+ def test_py_logging_fatal_main_thread_only(self):
+ self._exec_test(
+ _verify_fatal,
+ [['stderr', None, _get_fatal_log_expectation(
+ self, 'fatal_main_thread_only', False)]],
+ test_name='fatal_main_thread_only')
+
+ def test_py_logging_fatal_with_other_threads(self):
+ self._exec_test(
+ _verify_fatal,
+ [['stderr', None, _get_fatal_log_expectation(
+ self, 'fatal_with_other_threads', False)]],
+ test_name='fatal_with_other_threads')
+
+ def test_py_logging_fatal_non_main_thread(self):
+ self._exec_test(
+ _verify_fatal,
+ [['stderr', None, _get_fatal_log_expectation(
+ self, 'fatal_non_main_thread', False)]],
+ test_name='fatal_non_main_thread')
+
+ def test_py_logging_critical_non_absl(self):
+ self._exec_test(
+ _verify_ok,
+ [['stderr', None, _CRITICAL_DOWNGRADE_TO_ERROR_MESSAGE]],
+ test_name='critical_from_non_absl_logger')
+
+ def test_py_logging_skip_log_prefix(self):
+ self._exec_test(
+ _verify_ok,
+ [['stderr', None, '']],
+ test_name='register_frame_to_skip')
+
+ def test_py_logging_flush(self):
+ self._exec_test(
+ _verify_ok,
+ [['stderr', None, '']],
+ test_name='flush')
+
+ @parameterized.named_parameters(*_VERBOSITY_FLAG_TEST_PARAMETERS)
+ def test_py_logging_verbosity_stderr(self, verbosity):
+ """Tests -v/--verbosity flag with python logging to stderr."""
+ v_flag = '-v=%d' % verbosity
+ self._exec_test(
+ _verify_ok,
+ [['stderr', None, self._get_logs(verbosity)]],
+ extra_args=[v_flag])
+
+ @parameterized.named_parameters(*_VERBOSITY_FLAG_TEST_PARAMETERS)
+ def test_py_logging_verbosity_file(self, verbosity):
+ """Tests -v/--verbosity flag with Python logging to stderr."""
+ v_flag = '-v=%d' % verbosity
+ self._exec_test(
+ _verify_ok,
+ [['stderr', None, ''],
+ # When using python logging, it only creates a file named INFO,
+ # unlike C++ it also creates WARNING and ERROR files.
+ ['absl_log_file', 'INFO', self._get_logs(verbosity)]],
+ use_absl_log_file=True,
+ extra_args=[v_flag])
+
+ def test_stderrthreshold_py_logging(self):
+ """Tests --stderrthreshold."""
+
+ stderr_logs = '''\
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] FLAGS.stderrthreshold=debug, debug log
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] FLAGS.stderrthreshold=debug, info log
+W0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] FLAGS.stderrthreshold=debug, warn log
+E0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] FLAGS.stderrthreshold=debug, error log
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] FLAGS.stderrthreshold=info, info log
+W0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] FLAGS.stderrthreshold=info, warn log
+E0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] FLAGS.stderrthreshold=info, error log
+W0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] FLAGS.stderrthreshold=warn, warn log
+E0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] FLAGS.stderrthreshold=warn, error log
+E0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] FLAGS.stderrthreshold=error, error log
+'''
+
+ expected_logs = [
+ ['stderr', None, stderr_logs],
+ ['absl_log_file', 'INFO', None],
+ ]
+ # Set verbosity to debug to test stderrthreshold == debug.
+ extra_args = ['-v=1']
+
+ self._exec_test(
+ _verify_ok,
+ expected_logs,
+ test_name='stderrthreshold',
+ extra_args=extra_args,
+ use_absl_log_file=True)
+
+ def test_std_logging_py_logging(self):
+ """Tests logs from std logging."""
+ stderr_logs = '''\
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] std debug log
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] std info log
+W0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] std warn log
+E0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] std error log
+'''
+ expected_logs = [['stderr', None, stderr_logs]]
+
+ extra_args = ['-v=1', '--logtostderr']
+ self._exec_test(
+ _verify_ok,
+ expected_logs,
+ test_name='std_logging',
+ extra_args=extra_args)
+
+ def test_bad_exc_info_py_logging(self):
+
+ def assert_stderr(stderr):
+ # The exact message differs among different Python versions. So it just
+ # asserts some certain information is there.
+ self.assertIn('Traceback (most recent call last):', stderr)
+ self.assertIn('IndexError', stderr)
+
+ expected_logs = [
+ ['stderr', None, assert_stderr],
+ ['absl_log_file', 'INFO', '']]
+
+ self._exec_test(
+ _verify_ok,
+ expected_logs,
+ test_name='bad_exc_info',
+ use_absl_log_file=True)
+
+ def test_none_exc_info_py_logging(self):
+
+ if six.PY2:
+ expected_stderr = ''
+ expected_info = '''\
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] None exc_info
+None
+'''
+ else:
+ if sys.version_info[0:2] == (3, 4):
+ # Python 3.4 is different.
+ def expected_stderr(stderr):
+ regex = r'''--- Logging error ---
+Traceback \(most recent call last\):
+.*
+Message: 'None exc_info'
+Arguments: \(\)'''
+ if not re.search(regex, stderr, flags=re.DOTALL | re.MULTILINE):
+ self.fail('Cannot find regex "%s" in stderr:\n%s' % (regex, stderr))
+ expected_info = ''
+ else:
+ expected_stderr = ''
+ expected_info = '''\
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] None exc_info
+NoneType: None
+'''
+
+ expected_logs = [
+ ['stderr', None, expected_stderr],
+ ['absl_log_file', 'INFO', expected_info]]
+
+ self._exec_test(
+ _verify_ok,
+ expected_logs,
+ test_name='none_exc_info',
+ use_absl_log_file=True)
+
+ def test_unicode_py_logging(self):
+
+ def get_stderr_message(stderr, name):
+ match = re.search(
+ '-- begin {} --\n(.*)-- end {} --'.format(name, name),
+ stderr, re.MULTILINE | re.DOTALL)
+ self.assertTrue(
+ match, 'Cannot find stderr message for test {}'.format(name))
+ return match.group(1)
+
+ def assert_stderr_python2(stderr):
+ """Verifies that it writes correct information to stderr for Python 2.
+
+ For unicode errors, it logs the exception with a stack trace to stderr.
+
+ Args:
+ stderr: the message from stderr.
+ """
+ # Successful logs:
+ for name in ('unicode', 'unicode % unicode', 'bytes % bytes'):
+ self.assertEqual('', get_stderr_message(stderr, name))
+
+ # UnicodeDecodeError errors:
+ for name in (
+ 'unicode % bytes', 'bytes % unicode', 'unicode % iso8859-15'):
+ self.assertIn('UnicodeDecodeError',
+ get_stderr_message(stderr, name))
+ self.assertIn('Traceback (most recent call last):',
+ get_stderr_message(stderr, name))
+
+ # UnicodeEncodeError errors:
+ self.assertIn('UnicodeEncodeError',
+ get_stderr_message(stderr, 'str % exception'))
+ self.assertIn('Traceback (most recent call last):',
+ get_stderr_message(stderr, 'str % exception'))
+
+ def assert_stderr_python3(stderr):
+ """Verifies that it writes correct information to stderr for Python 3.
+
+ There are no unicode errors in Python 3.
+
+ Args:
+ stderr: the message from stderr.
+ """
+ # Successful logs:
+ for name in (
+ 'unicode', 'unicode % unicode', 'bytes % bytes', 'unicode % bytes',
+ 'bytes % unicode', 'unicode % iso8859-15', 'str % exception',
+ 'str % exception'):
+ logging.info('name = %s', name)
+ self.assertEqual('', get_stderr_message(stderr, name))
+
+ expected_logs = [[
+ 'stderr', None,
+ assert_stderr_python2 if six.PY2 else assert_stderr_python3]]
+
+ if six.PY2:
+ # In Python 2, only successfully formatted messages are logged.
+ info_log = u'''\
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] G\u00eete: Ch\u00e2tonnaye
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] G\u00eete: Ch\u00e2tonnaye
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] G\u00eete: Ch\u00e2tonnaye
+'''.encode('utf-8')
+ else:
+ # In Python 3, all messages are formatted successfully and logged.
+ info_log = u'''\
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] G\u00eete: Ch\u00e2tonnaye
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] G\u00eete: Ch\u00e2tonnaye
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] b'G\\xc3\\xaete: b'Ch\\xc3\\xa2tonnaye''
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] G\u00eete: b'Ch\\xc3\\xa2tonnaye'
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] b'G\\xc3\\xaete: Ch\u00e2tonnaye'
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] G\u00eete: b'Ch\\xe2tonnaye'
+I0000 00:00:00.000000 12345 logging_functional_test_helper.py:123] exception: Ch\u00e2tonnaye
+'''
+ expected_logs.append(['absl_log_file', 'INFO', info_log])
+
+ self._exec_test(
+ _verify_ok,
+ expected_logs,
+ test_name='unicode',
+ use_absl_log_file=True)
+
+
+if __name__ == '__main__':
+ absltest.main()
diff --git a/absl/logging/tests/logging_functional_test_helper.py b/absl/logging/tests/logging_functional_test_helper.py
new file mode 100755
index 0000000..017206d
--- /dev/null
+++ b/absl/logging/tests/logging_functional_test_helper.py
@@ -0,0 +1,302 @@
+# Copyright 2017 The Abseil Authors.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+"""Helper script for logging_functional_test."""
+
+from __future__ import absolute_import
+from __future__ import division
+from __future__ import print_function
+
+import logging as std_logging
+import os
+import sys
+import threading
+import time
+
+from absl import app
+from absl import flags
+from absl import logging
+from six.moves import xrange # pylint: disable=redefined-builtin
+
+FLAGS = flags.FLAGS
+
+
+class VerboseDel(object):
+ """Dummy class to test __del__ running."""
+
+ def __init__(self, msg):
+ self._msg = msg
+
+ def __del__(self):
+ sys.stderr.write(self._msg)
+ sys.stderr.flush()
+
+
+def _test_do_logging():
+ """Do some log operations."""
+ logging.vlog(3, 'This line is VLOG level 3')
+ logging.vlog(2, 'This line is VLOG level 2')
+ logging.log(2, 'This line is log level 2')
+
+ logging.vlog(1, 'This line is VLOG level 1')
+ logging.log(1, 'This line is log level 1')
+ logging.debug('This line is DEBUG')
+
+ logging.vlog(0, 'This line is VLOG level 0')
+ logging.log(0, 'This line is log level 0')
+ logging.info('Interesting Stuff\0')
+ logging.info('Interesting Stuff with Arguments: %d', 42)
+ logging.info('%(a)s Stuff with %(b)s',
+ {'a': 'Interesting', 'b': 'Dictionary'})
+
+ for i in xrange(1, 5):
+ logging.log_first_n(logging.INFO, 'Info first %d of %d', 2, i, 2)
+ logging.log_every_n(logging.INFO, 'Info %d (every %d)', 3, i, 3)
+
+ logging.vlog(-1, 'This line is VLOG level -1')
+ logging.log(-1, 'This line is log level -1')
+ logging.warn('Worrying Stuff')
+ for i in xrange(1, 5):
+ logging.log_first_n(logging.WARN, 'Warn first %d of %d', 2, i, 2)
+ logging.log_every_n(logging.WARN, 'Warn %d (every %d)', 3, i, 3)
+
+ logging.vlog(-2, 'This line is VLOG level -2')
+ logging.log(-2, 'This line is log level -2')
+ try:
+ raise OSError('Fake Error')
+ except OSError:
+ saved_exc_info = sys.exc_info()
+ logging.exception('An Exception %s')
+ logging.exception('Once more, %(reason)s', {'reason': 'just because'})
+ logging.error('Exception 2 %s', exc_info=True)
+ logging.error('Non-exception', exc_info=False)
+
+ try:
+ sys.exc_clear()
+ except AttributeError:
+ # No sys.exc_clear() in Python 3, but this will clear sys.exc_info() too.
+ pass
+
+ logging.error('Exception %s', '3', exc_info=saved_exc_info)
+ logging.error('No traceback', exc_info=saved_exc_info[:2] + (None,))
+
+ logging.error('Alarming Stuff')
+ for i in xrange(1, 5):
+ logging.log_first_n(logging.ERROR, 'Error first %d of %d', 2, i, 2)
+ logging.log_every_n(logging.ERROR, 'Error %d (every %d)', 3, i, 3)
+ logging.flush()
+
+
+def _test_fatal_main_thread_only():
+ """Test logging.fatal from main thread, no other threads running."""
+ v = VerboseDel('fatal_main_thread_only main del called\n')
+ try:
+ logging.fatal('fatal_main_thread_only message')
+ finally:
+ del v
+
+
+def _test_fatal_with_other_threads():
+ """Test logging.fatal from main thread, other threads running."""
+
+ lock = threading.Lock()
+ lock.acquire()
+
+ def sleep_forever(lock=lock):
+ v = VerboseDel('fatal_with_other_threads non-main del called\n')
+ try:
+ lock.release()
+ while True:
+ time.sleep(10000)
+ finally:
+ del v
+
+ v = VerboseDel('fatal_with_other_threads main del called\n')
+ try:
+ # Start new thread
+ t = threading.Thread(target=sleep_forever)
+ t.start()
+
+ # Wait for other thread
+ lock.acquire()
+ lock.release()
+
+ # Die
+ logging.fatal('fatal_with_other_threads message')
+ while True:
+ time.sleep(10000)
+ finally:
+ del v
+
+
+def _test_fatal_non_main_thread():
+ """Test logging.fatal from non main thread."""
+
+ lock = threading.Lock()
+ lock.acquire()
+
+ def die_soon(lock=lock):
+ v = VerboseDel('fatal_non_main_thread non-main del called\n')
+ try:
+ # Wait for signal from other thread
+ lock.acquire()
+ lock.release()
+ logging.fatal('fatal_non_main_thread message')
+ while True:
+ time.sleep(10000)
+ finally:
+ del v
+
+ v = VerboseDel('fatal_non_main_thread main del called\n')
+ try:
+ # Start new thread
+ t = threading.Thread(target=die_soon)
+ t.start()
+
+ # Signal other thread
+ lock.release()
+
+ # Wait for it to die
+ while True:
+ time.sleep(10000)
+ finally:
+ del v
+
+
+def _test_critical_from_non_absl_logger():
+ """Test CRITICAL logs from non-absl loggers."""
+
+ std_logging.critical('A critical message')
+
+
+def _test_register_frame_to_skip():
+ """Test skipping frames for line number reporting."""
+
+ def _getline():
+
+ def _getline_inner():
+ return logging.get_absl_logger().findCaller()[1]
+
+ return _getline_inner()
+
+ # Check register_frame_to_skip function to see if log frame skipping works.
+ line1 = _getline()
+ line2 = _getline()
+ logging.get_absl_logger().register_frame_to_skip(__file__, '_getline')
+ line3 = _getline()
+ # Both should be line number of the _getline_inner() call.
+ assert (line1 == line2), (line1, line2)
+ # line3 should be a line number in this function.
+ assert (line2 != line3), (line2, line3)
+
+
+def _test_flush():
+ """Test flush in various difficult cases."""
+ # Flush, but one of the logfiles is closed
+ log_filename = os.path.join(FLAGS.log_dir, 'a_thread_with_logfile.txt')
+ with open(log_filename, 'w') as log_file:
+ logging.get_absl_handler().python_handler.stream = log_file
+ logging.flush()
+
+
+def _test_stderrthreshold():
+ """Tests modifying --stderrthreshold after flag parsing will work."""
+
+ def log_things():
+ logging.debug('FLAGS.stderrthreshold=%s, debug log', FLAGS.stderrthreshold)
+ logging.info('FLAGS.stderrthreshold=%s, info log', FLAGS.stderrthreshold)
+ logging.warn('FLAGS.stderrthreshold=%s, warn log', FLAGS.stderrthreshold)
+ logging.error('FLAGS.stderrthreshold=%s, error log', FLAGS.stderrthreshold)
+
+ FLAGS.stderrthreshold = 'debug'
+ log_things()
+ FLAGS.stderrthreshold = 'info'
+ log_things()
+ FLAGS.stderrthreshold = 'warn'
+ log_things()
+ FLAGS.stderrthreshold = 'error'
+ log_things()
+
+
+def _test_std_logging():
+ """Tests logs from std logging."""
+ std_logging.debug('std debug log')
+ std_logging.info('std info log')
+ std_logging.warn('std warn log')
+ std_logging.error('std error log')
+
+
+def _test_bad_exc_info():
+ """Tests when a bad exc_info valud is provided."""
+ logging.info('Bad exc_info', exc_info=(None, None))
+
+
+def _test_none_exc_info():
+ """Tests when exc_info is requested but not available."""
+ # Clear exc_info first.
+ try:
+ sys.exc_clear()
+ except AttributeError:
+ # No sys.exc_clear() in Python 3, but this will clear sys.exc_info() too.
+ pass
+ logging.info('None exc_info', exc_info=True)
+
+
+def _test_unicode():
+ """Tests unicode handling."""
+
+ test_names = []
+
+ def log(name, msg, *args):
+ """Logs the message, and ensures the same name is not logged again."""
+ assert name not in test_names, ('test_unicode expects unique names to work,'
+ ' found existing name {}').format(name)
+ test_names.append(name)
+
+ # Add line seprators so that tests can verify the output for each log
+ # message.
+ sys.stderr.write('-- begin {} --\n'.format(name))
+ logging.info(msg, *args)
+ sys.stderr.write('-- end {} --\n'.format(name))
+
+ log('unicode', u'G\u00eete: Ch\u00e2tonnaye')
+ log('unicode % unicode', u'G\u00eete: %s', u'Ch\u00e2tonnaye')
+ log('bytes % bytes', u'G\u00eete: %s'.encode('utf-8'),
+ u'Ch\u00e2tonnaye'.encode('utf-8'))
+ log('unicode % bytes', u'G\u00eete: %s', u'Ch\u00e2tonnaye'.encode('utf-8'))
+ log('bytes % unicode', u'G\u00eete: %s'.encode('utf-8'), u'Ch\u00e2tonnaye')
+ log('unicode % iso8859-15', u'G\u00eete: %s',
+ u'Ch\u00e2tonnaye'.encode('iso-8859-15'))
+ log('str % exception', 'exception: %s', Exception(u'Ch\u00e2tonnaye'))
+
+
+def main(argv):
+ del argv # Unused.
+
+ test_name = os.environ.get('TEST_NAME', None)
+ test_fn = globals().get('_test_%s' % test_name)
+ if test_fn is None:
+ raise AssertionError('TEST_NAME must be set to a valid value')
+ # Flush so previous messages are written to file before we switch to a new
+ # file with use_absl_log_file.
+ logging.flush()
+ if os.environ.get('USE_ABSL_LOG_FILE') == '1':
+ logging.get_absl_handler().use_absl_log_file('absl_log_file', FLAGS.log_dir)
+
+ test_fn()
+
+
+if __name__ == '__main__':
+ sys.argv[0] = 'py_argv_0'
+ app.run(main)
diff --git a/absl/logging/tests/logging_test.py b/absl/logging/tests/logging_test.py
new file mode 100644
index 0000000..f6eddb4
--- /dev/null
+++ b/absl/logging/tests/logging_test.py
@@ -0,0 +1,734 @@
+# Copyright 2017 The Abseil Authors.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+"""Unit tests for absl.logging."""
+
+from __future__ import absolute_import
+from __future__ import division
+from __future__ import print_function
+
+import getpass
+import io
+import logging as std_logging
+import os
+import socket
+import sys
+import threading
+import time
+import traceback
+import unittest
+
+from absl import flags
+from absl import logging
+from absl.testing import absltest
+from absl.testing import flagsaver
+from absl.testing import parameterized
+import mock
+import six
+from six.moves import range # pylint: disable=redefined-builtin
+
+
+FLAGS = flags.FLAGS
+
+_StreamIO = io.StringIO if six.PY3 else io.BytesIO # pylint: disable=invalid-name
+
+
+class ConfigurationTest(absltest.TestCase):
+ """Tests the initial logging configuration."""
+
+ def test_logger_and_handler(self):
+ absl_logger = std_logging.getLogger('absl')
+ self.assertIs(absl_logger, logging.get_absl_logger())
+ self.assertTrue(isinstance(absl_logger, logging.ABSLLogger))
+ self.assertTrue(
+ isinstance(logging.get_absl_handler().python_handler.formatter,
+ logging.PythonFormatter))
+
+
+class PythonHandlerTest(absltest.TestCase):
+ """Tests the PythonHandler class."""
+
+ def setUp(self):
+ (year, month, day, hour, minute, sec,
+ dunno, dayofyear, dst_flag) = (1979, 10, 21, 18, 17, 16, 3, 15, 0)
+ self.now_tuple = (year, month, day, hour, minute, sec,
+ dunno, dayofyear, dst_flag)
+ self.python_handler = logging.PythonHandler()
+
+ def tearDown(self):
+ mock.patch.stopall()
+
+ @flagsaver.flagsaver(logtostderr=False)
+ def test_set_google_log_file_no_log_to_stderr(self):
+ with mock.patch.object(self.python_handler, 'start_logging_to_file'):
+ self.python_handler.use_absl_log_file()
+ self.python_handler.start_logging_to_file.assert_called_once_with(
+ program_name=None, log_dir=None)
+
+ @flagsaver.flagsaver(logtostderr=True)
+ def test_set_google_log_file_with_log_to_stderr(self):
+ self.python_handler.stream = None
+ self.python_handler.use_absl_log_file()
+ self.assertEqual(sys.stderr, self.python_handler.stream)
+
+ @mock.patch.object(logging, 'find_log_dir_and_names')
+ @mock.patch.object(logging.time, 'localtime')
+ @mock.patch.object(logging.time, 'time')
+ @mock.patch.object(os.path, 'islink')
+ @mock.patch.object(os, 'unlink')
+ @mock.patch.object(os, 'getpid')
+ def test_start_logging_to_file(
+ self, mock_getpid, mock_unlink, mock_islink, mock_time,
+ mock_localtime, mock_find_log_dir_and_names):
+ mock_find_log_dir_and_names.return_value = ('here', 'prog1', 'prog1')
+ mock_time.return_value = '12345'
+ mock_localtime.return_value = self.now_tuple
+ mock_getpid.return_value = 4321
+ symlink = os.path.join('here', 'prog1.INFO')
+ mock_islink.return_value = True
+ with mock.patch.object(
+ logging, 'open', return_value=sys.stdout, create=True):
+ if getattr(os, 'symlink', None):
+ with mock.patch.object(os, 'symlink'):
+ self.python_handler.start_logging_to_file()
+ mock_unlink.assert_called_once_with(symlink)
+ os.symlink.assert_called_once_with(
+ 'prog1.INFO.19791021-181716.4321', symlink)
+ else:
+ self.python_handler.start_logging_to_file()
+
+ def test_log_file(self):
+ handler = logging.PythonHandler()
+ self.assertEqual(sys.stderr, handler.stream)
+
+ stream = mock.Mock()
+ handler = logging.PythonHandler(stream)
+ self.assertEqual(stream, handler.stream)
+
+ def test_flush(self):
+ stream = mock.Mock()
+ handler = logging.PythonHandler(stream)
+ handler.flush()
+ stream.flush.assert_called_once()
+
+ def test_flush_with_value_error(self):
+ stream = mock.Mock()
+ stream.flush.side_effect = ValueError
+ handler = logging.PythonHandler(stream)
+ handler.flush()
+ stream.flush.assert_called_once()
+
+ def test_flush_with_environment_error(self):
+ stream = mock.Mock()
+ stream.flush.side_effect = EnvironmentError
+ handler = logging.PythonHandler(stream)
+ handler.flush()
+ stream.flush.assert_called_once()
+
+ def test_flush_with_assertion_error(self):
+ stream = mock.Mock()
+ stream.flush.side_effect = AssertionError
+ handler = logging.PythonHandler(stream)
+ with self.assertRaises(AssertionError):
+ handler.flush()
+
+ def test_log_to_std_err(self):
+ record = std_logging.LogRecord(
+ 'name', std_logging.INFO, 'path', 12, 'logging_msg', [], False)
+ with mock.patch.object(std_logging.StreamHandler, 'emit'):
+ self.python_handler._log_to_stderr(record)
+ std_logging.StreamHandler.emit.assert_called_once_with(record)
+
+ @flagsaver.flagsaver(logtostderr=True)
+ def test_emit_log_to_stderr(self):
+ record = std_logging.LogRecord(
+ 'name', std_logging.INFO, 'path', 12, 'logging_msg', [], False)
+ with mock.patch.object(self.python_handler, '_log_to_stderr'):
+ self.python_handler.emit(record)
+ self.python_handler._log_to_stderr.assert_called_once_with(record)
+
+ def test_emit(self):
+ stream = _StreamIO()
+ handler = logging.PythonHandler(stream)
+ handler.stderr_threshold = std_logging.FATAL
+ record = std_logging.LogRecord(
+ 'name', std_logging.INFO, 'path', 12, 'logging_msg', [], False)
+ handler.emit(record)
+ self.assertEqual(1, stream.getvalue().count('logging_msg'))
+
+ @flagsaver.flagsaver(stderrthreshold='debug')
+ def test_emit_and_stderr_threshold(self):
+ mock_stderr = _StreamIO()
+ stream = _StreamIO()
+ handler = logging.PythonHandler(stream)
+ record = std_logging.LogRecord(
+ 'name', std_logging.INFO, 'path', 12, 'logging_msg', [], False)
+ with mock.patch.object(sys, 'stderr', new=mock_stderr) as mock_stderr:
+ handler.emit(record)
+ self.assertEqual(1, stream.getvalue().count('logging_msg'))
+ self.assertEqual(1, mock_stderr.getvalue().count('logging_msg'))
+
+ @flagsaver.flagsaver(alsologtostderr=True)
+ def test_emit_also_log_to_stderr(self):
+ mock_stderr = _StreamIO()
+ stream = _StreamIO()
+ handler = logging.PythonHandler(stream)
+ handler.stderr_threshold = std_logging.FATAL
+ record = std_logging.LogRecord(
+ 'name', std_logging.INFO, 'path', 12, 'logging_msg', [], False)
+ with mock.patch.object(sys, 'stderr', new=mock_stderr) as mock_stderr:
+ handler.emit(record)
+ self.assertEqual(1, stream.getvalue().count('logging_msg'))
+ self.assertEqual(1, mock_stderr.getvalue().count('logging_msg'))
+
+ def test_emit_on_stderr(self):
+ mock_stderr = _StreamIO()
+ with mock.patch.object(sys, 'stderr', new=mock_stderr) as mock_stderr:
+ handler = logging.PythonHandler()
+ handler.stderr_threshold = std_logging.INFO
+ record = std_logging.LogRecord(
+ 'name', std_logging.INFO, 'path', 12, 'logging_msg', [], False)
+ handler.emit(record)
+ self.assertEqual(1, mock_stderr.getvalue().count('logging_msg'))
+
+ def test_emit_fatal_absl(self):
+ stream = _StreamIO()
+ handler = logging.PythonHandler(stream)
+ record = std_logging.LogRecord(
+ 'name', std_logging.FATAL, 'path', 12, 'logging_msg', [], False)
+ record.__dict__[logging._ABSL_LOG_FATAL] = True
+ with mock.patch.object(handler, 'flush') as mock_flush:
+ with mock.patch.object(os, 'abort') as mock_abort:
+ handler.emit(record)
+ mock_abort.assert_called_once()
+ mock_flush.assert_called() # flush is also called by super class.
+
+ def test_emit_fatal_non_absl(self):
+ stream = _StreamIO()
+ handler = logging.PythonHandler(stream)
+ record = std_logging.LogRecord(
+ 'name', std_logging.FATAL, 'path', 12, 'logging_msg', [], False)
+ with mock.patch.object(os, 'abort') as mock_abort:
+ handler.emit(record)
+ mock_abort.assert_not_called()
+
+ def test_close(self):
+ stream = mock.Mock()
+ stream.isatty.return_value = True
+ handler = logging.PythonHandler(stream)
+ with mock.patch.object(handler, 'flush') as mock_flush:
+ with mock.patch.object(std_logging.StreamHandler, 'close') as super_close:
+ handler.close()
+ mock_flush.assert_called_once()
+ super_close.assert_called_once()
+ stream.close.assert_not_called()
+
+ def test_close_afile(self):
+ stream = mock.Mock()
+ stream.isatty.return_value = False
+ stream.close.side_effect = ValueError
+ handler = logging.PythonHandler(stream)
+ with mock.patch.object(handler, 'flush') as mock_flush:
+ with mock.patch.object(std_logging.StreamHandler, 'close') as super_close:
+ handler.close()
+ mock_flush.assert_called_once()
+ super_close.assert_called_once()
+
+ def test_close_stderr(self):
+ with mock.patch.object(sys, 'stderr') as mock_stderr:
+ mock_stderr.isatty.return_value = False
+ handler = logging.PythonHandler(sys.stderr)
+ handler.close()
+ mock_stderr.close.assert_not_called()
+
+ def test_close_stdout(self):
+ with mock.patch.object(sys, 'stdout') as mock_stdout:
+ mock_stdout.isatty.return_value = False
+ handler = logging.PythonHandler(sys.stdout)
+ handler.close()
+ mock_stdout.close.assert_not_called()
+
+ def test_close_fake_file(self):
+
+ class FakeFile(object):
+ """A file-like object that does not implement "isatty"."""
+
+ def __init__(self):
+ self.closed = False
+
+ def close(self):
+ self.closed = True
+
+ def flush(self):
+ pass
+
+ fake_file = FakeFile()
+ handler = logging.PythonHandler(fake_file)
+ handler.close()
+ self.assertTrue(fake_file.closed)
+
+
+class PrefixFormatterTest(absltest.TestCase):
+ """Tests the PrefixFormatter class."""
+
+ def setUp(self):
+ self.now_tuple = time.localtime(time.mktime(
+ (1979, 10, 21, 18, 17, 16, 3, 15, 1)))
+ self.new_prefix = lambda level: '(blah_prefix)'
+ mock.patch.object(time, 'time').start()
+ mock.patch.object(time, 'localtime').start()
+ self.record = std_logging.LogRecord(
+ 'name', std_logging.INFO, 'path', 12, 'A Message', [], False)
+ self.formatter = logging.PythonFormatter()
+
+ def tearDown(self):
+ mock.patch.stopall()
+
+ @mock.patch.object(logging._thread_lib, 'get_ident')
+ def test_get_thread_id(self, mock_get_ident):
+ mock_get_ident.return_value = 12345
+ self.assertEqual(12345, logging._get_thread_id())
+
+
+
+class ABSLHandlerTest(absltest.TestCase):
+
+ def setUp(self):
+ formatter = logging.PythonFormatter()
+ self.absl_handler = logging.ABSLHandler(formatter)
+
+ def test_activate_python_handler(self):
+ self.absl_handler.activate_python_handler()
+ self.assertEqual(
+ self.absl_handler._current_handler, self.absl_handler.python_handler)
+
+
+class ABSLLoggerTest(absltest.TestCase):
+ """Tests the ABSLLogger class."""
+
+ def set_up_mock_frames(self):
+ """Sets up mock frames for use with the testFindCaller methods."""
+ logging_file = os.path.join('absl', 'logging', '__init__.py')
+
+ # Set up mock frame 0
+ mock_frame_0 = mock.Mock()
+ mock_code_0 = mock.Mock()
+ mock_code_0.co_filename = logging_file
+ mock_code_0.co_name = 'LoggingLog'
+ mock_frame_0.f_code = mock_code_0
+ mock_frame_0.f_lineno = 125
+
+ # Set up mock frame 1
+ mock_frame_1 = mock.Mock()
+ mock_code_1 = mock.Mock()
+ mock_code_1.co_filename = 'myfile.py'
+ mock_code_1.co_name = 'Method1'
+ mock_frame_1.f_code = mock_code_1
+ mock_frame_1.f_lineno = 125
+
+ # Set up mock frame 2
+ mock_frame_2 = mock.Mock()
+ mock_code_2 = mock.Mock()
+ mock_code_2.co_filename = 'myfile.py'
+ mock_code_2.co_name = 'Method2'
+ mock_frame_2.f_code = mock_code_2
+ mock_frame_2.f_lineno = 125
+
+ # Set up mock frame 3
+ mock_frame_3 = mock.Mock()
+ mock_code_3 = mock.Mock()
+ mock_code_3.co_filename = 'myfile.py'
+ mock_code_3.co_name = 'Method3'
+ mock_frame_3.f_code = mock_code_3
+ mock_frame_3.f_lineno = 125
+
+ # Tie them together.
+ mock_frame_3.f_back = None
+ mock_frame_2.f_back = mock_frame_3
+ mock_frame_1.f_back = mock_frame_2
+ mock_frame_0.f_back = mock_frame_1
+
+ mock.patch.object(std_logging, 'currentframe').start()
+ std_logging.currentframe.return_value = mock_frame_0
+
+ def setUp(self):
+ self.message = 'Hello Nurse'
+ self.logger = logging.ABSLLogger('')
+
+ def tearDown(self):
+ mock.patch.stopall()
+
+ def test_constructor_without_level(self):
+ self.logger = logging.ABSLLogger('')
+ self.assertEqual(std_logging.NOTSET, self.logger.getEffectiveLevel())
+
+ def test_constructor_with_level(self):
+ self.logger = logging.ABSLLogger('', std_logging.DEBUG)
+ self.assertEqual(std_logging.DEBUG, self.logger.getEffectiveLevel())
+
+ def test_find_caller_normal(self):
+ self.set_up_mock_frames()
+ expected_name = 'Method1'
+ self.assertEqual(expected_name, self.logger.findCaller()[2])
+
+ def test_find_caller_skip_method1(self):
+ self.set_up_mock_frames()
+ self.logger.register_frame_to_skip('myfile.py', 'Method1')
+ expected_name = 'Method2'
+ self.assertEqual(expected_name, self.logger.findCaller()[2])
+
+ def test_find_caller_skip_method1_and_method3(self):
+ self.set_up_mock_frames()
+ self.logger.register_frame_to_skip('myfile.py', 'Method1')
+ # Skiping Method3 should change nothing since Method2 should be hit.
+ self.logger.register_frame_to_skip('myfile.py', 'Method3')
+ expected_name = 'Method2'
+ self.assertEqual(expected_name, self.logger.findCaller()[2])
+
+ @unittest.skipIf(six.PY2, 'stack_info is only supported in Python 3.')
+ def test_find_caller_stack_info(self):
+ self.set_up_mock_frames()
+ with mock.patch.object(traceback, 'print_stack') as print_stack:
+ self.assertEqual(
+ ('myfile.py', 125, 'Method2', 'Stack (most recent call last):'),
+ self.logger.findCaller(stack_info=True))
+ print_stack.assert_called_once()
+
+ def test_critical(self):
+ with mock.patch.object(self.logger, 'log'):
+ self.logger.critical(self.message)
+ self.logger.log.assert_called_once_with(
+ std_logging.CRITICAL, self.message)
+
+ def test_fatal(self):
+ with mock.patch.object(self.logger, 'log'):
+ self.logger.fatal(self.message)
+ self.logger.log.assert_called_once_with(std_logging.FATAL, self.message)
+
+ def test_error(self):
+ with mock.patch.object(self.logger, 'log'):
+ self.logger.error(self.message)
+ self.logger.log.assert_called_once_with(std_logging.ERROR, self.message)
+
+ def test_warn(self):
+ with mock.patch.object(self.logger, 'log'):
+ self.logger.warn(self.message)
+ self.logger.log.assert_called_once_with(std_logging.WARN, self.message)
+
+ def test_warning(self):
+ with mock.patch.object(self.logger, 'log'):
+ self.logger.warning(self.message)
+ self.logger.log.assert_called_once_with(std_logging.WARNING, self.message)
+
+ def test_info(self):
+ with mock.patch.object(self.logger, 'log'):
+ self.logger.info(self.message)
+ self.logger.log.assert_called_once_with(std_logging.INFO, self.message)
+
+ def test_debug(self):
+ with mock.patch.object(self.logger, 'log'):
+ self.logger.debug(self.message)
+ self.logger.log.assert_called_once_with(std_logging.DEBUG, self.message)
+
+ def test_log_debug_with_python(self):
+ with mock.patch.object(self.logger, 'log'):
+ FLAGS.verbosity = 1
+ self.logger.debug(self.message)
+ self.logger.log.assert_called_once_with(std_logging.DEBUG, self.message)
+
+ def test_log_fatal_with_python(self):
+ with mock.patch.object(self.logger, 'log'):
+ self.logger.fatal(self.message)
+ self.logger.log.assert_called_once_with(std_logging.FATAL, self.message)
+
+ def test_register_frame_to_skip(self):
+ # This is basically just making sure that if I put something in a
+ # list, it actually appears in that list.
+ frame_tuple = ('file', 'method')
+ self.logger.register_frame_to_skip(frame_tuple[0], frame_tuple[1])
+ self.assertIn(frame_tuple, self.logger._frames_to_skip)
+
+ def test_logger_cannot_be_disabled(self):
+ self.logger.disabled = True
+ record = self.logger.makeRecord(
+ 'name', std_logging.INFO, 'fn', 20, 'msg', [], False)
+ with mock.patch.object(self.logger, 'callHandlers') as mock_call_handlers:
+ self.logger.handle(record)
+ mock_call_handlers.assert_called_once()
+
+
+class ABSLLogPrefixTest(parameterized.TestCase):
+
+ def setUp(self):
+ self.record = std_logging.LogRecord(
+ 'name', std_logging.INFO, 'path/to/source.py', 13, 'log message',
+ None, None)
+
+ @parameterized.named_parameters(
+ ('debug', std_logging.DEBUG, 'I'),
+ ('info', std_logging.INFO, 'I'),
+ ('warning', std_logging.WARNING, 'W'),
+ ('error', std_logging.ERROR, 'E'),
+ )
+ def test_default_prefixes(self, levelno, level_prefix):
+ self.record.levelno = levelno
+ self.record.created = 1494293880.378885
+ thread_id = '{: >5}'.format(logging._get_thread_id())
+ # Use UTC so the test passes regardless of the local time zone.
+ with mock.patch.object(time, 'localtime', side_effect=time.gmtime):
+ self.assertEqual(
+ '{}0509 01:38:00.378885 {} source.py:13] '.format(
+ level_prefix, thread_id),
+ logging.get_absl_log_prefix(self.record))
+ time.localtime.assert_called_once_with(self.record.created)
+
+ def test_critical_absl(self):
+ self.record.levelno = std_logging.CRITICAL
+ self.record.created = 1494293880.378885
+ self.record._absl_log_fatal = True
+ thread_id = '{: >5}'.format(logging._get_thread_id())
+ # Use UTC so the test passes regardless of the local time zone.
+ with mock.patch.object(time, 'localtime', side_effect=time.gmtime):
+ self.assertEqual(
+ 'F0509 01:38:00.378885 {} source.py:13] '.format(thread_id),
+ logging.get_absl_log_prefix(self.record))
+ time.localtime.assert_called_once_with(self.record.created)
+
+ def test_critical_non_absl(self):
+ self.record.levelno = std_logging.CRITICAL
+ self.record.created = 1494293880.378885
+ thread_id = '{: >5}'.format(logging._get_thread_id())
+ # Use UTC so the test passes regardless of the local time zone.
+ with mock.patch.object(time, 'localtime', side_effect=time.gmtime):
+ self.assertEqual(
+ 'E0509 01:38:00.378885 {} source.py:13] CRITICAL - '.format(
+ thread_id),
+ logging.get_absl_log_prefix(self.record))
+ time.localtime.assert_called_once_with(self.record.created)
+
+
+class LogCountTest(absltest.TestCase):
+
+ def test_counter_threadsafe(self):
+ threads_start = threading.Event()
+ counts = set()
+ k = object()
+
+ def t():
+ threads_start.wait()
+ counts.add(logging._get_next_log_count_per_token(k))
+
+ threads = [threading.Thread(target=t) for _ in range(100)]
+ for thread in threads:
+ thread.start()
+ threads_start.set()
+ for thread in threads:
+ thread.join()
+ self.assertEqual(counts, {i for i in range(100)})
+
+
+class LoggingTest(absltest.TestCase):
+
+ def test_fatal(self):
+ with mock.patch.object(os, 'abort') as mock_abort:
+ logging.fatal('Die!')
+ mock_abort.assert_called_once()
+
+ def test_find_log_dir_with_arg(self):
+ with mock.patch.object(os, 'access'), \
+ mock.patch.object(os.path, 'isdir'):
+ os.path.isdir.return_value = True
+ os.access.return_value = True
+ log_dir = logging.find_log_dir(log_dir='./')
+ self.assertEqual('./', log_dir)
+
+ @flagsaver.flagsaver(log_dir='./')
+ def test_find_log_dir_with_flag(self):
+ with mock.patch.object(os, 'access'), \
+ mock.patch.object(os.path, 'isdir'):
+ os.path.isdir.return_value = True
+ os.access.return_value = True
+ log_dir = logging.find_log_dir()
+ self.assertEqual('./', log_dir)
+
+ @flagsaver.flagsaver(log_dir='')
+ def test_find_log_dir_with_hda_tmp(self):
+ with mock.patch.object(os, 'access'), \
+ mock.patch.object(os.path, 'exists'), \
+ mock.patch.object(os.path, 'isdir'):
+ os.path.exists.return_value = True
+ os.path.isdir.return_value = True
+ os.access.return_value = True
+ log_dir = logging.find_log_dir()
+ self.assertEqual('/tmp/', log_dir)
+
+ @flagsaver.flagsaver(log_dir='')
+ def test_find_log_dir_with_tmp(self):
+ with mock.patch.object(os, 'access'), \
+ mock.patch.object(os.path, 'exists'), \
+ mock.patch.object(os.path, 'isdir'):
+ os.path.exists.return_value = False
+ os.path.isdir.side_effect = lambda path: path == '/tmp/'
+ os.access.return_value = True
+ log_dir = logging.find_log_dir()
+ self.assertEqual('/tmp/', log_dir)
+
+ def test_find_log_dir_with_nothing(self):
+ with mock.patch.object(os.path, 'exists'), \
+ mock.patch.object(os.path, 'isdir'), \
+ mock.patch.object(logging.get_absl_logger(), 'fatal') as mock_fatal:
+ os.path.exists.return_value = False
+ os.path.isdir.return_value = False
+ log_dir = logging.find_log_dir()
+ mock_fatal.assert_called()
+ self.assertEqual(None, log_dir)
+
+ def test_find_log_dir_and_names_with_args(self):
+ user = 'test_user'
+ host = 'test_host'
+ log_dir = 'here'
+ program_name = 'prog1'
+ with mock.patch.object(getpass, 'getuser'), \
+ mock.patch.object(logging, 'find_log_dir') as mock_find_log_dir, \
+ mock.patch.object(socket, 'gethostname') as mock_gethostname:
+ getpass.getuser.return_value = user
+ mock_gethostname.return_value = host
+ mock_find_log_dir.return_value = log_dir
+
+ prefix = '%s.%s.%s.log' % (program_name, host, user)
+ self.assertEqual((log_dir, prefix, program_name),
+ logging.find_log_dir_and_names(
+ program_name=program_name, log_dir=log_dir))
+
+ def test_find_log_dir_and_names_without_args(self):
+ user = 'test_user'
+ host = 'test_host'
+ log_dir = 'here'
+ py_program_name = 'py_prog1'
+ sys.argv[0] = 'path/to/prog1'
+ with mock.patch.object(getpass, 'getuser'), \
+ mock.patch.object(logging, 'find_log_dir') as mock_find_log_dir, \
+ mock.patch.object(socket, 'gethostname'):
+ getpass.getuser.return_value = user
+ socket.gethostname.return_value = host
+ mock_find_log_dir.return_value = log_dir
+ prefix = '%s.%s.%s.log' % (py_program_name, host, user)
+ self.assertEqual((log_dir, prefix, py_program_name),
+ logging.find_log_dir_and_names())
+
+ def test_errors_in_logging(self):
+ with mock.patch.object(sys, 'stderr', new=_StreamIO()) as stderr:
+ logging.info('not enough args: %s %s', 'foo') # pylint: disable=logging-too-few-args
+ self.assertIn('Traceback (most recent call last):', stderr.getvalue())
+ self.assertIn('TypeError', stderr.getvalue())
+
+ def test_dict_arg(self):
+ # Tests that passing a dictionary as a single argument does not crash.
+ logging.info('%(test)s', {'test': 'Hello world!'})
+
+ def test_exception_dict_format(self):
+ # Just verify that this doesn't raise a TypeError.
+ logging.exception('%(test)s', {'test': 'Hello world!'})
+
+ def test_logging_levels(self):
+ old_level = logging.get_verbosity()
+
+ logging.set_verbosity(logging.DEBUG)
+ self.assert_(logging.get_verbosity() == logging.DEBUG)
+ self.assert_(logging.level_debug())
+ self.assert_(logging.level_info())
+ self.assert_(logging.level_warn())
+ self.assert_(logging.level_error())
+
+ logging.set_verbosity(logging.INFO)
+ self.assert_(logging.get_verbosity() == logging.INFO)
+ self.assert_(not logging.level_debug())
+ self.assert_(logging.level_info())
+ self.assert_(logging.level_warn())
+ self.assert_(logging.level_error())
+
+ logging.set_verbosity(logging.WARN)
+ self.assert_(logging.get_verbosity() == logging.WARN)
+ self.assert_(not logging.level_debug())
+ self.assert_(not logging.level_info())
+ self.assert_(logging.level_warn())
+ self.assert_(logging.level_error())
+
+ logging.set_verbosity(logging.ERROR)
+ self.assert_(logging.get_verbosity() == logging.ERROR)
+ self.assert_(not logging.level_debug())
+ self.assert_(not logging.level_info())
+ self.assert_(not logging.level_warn())
+ self.assert_(logging.level_error())
+
+ logging.set_verbosity(old_level)
+
+ def test_set_verbosity_strings(self):
+ old_level = logging.get_verbosity()
+
+ # Lowercase names.
+ logging.set_verbosity('debug')
+ self.assert_(logging.get_verbosity() == logging.DEBUG)
+ logging.set_verbosity('info')
+ self.assert_(logging.get_verbosity() == logging.INFO)
+ logging.set_verbosity('warn')
+ self.assert_(logging.get_verbosity() == logging.WARN)
+ logging.set_verbosity('error')
+ self.assert_(logging.get_verbosity() == logging.ERROR)
+ logging.set_verbosity('fatal')
+
+ # Uppercase names.
+ self.assert_(logging.get_verbosity() == logging.FATAL)
+ logging.set_verbosity('DEBUG')
+ self.assert_(logging.get_verbosity() == logging.DEBUG)
+ logging.set_verbosity('INFO')
+ self.assert_(logging.get_verbosity() == logging.INFO)
+ logging.set_verbosity('WARN')
+ self.assert_(logging.get_verbosity() == logging.WARN)
+ logging.set_verbosity('ERROR')
+ self.assert_(logging.get_verbosity() == logging.ERROR)
+ logging.set_verbosity('FATAL')
+ self.assert_(logging.get_verbosity() == logging.FATAL)
+
+ # Integers as strings.
+ logging.set_verbosity(str(logging.DEBUG))
+ self.assert_(logging.get_verbosity() == logging.DEBUG)
+ logging.set_verbosity(str(logging.INFO))
+ self.assert_(logging.get_verbosity() == logging.INFO)
+ logging.set_verbosity(str(logging.WARN))
+ self.assert_(logging.get_verbosity() == logging.WARN)
+ logging.set_verbosity(str(logging.ERROR))
+ self.assert_(logging.get_verbosity() == logging.ERROR)
+ logging.set_verbosity(str(logging.FATAL))
+ self.assert_(logging.get_verbosity() == logging.FATAL)
+
+ logging.set_verbosity(old_level)
+
+ def test_key_flags(self):
+ key_flags = FLAGS.get_key_flags_for_module(logging)
+ key_flag_names = [flag.name for flag in key_flags]
+ self.assertIn('stderrthreshold', key_flag_names)
+ self.assertIn('verbosity', key_flag_names)
+
+ def test_get_absl_logger(self):
+ self.assertIsInstance(
+ logging.get_absl_logger(), logging.ABSLLogger)
+
+ def test_get_absl_handler(self):
+ self.assertIsInstance(
+ logging.get_absl_handler(), logging.ABSLHandler)
+
+
+if __name__ == '__main__':
+ absltest.main()
diff --git a/absl/logging/tests/verbosity_flag_test.py b/absl/logging/tests/verbosity_flag_test.py
new file mode 100644
index 0000000..66436d2
--- /dev/null
+++ b/absl/logging/tests/verbosity_flag_test.py
@@ -0,0 +1,58 @@
+# Copyright 2017 The Abseil Authors.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+"""Tests -v/--verbosity flag and logging.root level's sync behavior."""
+
+from __future__ import absolute_import
+from __future__ import division
+from __future__ import print_function
+
+import logging
+
+assert logging.root.getEffectiveLevel() == logging.WARN, (
+ 'default logging.root level should be WARN, but found {}'.format(
+ logging.root.getEffectiveLevel()))
+
+# This is here to test importing logging won't change the level.
+logging.root.setLevel(logging.ERROR)
+
+assert logging.root.getEffectiveLevel() == logging.ERROR, (
+ 'logging.root level should be changed to ERROR, but found {}'.format(
+ logging.root.getEffectiveLevel()))
+
+
+from absl import flags
+from absl import logging as _ # pylint: disable=unused-import
+from absl.testing import absltest
+
+
+FLAGS = flags.FLAGS
+
+assert FLAGS['verbosity'].value == -1, (
+ '-v/--verbosity should be -1 before flags are parsed.')
+
+assert logging.root.getEffectiveLevel() == logging.ERROR, (
+ 'logging.root level should be kept to ERROR, but found {}'.format(
+ logging.root.getEffectiveLevel()))
+
+
+class VerbosityFlagTest(absltest.TestCase):
+
+ def test_default_value_after_init(self):
+ self.assertEqual(0, FLAGS.verbosity)
+ self.assertEqual(logging.INFO, logging.root.getEffectiveLevel())
+
+
+if __name__ == '__main__':
+ absltest.main()