CTS問題分析4
9888 ワード
CTS/GTS問題分析4
問題の初探査
テストコマンド:run cts-m CtsosTestCases-t android.os.cts.SeccompTest#testIsolatedServicePolicy
エラースタック:07-24 00:50:08.627 2633 4112 I Activity Management:Process android.os.cts (pid 13402) has died: vis SF 07-24 00:50:08.627 2022 2022 I Zygote : Process 13402 exited due to signal (31) 07-24 00:50:08.627 13379 13399 I TestRunner: failed: testIsolatedServicePolicy(android.os.cts.SeccompTest) 07-24 00:50:08.627 13379 13399 I TestRunner: ----- begin exception ----- 07-24 00:50:08.628 2633 4112 I AutoStartManagerService: MIUILOG- Reject RestartService packageName :android.os.cts uid : 10148 07-24 00:50:08.628 5696 5801 D PowerKeeper.Event: notifyAMProcDied pacakageName: android.os.cts, pid:13402 07-24 00:50:08.628 13379 13399 I TestRunner: android.os.DeadObjectException
肝心なのはProcess 13402 exited due to signal(31)でsignal 31による問題が発生したため、テストプロセスが殺された.signal 31はSIGSYSを代表し、bad system callを呼び出してcase failを招いたが、bugreportにtombstoneがなく、スタックが見えず、syscallが呼び出されたものが見つからず、syscallがどこで呼び出されたかによる問題である.
テスト中にtracing_を開くon,実行:
echo 1 >/d/tracing/events/signal/enable echo 1 >/d/tracing/tracing_on cat trace_pipe echo 0 >/d/tracing/tracing_on <...>-14399 [001] d..2 923.002473: signal_generate: sig=31 errno=1 code=458753 comm=Binder:14381_3 pid=14399 grp=0 res=0
<...>-14399 [001] d..2 923.002511: signal_deliver: sig=31 errno=1 code=458753 sa_handler=0 sa_flags=0
<...>-14381 [000] d..2 923.002953: signal_deliver: sig=9 errno=0 code=0 sa_handler=0 sa_flags=0
08-01 22:05:17.549 2342 5098 I ActivityManager: Start proc 14381:android.os.cts/u0i1 for service android.os.cts/.SeccompTest$IsolatedService caller=android.os.cts
キー:1つのテストcaseは2つのプロセスを開始し、そのうちの1つのテストプロセスはsig=31を発行し、テストプロセスandroidを引き起こす.os.ctsが殺され、プログラムが終了したが、これはsignal 31の影響であり、さらなる情報が見えないことを証明するしかない.
もんだいぶんせき
しかしやはり上の呼び出しスタックは見えず、まずはseccomp_send_Sigsysプラスlogstatic void seccomp_send_sigsys(int syscall, int reason)
{
struct siginfo info;
memset(&info, 0, sizeof(info));
info.si_signo = SIGSYS;
info.si_code = SYS_SECCOMP;
info.si_call_addr = (void __user *)KSTK_EIP(current);
info.si_errno = reason;
info.si_arch = syscall_get_arch();
info.si_syscall = syscall;
printk("syscall = %d",syscall);
dump_stack();
}
<4>[ 560.550830] syscall = 120
<4>[ 560.550888] CPU: 2 PID: 13457 Comm: Binder:13442_2 Tainted: G W O 3.18.31-perf-g23a16ea #1
<4>[ 560.550912] Hardware name: Qualcomm Technologies, Inc. MSM8953 QRD SKU3 (DT)
<0>[ 560.550927] Call trace:
<4>[ 560.550961] [] dump_backtrace+0x0/0x24c
<4>[ 560.550981] [] show_stack+0x20/0x28
<4>[ 560.551003] [] dump_stack+0x80/0xa4
<4>[ 560.551025] [] seccomp_send_sigsys+0xbc/0x104
<4>[ 560.551042] [] seccomp_phase1+0x154/0x22c
<4>[ 560.551060] [] __secure_computing+0x18/0x40
<4>[ 560.551081] [] syscall_trace_enter+0x44/0x1e8
これでカーネルスタックしか見えませんが、さらにsyscall=120によるエラーが表示されますが、これはあまり役に立たず、SIGSYS信号に応答して呼び出しスタックを完全に捕まえる必要があります.
そこでまず思いついたのは、他の信号を真似てSISGSYS信号を登録し、tombstoneでメッセージを発信することですhttp://gerrit.pt.miui.com/#/c/357188/http://gerrit.pt.miui.com/#/c/357196/上記の2つのchange(system/core/debuggerd&bionic/linker)を使用しても、tombstoneとdebuggerdに関する流れを参照して機能しません.CTS問題分析4拡張-tombstoneの原因をつかむことができない;
しかしSIGSYS信号はcoredumpに応答できることが分かった.#define sig_kernel_coredump(sig) siginmask(sig, SIG_KERNEL_COREDUMP_MASK)
431#define SIG_KERNEL_COREDUMP_MASK (\
432 rt_sigmask(SIGQUIT) | rt_sigmask(SIGILL) | \
433 rt_sigmask(SIGTRAP) | rt_sigmask(SIGABRT) | \
434 rt_sigmask(SIGFPE) | rt_sigmask(SIGSEGV) | \
435 rt_sigmask(SIGBUS) | rt_sigmask(SIGSYS) | \
436 rt_sigmask(SIGXCPU) | rt_sigmask(SIGXFSZ) | \
437 SIGEMT_MASK
簡単だcoredumpを直接つかめばいいadb shell setprop persist.debug.trace 1
adb shell setenforce 0
テストを実行し、/data/coreのcoredumpを取り出します.
次に、以下の手順に従って操作する.にあるhttp://eng.pt.miui.com/?r=eng&dir=/symbols対応するromのsymbolsをダウンロードし、ローカルに解凍します.2.実行gdb、gdbはromソース(prebuilts/gdb/linux-x 86/bin/gdb)で見つけることができ、実行ソースルートディレクトリ/prebuilts/gdb/linux-x 86/bin/gdb./gdb 3.app_をロードprocess実行プログラム、32ビットアプリケーションであればapp_をロードprocess 32,64ビットアプリケーションapp_のロードprocess 64は、ダウンロードされたsymbolsにあり、gdbで実行される実行可能プログラム:(gdb)file out/target/product/****/symbols/system/bin/app_process32 4.coredumpをロードし、gdbで実行:(gdb)core!system!bin!app_process32.5358.dboxed_process0 5.symbolsを設定し、gdbで実行:(gdb)set sysroot out/target/product/sagit/symbls/6.このときdebug環境はすでに構築されており、gdbを通じてdebug native crash(gdb) bt
#0 sched_getscheduler () at bionic/libc/arch-arm64/syscalls/sched_getscheduler.S:9
#1 0x0000007f9d641d2c in android::os::statistics::PerfEventReporter::beginReportPerfEvent (env=env@entry=0x7f91c1c900, threadPriorityInfo=...)
at out/target/product/mido/obj/SHARED_LIBRARIES/libandroid_runtime_intermediates/android/os/statistics/PerfEventReporter.cpp:60
#2 0x0000007f9d642b10 in android::os::statistics::reportConditionSatisfied (env=0x7f91c1c900, monitorId=548042869504, awakenReason=1, beginUptimeMs=, endUptimeMs=)
at out/target/product/mido/obj/SHARED_LIBRARIES/libandroid_runtime_intermediates/android/os/statistics/JavaVMSupervisionCallBacks.cpp:317
#3 0x0000007f99b53ee8 in art::Monitor::ReportConditionSatisfied (self=0x7f91c35c00, monitor=, wait_awaken_ms=553640, wait_start_ms=, awaken_reason=) at art/runtime/monitor.cc:439
#4 art::Monitor::Wait (this=, self=, ms=, ns=, interruptShouldThrow=, why=art::kWaiting) at art/runtime/monitor.cc:1018
#5 0x000000007060d84c in java.lang.Thread.sleep () from /home/weijuncheng/cts/ /HQ-23018/out/target/product/mido/symbols/system/framework/arm64/boot.oat
#6 0x000000007060d688 in java.lang.Thread.sleep () from /home/weijuncheng/cts/ /HQ-23018/out/target/product/mido/symbols/system/framework/arm64/boot.oat
#7 0x000000007060d294 in java.lang.Thread.sleep () from /home/weijuncheng/cts/ /HQ-23018/out/target/product/mido/symbols/system/framework/arm64/boot.oat
#8 0x0000007f998acaec in art_quick_invoke_static_stub () at art/runtime/arch/arm64/quick_entrypoints_arm64.S:1542
#9 0x0000007f998b9534 in art::ArtMethod::Invoke (this=0x6f520180, self=0x7f91c35c00, args=0x7f920d9a04, args_size=8, result=0x7f920d9bf8, shorty=0x702c1dc4 "VJ") at art/runtime/art_method.cc:291
#10 0x0000007f99a67c44 in art::interpreter::ArtInterpreterToCompiledCodeBridge (self=0x7f91c35c00, caller=0x7f8c5242c8, code_item=0x700939c0 , shadow_frame=0x7f920d99c0, result=0x7f920d9bf8)
at art/runtime/interpreter/interpreter_common.cc:538f
これで呼び出しスタックが明らかになり、threadが呼び出されます.sleep時にパフォーマンスドットがsyscall(sched_getscheduler)を呼び出したことによる問題
問題のまとめ
tombstoneを生成する信号セットはcoredumpの信号セットとは異なり、前者は後者のサブセットである.
問題の拡張
なぜコードを修正した後tombstoneが生成しないのかを調査する.
まずテストを実行します.signal trace logは次のとおりです.Binder:28925_3-28943 [002] d..2 83514.980997: signal_generate: sig=31 errno=1 code=458753 comm=Binder:28925_3 pid=28943 grp=0 res=0
Binder:28925_3-28943 [002] d..2 83514.981028: signal_deliver: sig=31 errno=1 code=458753 sa_handler=7f7cd89d5c sa_flags=18000004
Binder:28925_3-28943 [002] d..2 83514.981146: signal_generate: sig=31 errno=1 code=458753 comm=Binder:28925_3 pid=28943 grp=0 res=0
Binder:28925_3-28943 [002] d..2 83514.981154: signal_deliver: sig=31 errno=1 code=458753 sa_handler=0 sa_flags=10000000
最終的には信号のデフォルト処理フローに移行しcoredumpを生成する
sa_によるとhandler=7 f 7 cd 89 d 5 c、実行時にcat/proc/$(pidof「android.os.cts」)/mapsで見つける7f7cd83000-7f7ce2c000 r-xp 00000000 b3:18 749 /system/bin/linker64
7f7ce2c000-7f7ce2d000 r--p 00000000 00:00 0 [anon:atexit handlers]
7f7ce2d000-7f7ce30000 r--p 000a9000 b3:18 749 /system/bin/linker64
7f7ce30000-7f7ce31000 rw-p 000ac000 b3:18 749 /system/bin/linker64
信号処理関数はlinker 64でodjdumpを介してアセンブリコードを出力し、関連するhandlerを計算した結果、debuggerd_であることが分かった.signal_handler 0000000000006d5c <__dl__zl24debuggerd_signal_handlerip7siginfopv>:
6d5c: a9bb67fa ldmibge fp!, {r1, r3, r4, r5, r6, r7, r8, r9, sl, sp, lr}
6d60: a9015ff8 stmdbge r1, {r3, r4, r5, r6, r7, r8, r9, sl, fp, ip, lr}
6d64: a90257f6 stmdbge r2, {r1, r2, r4, r5, r6, r7, r8, r9, sl, ip, lr}
6d68: a9034ff4 stmdbge r3, {r2, r4, r5, r6, r7, r8, r9, sl, fp, lr}
6d6c: a9047bfd stmdbge r4, {r0, r2, r3, r4, r5, r6, r7, r8, r9, fp, ip, sp, lr}
しかし、その中にロゴを付けるのは呼び出される気配がなく、これはかなりおかしい.計算ミスを防ぐため、ここに登録されているSIGSYS文の注釈を外してもう一度走り直し、signal trace logを見ますBinder:7495_3-7514 [000] d..2 198.369068: signal_generate: sig=31 errno=1 code=458753 comm=Binder:7495_3 pid=7514 grp=0 res=0
Binder:7495_3-7514 [000] d..2 198.369097: signal_deliver: sig=31 errno=1 code=458753 sa_handler=0 sa_flags=0
<...>-7510 [005] d..2 198.369218: signal_deliver: sig=9 errno=0 code=0 sa_handler=0 sa_flags=0
Signal Catcher-7501 [000] d..2 198.369230: signal_deliver: sig=9 errno=0 code=0 sa_handler=0 sa_flags=0
やはりhandler関連のロゴがなくなったことに気づいた.
では問題は、なぜ信号処理関数を登録したのか、trace logにも出てきたが、実行されていないようだ.追加したlogは出力されずtombstoneは生成されませんでした
<...>-14399 [001] d..2 923.002473: signal_generate: sig=31 errno=1 code=458753 comm=Binder:14381_3 pid=14399 grp=0 res=0
<...>-14399 [001] d..2 923.002511: signal_deliver: sig=31 errno=1 code=458753 sa_handler=0 sa_flags=0
<...>-14381 [000] d..2 923.002953: signal_deliver: sig=9 errno=0 code=0 sa_handler=0 sa_flags=0
static void seccomp_send_sigsys(int syscall, int reason)
{
struct siginfo info;
memset(&info, 0, sizeof(info));
info.si_signo = SIGSYS;
info.si_code = SYS_SECCOMP;
info.si_call_addr = (void __user *)KSTK_EIP(current);
info.si_errno = reason;
info.si_arch = syscall_get_arch();
info.si_syscall = syscall;
printk("syscall = %d",syscall);
dump_stack();
}
<4>[ 560.550830] syscall = 120
<4>[ 560.550888] CPU: 2 PID: 13457 Comm: Binder:13442_2 Tainted: G W O 3.18.31-perf-g23a16ea #1
<4>[ 560.550912] Hardware name: Qualcomm Technologies, Inc. MSM8953 QRD SKU3 (DT)
<0>[ 560.550927] Call trace:
<4>[ 560.550961] [] dump_backtrace+0x0/0x24c
<4>[ 560.550981] [] show_stack+0x20/0x28
<4>[ 560.551003] [] dump_stack+0x80/0xa4
<4>[ 560.551025] [] seccomp_send_sigsys+0xbc/0x104
<4>[ 560.551042] [] seccomp_phase1+0x154/0x22c
<4>[ 560.551060] [] __secure_computing+0x18/0x40
<4>[ 560.551081] [] syscall_trace_enter+0x44/0x1e8
#define sig_kernel_coredump(sig) siginmask(sig, SIG_KERNEL_COREDUMP_MASK)
431#define SIG_KERNEL_COREDUMP_MASK (\
432 rt_sigmask(SIGQUIT) | rt_sigmask(SIGILL) | \
433 rt_sigmask(SIGTRAP) | rt_sigmask(SIGABRT) | \
434 rt_sigmask(SIGFPE) | rt_sigmask(SIGSEGV) | \
435 rt_sigmask(SIGBUS) | rt_sigmask(SIGSYS) | \
436 rt_sigmask(SIGXCPU) | rt_sigmask(SIGXFSZ) | \
437 SIGEMT_MASK
adb shell setprop persist.debug.trace 1
adb shell setenforce 0
(gdb) bt
#0 sched_getscheduler () at bionic/libc/arch-arm64/syscalls/sched_getscheduler.S:9
#1 0x0000007f9d641d2c in android::os::statistics::PerfEventReporter::beginReportPerfEvent (env=env@entry=0x7f91c1c900, threadPriorityInfo=...)
at out/target/product/mido/obj/SHARED_LIBRARIES/libandroid_runtime_intermediates/android/os/statistics/PerfEventReporter.cpp:60
#2 0x0000007f9d642b10 in android::os::statistics::reportConditionSatisfied (env=0x7f91c1c900, monitorId=548042869504, awakenReason=1, beginUptimeMs=, endUptimeMs=)
at out/target/product/mido/obj/SHARED_LIBRARIES/libandroid_runtime_intermediates/android/os/statistics/JavaVMSupervisionCallBacks.cpp:317
#3 0x0000007f99b53ee8 in art::Monitor::ReportConditionSatisfied (self=0x7f91c35c00, monitor=, wait_awaken_ms=553640, wait_start_ms=, awaken_reason=) at art/runtime/monitor.cc:439
#4 art::Monitor::Wait (this=, self=, ms=, ns=, interruptShouldThrow=, why=art::kWaiting) at art/runtime/monitor.cc:1018
#5 0x000000007060d84c in java.lang.Thread.sleep () from /home/weijuncheng/cts/ /HQ-23018/out/target/product/mido/symbols/system/framework/arm64/boot.oat
#6 0x000000007060d688 in java.lang.Thread.sleep () from /home/weijuncheng/cts/ /HQ-23018/out/target/product/mido/symbols/system/framework/arm64/boot.oat
#7 0x000000007060d294 in java.lang.Thread.sleep () from /home/weijuncheng/cts/ /HQ-23018/out/target/product/mido/symbols/system/framework/arm64/boot.oat
#8 0x0000007f998acaec in art_quick_invoke_static_stub () at art/runtime/arch/arm64/quick_entrypoints_arm64.S:1542
#9 0x0000007f998b9534 in art::ArtMethod::Invoke (this=0x6f520180, self=0x7f91c35c00, args=0x7f920d9a04, args_size=8, result=0x7f920d9bf8, shorty=0x702c1dc4 "VJ") at art/runtime/art_method.cc:291
#10 0x0000007f99a67c44 in art::interpreter::ArtInterpreterToCompiledCodeBridge (self=0x7f91c35c00, caller=0x7f8c5242c8, code_item=0x700939c0 , shadow_frame=0x7f920d99c0, result=0x7f920d9bf8)
at art/runtime/interpreter/interpreter_common.cc:538f
Binder:28925_3-28943 [002] d..2 83514.980997: signal_generate: sig=31 errno=1 code=458753 comm=Binder:28925_3 pid=28943 grp=0 res=0
Binder:28925_3-28943 [002] d..2 83514.981028: signal_deliver: sig=31 errno=1 code=458753 sa_handler=7f7cd89d5c sa_flags=18000004
Binder:28925_3-28943 [002] d..2 83514.981146: signal_generate: sig=31 errno=1 code=458753 comm=Binder:28925_3 pid=28943 grp=0 res=0
Binder:28925_3-28943 [002] d..2 83514.981154: signal_deliver: sig=31 errno=1 code=458753 sa_handler=0 sa_flags=10000000
7f7cd83000-7f7ce2c000 r-xp 00000000 b3:18 749 /system/bin/linker64
7f7ce2c000-7f7ce2d000 r--p 00000000 00:00 0 [anon:atexit handlers]
7f7ce2d000-7f7ce30000 r--p 000a9000 b3:18 749 /system/bin/linker64
7f7ce30000-7f7ce31000 rw-p 000ac000 b3:18 749 /system/bin/linker64
0000000000006d5c <__dl__zl24debuggerd_signal_handlerip7siginfopv>:
6d5c: a9bb67fa ldmibge fp!, {r1, r3, r4, r5, r6, r7, r8, r9, sl, sp, lr}
6d60: a9015ff8 stmdbge r1, {r3, r4, r5, r6, r7, r8, r9, sl, fp, ip, lr}
6d64: a90257f6 stmdbge r2, {r1, r2, r4, r5, r6, r7, r8, r9, sl, ip, lr}
6d68: a9034ff4 stmdbge r3, {r2, r4, r5, r6, r7, r8, r9, sl, fp, lr}
6d6c: a9047bfd stmdbge r4, {r0, r2, r3, r4, r5, r6, r7, r8, r9, fp, ip, sp, lr}
Binder:7495_3-7514 [000] d..2 198.369068: signal_generate: sig=31 errno=1 code=458753 comm=Binder:7495_3 pid=7514 grp=0 res=0
Binder:7495_3-7514 [000] d..2 198.369097: signal_deliver: sig=31 errno=1 code=458753 sa_handler=0 sa_flags=0
<...>-7510 [005] d..2 198.369218: signal_deliver: sig=9 errno=0 code=0 sa_handler=0 sa_flags=0
Signal Catcher-7501 [000] d..2 198.369230: signal_deliver: sig=9 errno=0 code=0 sa_handler=0 sa_flags=0