Big refactor of debug logging

1 files changed, 30 insertions, 20 deletions

diff --git a/tests/test_debug.py b/tests/test_debug.py
index b019915..6a33479 100644
--- a/tests/test_debug.py
+++ b/tests/test_debug.py
@@ -4,15 +4,15 @@
 """Tests of coverage/debug.py"""
 
 import os
-import re
 
 import pytest
 
 import coverage
 from coverage.backward import StringIO
-from coverage.debug import info_formatter, info_header, short_id, short_stack
+from coverage.debug import filter_text, info_formatter, info_header, short_id, short_stack
 
 from tests.coveragetest import CoverageTest
+from tests.helpers import re_lines
 
 
 class InfoFormatterTest(CoverageTest):
@@ -60,6 +60,17 @@ def test_short_id(id64, id16):
     assert short_id(id64) == id16
 
 
+@pytest.mark.parametrize("text, filters, result", [
+    ("hello", [], "hello"),
+    ("hello\n", [], "hello\n"),
+    ("hello\nhello\n", [], "hello\nhello\n"),
+    ("hello\nbye\n", [lambda x: "="+x], "=hello\n=bye\n"),
+    ("hello\nbye\n", [lambda x: "="+x, lambda x: x+"\ndone\n"], "=hello\ndone\n=bye\ndone\n"),
+])
+def test_filter_text(text, filters, result):
+    assert filter_text(text, filters) == result
+
+
 class DebugTraceTest(CoverageTest):
     """Tests of debug output."""
 
@@ -80,7 +91,7 @@ class DebugTraceTest(CoverageTest):
         self.start_import_stop(cov, "f1")
         cov.save()
 
-        out_lines = debug_out.getvalue().splitlines()
+        out_lines = debug_out.getvalue()
         return out_lines
 
     def test_debug_no_trace(self):
@@ -96,7 +107,7 @@ class DebugTraceTest(CoverageTest):
         self.assertIn("Tracing 'f1.py'", out_lines)
 
         # We should have lines like "Not tracing 'collector.py'..."
-        coverage_lines = lines_matching(
+        coverage_lines = re_lines(
             out_lines,
             r"^Not tracing .*: is part of coverage.py$"
             )
@@ -106,28 +117,29 @@ class DebugTraceTest(CoverageTest):
         out_lines = self.f1_debug_output(["trace", "pid"])
 
         # Now our lines are always prefixed with the process id.
-        pid_prefix = "^pid %5d: " % os.getpid()
-        pid_lines = lines_matching(out_lines, pid_prefix)
+        pid_prefix = r"^%5d\.[0-9a-f]{4}: " % os.getpid()
+        pid_lines = re_lines(out_lines, pid_prefix)
         self.assertEqual(pid_lines, out_lines)
 
         # We still have some tracing, and some not tracing.
-        self.assertTrue(lines_matching(out_lines, pid_prefix + "Tracing "))
-        self.assertTrue(lines_matching(out_lines, pid_prefix + "Not tracing "))
+        self.assertTrue(re_lines(out_lines, pid_prefix + "Tracing "))
+        self.assertTrue(re_lines(out_lines, pid_prefix + "Not tracing "))
 
     def test_debug_callers(self):
         out_lines = self.f1_debug_output(["pid", "dataop", "dataio", "callers"])
-        print("\n".join(out_lines))
+        print(out_lines)
         # For every real message, there should be a stack
         # trace with a line like "f1_debug_output : /Users/ned/coverage/tests/test_debug.py @71"
-        real_messages = lines_matching(out_lines, r"^pid\s+\d+: ")
+        real_messages = re_lines(out_lines, r" @\d+", match=False).splitlines()
         frame_pattern = r"\s+f1_debug_output : .*tests[/\\]test_debug.py @\d+$"
-        frames = lines_matching(out_lines, frame_pattern)
+        frames = re_lines(out_lines, frame_pattern).splitlines()
         self.assertEqual(len(real_messages), len(frames))
 
         # The last message should be "Writing data", and the last frame should
         # be write_file in data.py.
-        self.assertRegex(real_messages[-1], r"^pid\s+\d+: Writing data")
-        self.assertRegex(out_lines[-1], r"\s+write_file : .*coverage[/\\]data.py @\d+$")
+        self.assertRegex(real_messages[-1], r"^\d+\.\w{4}: Writing data")
+        last_line = out_lines.splitlines()[-1]
+        self.assertRegex(last_line, r"\s+write_file : .*coverage[/\\]data.py @\d+$")
 
     def test_debug_config(self):
         out_lines = self.f1_debug_output(["config"])
@@ -140,7 +152,10 @@ class DebugTraceTest(CoverageTest):
             """.split()
         for label in labels:
             label_pat = r"^\s*%s: " % label
-            self.assertEqual(len(lines_matching(out_lines, label_pat)), 1)
+            self.assertEqual(
+                len(re_lines(out_lines, label_pat).splitlines()),
+                1
+            )
 
     def test_debug_sys(self):
         out_lines = self.f1_debug_output(["sys"])
@@ -153,7 +168,7 @@ class DebugTraceTest(CoverageTest):
         for label in labels:
             label_pat = r"^\s*%s: " % label
             self.assertEqual(
-                len(lines_matching(out_lines, label_pat)),
+                len(re_lines(out_lines, label_pat).splitlines()),
                 1,
                 msg="Incorrect lines for %r" % label,
             )
@@ -191,8 +206,3 @@ class ShortStackTest(CoverageTest):
     def test_short_stack_skip(self):
         stack = f_one(skip=1).splitlines()
         self.assertIn("f_two", stack[-1])
-
-
-def lines_matching(lines, pat):
-    """Gives the list of lines from `lines` that match `pat`."""
-    return [l for l in lines if re.search(pat, l)]