def _format_string(self, formatter, arguments):
"""Searches for the formatter string in the debug information.
Also checks the downloadable capabilities.
Args:
string_ptr: Pointer to the formatter string.
arguments: Arguments for the formatter string. Note this can
change.
"""
try:
# python can't handle the '%p' format specifier, apparently.
formatter = re.sub(r'%([0-9]*)p', r'0x%\g<1>x', formatter)
formattedstr = formatter % tuple(
arguments) # works for an empty list too
except TypeError as exception:
# TypeError: %d format: a number is required, not str
# Nasty special case: if we incorrectly interpreted a large number
# as a string, the format specifier won't match here.
if re.search("arguments number is required", str(exception)):
specifiers = re.findall(r"%([\d\w]+)", formatter)
# if len(specifiers) != len(arguments) bad case
for idx, val in enumerate(specifiers):
# If the specifier isn't a string, but we have a string in
# args, try to correct our mistake.
cs_available = re.search("[cs]", val)
if not cs_available and isinstance(arguments[idx], str):
# Replace the string with the original large number.
# That requires a search through all the debug strings
# to work out what the number was.
debug_strings = self.debuginfo.get_kymera_debuginfo(
).debug_strings
for addr, string in debug_strings.items():
if string == arguments[idx]:
arguments[idx] = addr
formattedstr = formatter % tuple(arguments)
else:
formattedstr = ("\n@@@@ ERROR:" + str(exception) + "\n" +
" formatter string: %s\n" % (formatter) +
" arguments: %s\n" %
(cu.list_to_string(arguments)))
return formattedstr
def _decode_log(self):
"""Same as decode_log, but is not thread safe."""
# Form the list on a temporary list so we don't duplicate old entries
tmp_debug_log = []
# Read all the debug variables.
buffer_wrp = self.chipdata.get_data(self.p_buffer_wrp)
debug_buffer = self.chipdata.get_data(self.p_buffer, self.buffer_size)
if buffer_wrp == self.last_read + 1:
# Nothing new in the log so don't bother reading it
return
# The debug buffer looks like this:
#
# [appppaapapaa...............ppp]
# ^ ^ ^
# debug_buffer buffer_wrp len(debug_buffer)
#
# p = string pointer, arguments = string argument
# Decoding is more complicated than you might think, because:
# * We can't assume that a value > $flash.debugdata.__Base is a string
# pointer (it could just be a large number)
# * String pointers can in some circumstances be arguments to other
# strings (more details below).
# * The buffer may not be completely full
# * The buffer may have wrapped unevenly, so that the first few
# arguments after buffer_wrp are orphaned from the corresponding
# string.
#
# So what we need to do is work backwards from buffer_wrp, find the
# last string pointer, and count the number of format specifiers
# in it to check that it matches the number of arguments.
arguments = [] # list of args for each log statement
i = buffer_wrp - 1 # start with the newest entry in the buffer
last_read = i # record how far we will read up to this time
wrapped = False
while True:
# Check for a wrap/repeat
if i < 0:
i = len(debug_buffer) - 1
wrapped = True
if wrapped and i <= buffer_wrp:
# we've parsed the whole buffer
break
# We need to look for things that look like pointers to debug
# strings.
region = Arch.get_dm_region(debug_buffer[i], False)
if region == 'DEBUG' or region == 'DBG_DWL' or region == 'DBG_PTCH':
mystr = self._get_formatter_string(debug_buffer[i], arguments)
# Now it could just so happen that this value is an argument
# to printf AND a valid debug string pointer, like:
# AUDIO_LOG_STRING(hi, "hello");
# L0_DBG_MSG1("foo: %s", (DBG_STR)hi);
# (This construct is especially prevalent in isp_router).
#
# We can check that the string pointed-to has the same number
# of arguments as we have in a[], but that doesn't actually
# help in this case since it doesn't allow us to distinguish
# between a string that simply has no arguments, and a string
# that is an argument to another string.
# To avoid painful look-ahead, the simple way to solve this
# is to just assume every complete-looking string is actually
# complete, and put it into tmp_debug_log[]. If we then come
# across a string that doesn't seem to have enough
# arguments, we backtrack. Note that we only support one
# level of nesting here; if someone has put a formatted
# string inside a formatted string then all bets are off.
if mystr.count('%') == 0 and arguments:
# This could happen if you had something like:
# L0_DBG_MSG1("foo: %s %d", (DBG_STR)hi, 0x1234)
# This string is clearly just actually an argument.
arguments.append(mystr)
i -= 1
continue
if mystr.count('%') > len(arguments):
# We're missing some arguments. We probably put them into
# tmp_debug_log[], thinking they were complete strings.
num_args_missing = mystr.count('%') - len(arguments)
if num_args_missing == mystr.count('%s'):
temp_arguments = tmp_debug_log[-num_args_missing:]
if Arch.addr_per_word != 4:
# For Hydra platforms, like Crescendo and Aura
# the arguments in tmp_debug_log[] are in the
# right order, because the order in which the
# arguments are stored. For Blucore platforms,
# like Gordon and Rick, the array slice is in
# the wrong order.
temp_arguments.reverse()
arguments = temp_arguments + arguments
# now arguments[] contains what it would have held,
# had we not put the missing args into
# tmp_debug_log[]. Last thing to do is disavow them.
tmp_debug_log[-num_args_missing:] = []
# Now we should have the right number of arguments!
str_cnt = mystr.count('%')
# Assume this is a complete log.
# shrink-wrap the string we just read, and save it.
arguments.reverse() # because we added args in reverse order.
# format the string.
formatter_error = False
if str_cnt == len(arguments):
try:
formatted_str = self._format_string(mystr, arguments)
except ValueError:
# ValueError can be caused by erroneous formatting
# string like a "0x%08"
formatter_error = True
else:
formatter_error = True
if formatter_error:
formatted_str = (
"\n@@@@ ERROR: Wrong number of arguments! " +
"This could be caused by buffer tear. \n" +
"Buffer tear happens when messages are " +
"written too fast to the log buffer\n" +
"and the debug interface cannot keep up in reading them. \n"
+ " formatter string: %s\n" %
(mystr.replace("\n", "")) + " arguments: %s\n" %
(cu.list_to_string(arguments)))
# Add the formatted string to the debug log.
tmp_debug_log.append(formatted_str)
# Clear the arguments for the next run.
arguments = []
else:
# Found an argument.
arguments.append(debug_buffer[i])
i -= 1 # next
if i == self.last_read: # We've reached where we got to
break
self.last_read = last_read
# invert the debug log so it is printed in the correct order
tmp_debug_log.reverse()
return tmp_debug_log
