標籤:arguments sys ror error event bool lin stopped taobao
【問題現象】
啟動《神馬搜尋》APP,系統高機率重啟。
【分析問題】main日誌中,除了app的NE日誌合zygote重啟日誌外,無其他明顯的異常:
11-05 15:14:51.824 11179 11179 I DEBUG : pid: 23631, tid: 23693, name: ucsdk_setup >>> com.uc.searchbox <<<11-05 15:14:51.824 11179 11179 I DEBUG : signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr --------11-05 15:14:51.914 11179 11179 I DEBUG : r0 00000000 r1 00005c8d r2 00000006 r3 0000000011-05 15:14:51.914 11179 11179 I DEBUG : r4 00000006 r5 00000016 r6 00005c8d r7 0000010c11-05 15:14:51.914 11179 11179 I DEBUG : r8 7b6aa841 r9 00000000 sl 4173fc38 fp 71be6c9011-05 15:14:51.914 11179 11179 I DEBUG : ip 7c27cf8c sp 7a0da770 lr 400b5169 pc 400c410c cpsr 000f001...11-05 15:14:54.224 24116 24116 D AndroidRuntime:11-05 15:14:54.224 24116 24116 D AndroidRuntime: >>>>>> AndroidRuntime START com.android.internal.os.ZygoteInit <<<<<<11-05 15:14:55.054 232 232 I ServiceManager: service ‘simphonebook.0‘ died11-05 15:14:55.054 232 232 I ServiceManager: service ‘simphonebook‘ died11-05 15:14:55.054 232 232 I ServiceManager: service ‘iphonesubinfo.0‘ died
核心日誌中也沒有異常。
用stace查看zygote:
[email protected]:/ # ps |grep zygote root 18987 1 863628 60724 ffffffff 400a9854 S zygote [email protected]:/ # strace -CttTip 18987 15:14:53.566312 [400c2648] madvise(0x71aac000, 16384, 0xc /* MADV_??? */) = -1 EINVAL (Invalid argument) <0.000037>15:14:53.566502 [400c25a8] mmap2(NULL, 1040384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x71ab0000 <0.000041>15:14:53.566696 [400c2648] madvise(0x71ab0000, 1040384, 0xc /* MADV_??? */) = -1 EINVAL (Invalid argument) <0.000037>15:14:53.566942 [400c2628] mprotect(0x71ab0000, 4096, PROT_NONE) = 0 <0.000045>15:14:53.567160 [400c39d8] clone(child_stack=0x71baddc8, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM) = 24057 <0.000065>15:14:53.567381 [400c3a84] futex(0x71baddd0, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000083>15:14:53.567671 [400c3a84] futex(0x4174612c, FUTEX_WAKE_PRIVATE, 2147483647) = 1 <0.000052>15:14:53.567882 [400c3a84] futex(0x41746128, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000081>15:14:53.568118 [400c3a84] futex(0x6fccbdf0, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000063>15:14:53.568346 [400c211c] getpgid(0x4b30) = 18987 <0.000039>15:14:53.568542 [400c231c] setpgid(24049, 18987) = 0 <0.000039>15:14:53.568768 [400c3538] sendmsg(50, {msg_name(0)=NULL, msg_iov(1)=[{"\0\0]?", 4}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 4 <0.000061>15:14:53.569092 [400c3538] sendmsg(50, {msg_name(0)=NULL, msg_iov(1)=[{"\0", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 1 <0.000053>15:14:53.569426 [400c2854] select(51, [10 50], NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted) <0.328044>15:14:53.905148 [????????] +++ killed by SIGHUP +++
zygote原來是被SIGHUP給kill掉的!
zygote是root許可權,一般app無法在使用者態發送signal來殺死root的app,所以把問題的範圍縮小到核心代碼中。
在核心代碼中搜尋SIGHUP,發現如下代碼很可疑:
@kernel/kernel/exit.cstatic voidkill_orphaned_pgrp(struct task_struct *tsk, struct task_struct *parent){ struct pid *pgrp = task_pgrp(tsk); struct task_struct *ignored_task = tsk; if (!parent) parent = tsk->real_parent; else ignored_task = NULL; if (task_pgrp(parent) != pgrp && task_session(parent) == task_session(tsk) && will_become_orphaned_pgrp(pgrp, ignored_task) && has_stopped_jobs(pgrp)) { __kill_pgrp_info(SIGHUP, SEND_SIG_PRIV, pgrp); __kill_pgrp_info(SIGCONT, SEND_SIG_PRIV, pgrp); }}
開啟kernel的tracing開關
# echo 1 > /d/tracing/events/signal/enable# cat /d/tracing/trace_pipe <...>-9083 [003] d..3 88396.530478: signal_generate: sig=1 errno=0 code=128 comm=chmod pid=9083 grp=1 res=0 <...>-9083 [003] d..3 88396.530567: signal_generate: sig=1 errno=0 code=128 comm=ipayGphone:push pid=9024 grp=1 res=0 <...>-9083 [003] d..3 88396.530728: signal_generate: sig=1 errno=0 code=128 comm=m.taobao.taobao pid=8889 grp=1 res=0 <...>-9083 [003] d..3 88396.530891: signal_generate: sig=1 errno=0 code=128 comm=id.AlipayGphone pid=8824 grp=1 res=0 <...>-9083 [003] d..3 88396.531072: signal_generate: sig=1 errno=0 code=128 comm=.searchbox:push pid=8752 grp=1 res=0 ... <...>-9083 [003] dN.3 88396.535071: signal_generate: sig=1 errno=0 code=128 comm=zygote pid=11158 grp=1 res=0 <...>-9083 [003] dN.3 88396.535073: signal_generate: sig=18 errno=0 code=128 comm=chmod pid=9083 grp=1 res=1 <...>-9083 [003] dN.3 88396.535075: signal_generate: sig=18 errno=0 code=128 comm=ipayGphone:push pid=9024 grp=1 res=1 <...>-9083 [003] dN.3 88396.535077: signal_generate: sig=18 errno=0 code=128 comm=m.taobao.taobao pid=8889 grp=1 res=1 <...>-9083 [003] dN.3 88396.535079: signal_generate: sig=18 errno=0 code=128 comm=id.AlipayGphone pid=8824 grp=1 res=1 <...>-9083 [003] dN.3 88396.535081: signal_generate: sig=18 errno=0 code=128 comm=.searchbox:push pid=8752 grp=1 res=1 ... <...>-9083 [003] dN.3 88396.535363: signal_generate: sig=18 errno=0 code=128 comm=com.miui.core pid=11542 grp=1 res=1 <...>-9083 [003] dN.3 88396.535365: signal_generate: sig=18 errno=0 code=128 comm=ndroid.systemui pid=11522 grp=1 res=1 <...>-9083 [003] dN.3 88396.535368: signal_generate: sig=18 errno=0 code=128 comm=system_server pid=11430 grp=1 res=1 <...>-9083 [003] dN.3 88396.535370: signal_generate: sig=18 errno=0 code=128 comm=zygote pid=11158 grp=1 res=1
從log中能清楚的看到,這個9083線程給包括zygote在內的所有進程發送SIGHUP(1)和SIGCONT(18)。
這就能進一步確定問題點可能就是這個kill_orphaned_pgrp(),
這個函數是進程退出流程中發現自己成了“孤兒進程”時才會調用的。
下一步只需要監控fork、exec、exit等系統調用即可。
開啟fork、exec、exit的tracing開關,並抓取tracing log:
# echo 1 > /d/tracing/events/sched/sched_process_fork/enable# echo 1 > /d/tracing/events/sched/sched_process_exec/enable# echo 1 > /d/tracing/events/sched/sched_process_exit/enable# cat /d/tracing/trace_pipe <...>-9024 [003] ...1 88396.515526: sched_process_fork: comm=ipayGphone:push pid=9024 child_comm=ipayGphone:push child_pid=9080 <...>-9080 [001] ...1 88396.525226: sched_process_exec: filename=/system/bin/sh pid=9080 old_pid=9080 <...>-9080 [001] ...1 88396.527560: sched_process_fork: comm=sh pid=9080 child_comm=sh child_pid=9083 <...>-9083 [003] ...1 88396.528224: sched_process_exec: filename=/system/bin/chmod pid=9083 old_pid=9083 <...>-9080 [001] ...1 88396.528496: sched_process_exit: comm=sh pid=9080 prio=120 <...>-9083 [003] ...1 88396.530442: sched_process_exit: comm=chmod pid=9083 prio=120 <...>-9083 [003] d..3 88396.530478: signal_generate: sig=1 errno=0 code=128 comm=chmod pid=9083 grp=1 res=0 <...>-9083 [003] d..3 88396.530567: signal_generate: sig=1 errno=0 code=128 comm=ipayGphone:push pid=9024 grp=1 res=0 <...>-9083 [003] d..3 88396.530728: signal_generate: sig=1 errno=0 code=128 comm=m.taobao.taobao pid=8889 grp=1 res=0 <...>-9083 [003] d..3 88396.530891: signal_generate: sig=1 errno=0 code=128 comm=id.AlipayGphone pid=8824 grp=1 res=0 <...>-9083 [003] d..3 88396.531072: signal_generate: sig=1 errno=0 code=128 comm=.searchbox:push pid=8752 grp=1 res=0 <...>-9083 [003] d..3 88396.531088: signal_generate: sig=1 errno=0 code=128 comm=om.uc.searchbox pid=8596 grp=1 res=0 <...>-9083 [003] d..3 88396.531146: signal_generate: sig=1 errno=0 code=128 comm=encent.mobileqq pid=7818 grp=1 res=0 <...>-9083 [003] d..3 88396.531201: signal_generate: sig=1 errno=0 code=128 comm=viders.calendar pid=7797 grp=1 res=0 <...>-9083 [003] d..3 88396.531258: signal_generate: sig=1 errno=0 code=128 comm=ndroid.calendar pid=7772 grp=1 res=0 <...>-9083 [003] d..3 88396.531261: signal_generate: sig=1 errno=0 code=128 comm=com.miui.player pid=18654 grp=1 res=0 <...>-9083 [003] d..3 88396.531340: signal_generate: sig=1 errno=0 code=128 comm=id.thememanager pid=18636 grp=1 res=0 <...>-9083 [003] d..3 88396.531343: signal_generate: sig=1 errno=0 code=128 comm=ugreport:remote pid=15473 grp=1 res=0
從log中我們可以看到:
1、9083是chmod進程,是它在執行exit時發送signal給所有進程的。
2、chmod(9083)進程的父進程是sh(9080),這個sh(9080)fork完chmod(9083)後先退出。
3、sh(9080)正是阿里系應用com.eg.android.AlipayGphone應用的ipayGphone:push(9024)線程建立的。
這個log和之前的推理完全吻合,且多次驗證後都是相同的時序。
我們再看看kill_orphaned_pgrp()發送SIGHUP的幾個條件:
1、task_pgrp(parent) != pgrp
由chmod(9083)的父進程sh(9080)已經退出,因此它就會被託管到init(1),它的parent是init。
init的pgrp是init自己,
而zygote(所有其他被init fork出來的native服務都相同)被init fork出來後,會調用setpgid()將自己的pgrp設定成自己:
@system/core/init.cppvoid service_start(struct service *svc, const char *dynamic_args){ ... pid_t pid = fork(); if (pid == 0) { ... setpgid(0, getpid());
zygote的子孫進程如沒有顯式調用setpgid(),則他們的pgrp都是zygote,如chmod。
因此這判斷條件是滿足的,不過要注意,必須是chmod在退出前,它的父進程sh要先退出,不然這個條件不會得到滿足。
2、task_session(parent) == task_session(tsk)
Android下一般所有進程的session都指向init進程,所以這個條件也滿足
3、will_become_orphaned_pgrp(pgrp, ignored_task)
static int will_become_orphaned_pgrp(struct pid *pgrp, struct task_struct *ignored_task){ struct task_struct *p; do_each_pid_task(pgrp, PIDTYPE_PGID, p) { if ((p == ignored_task) || (p->exit_state && thread_group_empty(p)) || is_global_init(p->real_parent)) // 這裡排除了zygote,因為zygote的父進程是init continue; if (task_pgrp(p->real_parent) != pgrp && task_session(p->real_parent) == task_session(p)) return 0; } while_each_pid_task(pgrp, PIDTYPE_PGID, p); return 1;}
這個函數在遍曆當前進程組內的所有進程(除了zygote),如果它的父進程的pgrp合當前進程的pgrp不一樣,則返回0,否則返回1。
前面已經說過,zygote的子孫進程,他們的pgrp都是zygote,因此,這個函數必然返回1,條件滿足。
4、has_stopped_jobs(pgrp)
這個條件是判斷進程組內有沒有stop的進程,而出現問題時,前台有《神馬搜尋》在NE,
出現NE時Debuggerd進程會stop目標進程,然後再列印目標進程的tombstone。
因此這個條件也是有可能滿足的。
看起來四個條件都能滿足,其中2、3是必然條件,而1、4得有一定機率能滿足。
為了提高複現機率,自己寫了個app將1、4做成必然條件:
@HelloAndroid.java
public class HelloAndroid extends Activity { private static final String LOG_TAG = "PARK"; static { try { System.loadLibrary("helloandroid"); } catch (UnsatisfiedLinkError e) { e.printStackTrace(); } } public static native void native_function(); @Override public void onCreate(Bundle savedInstanceState) { super.onCreate(savedInstanceState); setContentView(R.layout.main); native_function(); while(true) { try { Thread.sleep(1000); } catch(Exception e) { } } }}@com_xl_helloandroid.cppstatic void native_function(){ int child0= fork(); if(child0 > 0) { int stop_proc = fork(); if(stop_proc > 0) { kill(stop_proc,19); // 製造stop進程來滿足條件4 } else { while(true) { LOGD("stop_proc loop"); sleep(1); } } } else { int child1 = fork(); if(child1 > 0) { LOGD("parent..exit"); // 父進程退出,子進程的父進程會變成init,滿足條件1 exit(-1); } else { LOGD("child"); sleep(5); LOGD("child exit.."); exit(-1); } }}
編出APK後,在NEXUS4 4.4版本和NEXUS5 5.1.1、6.0版本上都能必現問題。
不過這個APK放到64位機器上卻不能複現問題,原來64位機器上有兩個zygote。
32位APP的父進程是zygote32,64位APP的父進程是zygote64。
但無論是32位APP還是64位APP,他們的pgrp都是zygote64。
因為在zygote在收到ActivityManagerService的socket請求,fork出子進程後,要修改子進程的pgrp。
@framework/base/core/java/com/android/internal/os/ZygoteConnection.java private boolean handleParentProc(int pid, FileDescriptor[] descriptors, FileDescriptor pipeFd, Arguments parsedArgs) { if (pid > 0) { setChildPgid(pid); } if (descriptors != null) { for (FileDescriptor fd: descriptors) { IoUtils.closeQuietly(fd); } } private void setChildPgid(int pid) { // Try to move the new child into the peer‘s process group. try { Os.setpgid(pid, Os.getpgid(peer.getPid())); } catch (ErrnoException ex) { // This exception is expected in the case where // the peer is not in our session // TODO get rid of this log message in the case where // getsid(0) != getsid(peer.getPid()) Log.i(TAG, "Zygote: setpgid failed. This is " + "normal if peer is not in our session"); } }
這裡的peer.getPid()是system_server的pid。
system_server的pgid是zygote64,因此所有APP的pgrp被設定成zygote64。
我們再回過頭來看條件3:
static int will_become_orphaned_pgrp(struct pid *pgrp, struct task_struct *ignored_task){ struct task_struct *p; do_each_pid_task(pgrp, PIDTYPE_PGID, p) { if ((p == ignored_task) || (p->exit_state && thread_group_empty(p)) || is_global_init(p->real_parent)) continue; if (task_pgrp(p->real_parent) != pgrp && task_session(p->real_parent) == task_session(p)) return 0; } while_each_pid_task(pgrp, PIDTYPE_PGID, p); return 1;}
在遍曆zygote64進程組時,必然有進程不滿足下面這個條件:
task_pgrp(p->real_parent) != pgrp
因為對於32位APP來說,它的父進程是zygote32,而zygote32的pgrp是它自己。
所以在64位機器上,這個條件是必然不滿足的,所以也不會重啟。
到此,所有的疑惑都已經解決了,給aosp反饋問題,但收到的回複是暫時不改。
我們也決定不改,原因有如下幾點:
1、這個問題是app的特殊行為引起的。
2、時間視窗實際上很小是tombstone的時間長度,只不過因為我們加的調試代碼,把tombstone的時間長度拉長了,導致問題的機率增加。
3、64位下不會有問題。
後面遇到問題,再去考慮如何修複吧。
Linux漏洞引起zygote重啟問題分析報告