Author: tfiala Date: Thu Jul 14 16:02:45 2016 New Revision: 275472 URL: http://llvm.org/viewvc/llvm-project?rev=275472&view=rev Log: 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 Added: lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/ lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/Makefile lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/TestDarwinNSLogOutput.py lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/darwin_log.py lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/main.m Modified: lldb/trunk/include/lldb/Interpreter/Args.h lldb/trunk/source/Interpreter/Args.cpp lldb/trunk/source/Plugins/Platform/MacOSX/PlatformDarwin.cpp lldb/trunk/source/Plugins/Platform/MacOSX/PlatformDarwin.h Modified: lldb/trunk/include/lldb/Interpreter/Args.h URL: http://llvm.org/viewvc/llvm-project/lldb/trunk/include/lldb/Interpreter/Args.h?rev=275472&r1=275471&r2=275472&view=diff ============================================================================== --- lldb/trunk/include/lldb/Interpreter/Args.h (original) +++ lldb/trunk/include/lldb/Interpreter/Args.h Thu Jul 14 16:02:45 2016 @@ -438,6 +438,23 @@ public: void LongestCommonPrefix (std::string &common_prefix); + //------------------------------------------------------------------ + /// Return whether a given environment variable exists. + /// + /// This command treats Args like a list of environment variables, + /// as used in ProcessLaunchInfo. It treats each argument as + /// an {env_var_name}={value} or an {env_var_name} entry. + /// + /// @param[in] env_var_name + /// Specifies the name of the environment variable to check. + /// + /// @return + /// true if the specified env var name exists in the list in + /// either of the above-mentioned formats; otherwise, false. + //------------------------------------------------------------------ + bool + ContainsEnvironmentVariable(const char *env_var_name) const; + protected: //------------------------------------------------------------------ // Classes that inherit from Args can see and modify these Added: lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/Makefile URL: http://llvm.org/viewvc/llvm-project/lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/Makefile?rev=275472&view=auto ============================================================================== --- lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/Makefile (added) +++ lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/Makefile Thu Jul 14 16:02:45 2016 @@ -0,0 +1,6 @@ +LEVEL = ../../make + +OBJC_SOURCES := main.m +LD_EXTRAS = -framework Foundation + +include $(LEVEL)/Makefile.rules Added: lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/TestDarwinNSLogOutput.py URL: http://llvm.org/viewvc/llvm-project/lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/TestDarwinNSLogOutput.py?rev=275472&view=auto ============================================================================== --- lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/TestDarwinNSLogOutput.py (added) +++ lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/TestDarwinNSLogOutput.py Thu Jul 14 16:02:45 2016 @@ -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) Added: lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/darwin_log.py URL: http://llvm.org/viewvc/llvm-project/lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/darwin_log.py?rev=275472&view=auto ============================================================================== --- lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/darwin_log.py (added) +++ lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/darwin_log.py Thu Jul 14 16:02:45 2016 @@ -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) + Added: lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/main.m URL: http://llvm.org/viewvc/llvm-project/lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/main.m?rev=275472&view=auto ============================================================================== --- lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/main.m (added) +++ lldb/trunk/packages/Python/lldbsuite/test/macosx/nslog/main.m Thu Jul 14 16:02:45 2016 @@ -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; +} Modified: lldb/trunk/source/Interpreter/Args.cpp URL: http://llvm.org/viewvc/llvm-project/lldb/trunk/source/Interpreter/Args.cpp?rev=275472&r1=275471&r2=275472&view=diff ============================================================================== --- lldb/trunk/source/Interpreter/Args.cpp (original) +++ lldb/trunk/source/Interpreter/Args.cpp Thu Jul 14 16:02:45 2016 @@ -1139,6 +1139,47 @@ Args::LongestCommonPrefix (std::string & } } +bool +Args::ContainsEnvironmentVariable(const char *env_var_name) const +{ + // Validate args. + if (!env_var_name) + return false; + + // Check each arg to see if it matches the env var name. + for (size_t i = 0; i < GetArgumentCount(); ++i) + { + // Get the arg value. + const char *argument_value = GetArgumentAtIndex(i); + if (!argument_value) + continue; + + // Check if we are the "{env_var_name}={env_var_value}" style. + const char *equal_p = strchr(argument_value, '='); + if (equal_p) + { + if (strncmp(env_var_name, argument_value, + equal_p - argument_value) == 0) + { + // We matched. + return true; + } + } + else + { + // We're a simple {env_var_name}-style entry. + if (strcmp(argument_value, env_var_name) == 0) + { + // We matched. + return true; + } + } + } + + // We didn't find a match. + return false; +} + size_t Args::FindArgumentIndexForOption (Option *long_options, int long_options_index) { Modified: lldb/trunk/source/Plugins/Platform/MacOSX/PlatformDarwin.cpp URL: http://llvm.org/viewvc/llvm-project/lldb/trunk/source/Plugins/Platform/MacOSX/PlatformDarwin.cpp?rev=275472&r1=275471&r2=275472&view=diff ============================================================================== --- lldb/trunk/source/Plugins/Platform/MacOSX/PlatformDarwin.cpp (original) +++ lldb/trunk/source/Plugins/Platform/MacOSX/PlatformDarwin.cpp Thu Jul 14 16:02:45 2016 @@ -1695,3 +1695,28 @@ PlatformDarwin::LocateExecutable (const return FileSpec(); } + +lldb_private::Error +PlatformDarwin::LaunchProcess(lldb_private::ProcessLaunchInfo &launch_info) +{ + // Starting in Fall 2016 OSes, NSLog messages only get mirrored to stderr + // if the OS_ACTIVITY_DT_MODE environment variable is set. (It doesn't + // require any specific value; rather, it just needs to exist). + // We will set it here as long as the IDE_DISABLED_OS_ACTIVITY_DT_MODE flag + // is not set. Xcode makes use of IDE_DISABLED_OS_ACTIVITY_DT_MODE to tell + // LLDB *not* to muck with the OS_ACTIVITY_DT_MODE flag when they + // specifically want it unset. + const char *disable_env_var = "IDE_DISABLED_OS_ACTIVITY_DT_MODE"; + auto &env_vars = launch_info.GetEnvironmentEntries(); + if (!env_vars.ContainsEnvironmentVariable(disable_env_var)) + { + // We want to make sure that OS_ACTIVITY_DT_MODE is set so that + // we get os_log and NSLog messages mirrored to the target process + // stderr. + if (!env_vars.ContainsEnvironmentVariable("OS_ACTIVITY_DT_MODE")) + env_vars.AppendArgument("OS_ACTIVITY_DT_MODE=enable"); + } + + // Let our parent class do the real launching. + return PlatformPOSIX::LaunchProcess(launch_info); +} Modified: lldb/trunk/source/Plugins/Platform/MacOSX/PlatformDarwin.h URL: http://llvm.org/viewvc/llvm-project/lldb/trunk/source/Plugins/Platform/MacOSX/PlatformDarwin.h?rev=275472&r1=275471&r2=275472&view=diff ============================================================================== --- lldb/trunk/source/Plugins/Platform/MacOSX/PlatformDarwin.h (original) +++ lldb/trunk/source/Plugins/Platform/MacOSX/PlatformDarwin.h Thu Jul 14 16:02:45 2016 @@ -98,6 +98,9 @@ public: lldb_private::FileSpec LocateExecutable (const char *basename) override; + lldb_private::Error + LaunchProcess(lldb_private::ProcessLaunchInfo &launch_info) override; + protected: void ReadLibdispatchOffsetsAddress (lldb_private::Process *process); _______________________________________________ lldb-commits mailing list lldb-commits@lists.llvm.org http://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-commits