Unicorn 2 regression: Something is wrong with MSR not changing mode? #1531
Comments
|
I decide to label this as enhancement since we indeed need some extra debug output (logging) to help developers address the problem in a big script. |
|
Understood; sorry I couldn't make it smaller. I might have a see if there's anything I can do to isolate it better anyhow. I had wondered, when I was doing the prior changes to add debug to the MSR on my own branch, whether it would be possible to introduce a control interface to enable the back end qemu debug. Then it could just be enabled around the bit that was interesting. But I don't really have enough understanding of the innards for that, I think. |
There is some debugging output if you set |
|
The UNICORN_DEBUG looks like it's related to tcg operations? I wasn't sure that was useful. I have made some changes to my debug branch which has extra debug to help with isolating the mode problems that I encountered. The debug branch is here: https://github.com/gerph/unicorn/tree/cjf-debug-privileged-mode-problems and the change that adds the new runtime controls is here: gerph@38fb9b5 (not sure why the PPC things changed- I haven't touched that area of the code). Basically, I introduced a new My changes are all heavily based on https://gitlab.com/qemu-project/qemu/-/blob/master/util/log.c although I did a couple of things a little differently. It's not a PR - it's nowhere near production ready - but it's good enough to get a little more debug. In any case, with that then compiled into the Unicorn package, and with the test code updated to change that end section to: # <<<<< THIS IS WHERE BEHAVIOUR BEGINS TO DIFFER >>>>>
try:
uc2.ctl_set_debug_mask(0xFFFFFFFF)
except Exception as exc:
print("Could not turn on debug mask: %s" % (exc,))
dump_registers(uc2)
uc2.hook_add(unicorn.UC_HOOK_CODE, hook_code)
uc2.emu_start(value_40903, 0, timeout=0) # None
dump_registers(uc2)This sets the mask to 'everything' and then continues the execution. My code produces the following output: This is for the execution of the code block which is disassembled in the original code ie: There are two MSR operations listed, the first of which is the That's as far as I think I can go - I don't know how it ended up thinking it was in USR mode again, when it's not. Is that any help? |
That seems the key! Could you confirm how |
|
Ok, I've added the debug code earlier in the test run so that I can see what's going on further back, and I can see that when I do a New test code: This has the debug happening much higher up, and I've interleaved the debug output with the QEmu output by symlinking I've marked the bit where we issue the SWI to enter SVC mode (ie on return from the SWI call we should be in SVC32) with On return from that change CPSR is left as Is that any more help? |
AFAIK, you have to handle everything for an |
|
In my OS I don't handle it in the interrupt callback but stop the emulation then emu_start returns, and then we do the real work. I'll go through the code that's executed by after the service call returns to explain what's going on (at least, as well as I can, because there's a lot of stuff in the main OS that is perfectly sane in the original OS, but seems very weird here. I'll work through the code in the OS and try to explain each operation that the OS peforms and how that equates to what's going on in the script. Here's the script code in the area of the problem: uc2.emu_start(value_40542, 0, timeout=0) # (accessed but not returned yet)
#### Returning from this we're trying to execute a SWI 0x20016 : OS_EnterOS (enters SVC mode)
print("SWI OS_EnterOS executed")
dump_registers(uc2)
# uc2.hook_add:1:hook_intr(uc2, 2L, None) # (accessed but not returned yet)
# uc2.emu_stop() # None
# None (return from uc2.hook_add:1:hook_intr(uc2, 2L, None))
# None (return from uc2.emu_start(value_40542, 0, timeout=0))
value_40543 = uc2.mem_read(0, 32) # bytearray(b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00')
value_40544 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0
value_40545 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0
value_40546 = uc2.mem_read(0x70178dc, 4) # bytearray(b'\x16\x00\x02\xef')
value_40547 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0
value_40548 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000010
value_40549 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000010
value_40550 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000010
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, 0x60000013) # None
value_40551 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40551) # None
value_40552 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40552) # None
value_40553 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40553) # None
value_40554 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40550) # None
value_40555 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000010
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40554) # None
value_40556 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0
value_40557 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
value_40558 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
value_40559 = uc2.mem_read(0, 32) # bytearray(b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00')
value_40560 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0
print("Should now be in SVC32")
dump_registers(uc2)
uc2.emu_start(value_40560, 0, timeout=0) # (accessed but not returned yet)And hopefully I can annotate what's going on... uc2.emu_start(value_40542, 0, timeout=0) # (accessed but not returned yet)
#### Returning from this we're trying to execute a SWI 0x20016 : OS_EnterOS (enters SVC mode)
print("SWI OS_EnterOS executed")
dump_registers(uc2)
# uc2.hook_add:1:hook_intr(uc2, 2L, None) # (accessed but not returned yet)
# uc2.emu_stop() # None
# None (return from uc2.hook_add:1:hook_intr(uc2, 2L, None))
# None (return from uc2.emu_start(value_40542, 0, timeout=0))This section tries to execute some code the code, and requests that the execution stop at address 0. The code that is executed ends with: And then Unicorn calls def hook_intr(self, uc, intno, data):
"""
Interrupt or system call (the system entry points)
"""
self.exit_reason = ('exception', intno)
self.emu.emu_stop()which is why the script says that we call This causes the value_40543 = uc2.mem_read(0, 32) # bytearray(b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00')Next we check whether the reason that we stopped execution was because we executed code at address 0 (because 0 is the address that we've told it to stop at in the emu_start). That generates a special internal error in the OS. The original python code looks like this: if self.regs.pc == 0x0:
self.exit_reason = ('branchthrough0',)and this translates into the first read of pc: value_40544 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0Next we check the reason for exiting execution (which we set in elif exit_reason[0] == 'exception':
...
if intno == 2:
# SWI call.
pc = self.regs[15] - 4
if self.debug_swi:
print("SWI at &%08x" % (pc,))
value = self.memory.read_word(pc)This equates to the next two Unicorn operations: value_40545 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0
value_40546 = uc2.mem_read(0x70178dc, 4) # bytearray(b'\x16\x00\x02\xef')Having determined the SWI number we dispatch this to the Kernel... self.kernel.swi_dispatch(swi)The SWI dispatch code looks like this: def swi_dispatch(self, swi):
"""
SWI call by the user.
"""
try:
self.swi_enter(swi, self.ro.regs.pc)
self._swi_dispatch(swi)
self.swi_leave(swi, self.ro.regs.pc)
except RISCOSError as exc:
self.swi_leave(swi, self.ro.regs.pc, error=exc)
raiseSo the call to value_40547 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0Then we head into if self.ro.regs.cpsr_mode == self.ro.regs.MODE_IRQ:
self.ro.trace.warning(name='SWI misuse',
label="SWI called from within IRQ mode: &{:x} ({})".format(swi,
self.ro.kernel.swi_name(swi)))That gives us one of the CPSR reads: value_40548 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000010And as we can see we're in USR32 mode ( Then we enter a context handler which ensures that we're in SVC mode: with SVCMode(self.ro) as mode:The entry sequence of this code is: def __enter__(self):
self.old_mode = self.ro.regs.cpsr
self.ro.regs.cpsr_mode = self.want_mode
return selfwhere @cpsr_mode.setter
def cpsr_mode(self, value):
value = int(value) & self.MODE_MASK
current_cpsr = self.cpsr
self.emu.reg_write(arm.UC_ARM_REG_CPSR, (current_cpsr & ~self.MODE_MASK) | value)This between the value_40549 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000010
value_40550 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000010
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, 0x60000013) # NoneSo now we're in SVC32, and there's an odd sequence of 'read CPSR, set CPSR to the same value'. The first pair of these because we clear the V flag: if swin not in (swis.OS_CallAVector, swis.OS_BreakPt):
self.ro.regs.cpsr_v = FalseThe manipulation of the value_40551 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40551) # NoneThe kernel calls a dispatcher to find the SWI calls that we have registered - this is implemented as: @handlers.swi.register(swis.OS_EnterOS)
def swi_OS_EnterOS(ro, swin, regs):
"""
OS_EnterOS
<= In SVC32 mode
"""
if ro.config['apiwarnings.enterleaveos']:
ro.trace.warning(name='API warning',
label="OS_EnterOS SWI should not be used in normal applications")
regs.cpsr_mode = regs.MODE_SVCSo this value_40552 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40552) # NoneWe then return to the Kernel having successfully dispatched the SWI to the right place, and because no error was raised we clear the V flag (RISC OS uses the V flag on return from SWI calls to indicate errors): # Successful execution clears V
self.ro.regs.cpsr_v = FalseSo this explains the next two CPSR read-write sequences: value_40553 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40553) # NoneThen we leave the def __exit__(self, exctype, value, tb):
if value and not isinstance(value, RISCOSError):
# This is an exception that isn't a RISC OS Error, so we don't touch the mode
pass
else:
# Restore the mode
self.ro.regs.cpsr_mode = self.old_modeThere was no exception, so just the CPSR mode changes back to the mode it was when we entered the SWI, which was USR32. This is the next two CPSR read-write sequences: value_40554 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40550) # NoneThe That's this code being triggered: https://github.com/gerph/unicorn/blob/cjf-debug-privileged-mode-problems/qemu/target/arm/helper.c#L8015 The kernel is about to return from the SWI dispatcher but it has to fix things up, because although the SWI handler for OS_EnterOS switched to SVC32, it was thwarted by the SVCMode context handler restoring the mode to the entry mode: So this code is run: if swin == swis.OS_EnterOS:
# Put the mode back to SVC (whatever we might have restored)
self.ro.regs.cpsr_mode = self.ro.regs.MODE_SVCwhich is the next two CPSR read-write sequences in the script: value_40555 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000010
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40554) # NoneThis leave us in SVC32. In the debug output it's interesting that this only outputs: There is no corresponding message saying At this point we are now leaving the self.swi_leave(swi, self.ro.regs.pc)This accounts for the reading of the pc: value_40556 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0The value_40557 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013We come back to the main system execution loop and we check whether we are about to return to USR mode (if we did, we would trigger transient callbacks): if self.regs.cpsr_mode == self.regs.MODE_USR:This explains the script line: value_40558 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013Back at the beginning of the emulation handling we remembered the contents of all the watchpoints. This is so that we can trigger trace event if the watchpoints changed during the SWI call (as hooks for accessing memory don't fire if you're doing it in the python code). So before we go back into the emulation loop we read the watchpoint at 0 - 32 to check if there were any changes: value_40559 = uc2.mem_read(0, 32) # bytearray(b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00')Finally, we want to execute the next section of code, so we read the PC to pass to value_40560 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0
print("Should now be in SVC32")
dump_registers(uc2)
uc2.emu_start(value_40560, 0, timeout=0) # (accessed but not returned yet)At this point our CPSR is set to 0x13, but the next line of debug which is output from the So the change to SVC32 was not effective. I accept that that explanation may not have been any more helpful. But I think in reading through it I may be able to lift that bit of code out and put it in a smaller test program... Back in a mo... fingers crossed... |
|
Right I have a repro case in slightly fewer lines: #!/usr/bin/env python
# Sample code for ARM of Unicorn. Nguyen Anh Quynh <aquynh@gmail.com>
# Python sample ported by Loi Anh Tuan <loianhtuan@gmail.com>
import sys
import struct
import capstone
import unicorn
from unicorn import (
uc_version,
UcError,
Uc,
UC_ARCH_ARM, UC_MODE_ARM,
UC_ERR_EXCEPTION,
UC_VERSION_MAJOR, UC_VERSION_MINOR, UC_VERSION_EXTRA)
from unicorn.arm_const import (UC_ARM_REG_R0,
UC_ARM_REG_R1,
UC_ARM_REG_R2,
UC_ARM_REG_R3,
UC_ARM_REG_R4,
UC_ARM_REG_R5,
UC_ARM_REG_R6,
UC_ARM_REG_R7,
UC_ARM_REG_R8,
UC_ARM_REG_R9,
UC_ARM_REG_R10,
UC_ARM_REG_R11,
UC_ARM_REG_R12,
UC_ARM_REG_R13,
UC_ARM_REG_R14,
UC_ARM_REG_R15,
UC_ARM_REG_SP,
UC_ARM_REG_LR,
UC_ARM_REG_PC,
UC_ARM_REG_CPSR,
UC_ARM_REG_SPSR)
reg_map = [
UC_ARM_REG_R0,
UC_ARM_REG_R1,
UC_ARM_REG_R2,
UC_ARM_REG_R3,
UC_ARM_REG_R4,
UC_ARM_REG_R5,
UC_ARM_REG_R6,
UC_ARM_REG_R7,
UC_ARM_REG_R8,
UC_ARM_REG_R9,
UC_ARM_REG_R10,
UC_ARM_REG_R11,
UC_ARM_REG_R12,
UC_ARM_REG_SP,
UC_ARM_REG_LR,
UC_ARM_REG_PC,
]
arm_names = [
'r0', 'r1', 'r2', 'r3',
'r4', 'r5', 'r6', 'r7',
'r8', 'r9', 'r10', 'r11',
'r12', 'sp', 'lr', 'pc'
]
ADDRESS = 0x1000
ARM_INSTS = """
E10F6000 : MRS r6, apsr
E3C6601F : BIC r6, r6, #&1F
E3866010 : ORR r6, r6, #&10 ; switch to USR32
E121F006 : MSR cpsr_c, r6
EF020016 : SWI OS_EnterOS ; marker for our failing code
E121F006 : MSR cpsr_c, r6 ; return to USR32
E1A00000 : MOV r0,r0
EF000011 : SWI OS_Exit
"""
ARM_WORDS = []
for line in ARM_INSTS.splitlines():
if ' ' not in line or line.startswith('#'):
continue
word = line.split(' ')[0]
value = int(word, 16)
ARM_WORDS.append(struct.pack('<L', value))
ARM_CODE = b''.join(ARM_WORDS)
# Keep a copy of the code we're running.
with open('code', 'wb') as fh:
fh.write(ARM_CODE)
def dump_registers(uc):
print("Registers: ")
for rn in range(0, 16):
value = uc.reg_read(reg_map[rn])
sys.stdout.write(" %3s : 0x%08x" % (arm_names[rn], value))
if rn % 4 == 3:
sys.stdout.write("\n")
print(" CPSR = 0x{:08x}".format(uc.reg_read(UC_ARM_REG_CPSR)))
print(" SPSR = 0x{:08x}".format(uc.reg_read(UC_ARM_REG_SPSR)))
def read_word(uc, address):
data = uc.mem_read(address, 4)
word = data[0] | (data[1]<<8) | (data[2]<<16) | (data[3]<<24)
return word
def diss(codeword, address):
for i in md.disasm(codeword, address):
print("0x%08x: %-8s %s" %(i.address, i.mnemonic, i.op_str))
def hook_code(uc, address, size, user_data):
codeword = uc.mem_read(address, 4)
diss(codeword, address)
md = capstone.Cs(capstone.CS_ARCH_ARM, capstone.CS_MODE_ARM)
md.detail = True
md.syntax = capstone.CS_OPT_SYNTAX_NOREGNAME
# Test ARM
def test_arm():
print("Testing under Unicorn : {!r}".format(uc_version()))
print("Header version: {!r}".format((UC_VERSION_MAJOR, UC_VERSION_MINOR, UC_VERSION_EXTRA)))
print("Changing ARM modes")
try:
# Initialize emulator in ARM mode
mu = Uc(UC_ARCH_ARM, UC_MODE_ARM)
# initialize machine registers in different modes
mu.reg_write(UC_ARM_REG_CPSR, 0x40000013) # Current mode = SVC32 mode
mu.reg_write(UC_ARM_REG_SPSR, 0x40000013) # Saved mode = SVC32 mode
mu.reg_write(UC_ARM_REG_R13, 0x12345678) # SVC stack value
mu.reg_write(UC_ARM_REG_R14, 0x00102220) # SVC link value
print("--- Should be in SVC32, with R13 = 0x12345678, R14 = 0x00102220")
dump_registers(mu)
mu.reg_write(UC_ARM_REG_CPSR, 0x40000010) # Current mode = USR32 mode
mu.reg_write(UC_ARM_REG_R13, 0x0010000) # USR stack value
mu.reg_write(UC_ARM_REG_R14, 0x0001234) # USR link value
print("--- Should be in USR32, with R13 = 0x00010000, R14 = 0x0001234")
dump_registers(mu)
# Now the actual test, we're in SVC mode and we are going to execute some code
mu.reg_write(UC_ARM_REG_CPSR, 0x40000013) # Current mode = SVC32 mode
mu.mem_map(ADDRESS, 4096) # 4K at the execution address
mu.mem_write(ADDRESS, ARM_CODE)
uc2 = mu
uc2.hook_add(unicorn.UC_HOOK_CODE, hook_code)
try:
uc2.ctl_set_debug_mask(0xFFFFFFFF)
except Exception as exc:
print("Could not turn on debug mask: %s" % (exc,))
print("--- Executing code at 0x{:08x}".format(ADDRESS))
mu.reg_write(UC_ARM_REG_R15, ADDRESS)
while True:
pc = mu.reg_read(UC_ARM_REG_R15)
print("Run code at 0x{:08x}".format(pc))
dump_registers(mu)
try:
mu.emu_start(pc, ADDRESS + len(ARM_CODE))
except UcError as e:
if e.errno != UC_ERR_EXCEPTION:
raise
# This is an exception call, so we want to process the SWI call.
pc = mu.reg_read(UC_ARM_REG_R15) - 4
word = read_word(mu, pc)
swi_number = word & 0xFFFFFF
print("--- Reached SWI at 0x{:08x} (0x{:x})".format(pc, swi_number))
if swi_number == 0x11:
# OS_Exit - stop looping
break
if swi_number == 0x20016:
# OS_EnterOS
print("OS_EnterOS emulation")
# This is the section of code from our failing program:
# I've commented out the sections of the code that don't seem to matter.
# >>>> Failing code
#value_40543 = uc2.mem_read(0, 32) # bytearray(b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00')
#value_40544 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0
#value_40545 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0
#value_40546 = uc2.mem_read(0x70178dc, 4) # bytearray(b'\x16\x00\x02\xef')
#value_40547 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0
#value_40548 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000010
#value_40549 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000010
value_40550 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000010
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, 0x60000013) # None
#value_40551 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
#uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40551) # None
#value_40552 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
#uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40552) # None
#value_40553 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
#uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40553) # None
value_40554 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40550) # None
value_40555 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000010
uc2.reg_write(unicorn.arm_const.UC_ARM_REG_CPSR, value_40554) # None
#value_40556 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0
#value_40557 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
#value_40558 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_CPSR) # 0x60000013
#value_40559 = uc2.mem_read(0, 32) # bytearray(b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00')
#value_40560 = uc2.reg_read(unicorn.arm_const.UC_ARM_REG_PC) # 0x70178e0
print("Should now be in SVC32")
# <<<< End failing code
else:
# Unrecognised SWI call
raise
print("--- Should be in USR32, with R13 = 0x00010000, R14 = 0x0001234")
dump_registers(mu)
except UcError as e:
print("ERROR: %s" % e)
raise
if __name__ == '__main__':
test_arm()I've lifted the section I explained from the scripted code (I should have done this earlier!), and put it into one of my test harnesses. All the bits that aren't relevant have been commented out which leaves us with a short sequence that seems to go wrong. In the python code, with the state set to USR32:
And now we're in SVC32 according to CPSR, BUT the system thinks Failing output (Unicorn 2)At the end here we should be in USR32, but the MSR has been rejected because it thinks we're in USR32. Successful output (Unicorn 1)This doesn't have my extra debug from inside unicorn: And as you can see at the end we've got USR32 mode successfully. Hopefully that shorter repro code will be more useful! |
|
I'm getting some clue. The reason is TB caching. Could you try to clear all possible TB cache and try again? |
Good catch! I would have a look tomorrow. |
|
How do I clear the tb caches? It wasn't possible on Unicorn 1. Is that one of the ctl calls? Should I be doing that whenever I write code to the core? |
A sidenote: In UC1, all tb caches are cleaned per emulation and that's probably the reason why you get this regression. |
|
I wondered that - I felt that its performance was lower than I should expect due to many calls in and out of exceptions. I presume that I probably need to do something with them whenever memory is directly modified, in the same way that I would do a cache flush on a real OS, or a TLB flush if I changed the page tables? It's late here, so I shaln't be looking at this much more today... maybe tomorrow I'll know more. |
Try this diff and see whether it works for your project. |
Sorry, still fails, I'm afraid. |
|
Fixed in 6ed2214. Thanks for your cooperation! |
|
Very quick test with my example binary shows that this is now working. I'll put it through the full test suite shortly and see how it fares with to my regression tests. I'm hopeful! |
|
I've finally got around to trying it out with the full test suite - that's running in the background and I'll follow up with any issues, but I'm not expecting a problem. The reason I don't expect a problem is that I threw the full 'run the OS with the desktop components and some applications' manual test at it, and it worked fine. Whilst it doesn't show much of Unicorn itself, there's a recording of it running with Unicorn 2 here: https://share.gerph.org/s/T2U7zR4yiXCdZyd To be clear... the OS - system calls, and many of the extensions to the system - are implemented in Python, so all graphics that goes to the screen (and indeed the windows you see in the video) are all implemented in Python. But the rest is emulated ARM code. The Boot menu that starts up at the beginning of the menu is a C program in ARM, then we enter the desktop - the entire desktop implementation as ARM code, as well as the applications that are running - the task information window, the file explorer, and the game MineHunt are all ARM code, running nearly unmodified from their original versions. And the system seems to be functioning identically to how it was working under Unicorn 1. |
|
Tests completed... Both failures are pre-fetch failures:
|
|
Once again, thanks for the changes up to now to address mode changes in ARM. I think we're very close to things working as expected. The reason I say this is that I cannot reproduce the failure case for the bug I'm having with smaller code. Every time I tried creating code that looks like it does the same thing in a shorter section of code, the emulation worked fine, and so I decided to go about reproducing this in a different way - heavy handed, but which actually shows the problem in a way that you'll be able to reproduce, even if it's large.
Sorry the title isn't specific - there's something up with the MSR and it doesn't change mode in this specific circumstance.
Background
I have an implementation of the RISC OS operating system written in Python. It uses Unicorn to provide the ARM execution environment. The problem that is being encountered occurs when a C-based program is exiting and returning back to user space. This happens long after the system has been initialised and after the program has almost completed running - I have a small tool which causes the problem, but it's still a lot of ARM code to be executed.
The instruction that appears to be failing is
msr cpsr_c, r6, where r6 is0x60000010. In Unicorn 2 it fails to be executed, or the execution is treating the it as a different instruction likeandeq r0,r0,r0- either way, the mode is not changed. In Unicorn 1 this instruction causes us to return to USR32, as the value in r6 indicatesLots of mode changes are performed within the course of getting to this point in the OS, and I cannot see a way that the environment is different in the this case.
Because so much of the OS has been executed to this point, and I was unable to create a small repro case, the solution I chose was to create a new class to interpose between Unicorn and the OS, which logs every method and variable access. The log is python code - and for simple things, it means that you can run the log and it will behave like the system that ran it, reproducing any behaviour that the Unicorn system had originally. In my case there were a few minor tweaks but the repro case now runs correctly on Unicorn 1, but fails on Unicorn 2, just like the real OS does.
The repro case is 52014 lines of python, coming in at 4MB - sorry, it's large, but as I said I couldn't reproduce it by hand crafted cide, so this in-situ recording is the best I can do, and it ought to reproduce for you.
Source environment
I built unicorn on the dev branch at sha 36afa10.
This is the most recent version this afternoon, after the fixes for mode changes.
This has been tested on OSX system on Intel hardware (10.14.6)
Failure mode
The repro-case appears to work identically up to the point marked:
To make it easy to see what's going on from that point, some debug has been added which dumps the registers, adds a hook which disassembles the code being executed, and then dumps the registers again - the second set of registers, and the code path taken differs between Unicorn 1 and Unicorn 2.
The code being executed at the failure point is:
The difference is the
msr cpsr_c, r6instruction, which appears to have no effect on the Unicorn 2 execution, which then leaves us in SVC32 mode, rather than USR32, and thus thepop {lr}removes a value from the wrong stack, and more bad things happen after that - finally resulting in hitting the ARM exception vectors because thepopat0x07017944overflows the SVC32 stack (I think). In any case the point of divergence is the instruction at0x07017938, I believe.It is possible that something that the code I'm using is doing is wrong, but I cannot see it.
Test code
The repro case should be attached to this bug as a
.py.gzfile.:ucbroken.py.gz
The part of code where execution differs is at line 51905, which looks like this:
Failing output (Unicorn 2)
On Unicorn 2 the following output is produced:
Observe that we remain in SVC32 mode at the point of the exception (the
pop), and that the value oflris garbage (because it has been pulled from the SVC32 stack). The instruction at0x07017938should have selected USR32 mode (because r6 =0x60000010).The code executed after the second register dump is irrelevant as we're now trying to handle the exception caused by the unexpected behaviour.
Successful output (Unicorn 1)
In this case we can see that we're executing more code - the
popinstruction is happy, because we're in USR32 mode, and we continue until we hit ansvcinstruction. At that point we can see the registers and that we definitely are in USR32 (0x60000010).Final words
I'm not sure what else to suggest for reproducing this other than using the code as it stands - I assume that some internal state is different between the Unicorn 1 and Unicorn 2 systems. Hopefully this will be able to give you some clues as to what's going wrong - I've been unable to narrow it further.
I really hope you can help find the bug - whether it's in how I'm using Unicorn or in Unicorn 2 - because it's very close to making the OS work on Unicorn 2 now.
The text was updated successfully, but these errors were encountered: