data分区变成只读

chengyake

开发板运行测试脚本，测试uart相关apk时发现data分区在未重启的情况下变成了ro状态，导致apps崩溃。
具体信息如下：
开发板：x3399，android7.1， disable selinux 模式下
apk动作：操作ttyS4写一组数据，读一组，再写一组读一组。
monkey测试脚本动作：
1. adb 覆盖安装apk
2. 进入apk，点击读写按钮（如上所述读写两组数据）
3. 等待10s后重复1步骤。

以上步骤重复3-7小时内，必定复现此问题，相关日志如下：
serial_device:s0 tclass=chr_file permissive=1
[26757.261535] binder: 790:790 transaction failed 29189, size 88-0
[26775.791807] binder: 790:790 transaction failed 29189, size 88-0
[26787.930594] type=1400 audit(1543779602.710:791): avc: denied { write } for pid=1248 comm="com.act.r1_demo" name="ttyS4" dev="tmpfs" ino=10734 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=ubject_r:serial_device:s0 tclass=chr_file permissive=1
[26794.692348] binder: 790:790 transaction failed 29189, size 88-0
[26813.079239] binder: 790:790 transaction failed 29189, size 88-0
[26825.079594] type=1400 audit(1543779639.860:792): avc: denied { write } for pid=1497 comm="com.act.r1_demo" name="ttyS4" dev="tmpfs" ino=10734 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=ubject_r:serial_device:s0 tclass=chr_file permissive=1
[26831.791725] binder: 790:790 transaction failed 29189, size 88-0
[26850.625577] binder: 790:790 transaction failed 29189, size 88-0
[26862.316377] type=1400 audit(1543779677.096:793): avc: denied { write } for pid=1647 comm="com.act.r1_demo" name="ttyS4" dev="tmpfs" ino=10734 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=ubject_r:serial_device:s0 tclass=chr_file permissive=1
[26869.071822] binder: 790:790 transaction failed 29189, size 88-0
[26887.802012] binder: 790:790 transaction failed 29189, size 88-0
[26899.857094] type=1400 audit(1543779714.636:794): avc: denied { write } for pid=1833 comm="com.act.r1_demo" name="ttyS4" dev="tmpfs" ino=10734 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=ubject_r:serial_device:s0 tclass=chr_file permissive=1
[26906.583028] binder: 790:790 transaction failed 29189, size 88-0
[26918.702562] type=1400 audit(1543779733.483:795): avc: denied { write } for pid=1920 comm="com.act.r1_demo" name="ttyS4" dev="tmpfs" ino=10734 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=ubject_r:serial_device:s0 tclass=chr_file permissive=1
[26925.405577] binder: 790:790 transaction failed 29189, size 88-0

chengyake

[26952.189556] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [kworker/u12:2:27158]
[26952.189586] Modules linked in:
[26952.189591]
[26952.189601] CPU: 0 PID: 27158 Comm: kworker/u12:2 Tainted: G        W       4.4.52 #41
[26952.189605] Hardware name: 9tripod RK3399 Development Board (DT)
[26952.189623] Workqueue: events_power_efficient close_delayed_work
[26952.189629] task: ffffffc0da7c0000 ti: ffffffc0e1770000 task.ti: ffffffc0e1770000
[26952.189637] PC is at fib_get_table+0x18/0x38
[26952.189645] LR is at fib4_rule_action+0x58/0x88
[26952.189649] pc : [<ffffff80089fadac>] lr : [<ffffff8008a07744>] pstate: 20000145
[26952.189653] sp : ffffffc0f6ef78f0
[26952.189656] x29: ffffffc0f6ef78f0 x28: 0000000000000308
[26952.189661] x27: ffffffc0db198d00 x26: ffffffc0f6ef7af8
[26952.189666] x25: 0000000000000000 x24: ffffffc0f1b40200
[26952.189671] x23: ffffffc0f6ef7998 x22: ffffffc0f1b40180
[26952.189676] x21: ffffffc0f6ef7a50 x20: ffffffc0f6ef7998
[26952.189681] x19: 00000000fffffff5 x18: 0000000000000034
[26952.189686] x17: 000000000000000e x16: 0000000000000007
[26952.189691] x15: 000000000000000c x14: aaaaaaaaaaaaaaab
[26952.189696] x13: 0000000000000004 x12: 0000000000000003
[26952.189700] x11: 0000000000000000 x10: 0000000000000038
[26952.189705] x9 : 0000000000000001 x8 : 0000000000000000
[26952.189710] x7 : ffffffc0f6ef7af8 x6 : ffffffc0f0c10600
[26952.189715] x5 : 0000000000000000 x4 : ffffff8008a076ec
[26952.189720] x3 : ffffffc0f6ef7998 x2 : 00000000000007f8
[26952.189725] x1 : 00000000000000ff x0 : ffffffc0d77f0c80
[26952.189731]
[26952.189731] PC: 0xffffff80089fad2c:
[26952.189735] ad2c  f9015a60 aa1303e0 94001707 2a0003f4 36fffed4 f9415a60 97fe394f f9015a7f
[26952.189750] ad4c  17fffff0 a94153f3 f94013f5 a8c77bfd d65f03c0 a9be7bfd 910003fd f9000bf3
[26952.189762] ad6c  aa0003f3 94001726 f9415a60 97fe3942 f9015a7f aa1303e0 97fffedc f9400bf3
[26952.189775] ad8c  a8c27bfd d65f03c0 52801fc2 6b1f003f 1a821021 f9415000 d37d1c22 f8626800
[26952.189787] adac  b40000c0 b9401002 6b01005f 54000080 f9400000 17fffffb d2800000 d65f03c0
[26952.189799] adcc  a9b77bfd 90003a64 910003fd a90153f3 2a0103f3 2a0203e1 a9077fbf f9452882
[26952.189811] adec  aa0403f4 f90047a2 12001e62 a9057fbf a9067fbf f90043bf b9007fb3 34000322
[26952.189823] ae0c  3100067f 540002e0 121c0e73 528000a3 7103827f 54000280 f90013a1 52800073
[26952.189837]
[26952.189837] LR: 0xffffff8008a076c4:
[26952.189841] 76c4  35fffee0 f9401fa2 f9452aa1 eb01005f 54000040 97da5209 a94153f3 f94013f5
[26952.189853] 76e4  a8c47bfd d65f03c0 a9bd7bfd 910003fd a90153f3 f90013f5 aa0003f3 3940a002
[26952.189865] 7704  12800c80 71001c5f 540002c0 7100205f 12800180 54000260 7100045f 128002a0
[26952.189878] 7724  54000201 aa0303f4 aa0103f5 97dbabe6 f9402260 b9402661 12800153 97ffcd95
[26952.189889] 7744  b40000c0 f9400682 aa1503e1 b9401a83 97ffdb4a 2a0003f3 97dbac62 2a1303e0
[26952.189902] 7764  a94153f3 f94013f5 a8c37bfd d65f03c0 a9be7bfd 910003fd a90153f3 aa0003f3
[26952.189914] 7784  900015e0 910e4000 aa1303e1 97fdabb3 b140041f aa0003f4 54000069 2a0003f3
[26952.189926] 77a4  14000019 52800001 52801fe2 52800003 97fdab83 37f80220 528fffc1 aa1403e0
[26952.189940]
[26952.189940] SP: 0xffffffc0f6ef7870:
[26952.189944] 7870  f1b40180 ffffffc0 f6ef7998 ffffffc0 f1b40200 ffffffc0 00000000 00000000
[26952.189956] 7890  f6ef7af8 ffffffc0 db198d00 ffffffc0 00000308 00000000 f6ef78f0 ffffffc0
[26952.189968] 78b0  08a07744 ffffff80 f6ef78f0 ffffffc0 089fadac ffffff80 20000145 00000000
[26952.189980] 78d0  00000034 00000000 09146000 ffffff80 00000000 00000080 f0c10600 ffffffc0
[26952.189992] 78f0  f6ef7920 ffffffc0 08973058 ffffff80 f1b40240 ffffffc0 f6ef7a50 ffffffc0
[26952.190004] 7910  f0c10600 ffffffc0 db198d00 ffffffc0 f6ef7970 ffffffc0 08a07370 ffffff80
[26952.190017] 7930  09146000 ffffff80 00000000 00000000 f0c10600 ffffffc0 09255700 ffffff80
[26952.190029] 7950  f1b66000 ffffffc0 09146000 ffffff80 00000000 00000000 db198d00 ffffffc0
[26952.190042]

chengyake

[26955.940185] INFO: rcu_preempt self-detected stall on CPU
[26955.940219]         0-...: (1 GPs behind) idle=21f/140000000000002/0 softirq=2182117/2182117 fqs=3150
[26955.940226]          (t=6300 jiffies g=1293572 c=1293571 q=415)
[26955.940239] Task dump for CPU 0:
[26955.940246] kworker/u12:2   R  running task        0 27158      2 0x00000002
[26955.940273] Workqueue: events_power_efficient close_delayed_work
[26955.940283] Call trace:
[26955.940293] [<ffffff800808852c>] dump_backtrace+0x0/0x1c8
[26955.940300] [<ffffff8008088708>] show_stack+0x14/0x1c
[26955.940310] [<ffffff80080c6b8c>] sched_show_task+0xcc/0xd8
[26955.940318] [<ffffff80080c8de0>] dump_cpu_task+0x40/0x4c
[26955.940326] [<ffffff80080f3dec>] rcu_dump_cpu_stacks+0x88/0xb8
[26955.940333] [<ffffff80080f7590>] rcu_check_callbacks+0x300/0x8b8
[26955.940340] [<ffffff80080fcd80>] update_process_times+0x34/0x60
[26955.940348] [<ffffff800810b2a8>] tick_sched_handle.isra.12+0x54/0x64
[26955.940354] [<ffffff800810b3d8>] tick_sched_timer+0x6c/0xa0
[26955.940360] [<ffffff80080fd7e4>] __hrtimer_run_queues+0x1a0/0x33c
[26955.940366] [<ffffff80080fdea8>] hrtimer_interrupt+0x9c/0x1bc
[26955.940375] [<ffffff80088588d4>] arch_timer_handler_phys+0x2c/0x38
[26955.940382] [<ffffff80080edcfc>] handle_percpu_devid_irq+0xd8/0x1c8
[26955.940388] [<ffffff80080e9920>] generic_handle_irq+0x1c/0x2c
[26955.940393] [<ffffff80080e9c3c>] __handle_domain_irq+0x80/0xac
[26955.940399] [<ffffff8008080e34>] gic_handle_irq+0xbc/0x154
[26955.940404] Exception stack(0xffffffc0f6ef77b0 to 0xffffffc0f6ef78e0)
[26955.940410] 77a0:                                   ffffffc0f6ef77f0 0000008000000000
[26955.940415] 77c0: ffffffc0f6ef7920 ffffff8008972fe0 0000000040000145 ffffffc0f1b40200
[26955.940421] 77e0: ffffffc0f6ef4000 0000000000000000 0000000000000000 00000000ffffffff
[26955.940426] 7800: 0000000000000000 000000000000001e 000000000000001e 0000000000000000
[26955.940432] 7820: ffffffc0d77f0cb0 0000000000000000 0000000000000000 0000000000000001
[26955.940437] 7840: 0000000000000038 0000000000000000 0000000000000003 0000000000000004
[26955.940442] 7860: aaaaaaaaaaaaaaab 000000000000000c 0000000000000007 000000000000000e
[26955.940448] 7880: 0000000000000034 ffffffc0f0ee7c00 ffffffc0f6ef7a50 00000000fffffff5
[26955.940453] 78a0: ffffffc0f1b40180 ffffffc0f6ef7998 ffffffc0f1b40200 0000000000000000
[26955.940459] 78c0: ffffffc0f6ef7af8 ffffffc0db198d00 0000000000000308 ffffffc0f6ef7920
[26955.940464] [<ffffff8008081fb4>] el1_irq+0xb4/0x128
[26955.940471] [<ffffff8008a07370>] __fib_lookup+0x3c/0x68
[26955.940478] [<ffffff80089fb984>] fib_validate_source+0x170/0x388
[26955.940486] [<ffffff80089bd970>] ip_route_input_noref+0x654/0x824
[26955.940492] [<ffffff80089c0654>] ip_rcv_finish+0xa8/0x294
[26955.940497] [<ffffff80089c0cfc>] ip_rcv+0x2b0/0x36c
[26955.940506] [<ffffff8008954cf0>] __netif_receive_skb_core+0x5c8/0x994
[26955.940513] [<ffffff8008955818>] __netif_receive_skb+0x18/0x64
[26955.940519] [<ffffff80089558b8>] netif_receive_skb_internal+0x54/0xb4
[26955.940525] [<ffffff800895625c>] napi_gro_receive+0xb4/0x15c
[26955.940534] [<ffffff8008563d24>] stmmac_poll+0x3d0/0x62c
[26955.940540] [<ffffff8008956af4>] net_rx_action+0x128/0x360
[26955.940549] [<ffffff80080a0190>] __do_softirq+0x174/0x334
[26955.940555] [<ffffff80080a055c>] irq_exit+0x74/0xb4
[26955.940560] [<ffffff80080e9c48>] __handle_domain_irq+0x8c/0xac
[26955.940565] [<ffffff8008080e34>] gic_handle_irq+0xbc/0x154
[26955.940570] Exception stack(0xffffffc0e1773850 to 0xffffffc0e1773980)
[26955.940575] 3840:                                   0000000000000001 ffffff80091c61c8
[26955.940580] 3860: 0000000000000000 ffffff800850bd6c ffffff80085039f4 ffffffc0f0db4e00
[26955.940586] 3880: 0000000000000001 0000000000000176 ffffffc0da7c08d0 ffffffc0e1770000
[26955.940591] 38a0: 0000000000000870 0000000000000000 000000000000000e 0000000000000007
[26955.940597] 38c0: 0000000000000001 ffffff8008bde000 0000000000000007 000000000000000e
[26955.940602] 38e0: 0000000000000048 ffffffc0f0c23800 0000000000000000 0000000000000002
[26955.940608] 3900: ffffffc0f0db4d81 ffffffc0f0db4d81 0000000000000065 0000000000000000
[26955.940613] 3920: 0000000000000002 0000000000000000 0000000000000065 ffffffc0e1773980
[26955.940619] 3940: ffffff8008507480 ffffffc0e1773980 ffffff800850774c 0000000060000145
[26955.940624] 3960: ffffffc0f0c23800 00000000fffffdf4 ffffffffffffffff 0000000000000000
[26955.940629] [<ffffff8008081fb4>] el1_irq+0xb4/0x128
[26955.940637] [<ffffff800850774c>] _regmap_raw_write+0x4d8/0x714
[26955.940642] [<ffffff80085079f0>] _regmap_bus_raw_write+0x68/0x7c
[26955.940648] [<ffffff8008506824>] _regmap_write+0xf4/0x140
[26955.940653] [<ffffff8008506928>] _regmap_update_bits+0xb8/0xf0
[26955.940660] [<ffffff8008507e00>] regmap_update_bits_check+0x48/0x68
[26955.940667] [<ffffff800892ef28>] snd_soc_component_update_bits+0x30/0x68
[26955.940674] [<ffffff8008925ec8>] dapm_seq_run_coalesced+0x148/0x1b0
[26955.940680] [<ffffff8008926dac>] dapm_seq_run+0xe8/0x394
[26955.940686] [<ffffff8008927d74>] dapm_power_widgets+0x580/0x8ec
[26955.940692] [<ffffff8008929fdc>] snd_soc_dapm_stream_event+0x78/0x94
[26955.940699] [<ffffff800892b0b0>] close_delayed_work+0x44/0x5c
[26955.940707] [<ffffff80080b2b3c>] process_one_work+0x218/0x3e0
[26955.940713] [<ffffff80080b353c>] worker_thread+0x2e8/0x404
[26955.940719] [<ffffff80080b7e6c>] kthread+0xe8/0xf0
[26955.940725] [<ffffff8008082690>] ret_from_fork+0x10/0x40
[26964.333572] mmc1: yake flag Timeout waiting for hardware interrupt.
[27006.493907] mmcblk1: timed out sending r/w cmd command, card status 0x900
[27006.493935] mmcblk1: not retrying timeout
[27006.493954] blk_update_request: I/O error, dev mmcblk1, sector 13703768
[27006.493967] blk_update_request: I/O error, dev mmcblk1, sector 13703776
[27006.493975] blk_update_request: I/O error, dev mmcblk1, sector 13703784
[27006.493983] blk_update_request: I/O error, dev mmcblk1, sector 13703792
[27006.493990] blk_update_request: I/O error, dev mmcblk1, sector 13703800
[27018.489766] binder: 790:790 transaction failed 29189, size 88-0
[27028.405635] type=1400 audit(1543779843.186:796): avc: denied { write } for pid=2031 comm="com.act.r1_demo" name="ttyS4" dev="tmpfs" ino=10734 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=ubject_r:serial_device:s0 tclass=chr_file permissive=1
[27035.139331] binder: 790:790 transaction failed 29189, size 88-0

chengyake

系统重启，或adb命令重新挂载，可恢复成rw。

lxz

1、做一个实验 ，不安装apk 时候使用mount命令看下data分区状态 ，再安装apk之后的状态对比下
2、monkey测试里面填加一个mount data分区的命令

qingfeng623

lxz 发表于 2018-12-24 18:17
1、做一个实验 ，不安装apk 时候使用mount命令看下data分区状态 ，再安装apk之后的状态对比下
2、monkey测 ...

1,正常状态，不管是不是安装apk，mount 得到的data状态如下：
/dev/block/dm-1 on /data type f2fs (rw,seclabel,nosuid,nodev,noatime,nodiratime,background_gc=on,discard,user_xattr,inline_xattr,inline_data,extent_cache,active_logs=6)
一旦遇到应用程序的IO异常，data分区变如下
/dev/block/dm-1 on /data type f2fs (ro,seclabel,nosuid,nodev,noatime,nodiratime,background_gc=off,discard,user_xattr,inline_xattr,inline_data,extent_cache,active_logs=6
)

qingfeng623

lxz 发表于 2018-12-24 18:17
1、做一个实验 ，不安装apk 时候使用mount命令看下data分区状态 ，再安装apk之后的状态对比下
2、monkey测 ...

另外，2、monkey测试里面填加一个mount data分区的命令
这个是怎么操作？只用过比较初级的monkey测试。不太理解你提到的是怎么样一条命令。

lxz

qingfeng623 发表于 2018-12-25 18:16
1,正常状态，不管是不是安装apk，mount 得到的data状态如下：
/dev/block/dm-1 on /data type f2fs (rw,s ...

一旦遇到应用程序的IO异常,是什么程序io口异常 ，以我们的经验，data分析一般都是可以可读可写的，不会变成这个ro的状态

lxz

qingfeng623 发表于 2018-12-25 18:17
另外，2、monkey测试里面填加一个mount data分区的命令
这个是怎么操作？只用过比较初级的monkey测试。不 ...

关于data分区的挂载，你可以看看init.rc这个里面的实现过程