enhance debug tracing: print trace tags at the end of message and forget about "prefix".

Always log to "pytestdebug.log" if "--debug" option is given.
also move related code to pytest_helpconfig plugin.

_pytest/config.py

@@ -8,8 +8,6 @@ import pytest
 def pytest_cmdline_parse(pluginmanager, args):
     config = Config(pluginmanager)
     config.parse(args)
-    if config.option.debug:
-        config.trace.root.setwriter(sys.stderr.write)
     return config
 
 def pytest_unconfigure(config):
@@ -334,6 +332,7 @@ class Config(object):
         # Note that this can only be called once per testing process.
         assert not hasattr(self, 'args'), (
                 "can only parse cmdline args at most once per Config object")
+        self._origargs = args
         self._preparse(args)
         self._parser.hints.extend(self.pluginmanager._hints)
         args = self._parser.parse_setoption(args, self.option)

_pytest/core.py

@@ -16,11 +16,10 @@ default_plugins = (
  "junitxml resultlog doctest").split()
 
 class TagTracer:
-    def __init__(self, prefix="[pytest] "):
+    def __init__(self):
         self._tag2proc = {}
         self.writer = None
         self.indent = 0
-        self.prefix = prefix
 
     def get(self, name):
         return TagTracerSub(self, (name,))
@@ -30,7 +29,7 @@ class TagTracer:
             if args:
                 indent = "  " * self.indent
                 content = " ".join(map(str, args))
-                self.writer("%s%s%s\n" %(self.prefix, indent, content))
+                self.writer("%s%s [%s]\n" %(indent, content, ":".join(tags)))
         try:
             self._tag2proc[tags](tags, args)
         except KeyError:

_pytest/helpconfig.py

@@ -1,7 +1,7 @@
 """ version info, help messages, tracing configuration.  """
 import py
 import pytest
-import inspect, sys
+import os, inspect, sys
 from _pytest.core import varnames
 
 def pytest_addoption(parser):
@@ -18,7 +18,29 @@ def pytest_addoption(parser):
                help="trace considerations of conftest.py files."),
     group.addoption('--debug',
                action="store_true", dest="debug", default=False,
-               help="generate and show internal debugging information.")
+               help="store internal tracing debug information in 'pytestdebug.log'.")
+
+
+def pytest_cmdline_parse(__multicall__):
+    config = __multicall__.execute()
+    if config.option.debug:
+        path = os.path.abspath("pytestdebug.log")
+        f = open(path, 'w')
+        config._debugfile = f
+        f.write("versions pytest-%s, py-%s, python-%s\ncwd=%s\nargs=%s\n\n" %(
+            pytest.__version__, py.__version__, ".".join(map(str, sys.version_info)),
+            os.getcwd(), config._origargs))
+        config.trace.root.setwriter(f.write)
+        sys.stderr.write("writing pytestdebug information to %s\n" % path)
+    return config
+
+@pytest.mark.trylast
+def pytest_unconfigure(config):
+    if hasattr(config, '_debugfile'):
+        config._debugfile.close()
+        sys.stderr.write("wrote pytestdebug information to %s\n" %
+            config._debugfile.name)
+        config.trace.root.setwriter(None)
 
 
 def pytest_cmdline_main(config):

testing/test_config.py

@@ -88,7 +88,7 @@ class TestConfigAPI:
         config.trace.root.setwriter(l.append)
         config.trace("hello")
         assert len(l) == 1
-        assert l[0] == "[pytest] hello\n"
+        assert l[0] == "hello [config]\n"
 
     def test_config_getvalue_honours_conftest(self, testdir):
         testdir.makepyfile(conftest="x=1")

testing/test_core.py

@@ -586,17 +586,17 @@ class TestHookRelay:
 class TestTracer:
     def test_simple(self):
         from _pytest.core import TagTracer
-        rootlogger = TagTracer("[my] ")
+        rootlogger = TagTracer()
         log = rootlogger.get("pytest")
         log("hello")
         l = []
         rootlogger.setwriter(l.append)
         log("world")
         assert len(l) == 1
-        assert l[0] == "[my] world\n"
+        assert l[0] == "world [pytest]\n"
         sublog = log.get("collection")
         sublog("hello")
-        assert l[1] == "[my] hello\n"
+        assert l[1] == "hello [pytest:collection]\n"
 
     def test_indent(self):
         from _pytest.core import TagTracer
@@ -616,7 +616,7 @@ class TestTracer:
         log.root.indent -= 1
         log("last")
         assert len(l) == 7
-        names = [x.rstrip()[len(rootlogger.prefix):] for x in l]
+        names = [x[:x.rfind(' [')] for x in l]
         assert names == ['hello', '  line1', '  line2',
                      '    line3', '    line4', '  line5', 'last']
 

testing/test_helpconfig.py

@@ -62,3 +62,17 @@ def test_traceconfig(testdir):
         "*using*pytest*py*",
         "*active plugins*",
     ])
+
+def test_debug(testdir, monkeypatch):
+    result = testdir.runpytest("--debug")
+    assert result.ret == 0
+    p = testdir.tmpdir.join("pytestdebug.log")
+    assert "pytest_sessionstart" in p.read()
+
+def test_PYTEST_DEBUG(testdir, monkeypatch):
+    monkeypatch.setenv("PYTEST_DEBUG", "1")
+    result = testdir.runpytest()
+    assert result.ret == 0
+    result.stderr.fnmatch_lines([
+        "*registered*PluginManager*"
+    ])

testing/test_terminal.py

@@ -524,21 +524,6 @@ def test_traceconfig(testdir, monkeypatch):
     ])
     assert result.ret == 0
 
-def test_debug(testdir, monkeypatch):
-    result = testdir.runpytest("--debug")
-    result.stderr.fnmatch_lines([
-        "*pytest_sessionstart*session*",
-    ])
-    assert result.ret == 0
-
-def test_PYTEST_DEBUG(testdir, monkeypatch):
-    monkeypatch.setenv("PYTEST_DEBUG", "1")
-    result = testdir.runpytest()
-    assert result.ret == 0
-    result.stderr.fnmatch_lines([
-        "*registered*PluginManager*"
-    ])
-
 
 class TestGenericReporting:
     """ this test class can be subclassed with a different option