mirror of
https://github.com/capstone-engine/llvm-capstone.git
synced 2025-04-08 16:44:06 +00:00
5ec76fe720
This patch is the result of a discussion on lldb-dev, see http://lists.llvm.org/pipermail/lldb-dev/2018-January/013111.html for background. For each test (should be eventually: each test configuration) a separate build directory is created and we execute make VPATH=$srcdir/path/to/test -C $builddir/path/to/test -f $srcdir/path/to/test/Makefile -I $srcdir/path/to/test In order to make this work all LLDB tests need to be updated to find the executable in the test build directory, since CWD still points at the test's source directory, which is a requirement for unittest2. Although we have done extensive testing, I'm expecting that this first attempt will break a few bots. Please DO NOT HESITATE TO REVERT this patch in order to get the bots green again. We will likely have to iterate on this some more. Differential Revision: https://reviews.llvm.org/D42281 llvm-svn: 323803
458 lines
18 KiB
Python
458 lines
18 KiB
Python
"""
|
|
Base class for DarwinLog tests.
|
|
"""
|
|
|
|
# System imports
|
|
from __future__ import print_function
|
|
|
|
import json
|
|
import os
|
|
import platform
|
|
import re
|
|
import sys
|
|
import threading
|
|
|
|
|
|
# lldb imports
|
|
import lldb
|
|
from lldb import SBProcess, SBTarget
|
|
|
|
from lldbsuite.test import decorators
|
|
from lldbsuite.test import lldbtest
|
|
from lldbsuite.test import lldbtest_config
|
|
from lldbsuite.test import lldbutil
|
|
|
|
|
|
def expand_darwinlog_command(command):
|
|
return "plugin structured-data darwin-log " + command
|
|
|
|
|
|
def expand_darwinlog_settings_set_command(command):
|
|
return "settings set plugin.structured-data.darwin-log." + command
|
|
|
|
|
|
class DarwinLogTestBase(lldbtest.TestBase):
|
|
"""Base class for DarwinLog test cases that are pexpect-based."""
|
|
NO_DEBUG_INFO_TESTCASE = True
|
|
|
|
CONTINUE_REGEX = re.compile(r"Process \d+ resuming")
|
|
|
|
def setUp(self):
|
|
# Call super's setUp().
|
|
super(DarwinLogTestBase, self).setUp()
|
|
|
|
# Until other systems support this, exit
|
|
# early if we're not macOS version 10.12
|
|
# or greater.
|
|
version = platform.mac_ver()[0].split('.')
|
|
if ((int(version[0]) == 10) and (int(version[1]) < 12) or
|
|
(int(version[0]) < 10)):
|
|
self.skipTest("DarwinLog tests currently require macOS 10.12+")
|
|
return
|
|
|
|
self.child = None
|
|
self.child_prompt = '(lldb) '
|
|
self.strict_sources = False
|
|
self.enable_process_monitor_logging = False
|
|
|
|
def run_lldb_to_breakpoint(self, exe, source_file, line,
|
|
enable_command=None, settings_commands=None):
|
|
|
|
import pexpect
|
|
# 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
|
|
|
|
if self.enable_process_monitor_logging:
|
|
if platform.system() == 'Darwin':
|
|
self.runCmd(
|
|
"settings set target.process.extra-startup-command "
|
|
"QSetLogging:bitmask=LOG_DARWIN_LOG;")
|
|
self.expect_prompt()
|
|
|
|
# Run the enable command if we have one.
|
|
if enable_command is not None:
|
|
self.runCmd(enable_command)
|
|
self.expect_prompt()
|
|
|
|
# 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()
|
|
|
|
# While we're debugging, turn on packet logging.
|
|
self.runCmd("log enable -f /tmp/packets.log gdb-remote packets")
|
|
self.expect_prompt()
|
|
|
|
# Prevent mirroring of NSLog/os_log content to stderr. We want log
|
|
# messages to come exclusively through our log channel.
|
|
self.runCmd(
|
|
"settings set target.env-vars IDE_DISABLED_OS_ACTIVITY_DT_MODE=1")
|
|
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(
|
|
expand_darwinlog_settings_set_command(setting_command))
|
|
self.expect_prompt()
|
|
|
|
# Set breakpoint right before the os_log() macros. We don't
|
|
# set it on the os_log*() calls because these are a number of
|
|
# nested-scoped calls that will cause the debugger to stop
|
|
# multiple times on the same line. That is difficult to match
|
|
# os_log() content by since it is non-deterministic what the
|
|
# ordering between stops and log lines will be. This is why
|
|
# we stop before, and then have the process run in a sleep
|
|
# afterwards, so we get the log messages while the target
|
|
# process is "running" (sleeping).
|
|
child.sendline('breakpoint set -f %s -l %d' % (source_file, line))
|
|
child.expect_exact(prompt)
|
|
|
|
# Now run to the breakpoint that we just set.
|
|
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.skipTest("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")
|
|
|
|
def do_test(self, enable_options, 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)
|
|
|
|
# Build the darwin-log enable command.
|
|
enable_cmd = expand_darwinlog_command('enable')
|
|
if enable_options is not None and len(enable_options) > 0:
|
|
enable_cmd += ' ' + ' '.join(enable_options)
|
|
|
|
exe = self.getBuildArtifact(self.exe_name)
|
|
self.run_lldb_to_breakpoint(exe, self.source, self.line,
|
|
enable_command=enable_cmd,
|
|
settings_commands=settings_commands)
|
|
self.expect_prompt()
|
|
|
|
# Now go.
|
|
self.runCmd("process continue")
|
|
self.expect(self.CONTINUE_REGEX)
|
|
|
|
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)
|
|
|
|
|
|
def remove_add_mode_entry(log_entries):
|
|
"""libtrace creates an "Add Mode:..." message when logging is enabled.
|
|
Strip this out of results since our test subjects don't create it."""
|
|
return [entry for entry in log_entries
|
|
if "message" in entry and
|
|
not entry["message"].startswith("Add Mode:")]
|
|
|
|
|
|
class DarwinLogEventBasedTestBase(lldbtest.TestBase):
|
|
"""Base class for event-based DarwinLog tests."""
|
|
NO_DEBUG_INFO_TESTCASE = True
|
|
|
|
class EventListenerThread(threading.Thread):
|
|
|
|
def __init__(self, listener, process, trace_on, max_entry_count):
|
|
super(
|
|
DarwinLogEventBasedTestBase.EventListenerThread,
|
|
self).__init__()
|
|
self.process = process
|
|
self.listener = listener
|
|
self.trace_on = trace_on
|
|
self.max_entry_count = max_entry_count
|
|
self.exception = None
|
|
self.structured_data_event_count = 0
|
|
self.wait_seconds = 2
|
|
self.max_timeout_count = 4
|
|
self.log_entries = []
|
|
|
|
def handle_structured_data_event(self, event):
|
|
structured_data = SBProcess.GetStructuredDataFromEvent(event)
|
|
if not structured_data.IsValid():
|
|
if self.trace_on:
|
|
print("invalid structured data")
|
|
return
|
|
|
|
# Track that we received a valid structured data event.
|
|
self.structured_data_event_count += 1
|
|
|
|
# Grab the individual log entries from the JSON.
|
|
stream = lldb.SBStream()
|
|
structured_data.GetAsJSON(stream)
|
|
dict = json.loads(stream.GetData())
|
|
self.log_entries.extend(dict["events"])
|
|
if self.trace_on:
|
|
print("Structured data (raw):", stream.GetData())
|
|
|
|
# Print the pretty-printed version.
|
|
if self.trace_on:
|
|
stream.Clear()
|
|
structured_data.PrettyPrint(stream)
|
|
print("Structured data (pretty print):",
|
|
stream.GetData())
|
|
|
|
def done(self, timeout_count):
|
|
"""Returns True when we're done listening for events."""
|
|
# See if we should consider the number of events retrieved.
|
|
if self.max_entry_count is not None:
|
|
if len(self.log_entries) >= self.max_entry_count:
|
|
# We've received the max threshold of events expected,
|
|
# we can exit here.
|
|
if self.trace_on:
|
|
print("Event listener thread exiting due to max "
|
|
"expected log entry count being reached.")
|
|
return True
|
|
|
|
# If our event timeout count has exceeded our maximum timeout count,
|
|
# we're done.
|
|
if timeout_count >= self.max_timeout_count:
|
|
if self.trace_on:
|
|
print("Event listener thread exiting due to max number of "
|
|
"WaitForEvent() timeouts being reached.")
|
|
return True
|
|
|
|
# If our process is dead, we're done.
|
|
if not self.process.is_alive:
|
|
if self.trace_on:
|
|
print("Event listener thread exiting due to test inferior "
|
|
"exiting.")
|
|
return True
|
|
|
|
# We're not done.
|
|
return False
|
|
|
|
def run(self):
|
|
event = lldb.SBEvent()
|
|
try:
|
|
timeout_count = 0
|
|
|
|
# Wait up to 4 times for the event to arrive.
|
|
while not self.done(timeout_count):
|
|
if self.trace_on:
|
|
print("Calling wait for event...")
|
|
if self.listener.WaitForEvent(self.wait_seconds, event):
|
|
while event.IsValid():
|
|
# Check if it's a process event.
|
|
if SBProcess.EventIsStructuredDataEvent(event):
|
|
self.handle_structured_data_event(event)
|
|
else:
|
|
if self.trace_on:
|
|
print("ignoring unexpected event:",
|
|
lldbutil.get_description(event))
|
|
# Grab the next event, if there is one.
|
|
event.Clear()
|
|
if not self.listener.GetNextEvent(event):
|
|
if self.trace_on:
|
|
print("listener has no more events "
|
|
"available at this time")
|
|
else:
|
|
if self.trace_on:
|
|
print("timeout occurred waiting for event...")
|
|
timeout_count += 1
|
|
self.listener.Clear()
|
|
except Exception as e:
|
|
self.exception = e
|
|
|
|
def setUp(self):
|
|
# Call super's setUp().
|
|
super(DarwinLogEventBasedTestBase, self).setUp()
|
|
|
|
# Until other systems support this, exit
|
|
# early if we're not macOS version 10.12
|
|
# or greater.
|
|
version = platform.mac_ver()[0].split('.')
|
|
if ((int(version[0]) == 10) and (int(version[1]) < 12) or
|
|
(int(version[0]) < 10)):
|
|
self.skipTest("DarwinLog tests currently require macOS 10.12+")
|
|
return
|
|
|
|
# Source filename.
|
|
self.source = 'main.c'
|
|
|
|
# Output filename.
|
|
self.exe_name = 'a.out'
|
|
self.d = {'C_SOURCES': self.source, 'EXE': self.exe_name}
|
|
|
|
# Locate breakpoint.
|
|
self.line = lldbtest.line_number(self.source, '// break here')
|
|
|
|
# Enable debugserver logging of the darwin log collection
|
|
# mechanism.
|
|
self.runCmd("settings set target.process.extra-startup-command "
|
|
"QSetLogging:bitmask=LOG_DARWIN_LOG;")
|
|
|
|
def darwin_log_available(self):
|
|
match = self.match("plugin structured-data darwin-log status",
|
|
patterns=[r"Availability: ([\S]+)"])
|
|
return match is not None and (match.group(1) == "available")
|
|
|
|
def do_test(self, enable_options, settings_commands=None,
|
|
run_enable_after_breakpoint=False, max_entry_count=None):
|
|
"""Runs the test inferior, returning collected events.
|
|
|
|
This method runs the test inferior to the first breakpoint hit.
|
|
It then adds a listener for structured data events, and collects
|
|
all events from that point forward until end of execution of the
|
|
test inferior. It then returns those events.
|
|
|
|
@return
|
|
A list of structured data events received, in the order they
|
|
were received.
|
|
"""
|
|
self.build(dictionary=self.d)
|
|
self.setTearDownCleanup(dictionary=self.d)
|
|
|
|
exe = self.getBuildArtifact(self.exe_name)
|
|
|
|
# Create a target by the debugger.
|
|
target = self.dbg.CreateTarget(exe)
|
|
self.assertTrue(target, lldbtest.VALID_TARGET)
|
|
|
|
# Run the darwin-log settings commands.
|
|
if settings_commands is not None:
|
|
for setting_command in settings_commands:
|
|
self.runCmd(
|
|
expand_darwinlog_settings_set_command(setting_command))
|
|
|
|
# Build the darwin-log enable command.
|
|
enable_cmd = expand_darwinlog_command("enable")
|
|
if enable_options is not None and len(enable_options) > 0:
|
|
enable_cmd += ' ' + ' '.join(enable_options)
|
|
|
|
# Run the darwin-log enable command now if we are not supposed
|
|
# to do it at the first breakpoint. This tests the start-up
|
|
# code, which has the benefit of being able to set os_log-related
|
|
# environment variables.
|
|
if not run_enable_after_breakpoint:
|
|
self.runCmd(enable_cmd)
|
|
|
|
# Create the breakpoint.
|
|
breakpoint = target.BreakpointCreateByLocation(self.source, self.line)
|
|
self.assertIsNotNone(breakpoint)
|
|
self.assertTrue(breakpoint.IsValid())
|
|
self.assertEqual(1, breakpoint.GetNumLocations(),
|
|
"Should have found one breakpoint")
|
|
|
|
# Enable packet logging.
|
|
# self.runCmd("log enable -f /tmp/packets.log gdb-remote packets")
|
|
# self.runCmd("log enable lldb process")
|
|
|
|
# Launch the process - doesn't stop at entry.
|
|
process = target.LaunchSimple(None, None, self.getBuildDir())
|
|
self.assertIsNotNone(process, lldbtest.PROCESS_IS_VALID)
|
|
|
|
# Keep track of whether we're tracing output.
|
|
trace_on = self.TraceOn()
|
|
|
|
# Get the next thread that stops.
|
|
from lldbsuite.test.lldbutil import get_stopped_thread
|
|
thread = get_stopped_thread(process, lldb.eStopReasonBreakpoint)
|
|
|
|
self.assertIsNotNone(thread, "There should be a thread stopped "
|
|
"due to breakpoint")
|
|
|
|
# The process should be stopped at this point.
|
|
self.expect("process status", lldbtest.PROCESS_STOPPED,
|
|
patterns=['Process .* stopped'])
|
|
|
|
# The stop reason of the thread should be breakpoint.
|
|
self.expect("thread list", lldbtest.STOPPED_DUE_TO_BREAKPOINT,
|
|
substrs=['stopped', 'stop reason = breakpoint'])
|
|
|
|
# And our one and only breakpoint should have been hit.
|
|
self.assertEquals(breakpoint.GetHitCount(), 1)
|
|
|
|
# Check if DarwinLog is available. This check cannot be done
|
|
# until after the process has started, as the feature availability
|
|
# comes through the stub. The stub isn't running until
|
|
# the target process is running. So this is really the earliest
|
|
# we can check.
|
|
if not self.darwin_log_available():
|
|
self.skipTest("DarwinLog not available")
|
|
|
|
# Now setup the structured data listener.
|
|
#
|
|
# Grab the broadcaster for the process. We'll be attaching our
|
|
# listener to it.
|
|
broadcaster = process.GetBroadcaster()
|
|
self.assertIsNotNone(broadcaster)
|
|
|
|
listener = lldb.SBListener("SBStructuredData listener")
|
|
self.assertIsNotNone(listener)
|
|
|
|
rc = broadcaster.AddListener(
|
|
listener, lldb.SBProcess.eBroadcastBitStructuredData)
|
|
self.assertTrue(rc, "Successfully add listener to process broadcaster")
|
|
|
|
# Start the listening thread to retrieve the events.
|
|
# Bump up max entry count for the potentially included Add Mode:
|
|
# entry.
|
|
if max_entry_count is not None:
|
|
max_entry_count += 1
|
|
event_thread = self.EventListenerThread(listener, process, trace_on,
|
|
max_entry_count)
|
|
event_thread.start()
|
|
|
|
# Continue the test inferior. We should get any events after this.
|
|
process.Continue()
|
|
|
|
# Wait until the event thread terminates.
|
|
# print("main thread now waiting for event thread to receive events.")
|
|
event_thread.join()
|
|
|
|
# If the process is still alive, we kill it here.
|
|
if process.is_alive:
|
|
process.Kill()
|
|
|
|
# Fail on any exceptions that occurred during event execution.
|
|
if event_thread.exception is not None:
|
|
# Re-raise it here so it shows up as a test error.
|
|
raise event_thread
|
|
|
|
# Return the collected logging events.
|
|
return remove_add_mode_entry(event_thread.log_entries)
|