fix command-line LLDB so NSLog messages show up

Changes to the underlying logging infrastructure in Fall 2016 Darwin
OSes were no longer showing up NSLog messages in command-line LLDB.
This change restores that functionality, and adds test cases to
verify the new behavior.

rdar://26732492

llvm-svn: 275472

4 files changed, 304 insertions, 0 deletions

diff --git a/lldb/packages/Python/lldbsuite/test/macosx/nslog/Makefile b/lldb/packages/Python/lldbsuite/test/macosx/nslog/Makefile
new file mode 100644
index 00000000000..de2b618b3d7
--- /dev/null
+++ b/lldb/packages/Python/lldbsuite/test/macosx/nslog/Makefile
@@ -0,0 +1,6 @@
+LEVEL = ../../make
+
+OBJC_SOURCES := main.m
+LD_EXTRAS = -framework Foundation
+
+include $(LEVEL)/Makefile.rules
diff --git a/lldb/packages/Python/lldbsuite/test/macosx/nslog/TestDarwinNSLogOutput.py b/lldb/packages/Python/lldbsuite/test/macosx/nslog/TestDarwinNSLogOutput.py
new file mode 100644
index 00000000000..8d0b7e10311
--- /dev/null
+++ b/lldb/packages/Python/lldbsuite/test/macosx/nslog/TestDarwinNSLogOutput.py
@@ -0,0 +1,141 @@
+"""
+Test DarwinLog "source include debug-level" functionality provided by the
+StructuredDataDarwinLog plugin.
+
+These tests are currently only supported when running against Darwin
+targets.
+"""
+
+from __future__ import print_function
+
+import lldb
+import os
+import pexpect
+import re
+import sys
+
+from lldbsuite.test import decorators
+from lldbsuite.test import lldbtest
+from lldbsuite.test import lldbtest_config
+
+@decorators.skipUnlessDarwin
+class DarwinNSLogOutputTestCase(lldbtest.TestBase):
+    NO_DEBUG_INFO_TESTCASE = True
+
+    mydir = lldbtest.TestBase.compute_mydir(__file__)
+
+    def setUp(self):
+        # Call super's setUp().
+        super(DarwinNSLogOutputTestCase, self).setUp()
+        self.child = None
+        self.child_prompt = '(lldb) '
+        self.strict_sources = False
+
+        # Source filename.
+        self.source = 'main.m'
+
+        # Output filename.
+        self.exe_name = 'a.out'
+        self.d = {'OBJC_SOURCES': self.source, 'EXE': self.exe_name}
+
+        # Locate breakpoint.
+        self.line = lldbtest.line_number(self.source, '// break here')
+
+    def tearDown(self):
+        # Shut down the process if it's still running.
+        if self.child:
+            self.runCmd('process kill')
+            self.expect_prompt()
+            self.runCmd('quit')
+
+        # Let parent clean up
+        super(DarwinNSLogOutputTestCase, self).tearDown()
+
+    def run_lldb_to_breakpoint(self, exe, source_file, line,
+                               settings_commands=None):
+        # Set self.child_prompt, which is "(lldb) ".
+        prompt = self.child_prompt
+
+        # So that the child gets torn down after the test.
+        self.child = pexpect.spawn('%s %s %s' % (lldbtest_config.lldbExec,
+                                                 self.lldbOption, exe))
+        child = self.child
+
+        # Turn on logging for what the child sends back.
+        if self.TraceOn():
+            child.logfile_read = sys.stdout
+
+        # Disable showing of source lines at our breakpoint.
+        # This is necessary for the logging tests, because the very
+        # text we want to match for output from the running inferior
+        # will show up in the source as well.  We don't want the source
+        # output to erroneously make a match with our expected output.
+        self.runCmd("settings set stop-line-count-before 0")
+        self.expect_prompt()
+        self.runCmd("settings set stop-line-count-after 0")
+        self.expect_prompt()
+
+        # Run any test-specific settings commands now.
+        if settings_commands is not None:
+            for setting_command in settings_commands:
+                self.runCmd(setting_command)
+                self.expect_prompt()
+
+        # Set the breakpoint, and run to it.
+        child.sendline('breakpoint set -f %s -l %d' % (source_file, line))
+        child.expect_exact(prompt)
+        child.sendline('run')
+        child.expect_exact(prompt)
+
+        # Ensure we stopped at a breakpoint.
+        self.runCmd("thread list")
+        self.expect(re.compile(r"stop reason = breakpoint"))
+
+    def runCmd(self, cmd):
+        self.child.sendline(cmd)
+
+    def expect_prompt(self, exactly=True):
+        self.expect(self.child_prompt, exactly=exactly)
+
+    def expect(self, pattern, exactly=False, *args, **kwargs):
+        if exactly:
+            return self.child.expect_exact(pattern, *args, **kwargs)
+        return self.child.expect(pattern, *args, **kwargs)
+
+    def do_test(self, expect_regexes=None, settings_commands=None):
+        """ Run a test. """
+        self.build(dictionary=self.d)
+        self.setTearDownCleanup(dictionary=self.d)
+
+        exe = os.path.join(os.getcwd(), self.exe_name)
+        self.run_lldb_to_breakpoint(exe, self.source, self.line,
+                                    settings_commands=settings_commands)
+        self.expect_prompt()
+
+        # Now go.
+        self.runCmd("process continue")
+        self.expect(expect_regexes)
+
+    def test_nslog_output_is_displayed(self):
+        """Test that NSLog() output shows up in the command-line debugger."""
+        self.do_test(expect_regexes=[
+            re.compile(r"(This is a message from NSLog)"),
+            re.compile(r"Process \d+ exited with status")
+        ])
+        self.assertIsNotNone(self.child.match)
+        self.assertGreater(len(self.child.match.groups()), 0)
+        self.assertEqual("This is a message from NSLog", self.child.match.group(1))
+
+    def test_nslog_output_is_suppressed_with_env_var(self):
+        """Test that NSLog() output does not show up with the ignore env var."""
+        self.do_test(
+            expect_regexes=[
+                re.compile(r"(This is a message from NSLog)"),
+                re.compile(r"Process \d+ exited with status")
+            ],
+            settings_commands=[
+                "settings set target.env-vars "
+                "\"IDE_DISABLED_OS_ACTIVITY_DT_MODE=1\""
+            ])
+        self.assertIsNotNone(self.child.match)
+        self.assertEqual(len(self.child.match.groups()), 0)
diff --git a/lldb/packages/Python/lldbsuite/test/macosx/nslog/darwin_log.py b/lldb/packages/Python/lldbsuite/test/macosx/nslog/darwin_log.py
new file mode 100644
index 00000000000..0689813f2c6
--- /dev/null
+++ b/lldb/packages/Python/lldbsuite/test/macosx/nslog/darwin_log.py
@@ -0,0 +1,139 @@
+"""
+Base class for DarwinLog tests.
+"""
+
+from __future__ import print_function
+
+import lldb
+import os
+import pexpect
+import re
+import sys
+
+from lldbsuite.test import decorators
+from lldbsuite.test import lldbtest
+from lldbsuite.test import lldbtest_config
+from lldbsuite.test import lldbutil
+
+
+class DarwinLogTestBase(lldbtest.TestBase):
+    NO_DEBUG_INFO_TESTCASE = True
+
+    def setUp(self):
+        # Call super's setUp().
+        super(DarwinLogTestBase, self).setUp()
+        self.child = None
+        self.child_prompt = '(lldb) '
+        self.strict_sources = False
+
+    def run_lldb_to_breakpoint(self, exe, source_file, line,
+                               settings_commands=None):
+        # Set self.child_prompt, which is "(lldb) ".
+        prompt = self.child_prompt
+
+        # So that the child gets torn down after the test.
+        self.child = pexpect.spawn('%s %s %s' % (lldbtest_config.lldbExec,
+                                                 self.lldbOption, exe))
+        child = self.child
+
+        # Turn on logging for what the child sends back.
+        if self.TraceOn():
+            child.logfile_read = sys.stdout
+
+        # Disable showing of source lines at our breakpoint.
+        # This is necessary for the logging tests, because the very
+        # text we want to match for output from the running inferior
+        # will show up in the source as well.  We don't want the source
+        # output to erroneously make a match with our expected output.
+        self.runCmd("settings set stop-line-count-before 0")
+        self.expect_prompt()
+        self.runCmd("settings set stop-line-count-after 0")
+        self.expect_prompt()
+
+        # This setting is required to be set to true in order to get LLDB to set
+        # the environment variable required by libtrace to have it respect our
+        # 'plugin structured-data darwin-log source enable/disable' settings.
+        # Without that, libtrace assumes we want all types of messages when
+        # attaching with a debugger.
+        setting = "strict-sources " + "true" if self.strict_sources else "false"
+        self.runCmd(self.expand_darwinlog_settings_set_command(setting))
+        self.expect_prompt()
+
+        # Run any darwin-log settings commands now, before we enable logging.
+        if settings_commands is not None:
+            for setting_command in settings_commands:
+                self.runCmd(
+                    self.expand_darwinlog_settings_set_command(setting_command))
+                self.expect_prompt()
+
+        # child.expect_exact(prompt)
+        child.sendline('breakpoint set -f %s -l %d' % (source_file, line))
+        child.expect_exact(prompt)
+        child.sendline('run')
+        child.expect_exact(prompt)
+
+        # Ensure we stopped at a breakpoint.
+        self.runCmd("thread list")
+        self.expect(re.compile(r"stop reason = breakpoint"))
+
+        # Now we're ready to check if DarwinLog is available.
+        if not self.darwin_log_available():
+            self.skip("DarwinLog not available")
+
+    def runCmd(self, cmd):
+        self.child.sendline(cmd)
+
+    def expect_prompt(self, exactly=True):
+        self.expect(self.child_prompt, exactly=exactly)
+
+    def expect(self, pattern, exactly=False, *args, **kwargs):
+        if exactly:
+            return self.child.expect_exact(pattern, *args, **kwargs)
+        return self.child.expect(pattern, *args, **kwargs)
+
+    def darwin_log_available(self):
+        self.runCmd("plugin structured-data darwin-log status")
+        self.expect(re.compile(r"Availability: ([\S]+)"))
+        return self.child.match is not None and (
+            self.child.match.group(1) == "available")
+
+    @classmethod
+    def expand_darwinlog_command(cls, command):
+        return "plugin structured-data darwin-log " + command
+
+    @classmethod
+    def expand_darwinlog_settings_set_command(cls, command):
+        return "settings set plugin.structured-data.darwin-log." + command
+
+    def do_test(self, logging_setup_commands, expect_regexes=None,
+                settings_commands=None):
+        """Test that a single fall-through reject rule rejects all logging."""
+        self.build(dictionary=self.d)
+        self.setTearDownCleanup(dictionary=self.d)
+
+        exe = os.path.join(os.getcwd(), self.exe_name)
+        self.run_lldb_to_breakpoint(exe, self.source, self.line,
+                                    settings_commands=settings_commands)
+        self.expect_prompt()
+
+        # Run each of the logging setup commands.
+        for setup_command in logging_setup_commands:
+            self.runCmd(self.expand_darwinlog_command(setup_command))
+            self.expect_prompt()
+
+        # Enable logging.
+        self.runCmd(self.expand_darwinlog_command("enable"))
+        self.expect_prompt()
+
+        # Now go.
+        self.runCmd("process continue")
+
+        if expect_regexes is None:
+            # Expect matching a log line or program exit.
+            # Test methods determine which ones are valid.
+            expect_regexes = (
+                [re.compile(r"source-log-([^-]+)-(\S+)"),
+                 re.compile(r"exited with status")
+                ])
+        self.expect(expect_regexes)
+
diff --git a/lldb/packages/Python/lldbsuite/test/macosx/nslog/main.m b/lldb/packages/Python/lldbsuite/test/macosx/nslog/main.m
new file mode 100644
index 00000000000..dab4089e927
--- /dev/null
+++ b/lldb/packages/Python/lldbsuite/test/macosx/nslog/main.m
@@ -0,0 +1,18 @@
+//===-- main.m --------------------------------------------------*- C++ -*-===//
+//
+//                     The LLVM Compiler Infrastructure
+//
+// This file is distributed under the University of Illinois Open Source
+// License. See LICENSE.TXT for details.
+//
+//===----------------------------------------------------------------------===//
+
+#include <Foundation/Foundation.h>
+
+int main(int argc, char** argv)
+{
+    printf("About to log\n"); // break here
+    NSLog(@"This is a message from NSLog");
+
+    return 0;
+}