[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID:
<PH0PR02MB731916ECDB6C613665863B6CFFAA2@PH0PR02MB7319.namprd02.prod.outlook.com>
Date: Wed, 24 Jul 2024 14:21:26 +0000
From: Yuvaraj Ranganathan <yrangana@....qualcomm.com>
To: "linux-fscrypt@...r.kernel.org" <linux-fscrypt@...r.kernel.org>,
"linux-fsdevel@...r.kernel.org" <linux-fsdevel@...r.kernel.org>,
"linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>
Subject: Software encryption at fscrypt causing the filesystem access
unresponsive
Hello developers,
We are trying to validate a Software file based encryption with standard key by disabling Inline encryption and we are observing the adb session is hung.
We are not able to access the same filesystem at that moment.
Please note, we don't see any issues on validating the standard key with Inline encryption HW.
Test:
adb push/pull of 1MB file with a sleep of 1s between each push & pull on the encrypted filesystem for 10 iterations and device going to hung at 7th iterations.
Dump:
[ 1694.844307] INFO: task systemd-journal:575 blocked for more than 120 seconds.
[ 1694.852455] Tainted: G W O 6.6.33-debug #1
[ 1694.859301] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1694.868128] task:systemd-journal state:D stack:0 pid:575 ppid:1 flags:0x00000801
[ 1694.868147] Call trace:
[ 1694.868153] __switch_to+0xf0/0x16c
[ 1694.868175] __schedule+0x334/0x980
[ 1694.868184] schedule+0x5c/0xf8
[ 1694.868194] wait_transaction_locked+0x7c/0xcc
[ 1694.868208] add_transaction_credits+0x130/0x338
[ 1694.868218] start_this_handle+0xf0/0x52c
[ 1694.868227] jbd2__journal_start+0x110/0x24c
[ 1694.868237] __ext4_journal_start_sb+0x114/0x1c4
[ 1694.868250] ext4_dirty_inode+0x38/0x88
[ 1694.868261] __mark_inode_dirty+0x58/0x41c
[ 1694.868274] generic_update_time+0x4c/0x60
[ 1694.868285] touch_atime+0x1bc/0x21c
[ 1694.868294] ovl_update_time+0x50/0x94 [overlay]
[ 1694.868351] touch_atime+0x178/0x21c
[ 1694.868362] ovl_file_accessed.part.0+0x50/0x7c [overlay]
[ 1694.868396] ovl_read_iter+0x180/0x274 [overlay]
[ 1694.868423] vfs_read+0x200/0x2a0
[ 1694.868429] ksys_pread64+0x78/0xbc
[ 1694.868434] __arm64_sys_pread64+0x20/0x2c
[ 1694.868439] invoke_syscall+0x48/0x118
[ 1694.868453] el0_svc_common.constprop.0+0xc8/0xe8
[ 1694.868459] do_el0_svc+0x20/0x2c
[ 1694.868465] el0_svc+0x40/0x120
[ 1694.868473] el0t_64_sync_handler+0x13c/0x158
[ 1694.868479] el0t_64_sync+0x1a0/0x1a4
[ 1694.868487] INFO: task journal-offline:2276 blocked for more than 120 seconds.
[ 1694.876656] Tainted: G W O 6.6.33-debug #1
[ 1694.884212] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1694.893185] task:journal-offline state:D stack:0 pid:2276 ppid:1 flags:0x00000a00
[ 1694.893190] Call trace:
[ 1694.893191] __switch_to+0xf0/0x16c
[ 1694.893195] __schedule+0x334/0x980
[ 1694.893197] schedule+0x5c/0xf8
[ 1694.893199] wait_transaction_locked+0x7c/0xcc
[ 1694.893202] add_transaction_credits+0x130/0x338
[ 1694.893204] start_this_handle+0xf0/0x52c
[ 1694.893206] jbd2__journal_start+0x110/0x24c
[ 1694.893208] __ext4_journal_start_sb+0x114/0x1c4
[ 1694.893211] ext4_dirty_inode+0x38/0x88
[ 1694.893213] __mark_inode_dirty+0x58/0x41c
[ 1694.893215] generic_update_time+0x4c/0x60
[ 1694.893217] file_update_time+0xa0/0xa4
[ 1694.893219] ext4_page_mkwrite+0x84/0x554
[ 1694.893221] do_page_mkwrite+0x58/0xdc
[ 1694.893225] do_wp_page+0x14c/0xe08
[ 1694.893227] __handle_mm_fault+0x5c8/0xce8
[ 1694.893230] handle_mm_fault+0x68/0x2a0
[ 1694.893232] do_page_fault+0x228/0x514
[ 1694.893235] do_mem_abort+0x44/0x94
[ 1694.893238] el0_da+0x30/0xb4
[ 1694.893240] el0t_64_sync_handler+0xe4/0x158
[ 1694.893243] el0t_64_sync+0x1a0/0x1a4
[ 1694.893245] INFO: task journal-offline:2277 blocked for more than 120 seconds.
[ 1694.901766] Tainted: G W O 6.6.33-debug #1
[ 1694.908540] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1694.917324] task:journal-offline state:D stack:0 pid:2277 ppid:1 flags:0x00000a00
[ 1694.917328] Call trace:
[ 1694.917329] __switch_to+0xf0/0x16c
[ 1694.917333] __schedule+0x334/0x980
[ 1694.917335] schedule+0x5c/0xf8
[ 1694.917337] jbd2_log_wait_commit+0xb4/0x14c
[ 1694.917341] jbd2_complete_transaction+0x90/0xd0
[ 1694.917343] ext4_fc_commit+0x400/0x754
[ 1694.917345] ext4_sync_file+0x1d8/0x3c8
[ 1694.917348] vfs_fsync_range+0x34/0x80
[ 1694.917351] ovl_fsync+0x10c/0x124 [overlay]
[ 1694.917363] vfs_fsync_range+0x34/0x80
[ 1694.917365] do_fsync+0x3c/0x84
[ 1694.917367] __arm64_sys_fsync+0x18/0x28
[ 1694.917370] invoke_syscall+0x48/0x118
[ 1694.917372] el0_svc_common.constprop.0+0xc8/0xe8
[ 1694.917375] do_el0_svc+0x20/0x2c
[ 1694.917378] el0_svc+0x40/0x120
[ 1694.917380] el0t_64_sync_handler+0x13c/0x158
[ 1694.917382] el0t_64_sync+0x1a0/0x1a4
[ 1694.917396] INFO: task jbd2/sda6-8:787 blocked for more than 120 seconds.
[ 1694.925099] Tainted: G W O 6.6.33-debug #1
[ 1694.931810] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1694.940558] task:jbd2/sda6-8 state:D stack:0 pid:787 ppid:2 flags:0x00000208
[ 1694.940561] Call trace:
[ 1694.940562] __switch_to+0xf0/0x16c
[ 1694.940564] __schedule+0x334/0x980
[ 1694.940566] schedule+0x5c/0xf8
[ 1694.940567] jbd2_journal_wait_updates+0x68/0xdc
[ 1694.940569] jbd2_journal_commit_transaction+0x184/0x1b4c
[ 1694.940572] kjournald2+0xbc/0x260
[ 1694.940573] kthread+0x118/0x11c
[ 1694.940576] ret_from_fork+0x10/0x20
[ 1694.940583] INFO: task systemd-timesyn:859 blocked for more than 120 seconds.
[ 1694.948628] Tainted: G W O 6.6.33-debug #1
[ 1694.955332] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1694.964088] task:systemd-timesyn state:D stack:0 pid:859 ppid:1 flags:0x00000a00
[ 1694.964090] Call trace:
[ 1694.964091] __switch_to+0xf0/0x16c
[ 1694.964093] __schedule+0x334/0x980
[ 1694.964094] schedule+0x5c/0xf8
[ 1694.964096] wait_transaction_locked+0x7c/0xcc
[ 1694.964098] add_transaction_credits+0x130/0x338
[ 1694.964100] start_this_handle+0xf0/0x52c
[ 1694.964102] jbd2__journal_start+0x110/0x24c
[ 1694.964104] __ext4_journal_start_sb+0x114/0x1c4
[ 1694.964106] ext4_dirty_inode+0x38/0x88
[ 1694.964108] __mark_inode_dirty+0x58/0x41c
[ 1694.964110] ext4_setattr+0x48c/0xa64
[ 1694.964112] notify_change+0x1a8/0x3f8
[ 1694.964114] ovl_setattr+0x114/0x1f0 [overlay]
[ 1694.964121] notify_change+0x1a8/0x3f8
[ 1694.964122] vfs_utimes+0x12c/0x228
[ 1694.964125] do_utimes+0x94/0x178
[ 1694.964127] __arm64_sys_utimensat+0x78/0xd0
[ 1694.964130] invoke_syscall+0x48/0x118
[ 1694.964132] el0_svc_common.constprop.0+0xc8/0xe8
[ 1694.964135] do_el0_svc+0x20/0x2c
[ 1694.964137] el0_svc+0x40/0x120
[ 1694.964139] el0t_64_sync_handler+0x13c/0x158
[ 1694.964141] el0t_64_sync+0x1a0/0x1a4
[ 1694.964179] INFO: task rs:main Q:Reg:2005 blocked for more than 120 seconds.
[ 1694.972145] Tainted: G W O 6.6.33-debug #1
[ 1694.978856] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1694.987612] task:rs:main Q:Reg state:D stack:0 pid:2005 ppid:1 flags:0x00000200
[ 1694.987614] Call trace:
[ 1694.987614] __switch_to+0xf0/0x16c
[ 1694.987617] __schedule+0x334/0x980
[ 1694.987618] schedule+0x5c/0xf8
[ 1694.987620] wait_transaction_locked+0x7c/0xcc
[ 1694.987622] add_transaction_credits+0x130/0x338
[ 1694.987624] start_this_handle+0xf0/0x52c
[ 1694.987626] jbd2__journal_start+0x110/0x24c
[ 1694.987628] __ext4_journal_start_sb+0x114/0x1c4
[ 1694.987630] ext4_dirty_inode+0x38/0x88
[ 1694.987632] __mark_inode_dirty+0x58/0x41c
[ 1694.987634] generic_update_time+0x4c/0x60
[ 1694.987635] file_modified+0xcc/0xd0
[ 1694.987637] ext4_buffered_write_iter+0x58/0x10c
[ 1694.987640] ext4_file_write_iter+0x54/0x69c
[ 1694.987642] do_iter_readv_writev+0xbc/0x14c
[ 1694.987645] do_iter_write+0x94/0x214
[ 1694.987646] vfs_iter_write+0x1c/0x30
[ 1694.987648] ovl_write_iter+0x278/0x300 [overlay]
[ 1694.987654] vfs_write+0x230/0x2f0
[ 1694.987655] ksys_write+0x6c/0xfc
[ 1694.987656] __arm64_sys_write+0x1c/0x28
[ 1694.987658] invoke_syscall+0x48/0x118
[ 1694.987660] el0_svc_common.constprop.0+0xc8/0xe8
[ 1694.987663] do_el0_svc+0x20/0x2c
[ 1694.987665] el0_svc+0x40/0x120
[ 1694.987667] el0t_64_sync_handler+0x13c/0x158
[ 1694.987670] el0t_64_sync+0x1a0/0x1a4
[ 1694.987674] INFO: task kworker/u16:3:2154 blocked for more than 120 seconds.
[ 1694.995628] Tainted: G W O 6.6.33-debug #1
[ 1695.002335] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1695.011094] task:kworker/u16:3 state:D stack:0 pid:2154 ppid:2 flags:0x00000208
[ 1695.011097] Workqueue: writeback wb_workfn (flush-8:0)
[ 1695.011101] Call trace:
[ 1695.011102] __switch_to+0xf0/0x16c
[ 1695.011104] __schedule+0x334/0x980
[ 1695.011105] schedule+0x5c/0xf8
[ 1695.011107] schedule_timeout+0x19c/0x1c0
[ 1695.011110] wait_for_completion+0x78/0x188
[ 1695.011111] fscrypt_crypt_block+0x218/0x25c
[ 1695.011114] fscrypt_encrypt_pagecache_blocks+0x104/0x1b4
[ 1695.011117] ext4_bio_write_folio+0x534/0x7a8
[ 1695.011119] mpage_submit_folio+0x70/0x98
[ 1695.011120] mpage_map_and_submit_buffers+0x158/0x2c8
[ 1695.011122] ext4_do_writepages+0x788/0xbfc
[ 1695.011124] ext4_writepages+0x7c/0xfc
[ 1695.011126] do_writepages+0x8c/0x1c0
[ 1695.011128] __writeback_single_inode+0x44/0x4a4
[ 1695.011130] writeback_sb_inodes+0x214/0x498
[ 1695.011132] __writeback_inodes_wb+0x50/0x108
[ 1695.011134] wb_writeback+0x2d8/0x3bc
[ 1695.011136] wb_workfn+0x278/0x5c8
[ 1695.011138] process_one_work+0x170/0x3b8
[ 1695.011139] worker_thread+0x2c8/0x3d8
[ 1695.011141] kthread+0x118/0x11c
[ 1695.011143] ret_from_fork+0x10/0x20
[ 1695.011146] INFO: task sync:2271 blocked for more than 121 seconds.
[ 1695.018313] Tainted: G W O 6.6.33-debug #1
[ 1695.025025] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1695.033779] task:sync state:D stack:0 pid:2271 ppid:1086 flags:0x00000208
[ 1695.033781] Call trace:
[ 1695.033782] __switch_to+0xf0/0x16c
[ 1695.033784] __schedule+0x334/0x980
[ 1695.033786] schedule+0x5c/0xf8
[ 1695.033787] wb_wait_for_completion+0x9c/0xc8
[ 1695.033789] sync_inodes_sb+0xb8/0x268
[ 1695.033791] sync_inodes_one_sb+0x1c/0x28
[ 1695.033794] iterate_supers+0xa0/0x124
[ 1695.033796] ksys_sync+0x4c/0xb8
[ 1695.033798] __arm64_sys_sync+0x10/0x20
[ 1695.033800] invoke_syscall+0x48/0x118
[ 1695.033803] el0_svc_common.constprop.0+0xc8/0xe8
[ 1695.033805] do_el0_svc+0x20/0x2c
[ 1695.033808] el0_svc+0x40/0x120
[ 1695.033810] el0t_64_sync_handler+0x13c/0x158
[ 1695.033812] el0t_64_sync+0x1a0/0x1a4
Thanks,
Yuvaraj, Senior Engineer,
Qualcomm Incorporated.
Powered by blists - more mailing lists