search

DynamoRIO / dynamorio

Dynamic Instrumentation Tool Platform
Other
2.67k stars 562 forks source link

DynamoRIO Incorrectly switch to thumb mode when encountering the MRRC instruction on armv7l #5233

Closed zenhumany closed 2 years ago

zenhumany commented 2 years ago

Describe the bug when i run the drrun, it crash like the following:

./drrun -debug  /usr/bin/sftp
<Starting application /usr/bin/sftp (10975)>
<Not tested @dynamorio/dynamorio/core/arch/emit_utils_shared.c:5574>
<Initial options = -no_dynamic_options -code_api -stack_size 56K -signal_stack_size 32K -max_elide_jmp 0 -max_elide_call 0 -early_inject -emulate_brk -no_inline_ignored_syscalls -native_exec_default_list '' -no_native_exec_managed_code -no_indcall2direct >
<Paste into GDB to debug DynamoRIO clients:
set confirm off
add-symbol-file 'DynamoRIO-ARM-Linux-EABIHF-8.0.18929/lib32/debug/libdynamorio.so' 0x54b685a0
>
<(1+x) Handling our fault in a TRY at 0x54d31024>
<Invalid opcode encountered>
<Application /usr/bin/sftp (10975).  Application exception at PC 0x76f62f52.  
Signal 4 delivered to application as default action.
Callstack:
0x76f62f52   </usr/lib/libcrypto.so.1.0.0+0x119f52>
0xf8af04b0  
>
<Stopping application /usr/bin/sftp (10975)>
### Illegal instruction (core dumped)

The following is the cpu information :

Architecture: armv7l Byte Order: Little Endian CPU(s): 2 On-line CPU(s) list: 0,1 Thread(s) per core: 1 Core(s) per socket: 2 Socket(s): 1 Model name: ARMv7 Processor rev 10 (v7l) CPU max MHz: 996.0000 CPU min MHz: 396.0000

Some analysis

1. Switch to thumb mode incorrectly

The following is the output of DR with "loglevel 3" , in 53560 line ,DR switch to ARM mode, but at 53589 line , the DR use thumb decode the opcode.I think this is the first incorrectly place.

The IDA disassembly :

.text:0011993C                               ; void __fastcall __noreturn sub_11993C(int val)
.text:0011993C                               sub_11993C                              ; DATA XREF: OPENSSL_cpuid_setup+F0↑o
.text:0011993C                                                                       ; .text:off_3F9A8↑o
.text:0011993C 00 10 A0 E1                                   MOV             R1, R0  ; val
.text:00119940 08 00 9F E5                                   LDR             R0, =(unk_16B3A8 - 0x119950)
.text:00119944 10 40 2D E9                                   STMFD           SP!, {R4,LR}
.text:00119948 00 00 8F E0                                   ADD             R0, PC, R0 ; unk_16B3A8 ; env
.text:0011994C 24 97 FC EB                                   BL              siglongjmp
.text:0011994C                               ; End of function sub_11993C

The DR output :

53434 recreate_app : looking for 0x6b033198 in frag @ 0x6b033198 (tag 0x76f05a08) 
53435 recreate_app -- found valid state pc 0x76f05a08
53436         translation 0x76f05a08 is post-walk 0x00000000 so not fixing xsp
53437 recreate_app -- found ok pc 0x76f05a08
53438         restoring stolen register to 0x76f8a000
53439 recreate_app_state -- translation is:
53440 priv_mcontext_t @0x6aff49ac
......
53473         eflags = 0x600b0010
53474         pc     = 0x76f05a08
53475         translate_sigcontext: just set frame's eip to 0x76f05a08
53476 Got signal at pc 0x6b033198 in this fragment:
53477 Fragment 1412, tag 0x76f05a08, flags 0x1000030, shared, size 36:
53478 
53479   -------- prefix entry: --------
53480   0x6b033194  e59a0000   ldr    (%r10)[4byte] -> %r0
53481   -------- normal entry: --------
53482   0x6b033198  ec510f1e   mrrc   $0x0f $0x0e %c14 -> %r0 %r1
53483   0x6b03319c  e58a2008   str    %r2 -> +0x08(%r10)[4byte]
53484   0x6b0331a0  e1a0200e   mov    %lr -> %r2
53485   0x6b0331a4  eaffffff   b      $0x6b0331a8 <exit stub 0>
53486   -------- exit stub 0: -------- <target: 0x6af95180> type: ret
53487   0x6b0331a8  e58a1004   str    %r1 -> +0x04(%r10)[4byte]
53488   0x6b0331ac  e3041e10   movw   $0x00004e10 -> %r1
53489   0x6b0331b0  e3461b02   movt   $0x6b02 -> %r1[2byte]
53490   0x6b0331b4  e59af03c   ldr    +0x3c(%r10)[4byte] -> %pc
53491 
53492 Going to receive signal now
53493 get_sigstack_frame_ptr: using frame's xsp 0x7ec48a00
53494         placing frame at 0x7ec48700
53495 execute_handler_from_cache for signal 4
53496         xsp is 0x7ec48700
53497 copy_frame_to_stack: rt=0, src=0x6aff4c90, sp=0x7ec48700
53498 fixup_siginfo: updating si_addr from 0x6b033198 to 0x76f05a08
53499         converted sig=4 rt frame to non-rt frame
53500         copied frame from 0x6aff4c90 to 0x7ec48700
53501 blocked signals are now:
53502         1 = blocked
......
53559         64 = blocked
### 53560 Switching to ARM mode @0x76f0593c
53561         saved xax 0x00000004
53562         set next_tag to 0x76f0593c, resuming in fcache_return
53563 transfer_from_sig_handler_to_fcache_return
53564 sigcontext @0x6aff4d24:
53565         r0  =0x54de219c
53566         r1  =0x00000000
53567         r2  =0x76f574ac
53568         r3  =0x00000008
53569         r4  =0x76f57534
53570         r5  =0x76f573a8
53571         r6  =0x76f575b4
53572         r7  =0x7ec48b18
53573         r8  =0x00000001
53574         r9  =0x7ec48c0c
53575         r10 =0x6afc5000
53576         r11 =0x00000000
53577         r12 =0x76f57410
53578         sp  =0x7ec48700
53579         r14 =0x76c32800
53580         pc  =0x6af94ee0
53581         cpsr=0x600b0030
53582         set next_tag to handler 0x76f0593c, xsp to 0x7ec48700
53583         master_signal_handler 4 returning now to 0x6af94ee0
53584 
53585 Exit from asynch event
53586 
53587 d_r_dispatch: target = 0x76f0593c
53588 
### 53589 interp: start_pc = 0x76f0593c
### 53590   0x76f0593c  1000       asrs   %r0 $0x00000000 -> %r0
### 53591   0x76f0593e  e1a0       b      $0x76f05c82
53592 end_pc = 0x76f05940
53593 
53594 exit_branch_type=0x0 target=0x76f05c82 l->flags=0x1801
53595 Exit cti 0x6b0331c2 is targeting 0x6b0331c8 + 0x0 => 0x6b0331c8
53596 Fragment 1413, tag 0x76f0593c, flags 0x1400030, shared, size 32:
53597 
53598 Entry into F1413(0x76f0593c).0x6b0331c0 (T32)(shared)
53599 
53600 Exit from F1413(0x76f0593c).0x6b0331c2 (T32)(shared)
53601  (target 0x76f05c82 not in cache)
53602 
53603 d_r_dispatch: target = 0x76f05c82
53604 
53605 interp: start_pc = 0x76f05c82
53606   0x76f05c82  e12f       b      $0x76f05ee4
53607 end_pc = 0x76f05c84
53608 
53609 exit_branch_type=0x0 target=0x76f05ee4 l->flags=0x1801
53610 Exit cti 0x6b0331e4 is targeting 0x6b0331e8 + 0x0 => 0x6b0331e8
53611 Fragment 1414, tag 0x76f05c82, flags 0x1400030, shared, size 28:
53612 
53613 Entry into F1414(0x76f05c82).0x6b0331e4 (T32)(shared)
53614 
53615 Exit from F1414(0x76f05c82).0x6b0331e4 (T32)(shared)
53616  (target 0x76f05ee4 not in cache)
53617 
53618 d_r_dispatch: target = 0x76f05ee4
53619 
53620 interp: start_pc = 0x76f05ee4
53621   0x76f05ee4  0102       lsls   %r0 $0x00000004 -> %r2
53622   0x76f05ee6  b3a0       cbz    $0x76f05f52 %r0
53623 end_pc = 0x76f05ee8
53624 
53625 exit_branch_type=0x0 bb->exit_target=0x76f05ee8
53626 convert_to_near_rel: cbz/cbnz opcode
53627 exit_branch_type=0x11 target=0x76f05f52 l->flags=0x11
53628 exit_branch_type=0x0 target=0x76f05ee8 l->flags=0x1001
53629 Exit cti 0x6b033206 is targeting 0x6b033210 + 0x0 => 0x6b033210
53630 Exit cti 0x6b03320c is targeting 0x6b033224 + 0x0 => 0x6b033224
53631 Fragment 1415, tag 0x76f05ee4, flags 0x9400030, shared, size 56:
53632 
53633 Entry into F1415(0x76f05ee4).0x6b033204 (T32)(shared)
53634 
53635 Exit from F1415(0x76f05ee4).0x6b033206 (T32)(shared)
53636  (target 0x76f05f52 not in cache)
53637 
53638 d_r_dispatch: target = 0x76f05f52
53639 
53640 interp: start_pc = 0x76f05f52
53641 SYSLOG_WARNING: Invalid opcode encountered
53642 Invalid Thumb opcode @0x76f05f52: 0xebfc8002
53643 decode: invalid instr at 0x76f05f52
53644 Invalid Thumb opcode @0x76f05f52: 0xebfc8002
53645 decode: invalid instr at 0x76f05f52
53646   0x76f05f52  ebfc 8002  <INVALID>
53647 interp: invalid instr at 0x76f05f52
53648 record_pending_signal(4 at pc 0x76f05f52): signal is currently blocked
53649         action is not SIG_IGN
53650 blocked fatal signal 4 cannot be delayed: terminating
53651 execute_default_action for signal 4
53652 SYSLOG_WARNING: Application /usr/bin/sftp (19343).  Application exception at PC 0x76f05f52.
53653 Signal 4 delivered to application as default action.
53654 Callstack:
53657         0x76f05f52   </usr/lib/libcrypto.so.1.0.0+0x119f52>
53658         0xf8af04b0
53659 
53660 Terminating via kill
53661 SYSLOG_INFORMATION: Stopping application /usr/bin/sftp (19343)
53662 synch with all threads my id = 19343 Giving 4 permission and seeking 3 state
53663 add_process_lock: 0 lock 0x54eb2a7c: name=all_threads_synch_lock(mutex)@/home/runner/work/dynamorio/dynamorio/core/synch      .c:94

2. MRRC instruction lead to receare_app

the above switch to thumb mode incorrectly may be lead to by the mrrc instruction. MRRC instruction raised the SIGILL natively(not under DR). the following output is i run sftp natively under gdb.

./gdb-build/bin/gdb sftp
GNU gdb (GDB) 10.2
Copyright (C) 2021 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "arm-cortexa9_neon-linux-gnueabihf".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from sftp...
(No debugging symbols found in sftp)
(gdb) r
Starting program: /usr/bin/sftp 
### Program received signal SIGILL, Illegal instruction.
### 0x76f7ca08 in _armv7_tick () from /lib/libcrypto.so.1.0.0
(gdb) bt
#0  0x76f7ca08 in _armv7_tick () from /lib/libcrypto.so.1.0.0
#1  0x76ea2934 in OPENSSL_cpuid_setup () from /lib/libcrypto.so.1.0.0
#2  0x76fdefa8 in call_init (l=<optimized out>, argc=argc@entry=1, 
    argv=argv@entry=0x7efffd34, env=env@entry=0x7efffd3c) at dl-init.c:72
#3  0x76fdf104 in call_init (env=<optimized out>, argv=<optimized out>, 
    argc=<optimized out>, l=<optimized out>) at dl-init.c:30
#4  _dl_init (main_map=0x76fff958, argc=1, argv=0x7efffd34, env=0x7efffd3c) at dl-init.c:120
#5  0x76fcfb04 in _dl_start_user () from /lib/ld-linux-armhf.so.3
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
### (gdb) disassemble 0x76f7ca08
### Dump of assembler code for function _armv7_tick:
### => 0x76f7ca08 <+0>: mrrc 15, 1, r0, r1, cr14
###    0x76f7ca0c <+4>: bx lr
End of assembler dump.
(gdb) c
Continuing.
usage: sftp [-1246aCfpqrv] [-B buffer_size] [-b batchfile] [-c cipher]
          [-D sftp_server_path] [-F ssh_config] [-i identity_file] [-l limit]
          [-o ssh_option] [-P port] [-R num_requests] [-S program]
          [-s subsystem | sftp_server] host
       sftp [user@]host[:file ...]
       sftp [user@]host[:dir[/]]
       sftp -b batchfile [user@]host
[Inferior 1 (process 11536) exited with code 01]
(gdb)

The following may useful information to diag this issue which is output by DR with --loglevel 3.

53317 interp: start_pc = 0x76e2b930
53318   0x76e2b930  eb036834   bl     $0x76f05a08 -> %lr
53319         NOT following direct call from 0x76e2b930 to 0x76f05a08
53320 end_pc = 0x76e2b934
53321 
53322 exit_branch_type=0x9 bb->exit_target=0x76f05a08
53323 exit_branch_type=0x9 target=0x76f05a08 l->flags=0x1809
53324 Exit cti 0x6b033178 is targeting 0x6b03317c + 0x0 => 0x6b03317c
53325 Fragment 1411, tag 0x76e2b930, flags 0x1000030, shared, size 36:
53326 
53327 Entry into F1411(0x76e2b930).0x6b033170 (A32)(shared)
53328 
53329 Exit from F1411(0x76e2b930).0x6b033178 (A32)(shared)
53330  (target 0x76f05a08 not in cache)
53331 
53332 d_r_dispatch: target = 0x76f05a08
53333 
### 53334 interp: start_pc = 0x76f05a08
### 53335   0x76f05a08  ec510f1e   mrrc   $0x0f $0x0e %c14 -> %r0 %r1
### 53336   0x76f05a0c  e12fff1e   bx     %lr
53337 end_pc = 0x76f05a10
53338 
53339 exit_branch_type=0x6 bb->exit_target=0x6af95180
53340 emit_fragment: bb use ibl <0x6af95180>
53341 exit_branch_type=0x6 target=0x6af95180 l->flags=0x1006
53342 Exit cti 0x6b0331a4 is targeting 0x6b0331a8 + 0x0 => 0x6b0331a8
53343 Fragment 1412, tag 0x76f05a08, flags 0x1000030, shared, size 36:
53344 
53345 Entry into F1412(0x76f05a08).0x6b033198 (A32)(shared)
53346 
53347 
### 53348 master_signal_handler: thread=19343, sig=4, xsp=0x6aff4c90, retaddr=0x00000004
### 53349 siginfo: sig = 4, pid = 1795371416, status = -1414812757, errno = 0, si_code = 1
53350         r0  =0x00000000
53351         r1  =0x00000000
53352         r2  =0x76f574ac
53353         r3  =0x00000008
53354         r4  =0x76f57534
53355         r5  =0x76f573a8
53356         r6  =0x76f575b4
53357         r7  =0x7ec48b18
53358         r8  =0x00000001
53359         r9  =0x7ec48c0c
53360         r10 =0x6afc5000
53361         r11 =0x00000000
53362         r12 =0x76f57410
53363         sp  =0x7ec48a00
53364         r14 =0x76e2b934
53365         pc  =0x6b033198
53366         cpsr=0x600b0010
53367 handle_nudge_signal: sig=4 code=1 errno=0
53368 record_pending_signal(4) from cache pc 0x6b033198
53369         not certain can delay so handling now
53370         action is not SIG_IGN
53371 add_process_lock: 0 lock 0x6af66dc0: name=synch_lock(mutex)@/home/runner/work/dynamorio/dynamorio/core/synch.c:144
53372 rank=10 owner=19343 owning_dc=0x6afaf040 contended_event=0xffffffff prev=0x00000000
53373 lock count_times_acquired=       1                              0                               0                                    0                               0+2 synch_lock(mutex)@/home/runner/work/dynamorio/dynamorio/core/synch.c:144
### 53374 translate context, thread 19343 at pc_recreatable spot translating
### 53375 recreate_app_state -- translating from:
53376 priv_mcontext_t @0x6aff49ac
53377         r0  = 0x00000000
53378         r1  = 0x00000000
53379         r2  = 0x76f574ac
53380         r3  = 0x00000008
53381         r4  = 0x76f57534
53382         r5  = 0x76f573a8
53383         r6  = 0x76f575b4
53384         r7  = 0x7ec48b18
53385         r8  = 0x00000001
53386         r9  = 0x7ec48c0c
53387         r10 = 0x6afc5000
53388         r11 = 0x00000000
53389         r12 = 0x76f57410
53390         r13 = 0x7ec48a00
53391         r14 = 0x76e2b934
53392         r15 = 0x6b033198
53393         q0  = 0x76f575b4 7ec48b18 00000001 76f70254
53394         q1  = 0x00000000 00000000 00000000 00000000
53395         q2  = 0x00000000 00000000 00000000 00000000
53396         q3  = 0x00000000 00000000 00000000 00000000
53397         q4  = 0x00000000 00000000 00000000 00000000
53398         q5  = 0x00000000 00000000 00000000 00000000
53399         q6  = 0x00000000 00000000 00000000 00000000
53400         q7  = 0x00000000 00000000 00000000 00000000
53401         q8  = 0x00001000 00000000 0000000c 00000000
53402         q9  = 0x0000000d 00000000 00000000 00000000
53403         q10 = 0x00000000 00000000 00000000 00000000
53404         q11 = 0x00000000 00000000 00000000 00000000
53405         q12 = 0x00000000 00000000 00000000 00000000
53406         q13 = 0x00000000 00000000 00000000 00000000
53407         q14 = 0x00000000 00000000 00000000 00000000
53408         q15 = 0x00000000 00000000 00000000 00000000
53409         eflags = 0x600b0010
53410         pc     = 0x6b033198
53411 
53412 building bb instrlist now *********************
53413 
53414 interp: start_pc = 0x76f05a08
53415   0x76f05a08  ec510f1e   mrrc   $0x0f $0x0e %c14 -> %r0 %r1
53416   0x76f05a0c  e12fff1e   bx     %lr
53417 end_pc = 0x76f05a10
53418 
53419 setting cur_pc (for fall-through) to 0x76f05a10
53420 exit_branch_type=0x6 bb->exit_target=0x6af95180
53421 
53422 done building bb instrlist *********************
53423 
53424 recreate_app : pc is in F1412(0x76f05a08)
53425 ilist for recreation:
53426 TAG  0x76f05a08
53427  +0    L3 @0x6afdffe8  ec510f1e   mrrc   $0x0f $0x0e %c14 -> %r0 %r1
53428  +4    m4 @0x6afdfea8  e58a2008   str    %r2 -> +0x08(%r10)[4byte]
53429  +8    m4 @0x6afdebe0  e58a2008   <label>
53430  +8    m4 @0x6afdf708  e1a0200e   mov    %lr -> %r2
53431  +12   L4 @0x6afdfe08  eafe82fc   b      $0x6af95180 <shared_bb_ibl_ret>
53432 END 0x76f05a08
53433 
### 53434 recreate_app : looking for 0x6b033198 in frag @ 0x6b033198 (tag 0x76f05a08)
### 53435 recreate_app -- found valid state pc 0x76f05a0853436         translation 0x76f05a08 is post-walk 0x00000000 so not fixing xsp
53437 recreate_app -- found ok pc 0x76f05a08
53438         restoring stolen register to 0x76f8a000
53439 recreate_app_state -- translation is:
53440 priv_mcontext_t @0x6aff49ac
53441         r0  = 0x00000000
53442         r1  = 0x00000000
53443         r2  = 0x76f574ac
53444         r3  = 0x00000008
53445         r4  = 0x76f57534
53446         r5  = 0x76f573a8
53447         r6  = 0x76f575b4
53448         r7  = 0x7ec48b18
53449         r8  = 0x00000001
53450         r9  = 0x7ec48c0c
53451         r10 = 0x76f8a000
53452         r11 = 0x00000000
53453         r12 = 0x76f57410
53454         r13 = 0x7ec48a00
53455         r14 = 0x76e2b934
53456         r15 = 0x76f05a08
53457         q0  = 0x76f575b4 7ec48b18 00000001 76f70254
53458         q1  = 0x00000000 00000000 00000000 00000000
53459         q2  = 0x00000000 00000000 00000000 00000000
53460         q3  = 0x00000000 00000000 00000000 00000000
53461         q4  = 0x00000000 00000000 00000000 00000000
53462         q5  = 0x00000000 00000000 00000000 00000000
53463         q6  = 0x00000000 00000000 00000000 00000000
53464         q7  = 0x00000000 00000000 00000000 00000000
53465         q8  = 0x00001000 00000000 0000000c 00000000
53466         q9  = 0x0000000d 00000000 00000000 00000000
53467         q10 = 0x00000000 00000000 00000000 00000000
53468         q11 = 0x00000000 00000000 00000000 00000000
53469         q12 = 0x00000000 00000000 00000000 00000000
53470         q13 = 0x00000000 00000000 00000000 00000000
53471         q14 = 0x00000000 00000000 00000000 00000000
53472         q15 = 0x00000000 00000000 00000000 00000000
53473         eflags = 0x600b0010
53474         pc     = 0x76f05a08
53475         translate_sigcontext: just set frame's eip to 0x76f05a08
53476 Got signal at pc 0x6b033198 in this fragment:
53477 Fragment 1412, tag 0x76f05a08, flags 0x1000030, shared, size 36:
53478 
53479   -------- prefix entry: --------
53480   0x6b033194  e59a0000   ldr    (%r10)[4byte] -> %r0
53481   -------- normal entry: --------
53482   0x6b033198  ec510f1e   mrrc   $0x0f $0x0e %c14 -> %r0 %r1
53483   0x6b03319c  e58a2008   str    %r2 -> +0x08(%r10)[4byte]
53484   0x6b0331a0  e1a0200e   mov    %lr -> %r2
53485   0x6b0331a4  eaffffff   b      $0x6b0331a8 <exit stub 0>
53486   -------- exit stub 0: -------- <target: 0x6af95180> type: ret
53487   0x6b0331a8  e58a1004   str    %r1 -> +0x04(%r10)[4byte]
53488   0x6b0331ac  e3041e10   movw   $0x00004e10 -> %r1
53489   0x6b0331b0  e3461b02   movt   $0x6b02 -> %r1[2byte]
53490   0x6b0331b4  e59af03c   ldr    +0x3c(%r10)[4byte] -> %pc
53491 
53492 Going to receive signal now
53493 get_sigstack_frame_ptr: using frame's xsp 0x7ec48a00
53494         placing frame at 0x7ec48700
53495 execute_handler_from_cache for signal 4
53496         xsp is 0x7ec48700
53497 copy_frame_to_stack: rt=0, src=0x6aff4c90, sp=0x7ec48700
53498 fixup_siginfo: updating si_addr from 0x6b033198 to 0x76f05a08
53499         converted sig=4 rt frame to non-rt frame
53500         copied frame from 0x6aff4c90 to 0x7ec48700
53501 blocked signals are now:
53502         1 = blocked
53503         2 = blocked
53504         3 = blocked
53505         4 = blocked
53506         6 = blocked
53507         9 = blocked
53508         10 = blocked
53509         12 = blocked

some other information

i have open a session in the dynamorio users forum in this link [](https://groups.google.com/g/dynamorio-users/c/E_4R3GbwhiA) ,they suggested that I file an issue here.

derekbruening commented 2 years ago

So when the SIGILL arrives cpsr ends in 0x10 as expected for arm mode:

53348 master_signal_handler: thread=19343, sig=4, xsp=0x6aff4c90, retaddr=0x00000004
53349 siginfo: sig = 4, pid = 1795371416, status = -1414812757, errno = 0, si_code = 1
53350         r0  =0x00000000
53351         r1  =0x00000000
53352         r2  =0x76f574ac
53353         r3  =0x00000008
53354         r4  =0x76f57534
53355         r5  =0x76f573a8
53356         r6  =0x76f575b4
53357         r7  =0x7ec48b18
53358         r8  =0x00000001
53359         r9  =0x7ec48c0c
53360         r10 =0x6afc5000
53361         r11 =0x00000000
53362         r12 =0x76f57410
53363         sp  =0x7ec48a00
53364         r14 =0x76e2b934
53365         pc  =0x6b033198
53366         cpsr=0x600b0010

But when DR goes to deliver the signal it is now 0x30 (thumb mode):

53563 transfer_from_sig_handler_to_fcache_return
53564 sigcontext @0x6aff4d24:
53565         r0  =0x54de219c
53566         r1  =0x00000000
53567         r2  =0x76f574ac
53568         r3  =0x00000008
53569         r4  =0x76f57534
53570         r5  =0x76f573a8
53571         r6  =0x76f575b4
53572         r7  =0x7ec48b18
53573         r8  =0x00000001
53574         r9  =0x7ec48c0c
53575         r10 =0x6afc5000
53576         r11 =0x00000000
53577         r12 =0x76f57410
53578         sp  =0x7ec48700
53579         r14 =0x76c32800
53580         pc  =0x6af94ee0
53581         cpsr=0x600b0030

So who changed it?

derekbruening commented 2 years ago

Ah ok it's b/c fcache_return is Thumb, so that's just to run DR's generated code properly:

    /* We're going to our fcache_return gencode which uses DEFAULT_ISA_MODE */
    set_pc_mode_in_cpsr(sc, DEFAULT_ISA_MODE);

However, it seems to set it too early: and in fact it's set twice. The earlier one should just be removed it looks like as it causes the ISA mode to be drawn from the DR thumb target instead of the app handler target. So that's removing lines 5716-5719 from core/unix/signal.c https://github.com/DynamoRIO/dynamorio/blob/master/core/unix/signal.c#L5716. Does that fix the problem?

But, there is further weirdness as @zenhumany pointed at on the list https://groups.google.com/g/dynamorio-users/c/E_4R3GbwhiA/m/Hzi3dcrMBAAJ:

3667     dcontext->next_tag = canonicalize_pc_target(dcontext, next_pc);
3668     IF_ARM(dr_set_isa_mode(dcontext, get_pc_mode_from_cpsr(sc), NULL));

The first one sets the dcontext isa mode from the next_pc; the second overrides it with the mode from the cpsr. But the cpsr is what we interrupted; we want the mode of the target, which may be a signal handler. I think that if you register a Thumb mode signal handler you have to pass LSB=1. And for re-execution of the same interrupted PC: I don't remember whether the kernel sets LSB=1 when it reports the PC?? Maybe it doesn't and that's what this is trying to handle.

zenhumany commented 2 years ago

Thanks for your response!

1. Compile drrun and run sftp successfully

according to your advice that's removing lines 5716-5719 from core/unix/signal.c and compiler the DR, Run sftp with compiled drrun，it can success runing.

2. Run other program, may crash

but when i using this drrun run other program,

./drrun test-stack
some information output like this:
<-- parent 31041 forked child 31868 -->
### <Application test-stack (31041).  Internal Error: DynamoRIO debug check failure: /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/dispatch.c:486 dr_get_isa_mode(dcontext) == FRAG_ISA_MODE(targetf->flags) IF_X64(|| (dr_get_isa_mode(dcontext) == DR_ISA_IA32 && !FRAG_IS_32(targetf->flags) && DYNAMO_OPTION(x86_to_x64)))
(Error occurred @6087 frags in tid 31778)
version 8.0.0, custom build

some information output by DR with -loglevel 3

7212 ret_bb 30% cache density, cache_lines_used=8 (0KB), minimum needed 2 (0KB)
   7213 make_writable: pc 0x448bc000 -> 0x448bc000-0x448be000 0
   7214 
   7215 master_signal_handler: thread=5948, sig=11, xsp=0x44a65c90, retaddr=0x0000000b
   7216 siginfo: sig = 11, pid = 1150013021, status = -1414812757, errno = 0, si_code = 2
   7217         r0  =0x00000001
   7218         r1  =0x44888138
   7219         r2  =0x00000001
   7220         r3  =0x448bc000
   7221         r4  =0x54e60000
   7222         r5  =0x448bce6c
   7223         r6  =0x76feacf0
   7224         r7  =0x44a43b30
   7225         r8  =0x54e60000
   7226         r9  =0x76bfed1c
   7227         r10 =0x44a46000
   7228         r11 =0x54bdc447
   7229         r12 =0x448dc3a4
   7230         sp  =0x44a43b30
   7231         r14 =0x54bf415f
   7232         pc  =0x54cd0bb2
###    7233         cpsr=0x60010030
   7234 computing memory target for 0x54cd0bb2 causing SIGSEGV, kernel claims it is 0x448bce5d
   7235 fault_address: 0x448bce5d
   7236 memory operand 0 has address 0x448bce5d and size 1
   7237 For SIGSEGV at cache pc 0x54cd0bb2, computed target write 0x448bce5d
   7238         faulting instr: strb   %r2[1byte] -> +0x0e5d(%r3)[1byte]
   7239 add_process_lock: 0 lock 0x54e6d604: name=report_buf_lock(mutex)@/work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/utils.c:1998
7240 rank=88 owner=5948 owning_dc=0x448ddf60 contended_event=0xffffffff prev=0x00000000
   7241 lock count_times_acquired=       1                              0                               0                              0                               0+2 report_buf_lock(mutex)@/work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/utils.c:1998
   7242 SYSLOG_CRITICAL: Application /opt/nextev/bin/uds-stack (4112).  DynamoRIO internal crash at PC 0x54cd0bb2.  Please report this at http://dynamorio.org/issues/.  Program aborted.
   7243 Received SIGSEGV at pc 0x54cd0bb2 in thread 5948
   7244 Base: 0x54b4b000
   7245 Registers:  r0 =0x00000001 r1 =0x44888138 r2 =0x00000001 r3 =0x448bc000
   7246         r4 =0x54e60000 r5 =0x448bce6c r6 =0x76feacf0 r7 =0x44a43b30
   7247         r8 =0x54e60000 r9 =0x76bfed1c r10=0x44a46000 r11=0x54bdc447
   7248         r12=0x448dc3a4 r13=0x44a43b30 r14=0x54bf415f r15=0x54cd0bb2
   7249         eflags=0x60010030
   7250 version 8.0.0, custom build
derekbruening commented 2 years ago

Use lines with triple backtics to delimit literal output

derekbruening commented 2 years ago

https://github.com/DynamoRIO/dynamorio/issues/5233#issuecomment-982434928 has two different issues:

  1. An assert dispatch.c:486 dr_get_isa_mode(dcontext) == FRAG_ISA_MODE(targetf->flags) IF_X64(|| (dr_get_isa_mode(dcontext) == DR_ISA_IA32 && !FRAG_IS_32(targetf->flags) && DYNAMO_OPTION(x86_to_x64))) Does this happen without the signal.c line removal?

  2. A DR crash at -loglevel 3. For a DR crash, a callstack is the best thing to debug. Please use gdb and load libdynamorio symbols to get a callstack.

zenhumany commented 2 years ago

1. Crash at different points during gdb

when use gdb to debug dr, it may crash at different points.

2. crash point 1

dr crash call stack

using gdb debug DR, the crash call stack like following:

Thread 3 "test-stack" received signal SIGSEGV, Segmentation fault.
[Switching to LWP 2471]
0x54c2fbb2 in protect_generated_code (code_in=0x479b2000, writable=true)
    at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/arch/arch.c:1518
1518    /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/arch/arch.c: No such file or directory.
(gdb) bt
#0  0x54c2fbb2 in protect_generated_code (code_in=0x479b2000, writable=true)
    at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/arch/arch.c:1518
#1  0x54c39452 in update_indirect_branch_lookup (dcontext=0x479d5dc0)
    at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/arch/emit_utils_shared.c:3304
#2  0x54c2fa36 in update_generated_hashtable_access (dcontext=0x479d5dc0)
    at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/arch/arch.c:1493
#3  0x54af20a2 in hashtable_ibl_resized_custom (dcontext=0x479d5dc0, table=0x479d6b34, old_capacity=129, 
    old_table=0x47b815c0, old_table_unaligned=0x47b815a8, old_ref_count=4294967295, old_table_flags=150)
    at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/fragment.c:1071
#4  0x54aea98a in hashtable_ibl_check_size (dcontext=0x479d5dc0, table=0x479d6b34, add_now=1, add_later=0)
    at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/hashtablex.h:1162
#5  0x54ae9a3a in hashtable_ibl_add (dcontext=0x479d5dc0, e=..., table=0x479d6b34)
    at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/hashtablex.h:780
#6  0x54afbc82 in fragment_add_ibl_target_helper (dcontext=0x479d5dc0, f=0x47a7fad8, ibl_table=0x479d6b34)
    at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/fragment.c:4060
#7  0x54afc682 in fragment_add_ibl_target (dcontext=0x479d5dc0, 
    tag=0x76ca640c "\212\001p\343|\004\v\345p$\033\345\310\064\033\345\\\006", branch_type=IBL_RETURN)
    at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/fragment.c:4231
#8  0x54b3f78e in dispatch_exit_fcache (dcontext=0x479d5dc0)
    at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/dispatch.c:1161
#9  0x54b3f68a in dispatch_enter_dynamorio (dcontext=0x479d5dc0)
    at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/dispatch.c:1011
#10 0x54b3b4a8 in d_r_dispatch (dcontext=0x479d5dc0) at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/dispatch.c:160
#11 0x76ca640c in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

   0x54c2fba6 <+360>:   add r3, pc
   0x54c2fba8 <+362>:   mov r0, r3
   0x54c2fbaa <+364>:   bl  0x54b50bcc <d_r_internal_error>
   0x54c2fbae <+368>:   ldr r3, [r7, #16]
   0x54c2fbb0 <+370>:   ldrb    r2, [r7, #3]
**=> 0x54c2fbb2 <+372>: strb.w  r2, [r3, #3677] ; 0xe5d**
   0x54c2fbb6 <+376>:   nop
   0x54c2fbb8 <+378>:   adds    r7, #24
   0x54c2fbba <+380>:   mov sp, r7
   0x54c2fbbc <+382>:   pop {r4, r5, r7, pc}
   0x54c2fbbe <+384>:   nop
   0x54c2fbc0 <+386>:   subs.w  r0, r0, #9961472    ; 0x980000
   0x54c2fbc4 <+390>:   lsls    r4, r5, #4
   0x54c2fbc6 <+392>:   movs    r0, r0
   0x54c2fbc8 <+394>:   stmia   r3!, {r1, r6, r7}
   0x54c2fbca <+396>:   movs    r0, r2
   0x54c2fbcc <+398>:   stmia   r0!, {r2, r3}
   0x54c2fbce <+400>:   movs    r0, r2
   0x54c2fbd0 <+402>:   lsls    r4, r4, #10
   0x54c2fbd2 <+404>:   movs    r0, r0
   0x54c2fbd4 <+406>:   stmia   r2!, {r2, r4, r5, r6, r7}
   0x54c2fbd6 <+408>:   movs    r0, r2
   0x54c2fbd8 <+410>:   itee    cs
   0x54c2fbda <+412>:   movcs   r0, r2
End of assembler dump.
(gdb) info registers 
r0             0x1                 1
r1             0x4797e138          1201135928
r2             0x1                 1
r3             0x479b2000          1201348608
r4             0x54dbf000          1423699968
r5             0x479b2e6c          1201352300
r6             0x14                20
r7             0x47b6eb30          1203170096
r8             0x54dbf000          1423699968
r9             0x0                 0
r10            0x47b71000          1203179520
r11            0x54b3b447          1421063239
r12            0x479d239c          1201480604
sp             0x47b6eb30          0x47b6eb30
lr             0x54b5315f          1421160799
pc             0x54c2fbb2          0x54c2fbb2 <protect_generated_code+372>
cpsr           0x60070030          1611071536
fpscr          0x0                 0

Source code corresponding to the crash point

the source code line 1518 corresponding to the crash point

1496 void
1497 protect_generated_code(generated_code_t *code_in, bool writable)
1498 {
1499     /* i#936: prevent cl v16 (VS2010) from combining the two code->writable
1500      * stores into one prior to the change_protection() call and from
1501      * changing the conditionally-executed stores into always-executed
1502      * stores of conditionally-determined values.
1503      */
1504     volatile generated_code_t *code =
1505         (generated_code_t *)vmcode_get_writable_addr((byte *)code_in);
1506     if (TEST(SELFPROT_GENCODE, DYNAMO_OPTION(protect_mask)) &&
1507         code->writable != writable) {
1508         byte *genstart = (byte *)PAGE_START(code->gen_start_pc);
1509         if (!writable) {
1510             ASSERT(code->writable);
1511             code->writable = writable;
1512         }
1513         STATS_INC(gencode_prot_changes);
1514         change_protection(vmcode_get_writable_addr(genstart),
1515                           code->commit_end_pc - genstart, writable);
1516         if (writable) {
1517             ASSERT(!code->writable);
**1518             code->writable = writable;**
1519         }
1520     }
1521 }

3. crash point 2

[Switching to LWP 3921]
0x54c15e84 in our_isspace (c=32)
    at /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/io.c:366
366 /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/io.c: No such file or directory.
(gdb) c
Continuing.
<Application test-stack (29984).  Internal Error: DynamoRIO debug check failure: /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/dispatch.c:486 dr_get_isa_mode(dcontext) == FRAG_ISA_MODE(targetf->flags) IF_X64(|| (dr_get_isa_mode(dcontext) == DR_ISA_IA32 && !FRAG_IS_32(targetf->flags) && DYNAMO_OPTION(x86_to_x64)))
(Error occurred @6081 frags in tid 3921)
version 8.0.0, custom build
-no_dynamic_options -logdir './' -loglevel 3 -code_api -stack_size 56K -signal_stack_size 32K -max_elide_jmp 0 -max_elide_call 0 -early_inject -emulate_brk -no_inline_ignored_syscalls -native_exec_default_list '' -no_native_exec_managed_code -no_indcall2direct 
0x54b3b447 0x78af04b0
/home/ironman/build_arm/lib32/debug/libdynamorio.so=0x54aaa000>
[LWP 3990 exited]
[LWP 29984 exited]
[LWP 3955 exited]
[LWP 3833 exited]
[LWP 4048 exited]
[LWP 3914 exited]
[LWP 3921 exited]

the following is the output of dr with -loglevel 3

    4591 interp: start_pc = 0x76fb2938
   4592   0x76fb2938  e3a07001   mov    $0x00000001 -> %r7
   4593   0x76fb293c  e1a06000   mov    %r0 -> %r6
   4594   0x76fb2940  e1a00008   mov    %r8 -> %r0
   4595   0x76fb2944  ebfff2d2   bl     $0x76faf494 -> %lr
   4596         NOT following direct call from 0x76fb2944 to 0x76faf494
   4597 end_pc = 0x76fb2948
   4598 
   4599 exit_branch_type=0x9 bb->exit_target=0x76faf494
   4600 exit_branch_type=0x9 target=0x76faf494 l->flags=0x1809
   4601 Exit cti 0x441cfdfc is targeting 0x441cfe00 + 0x0 => 0x441cfe00
   4602 Fragment 6077, tag 0x76fb2938, flags 0x1000030, shared, size 48:
   4603 
   4604 Entry into F6077(0x76fb2938).0x441cfde8 (A32)(shared)
   4605 
   4606 Exit from F4469(0x76daba94).0x4416dd38 (A32)(shared)
   4607  (target 0x76fb2948 in cache but not lookup table)
   4608 fragment_add_ibl_target tag 0x76fb2948, branch 0, F6078
   4609 fragment_add_ibl_target added F6078(0x76fb2948), branch 0, to ret_bb, on exit from 0x4416dd38
   4610 add_ibl_target: shared BB F6078(0x76fb2948) added
   4611 
   4612 d_r_dispatch: target = 0x76fb2948
   4613 Entry into F6078(0x76fb2948).0x441cfe1c (A32)(shared)
   4614 
   4615 Exit from F6078(0x76fb2948).0x441cfe20 (A32)(shared)
   4616  (target 0x76fb2a04 not in cache)
   4617 
   4618 d_r_dispatch: target = 0x76fb2a04
   4619 Entry into F6079(0x76fb2a04).0x441cfe58 (A32)(shared)   4620 
   4621 Exit from F1700(0x76dad3c8).0x440fdaec (A32)(shared)
   4622  (target 0x76fb2a38 in cache but not lookup table)
   4623 fragment_add_ibl_target tag 0x76fb2a38, branch 0, F6080
   4624 fragment_add_ibl_target added F6080(0x76fb2a38), branch 0, to ret_bb, on exit from 0x440fdaec
   4625 add_ibl_target: shared BB F6080(0x76fb2a38) added
   4626 
   4627 d_r_dispatch: target = 0x76fb2a38
   4628 Entry into F6080(0x76fb2a38).0x441cfe84 (T32)(shared)
   4629 
   4630 add_process_lock: 0 lock 0x54dcc604: name=report_buf_lock(mutex)@/work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/utils.c:1998
   4631 rank=88 owner=3921 owning_dc=0x4407e2a0 contended_event=0xffffffff prev=0x00000000
   4632 lock count_times_acquired=       1                              0                               0                              0                               0+2 report_buf_lock(mutex)@/work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/utils.c:1998
   4633 
   4634 master_signal_handler: thread=3921, sig=12, xsp=0x44269c90, retaddr=0x0000000c
   4635 siginfo: sig = 12, pid = 29984, status = 0, errno = 0, si_code = -6
   4636         r0  =0x00000020
   4637         r1  =0x00000000
   4638         r2  =0x54d62c9d
   4639         r3  =0x00000020
   4640         r4  =0x54dbf000
   4641         r5  =0x442479fc   4642         r6  =0x76ffacf0
   4643         r7  =0x442478f8
   4644         r8  =0x54dbf000
   4645         r9  =0x75afed1c
   4646         r10 =0x4424a000
   4647         r11 =0x54b3b447
   4648         r12 =0x54df9f84
   4649         sp  =0x442478f8
   4650         r14 =0x54c16189
   4651         pc  =0x54c15e84
   4652         cpsr=0x60070030
   4653 handle_suspend_signal: suspended now
   4654 handle_suspend_signal: awake now
   4655         master_signal_handler 12 returning now to 0x54c15e84
   4656 
   4657 SYSLOG_ERROR: Application test-stack (29984).  Internal Error: DynamoRIO debug check failure: /work/dynamorio/dynamorio-cronbuild-8.0.18942-1/core/dispatch.c:486 dr_get_isa_mode(dcontext) == FRAG_ISA_MODE(targetf->flags) IF_X64(|| (dr_get_isa_mode(dcontext) == DR_ISA_IA32 && !FRAG_IS_32(targetf->flags) && DYNAMO_OPTION(x86_to_x64)))
   4658 (Error occurred @6081 frags in tid 3921)
   4659 version 8.0.0, custom build
derekbruening commented 2 years ago

For your posts with verbatim output: use lines with triple backtics to delimit literal output like this:

literal output
derekbruening commented 2 years ago

We are about to put out a 9.0 release of DR. We may not have time to figure everything out here for that -- but should we include the signal.c removal of lines 5716-5719? That is why the first question at https://github.com/DynamoRIO/dynamorio/issues/5233#issuecomment-982814458 is whether that assert in dispatch.c happens without the signal.c change, or is it a new problem introduced by the signal.c change?

zenhumany commented 2 years ago

So far, I can't judge whether that assert in dispatch.c happens is introduced by removal of lines 5716-5719. Because if i am not removal of lines 5716-5719, the test-stack program crash at the same point with sftp. After removal of lines 5716-5719, sftp can run successfully. The test-stack program causes the assert in dispatch.c to occur.

derekbruening commented 2 years ago

So if I first work around QEMU bugs (https://github.com/DynamoRIO/dynamorio/issues/4719#issuecomment-802004640) to get the linux.signalNNNN tests working under QEMU, and then I augments the linux.signalNNNN tests to vary whether the main code and the signal handler are arm or thumb, I can repro a problem:

Entry into F1627(0x3be045c4).0x441630f8 (A32)(shared)
master_signal_handler: thread=1396672, sig=11, xsp=0x44123c88, retaddr=0x0000000b
        cpsr=0x600e0010
transfer_from_sig_handler_to_fcache_return
        cpsr=0x600e0030
Entry into F1599(0x3be041b4).0x44162a1c (A32)(shared)
SYSLOG_ERROR: Application /home/bruening/dr/git/build_a32_dbg_tests/suite/tests/bin/linux.signal1000 (1396672).  Internal Error: DynamoRIO debug check failure: /home/bruening/dr/git/src/core/dispatch.c:482 dr_get_isa_mode(dcontext) == FRAG_ISA_MODE(targetf->flags) IF_X64(|| (dr_get_isa_mode(dcontext) == DR_ISA_IA32 && !FRAG_IS_32(targetf->flags) && DYNAMO_OPTION(x86_to_x64)))

Removing the 5716-5719 lines solves that one, but another one fails. Removing the dr_set_isa_mode from the cpsr in transfer_from_sig_handler_to_fcache_return() fixes that one.

I think that should address this issue. I will post a PR; it would be great if you could test that patch.

derekbruening commented 2 years ago

@zenhumany if you could try the patch in PR #5242

zenhumany commented 2 years ago

Thank you for your hard work. I have compiler the DR with the patch #5242.But this issue still exists. The following is the crash information. when use DR with -loglevel 3 to run the test-stack program, it may crash at different points.

1.crash point 1

10468 Exit from F4436(0x76c8d320).0x475a551c (A32)(shared)
  10469  (cannot link F4436->F5638) (cannot link shared to private)
  10470 
  10471 d_r_dispatch: target = 0x76c8d390
  10472 Entry into F5638(0x76c8d390).0x4763d058 (A32)
  10473 
  10474 Exit from F5638(0x76c8d390).0x4763d070 (A32)
  10475  (cannot link F5638->F4438) (cannot link shared to private)
  10476 
  10477 d_r_dispatch: target = 0x76c8d3a0
  10478 Entry into F4438(0x76c8d3a0).0x475a5554 (A32)(shared)
  10479 
  10480 Exit from F4436(0x76c8d320).0x475a551c (A32)(shared)
  10481  (cannot link F4436->F5638) (cannot link shared to private)
  10482 
  10483 d_r_dispatch: target = 0x76c8d390
  10484 Entry into F5638(0x76c8d390).0x4763d058 (A32)
  10485 
  10486 Exit from F5638(0x76c8d390).0x4763d070 (A32)
  10487  (cannot link F5638->F4438) (cannot link shared to private)
  10488 
  10489 d_r_dispatch: target = 0x76c8d3a0
  10490 Entry into F4438(0x76c8d3a0).0x475a5554 (A32)(shared)
  10491 
  10492 Exit from F5656(0x76c78d4c).0x4760171c (A32)(shared)
  10493  (block ends with syscall)
  10494 Entry into do_syscall to execute a non-ignorable system call
  10495 system call 335
10496 
  10497 master_signal_handler: thread=1992, sig=12, xsp=0x4763ac90, retaddr=0x0000000c
  10498 siginfo: sig = 12, pid = 32176, status = 0, errno = 0, si_code = -6
  10499         r0  =0xfffffffc
  10500         r1  =0x76b57d1c
  10501         r2  =0x76b57d9c
  10502         r3  =0x00000000
  10503         r4  =0x76b57cd8
  10504         r5  =0x76b57ce0
  10505         r6  =0x00000006
  10506         r7  =0x0000014f
  10507         r8  =0x76b57d1c
  10508         r9  =0x76b57d1c
  10509         r10 =0x4761b000
  10510         r11 =0x0000003b
  10511         r12 =0x00000000
  10512         sp  =0x76b57cd8
  10513         r14 =0x76b58930
  10514         pc  =0x47492486
  10515         cpsr=0x80010030
  10516 handle_suspend_signal: suspended now
  10517 @@@@@@@@@@@@@@@@@@ SUSPENDED BY THREAD 2156 synch_with_thread @@@@@@@@@@@@@@@@@@
  10518 handle_suspend_signal: awake now
  10519         master_signal_handler 12 returning now to 0x47492486
  10520 
  10521 Exit from system call
  10522 post syscall: sysnum=0x0000014f, result=0xfffffffc (-4)
  10523 Unexpected failure of non-ignorable syscall 335
  10524 finished handling system call
  10525 
  10526 d_r_dispatch: target = 0x76c78d6c
  10527 Entry into F5660(0x76c78d6c).0x47601824 (A32)(shared)10528 
  10529 add_process_lock: 0 lock 0x54de4604: name=report_buf_lock(mutex)@/work/dynamorio_fix_thumb/dynamorio/core/utils.c:1998
  10530 rank=88 owner=1992 owning_dc=0x474b2f60 contended_event=0xffffffff prev=0x00000000
  10531 lock count_times_acquired=       1                              0                               0                              0                               0+2 report_buf_lock(mutex)@/work/dynamorio_fix_thumb/dynamorio/core/utils.c:1998
  10532 SYSLOG_ERROR: Application uds-stack (32176).  Internal Error: DynamoRIO debug check failure: /work/dynamorio_fix_thumb/dynamorio/core/dispatch.c:486 dr_get_isa_mode(dcontext) == FRAG_ISA_MODE(targetf->flags) IF_X64(|| (dr_get_isa_mode(dcontext) == DR_ISA_IA32 && !FRAG_IS_32(targetf->flags) && DYNAMO_OPTION(x86_to_x64)))
  10533 (Error occurred @7272 frags in tid 1992)
  10534 version 8.0.18967, custom build

crash point2

1862 ret_bb 31% cache density, cache_lines_used=4 (0KB), minimum needed 1 (0KB)
   1863 make_writable: pc 0x4c371000 -> 0x4c371000-0x4c373000 0
   1864 add_process_lock: 0 lock 0x54e29604: name=report_buf_lock(mutex)@/work/dynamorio_fix_thumb/dynamorio/core/utils.c:1998
   1865 rank=88 owner=28523 owning_dc=0x4c39a8c0 contended_event=0xffffffff prev=0x00000000
   1866 lock count_times_acquired=       1                              0                               0                              0                               0+2 report_buf_lock(mutex)@/work/dynamorio_fix_thumb/dynamorio/core/utils.c:1998
   1867 SYSLOG_ERROR: Application uds-stack (26545).  Internal Error: DynamoRIO debug check failure: /work/dynamorio_fix_thumb/dynamorio/core/arch/arch.c:1517 !code->writable
   1868 (Error occurred @5990 frags in tid 28523)
derekbruening commented 2 years ago

Signal 12 (SIGUSR2) is used for suspending threads for synch_with_thread. This looks like a new scenario; I would argue that the original issue is indeed fixed. I would suggest filing a new issue for the ISA mode assert with synch_with_thread. Why is it doing a synch? Is it a flush? A reset?

For the other assert !code->writable that seems rather separate. Maybe make the new issue about getting this "uds-stack" program to work; or else two separate issues on for each assert.

zenhumany commented 2 years ago

I agree with your that the original issue is indeed fixed. i filing two new issues #5243 for ISA mode assert with synch_with_thread and #5244 for assert !code->writable