#990020 kafs-client: Under a big load the user app hangs instead of a volume busy message from the kernel.

Package:
kafs-client
Source:
kafs-client
Description:
basic tools for kAFS and mounter for the AFS dynamic root
Submitter:
Jose M Calhariz
Date:
2023-01-30 00:03:03 UTC
Severity:
normal
Tags:
#990020#5
Date:
2021-06-17 23:29:26 UTC
From:
To:
I have a testing cell were I perform stress tests, this time with kafs
client.  I have a cron job on a server that performs vos backup every
day at 21h00.  Under normal load I get a volume busy on the kafs
client.  But under evry load the user app hangs on the kernel.

Follow messages from dmesg -T:

[Wed Jun  9 21:10:01 2021] kAFS: Volume 536870928 'service.src' is busy
[Fri Jun 11 21:10:00 2021] kAFS: Volume 536870928 'service.src' is busy
[Mon Jun 14 21:05:19 2021] INFO: task cc1:2413875 blocked for more than 120 seconds.
[Mon Jun 14 21:05:19 2021]       Not tainted 5.10.0-7-amd64 #1 Debian 5.10.40-1
[Mon Jun 14 21:05:19 2021] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Mon Jun 14 21:05:19 2021] task:cc1             state:D stack:    0 pid:2413875 ppid:2413872 flags:0x00004000
[Mon Jun 14 21:05:19 2021] Call Trace:
[Mon Jun 14 21:05:19 2021]  __schedule+0x282/0x870
[Mon Jun 14 21:05:19 2021]  schedule+0x46/0xb0
[Mon Jun 14 21:05:19 2021]  schedule_timeout+0xff/0x140
[Mon Jun 14 21:05:19 2021]  ? add_wait_queue+0x3a/0x70
[Mon Jun 14 21:05:19 2021]  rxrpc_send_data+0xbe5/0xe00 [rxrpc]
[Mon Jun 14 21:05:19 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:05:19 2021]  ? wake_up_q+0xa0/0xa0
[Mon Jun 14 21:05:19 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:05:19 2021]  rxrpc_kernel_send_data+0xb3/0x100 [rxrpc]
[Mon Jun 14 21:05:19 2021]  afs_send_pages+0xa4/0x200 [kafs]
[Mon Jun 14 21:05:19 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_make_call+0x230/0x410 [kafs]
[Mon Jun 14 21:05:19 2021]  ? afs_alloc_flat_call+0x93/0x100 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_wait_for_operation+0x76/0x1e0 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_store_data+0x17b/0x1f0 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_write_back_from_locked_page+0x38c/0x6c0 [kafs]
[Mon Jun 14 21:05:19 2021]  ? __mod_memcg_lruvec_state+0x21/0xe0
[Mon Jun 14 21:05:19 2021]  ? clear_page_dirty_for_io+0xd7/0x220
[Mon Jun 14 21:05:19 2021]  afs_writepages_region+0x8b/0x2a0 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_writepages+0x10d/0x140 [kafs]
[Mon Jun 14 21:05:19 2021]  do_writepages+0x34/0xc0
[Mon Jun 14 21:05:19 2021]  __filemap_fdatawrite_range+0xc5/0x100
[Mon Jun 14 21:05:19 2021]  file_write_and_wait_range+0x61/0xb0
[Mon Jun 14 21:05:19 2021]  afs_release+0x68/0x70 [kafs]
[Mon Jun 14 21:05:19 2021]  __fput+0x95/0x240
[Mon Jun 14 21:05:19 2021]  task_work_run+0x65/0xa0
[Mon Jun 14 21:05:19 2021]  exit_to_user_mode_prepare+0x111/0x120
[Mon Jun 14 21:05:19 2021]  syscall_exit_to_user_mode+0x28/0x140
[Mon Jun 14 21:05:19 2021]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Mon Jun 14 21:05:19 2021] RIP: 0033:0x7f6142933d77
[Mon Jun 14 21:05:19 2021] RSP: 002b:00007ffdaf666d98 EFLAGS: 00000202 ORIG_RAX: 0000000000000003
[Mon Jun 14 21:05:19 2021] RAX: 0000000000000000 RBX: 0000000003bf4450 RCX: 00007f6142933d77
[Mon Jun 14 21:05:19 2021] RDX: 00007f61429ff8a0 RSI: 000000000377bda0 RDI: 0000000000000003
[Mon Jun 14 21:05:19 2021] RBP: 0000000000000000 R08: 0000000000000000 R09: 000000000390db40
[Mon Jun 14 21:05:19 2021] R10: 000000000390db61 R11: 0000000000000202 R12: 00007f6142a004a0
[Mon Jun 14 21:05:19 2021] R13: 00007ffdaf66a290 R14: 0000000000000000 R15: 0000000000000000
[Mon Jun 14 21:05:19 2021] INFO: task cc1:2413908 blocked for more than 120 seconds.
[Mon Jun 14 21:05:19 2021]       Not tainted 5.10.0-7-amd64 #1 Debian 5.10.40-1
[Mon Jun 14 21:05:19 2021] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Mon Jun 14 21:05:19 2021] task:cc1             state:D stack:    0 pid:2413908 ppid:2413907 flags:0x00004000
[Mon Jun 14 21:05:19 2021] Call Trace:
[Mon Jun 14 21:05:19 2021]  __schedule+0x282/0x870
[Mon Jun 14 21:05:19 2021]  schedule+0x46/0xb0
[Mon Jun 14 21:05:19 2021]  schedule_timeout+0xff/0x140
[Mon Jun 14 21:05:19 2021]  ? add_wait_queue+0x3a/0x70
[Mon Jun 14 21:05:19 2021]  rxrpc_send_data+0xbe5/0xe00 [rxrpc]
[Mon Jun 14 21:05:19 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:05:19 2021]  ? wake_up_q+0xa0/0xa0
[Mon Jun 14 21:05:19 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:05:19 2021]  rxrpc_kernel_send_data+0xb3/0x100 [rxrpc]
[Mon Jun 14 21:05:19 2021]  afs_send_pages+0xa4/0x200 [kafs]
[Mon Jun 14 21:05:19 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_make_call+0x230/0x410 [kafs]
[Mon Jun 14 21:05:19 2021]  ? afs_alloc_flat_call+0x93/0x100 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_wait_for_operation+0x76/0x1e0 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_store_data+0x17b/0x1f0 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_write_back_from_locked_page+0x38c/0x6c0 [kafs]
[Mon Jun 14 21:05:19 2021]  ? clear_page_dirty_for_io+0xd7/0x220
[Mon Jun 14 21:05:19 2021]  afs_writepages_region+0x8b/0x2a0 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_writepages+0x10d/0x140 [kafs]
[Mon Jun 14 21:05:19 2021]  do_writepages+0x34/0xc0
[Mon Jun 14 21:05:19 2021]  __filemap_fdatawrite_range+0xc5/0x100
[Mon Jun 14 21:05:19 2021]  file_write_and_wait_range+0x61/0xb0
[Mon Jun 14 21:05:19 2021]  afs_release+0x68/0x70 [kafs]
[Mon Jun 14 21:05:19 2021]  __fput+0x95/0x240
[Mon Jun 14 21:05:19 2021]  task_work_run+0x65/0xa0
[Mon Jun 14 21:05:19 2021]  exit_to_user_mode_prepare+0x111/0x120
[Mon Jun 14 21:05:19 2021]  syscall_exit_to_user_mode+0x28/0x140
[Mon Jun 14 21:05:19 2021]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Mon Jun 14 21:05:19 2021] RIP: 0033:0x7f39c1e1ad77
[Mon Jun 14 21:05:19 2021] RSP: 002b:00007ffdc10482a8 EFLAGS: 00000202 ORIG_RAX: 0000000000000003
[Mon Jun 14 21:05:19 2021] RAX: 0000000000000000 RBX: 000000000352a6b0 RCX: 00007f39c1e1ad77
[Mon Jun 14 21:05:19 2021] RDX: 00007f39c1ee68a0 RSI: 0000000003516640 RDI: 0000000000000003
[Mon Jun 14 21:05:19 2021] RBP: 0000000000000000 R08: 0000000000000000 R09: 00000000037e9c30
[Mon Jun 14 21:05:19 2021] R10: 00000000037e9c47 R11: 0000000000000202 R12: 00007f39c1ee74a0
[Mon Jun 14 21:05:19 2021] R13: 00007ffdc104a2bc R14: 0000000000000000 R15: 0000000000000000
[Mon Jun 14 21:05:19 2021] INFO: task cc1:2413973 blocked for more than 120 seconds.
[Mon Jun 14 21:05:19 2021]       Not tainted 5.10.0-7-amd64 #1 Debian 5.10.40-1
[Mon Jun 14 21:05:19 2021] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Mon Jun 14 21:05:19 2021] task:cc1             state:D stack:    0 pid:2413973 ppid:2413970 flags:0x00004000
[Mon Jun 14 21:05:19 2021] Call Trace:
[Mon Jun 14 21:05:19 2021]  __schedule+0x282/0x870
[Mon Jun 14 21:05:19 2021]  schedule+0x46/0xb0
[Mon Jun 14 21:05:19 2021]  schedule_timeout+0xff/0x140
[Mon Jun 14 21:05:19 2021]  ? add_wait_queue+0x3a/0x70
[Mon Jun 14 21:05:19 2021]  rxrpc_send_data+0xbe5/0xe00 [rxrpc]
[Mon Jun 14 21:05:19 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:05:19 2021]  ? wake_up_q+0xa0/0xa0
[Mon Jun 14 21:05:19 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:05:19 2021]  rxrpc_kernel_send_data+0xb3/0x100 [rxrpc]
[Mon Jun 14 21:05:19 2021]  afs_send_pages+0xa4/0x200 [kafs]
[Mon Jun 14 21:05:19 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_make_call+0x230/0x410 [kafs]
[Mon Jun 14 21:05:19 2021]  ? afs_alloc_flat_call+0x93/0x100 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_wait_for_operation+0x76/0x1e0 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_store_data+0x17b/0x1f0 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_write_back_from_locked_page+0x38c/0x6c0 [kafs]
[Mon Jun 14 21:05:19 2021]  ? __mod_memcg_lruvec_state+0x21/0xe0
[Mon Jun 14 21:05:19 2021]  ? clear_page_dirty_for_io+0xd7/0x220
[Mon Jun 14 21:05:19 2021]  afs_writepages_region+0x8b/0x2a0 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_writepages+0x10d/0x140 [kafs]
[Mon Jun 14 21:05:19 2021]  do_writepages+0x34/0xc0
[Mon Jun 14 21:05:19 2021]  __filemap_fdatawrite_range+0xc5/0x100
[Mon Jun 14 21:05:19 2021]  file_write_and_wait_range+0x61/0xb0
[Mon Jun 14 21:05:19 2021]  afs_release+0x68/0x70 [kafs]
[Mon Jun 14 21:05:19 2021]  __fput+0x95/0x240
[Mon Jun 14 21:05:19 2021]  task_work_run+0x65/0xa0
[Mon Jun 14 21:05:19 2021]  exit_to_user_mode_prepare+0x111/0x120
[Mon Jun 14 21:05:19 2021]  syscall_exit_to_user_mode+0x28/0x140
[Mon Jun 14 21:05:19 2021]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Mon Jun 14 21:05:19 2021] RIP: 0033:0x7f93f13d4d77
[Mon Jun 14 21:05:19 2021] RSP: 002b:00007ffe5921da08 EFLAGS: 00000202 ORIG_RAX: 0000000000000003
[Mon Jun 14 21:05:19 2021] RAX: 0000000000000000 RBX: 0000000002729b90 RCX: 00007f93f13d4d77
[Mon Jun 14 21:05:19 2021] RDX: 00007f93f14a08a0 RSI: 000000000276f470 RDI: 0000000000000003
[Mon Jun 14 21:05:19 2021] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000002bbe380
[Mon Jun 14 21:05:19 2021] R10: 0000000002bbe39a R11: 0000000000000202 R12: 00007f93f14a14a0
[Mon Jun 14 21:05:19 2021] R13: 00007ffe5921f2c1 R14: 0000000000000000 R15: 0000000000000000
[Mon Jun 14 21:05:19 2021] INFO: task cc1:2414260 blocked for more than 120 seconds.
[Mon Jun 14 21:05:19 2021]       Not tainted 5.10.0-7-amd64 #1 Debian 5.10.40-1
[Mon Jun 14 21:05:19 2021] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Mon Jun 14 21:05:19 2021] task:cc1             state:D stack:    0 pid:2414260 ppid:2414257 flags:0x00004000
[Mon Jun 14 21:05:19 2021] Call Trace:
[Mon Jun 14 21:05:19 2021]  __schedule+0x282/0x870
[Mon Jun 14 21:05:19 2021]  schedule+0x46/0xb0
[Mon Jun 14 21:05:19 2021]  afs_wait_for_call_to_complete+0xcc/0x230 [kafs]
[Mon Jun 14 21:05:19 2021]  ? wake_up_q+0xa0/0xa0
[Mon Jun 14 21:05:19 2021]  afs_wait_for_operation+0x8a/0x1e0 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_store_data+0x17b/0x1f0 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_write_back_from_locked_page+0x38c/0x6c0 [kafs]
[Mon Jun 14 21:05:19 2021]  ? clear_page_dirty_for_io+0xd7/0x220
[Mon Jun 14 21:05:19 2021]  afs_writepages_region+0x8b/0x2a0 [kafs]
[Mon Jun 14 21:05:19 2021]  afs_writepages+0x10d/0x140 [kafs]
[Mon Jun 14 21:05:19 2021]  do_writepages+0x34/0xc0
[Mon Jun 14 21:05:19 2021]  __filemap_fdatawrite_range+0xc5/0x100
[Mon Jun 14 21:05:19 2021]  file_write_and_wait_range+0x61/0xb0
[Mon Jun 14 21:05:19 2021]  afs_release+0x68/0x70 [kafs]
[Mon Jun 14 21:05:19 2021]  __fput+0x95/0x240
[Mon Jun 14 21:05:19 2021]  task_work_run+0x65/0xa0
[Mon Jun 14 21:05:19 2021]  exit_to_user_mode_prepare+0x111/0x120
[Mon Jun 14 21:05:19 2021]  syscall_exit_to_user_mode+0x28/0x140
[Mon Jun 14 21:05:19 2021]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Mon Jun 14 21:05:19 2021] RIP: 0033:0x7f6b0e3a4d77
[Mon Jun 14 21:05:19 2021] RSP: 002b:00007ffd316d33a8 EFLAGS: 00000202 ORIG_RAX: 0000000000000003
[Mon Jun 14 21:05:19 2021] RAX: 0000000000000000 RBX: 0000000003ddfb90 RCX: 00007f6b0e3a4d77
[Mon Jun 14 21:05:19 2021] RDX: 00007f6b0e4708a0 RSI: 0000000003e23fe0 RDI: 0000000000000003
[Mon Jun 14 21:05:19 2021] RBP: 0000000000000000 R08: 0000000000000000 R09: 00000000041ed630
[Mon Jun 14 21:05:19 2021] R10: 00000000041ed64d R11: 0000000000000202 R12: 00007f6b0e4714a0
[Mon Jun 14 21:05:19 2021] R13: 00007ffd316d52af R14: 0000000000000000 R15: 0000000000000000
[Mon Jun 14 21:07:20 2021] INFO: task cc1:2413875 blocked for more than 241 seconds.
[Mon Jun 14 21:07:20 2021]       Not tainted 5.10.0-7-amd64 #1 Debian 5.10.40-1
[Mon Jun 14 21:07:20 2021] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Mon Jun 14 21:07:20 2021] task:cc1             state:D stack:    0 pid:2413875 ppid:2413872 flags:0x00004000
[Mon Jun 14 21:07:20 2021] Call Trace:
[Mon Jun 14 21:07:20 2021]  __schedule+0x282/0x870
[Mon Jun 14 21:07:20 2021]  schedule+0x46/0xb0
[Mon Jun 14 21:07:20 2021]  schedule_timeout+0xff/0x140
[Mon Jun 14 21:07:20 2021]  ? add_wait_queue+0x3a/0x70
[Mon Jun 14 21:07:20 2021]  rxrpc_send_data+0xbe5/0xe00 [rxrpc]
[Mon Jun 14 21:07:20 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:07:20 2021]  ? wake_up_q+0xa0/0xa0
[Mon Jun 14 21:07:20 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:07:20 2021]  rxrpc_kernel_send_data+0xb3/0x100 [rxrpc]
[Mon Jun 14 21:07:20 2021]  afs_send_pages+0xa4/0x200 [kafs]
[Mon Jun 14 21:07:20 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_make_call+0x230/0x410 [kafs]
[Mon Jun 14 21:07:20 2021]  ? afs_alloc_flat_call+0x93/0x100 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_wait_for_operation+0x76/0x1e0 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_store_data+0x17b/0x1f0 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_write_back_from_locked_page+0x38c/0x6c0 [kafs]
[Mon Jun 14 21:07:20 2021]  ? __mod_memcg_lruvec_state+0x21/0xe0
[Mon Jun 14 21:07:20 2021]  ? clear_page_dirty_for_io+0xd7/0x220
[Mon Jun 14 21:07:20 2021]  afs_writepages_region+0x8b/0x2a0 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_writepages+0x10d/0x140 [kafs]
[Mon Jun 14 21:07:20 2021]  do_writepages+0x34/0xc0
[Mon Jun 14 21:07:20 2021]  __filemap_fdatawrite_range+0xc5/0x100
[Mon Jun 14 21:07:20 2021]  file_write_and_wait_range+0x61/0xb0
[Mon Jun 14 21:07:20 2021]  afs_release+0x68/0x70 [kafs]
[Mon Jun 14 21:07:20 2021]  __fput+0x95/0x240
[Mon Jun 14 21:07:20 2021]  task_work_run+0x65/0xa0
[Mon Jun 14 21:07:20 2021]  exit_to_user_mode_prepare+0x111/0x120
[Mon Jun 14 21:07:20 2021]  syscall_exit_to_user_mode+0x28/0x140
[Mon Jun 14 21:07:20 2021]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Mon Jun 14 21:07:20 2021] RIP: 0033:0x7f6142933d77
[Mon Jun 14 21:07:20 2021] RSP: 002b:00007ffdaf666d98 EFLAGS: 00000202 ORIG_RAX: 0000000000000003
[Mon Jun 14 21:07:20 2021] RAX: 0000000000000000 RBX: 0000000003bf4450 RCX: 00007f6142933d77
[Mon Jun 14 21:07:20 2021] RDX: 00007f61429ff8a0 RSI: 000000000377bda0 RDI: 0000000000000003
[Mon Jun 14 21:07:20 2021] RBP: 0000000000000000 R08: 0000000000000000 R09: 000000000390db40
[Mon Jun 14 21:07:20 2021] R10: 000000000390db61 R11: 0000000000000202 R12: 00007f6142a004a0
[Mon Jun 14 21:07:20 2021] R13: 00007ffdaf66a290 R14: 0000000000000000 R15: 0000000000000000
[Mon Jun 14 21:07:20 2021] INFO: task cc1:2413908 blocked for more than 241 seconds.
[Mon Jun 14 21:07:20 2021]       Not tainted 5.10.0-7-amd64 #1 Debian 5.10.40-1
[Mon Jun 14 21:07:20 2021] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Mon Jun 14 21:07:20 2021] task:cc1             state:D stack:    0 pid:2413908 ppid:2413907 flags:0x00004000
[Mon Jun 14 21:07:20 2021] Call Trace:
[Mon Jun 14 21:07:20 2021]  __schedule+0x282/0x870
[Mon Jun 14 21:07:20 2021]  schedule+0x46/0xb0
[Mon Jun 14 21:07:20 2021]  schedule_timeout+0xff/0x140
[Mon Jun 14 21:07:20 2021]  ? add_wait_queue+0x3a/0x70
[Mon Jun 14 21:07:20 2021]  rxrpc_send_data+0xbe5/0xe00 [rxrpc]
[Mon Jun 14 21:07:20 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:07:20 2021]  ? wake_up_q+0xa0/0xa0
[Mon Jun 14 21:07:20 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:07:20 2021]  rxrpc_kernel_send_data+0xb3/0x100 [rxrpc]
[Mon Jun 14 21:07:20 2021]  afs_send_pages+0xa4/0x200 [kafs]
[Mon Jun 14 21:07:20 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_make_call+0x230/0x410 [kafs]
[Mon Jun 14 21:07:20 2021]  ? afs_alloc_flat_call+0x93/0x100 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_wait_for_operation+0x76/0x1e0 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_store_data+0x17b/0x1f0 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_write_back_from_locked_page+0x38c/0x6c0 [kafs]
[Mon Jun 14 21:07:20 2021]  ? clear_page_dirty_for_io+0xd7/0x220
[Mon Jun 14 21:07:20 2021]  afs_writepages_region+0x8b/0x2a0 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_writepages+0x10d/0x140 [kafs]
[Mon Jun 14 21:07:20 2021]  do_writepages+0x34/0xc0
[Mon Jun 14 21:07:20 2021]  __filemap_fdatawrite_range+0xc5/0x100
[Mon Jun 14 21:07:20 2021]  file_write_and_wait_range+0x61/0xb0
[Mon Jun 14 21:07:20 2021]  afs_release+0x68/0x70 [kafs]
[Mon Jun 14 21:07:20 2021]  __fput+0x95/0x240
[Mon Jun 14 21:07:20 2021]  task_work_run+0x65/0xa0
[Mon Jun 14 21:07:20 2021]  exit_to_user_mode_prepare+0x111/0x120
[Mon Jun 14 21:07:20 2021]  syscall_exit_to_user_mode+0x28/0x140
[Mon Jun 14 21:07:20 2021]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Mon Jun 14 21:07:20 2021] RIP: 0033:0x7f39c1e1ad77
[Mon Jun 14 21:07:20 2021] RSP: 002b:00007ffdc10482a8 EFLAGS: 00000202 ORIG_RAX: 0000000000000003
[Mon Jun 14 21:07:20 2021] RAX: 0000000000000000 RBX: 000000000352a6b0 RCX: 00007f39c1e1ad77
[Mon Jun 14 21:07:20 2021] RDX: 00007f39c1ee68a0 RSI: 0000000003516640 RDI: 0000000000000003
[Mon Jun 14 21:07:20 2021] RBP: 0000000000000000 R08: 0000000000000000 R09: 00000000037e9c30
[Mon Jun 14 21:07:20 2021] R10: 00000000037e9c47 R11: 0000000000000202 R12: 00007f39c1ee74a0
[Mon Jun 14 21:07:20 2021] R13: 00007ffdc104a2bc R14: 0000000000000000 R15: 0000000000000000
[Mon Jun 14 21:07:20 2021] INFO: task cc1:2413973 blocked for more than 241 seconds.
[Mon Jun 14 21:07:20 2021]       Not tainted 5.10.0-7-amd64 #1 Debian 5.10.40-1
[Mon Jun 14 21:07:20 2021] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Mon Jun 14 21:07:20 2021] task:cc1             state:D stack:    0 pid:2413973 ppid:2413970 flags:0x00004000
[Mon Jun 14 21:07:20 2021] Call Trace:
[Mon Jun 14 21:07:20 2021]  __schedule+0x282/0x870
[Mon Jun 14 21:07:20 2021]  schedule+0x46/0xb0
[Mon Jun 14 21:07:20 2021]  schedule_timeout+0xff/0x140
[Mon Jun 14 21:07:20 2021]  ? add_wait_queue+0x3a/0x70
[Mon Jun 14 21:07:20 2021]  rxrpc_send_data+0xbe5/0xe00 [rxrpc]
[Mon Jun 14 21:07:20 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:07:20 2021]  ? wake_up_q+0xa0/0xa0
[Mon Jun 14 21:07:20 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:07:20 2021]  rxrpc_kernel_send_data+0xb3/0x100 [rxrpc]
[Mon Jun 14 21:07:20 2021]  afs_send_pages+0xa4/0x200 [kafs]
[Mon Jun 14 21:07:20 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_make_call+0x230/0x410 [kafs]
[Mon Jun 14 21:07:20 2021]  ? afs_alloc_flat_call+0x93/0x100 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_wait_for_operation+0x76/0x1e0 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_store_data+0x17b/0x1f0 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_write_back_from_locked_page+0x38c/0x6c0 [kafs]
[Mon Jun 14 21:07:20 2021]  ? __mod_memcg_lruvec_state+0x21/0xe0
[Mon Jun 14 21:07:20 2021]  ? clear_page_dirty_for_io+0xd7/0x220
[Mon Jun 14 21:07:20 2021]  afs_writepages_region+0x8b/0x2a0 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_writepages+0x10d/0x140 [kafs]
[Mon Jun 14 21:07:20 2021]  do_writepages+0x34/0xc0
[Mon Jun 14 21:07:20 2021]  __filemap_fdatawrite_range+0xc5/0x100
[Mon Jun 14 21:07:20 2021]  file_write_and_wait_range+0x61/0xb0
[Mon Jun 14 21:07:20 2021]  afs_release+0x68/0x70 [kafs]
[Mon Jun 14 21:07:20 2021]  __fput+0x95/0x240
[Mon Jun 14 21:07:20 2021]  task_work_run+0x65/0xa0
[Mon Jun 14 21:07:20 2021]  exit_to_user_mode_prepare+0x111/0x120
[Mon Jun 14 21:07:20 2021]  syscall_exit_to_user_mode+0x28/0x140
[Mon Jun 14 21:07:20 2021]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Mon Jun 14 21:07:20 2021] RIP: 0033:0x7f93f13d4d77
[Mon Jun 14 21:07:20 2021] RSP: 002b:00007ffe5921da08 EFLAGS: 00000202 ORIG_RAX: 0000000000000003
[Mon Jun 14 21:07:20 2021] RAX: 0000000000000000 RBX: 0000000002729b90 RCX: 00007f93f13d4d77
[Mon Jun 14 21:07:20 2021] RDX: 00007f93f14a08a0 RSI: 000000000276f470 RDI: 0000000000000003
[Mon Jun 14 21:07:20 2021] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000002bbe380
[Mon Jun 14 21:07:20 2021] R10: 0000000002bbe39a R11: 0000000000000202 R12: 00007f93f14a14a0
[Mon Jun 14 21:07:20 2021] R13: 00007ffe5921f2c1 R14: 0000000000000000 R15: 0000000000000000
[Mon Jun 14 21:07:20 2021] INFO: task cc1:2414260 blocked for more than 241 seconds.
[Mon Jun 14 21:07:20 2021]       Not tainted 5.10.0-7-amd64 #1 Debian 5.10.40-1
[Mon Jun 14 21:07:20 2021] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Mon Jun 14 21:07:20 2021] task:cc1             state:D stack:    0 pid:2414260 ppid:2414257 flags:0x00004000
[Mon Jun 14 21:07:20 2021] Call Trace:
[Mon Jun 14 21:07:20 2021]  __schedule+0x282/0x870
[Mon Jun 14 21:07:20 2021]  schedule+0x46/0xb0
[Mon Jun 14 21:07:20 2021]  afs_wait_for_call_to_complete+0xcc/0x230 [kafs]
[Mon Jun 14 21:07:20 2021]  ? wake_up_q+0xa0/0xa0
[Mon Jun 14 21:07:20 2021]  afs_wait_for_operation+0x8a/0x1e0 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_store_data+0x17b/0x1f0 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_write_back_from_locked_page+0x38c/0x6c0 [kafs]
[Mon Jun 14 21:07:20 2021]  ? clear_page_dirty_for_io+0xd7/0x220
[Mon Jun 14 21:07:20 2021]  afs_writepages_region+0x8b/0x2a0 [kafs]
[Mon Jun 14 21:07:20 2021]  afs_writepages+0x10d/0x140 [kafs]
[Mon Jun 14 21:07:20 2021]  do_writepages+0x34/0xc0
[Mon Jun 14 21:07:20 2021]  __filemap_fdatawrite_range+0xc5/0x100
[Mon Jun 14 21:07:20 2021]  file_write_and_wait_range+0x61/0xb0
[Mon Jun 14 21:07:20 2021]  afs_release+0x68/0x70 [kafs]
[Mon Jun 14 21:07:20 2021]  __fput+0x95/0x240
[Mon Jun 14 21:07:20 2021]  task_work_run+0x65/0xa0
[Mon Jun 14 21:07:20 2021]  exit_to_user_mode_prepare+0x111/0x120
[Mon Jun 14 21:07:20 2021]  syscall_exit_to_user_mode+0x28/0x140
[Mon Jun 14 21:07:20 2021]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Mon Jun 14 21:07:20 2021] RIP: 0033:0x7f6b0e3a4d77
[Mon Jun 14 21:07:20 2021] RSP: 002b:00007ffd316d33a8 EFLAGS: 00000202 ORIG_RAX: 0000000000000003
[Mon Jun 14 21:07:20 2021] RAX: 0000000000000000 RBX: 0000000003ddfb90 RCX: 00007f6b0e3a4d77
[Mon Jun 14 21:07:20 2021] RDX: 00007f6b0e4708a0 RSI: 0000000003e23fe0 RDI: 0000000000000003
[Mon Jun 14 21:07:20 2021] RBP: 0000000000000000 R08: 0000000000000000 R09: 00000000041ed630
[Mon Jun 14 21:07:20 2021] R10: 00000000041ed64d R11: 0000000000000202 R12: 00007f6b0e4714a0
[Mon Jun 14 21:07:20 2021] R13: 00007ffd316d52af R14: 0000000000000000 R15: 0000000000000000
[Mon Jun 14 21:09:21 2021] INFO: task cc1:2413875 blocked for more than 362 seconds.
[Mon Jun 14 21:09:21 2021]       Not tainted 5.10.0-7-amd64 #1 Debian 5.10.40-1
[Mon Jun 14 21:09:21 2021] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Mon Jun 14 21:09:21 2021] task:cc1             state:D stack:    0 pid:2413875 ppid:2413872 flags:0x00004000
[Mon Jun 14 21:09:21 2021] Call Trace:
[Mon Jun 14 21:09:21 2021]  __schedule+0x282/0x870
[Mon Jun 14 21:09:21 2021]  schedule+0x46/0xb0
[Mon Jun 14 21:09:21 2021]  schedule_timeout+0xff/0x140
[Mon Jun 14 21:09:21 2021]  ? add_wait_queue+0x3a/0x70
[Mon Jun 14 21:09:21 2021]  rxrpc_send_data+0xbe5/0xe00 [rxrpc]
[Mon Jun 14 21:09:21 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:09:21 2021]  ? wake_up_q+0xa0/0xa0
[Mon Jun 14 21:09:21 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:09:21 2021]  rxrpc_kernel_send_data+0xb3/0x100 [rxrpc]
[Mon Jun 14 21:09:21 2021]  afs_send_pages+0xa4/0x200 [kafs]
[Mon Jun 14 21:09:21 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:09:21 2021]  afs_make_call+0x230/0x410 [kafs]
[Mon Jun 14 21:09:21 2021]  ? afs_alloc_flat_call+0x93/0x100 [kafs]
[Mon Jun 14 21:09:21 2021]  afs_wait_for_operation+0x76/0x1e0 [kafs]
[Mon Jun 14 21:09:21 2021]  afs_store_data+0x17b/0x1f0 [kafs]
[Mon Jun 14 21:09:21 2021]  afs_write_back_from_locked_page+0x38c/0x6c0 [kafs]
[Mon Jun 14 21:09:21 2021]  ? __mod_memcg_lruvec_state+0x21/0xe0
[Mon Jun 14 21:09:21 2021]  ? clear_page_dirty_for_io+0xd7/0x220
[Mon Jun 14 21:09:21 2021]  afs_writepages_region+0x8b/0x2a0 [kafs]
[Mon Jun 14 21:09:21 2021]  afs_writepages+0x10d/0x140 [kafs]
[Mon Jun 14 21:09:21 2021]  do_writepages+0x34/0xc0
[Mon Jun 14 21:09:21 2021]  __filemap_fdatawrite_range+0xc5/0x100
[Mon Jun 14 21:09:21 2021]  file_write_and_wait_range+0x61/0xb0
[Mon Jun 14 21:09:21 2021]  afs_release+0x68/0x70 [kafs]
[Mon Jun 14 21:09:21 2021]  __fput+0x95/0x240
[Mon Jun 14 21:09:21 2021]  task_work_run+0x65/0xa0
[Mon Jun 14 21:09:21 2021]  exit_to_user_mode_prepare+0x111/0x120
[Mon Jun 14 21:09:21 2021]  syscall_exit_to_user_mode+0x28/0x140
[Mon Jun 14 21:09:21 2021]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Mon Jun 14 21:09:21 2021] RIP: 0033:0x7f6142933d77
[Mon Jun 14 21:09:21 2021] RSP: 002b:00007ffdaf666d98 EFLAGS: 00000202 ORIG_RAX: 0000000000000003
[Mon Jun 14 21:09:21 2021] RAX: 0000000000000000 RBX: 0000000003bf4450 RCX: 00007f6142933d77
[Mon Jun 14 21:09:21 2021] RDX: 00007f61429ff8a0 RSI: 000000000377bda0 RDI: 0000000000000003
[Mon Jun 14 21:09:21 2021] RBP: 0000000000000000 R08: 0000000000000000 R09: 000000000390db40
[Mon Jun 14 21:09:21 2021] R10: 000000000390db61 R11: 0000000000000202 R12: 00007f6142a004a0
[Mon Jun 14 21:09:21 2021] R13: 00007ffdaf66a290 R14: 0000000000000000 R15: 0000000000000000
[Mon Jun 14 21:09:21 2021] INFO: task cc1:2413908 blocked for more than 362 seconds.
[Mon Jun 14 21:09:21 2021]       Not tainted 5.10.0-7-amd64 #1 Debian 5.10.40-1
[Mon Jun 14 21:09:21 2021] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Mon Jun 14 21:09:21 2021] task:cc1             state:D stack:    0 pid:2413908 ppid:2413907 flags:0x00004000
[Mon Jun 14 21:09:21 2021] Call Trace:
[Mon Jun 14 21:09:21 2021]  __schedule+0x282/0x870
[Mon Jun 14 21:09:21 2021]  schedule+0x46/0xb0
[Mon Jun 14 21:09:21 2021]  schedule_timeout+0xff/0x140
[Mon Jun 14 21:09:21 2021]  ? add_wait_queue+0x3a/0x70
[Mon Jun 14 21:09:21 2021]  rxrpc_send_data+0xbe5/0xe00 [rxrpc]
[Mon Jun 14 21:09:21 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:09:21 2021]  ? wake_up_q+0xa0/0xa0
[Mon Jun 14 21:09:21 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:09:21 2021]  rxrpc_kernel_send_data+0xb3/0x100 [rxrpc]
[Mon Jun 14 21:09:21 2021]  afs_send_pages+0xa4/0x200 [kafs]
[Mon Jun 14 21:09:21 2021]  ? afs_alloc_call+0x120/0x120 [kafs]
[Mon Jun 14 21:09:21 2021]  afs_make_call+0x230/0x410 [kafs]
[Mon Jun 14 21:09:21 2021]  ? afs_alloc_flat_call+0x93/0x100 [kafs]
[Mon Jun 14 21:09:21 2021]  afs_wait_for_operation+0x76/0x1e0 [kafs]
[Mon Jun 14 21:09:21 2021]  afs_store_data+0x17b/0x1f0 [kafs]
[Mon Jun 14 21:09:21 2021]  afs_write_back_from_locked_page+0x38c/0x6c0 [kafs]
[Mon Jun 14 21:09:21 2021]  ? clear_page_dirty_for_io+0xd7/0x220
[Mon Jun 14 21:09:21 2021]  afs_writepages_region+0x8b/0x2a0 [kafs]
[Mon Jun 14 21:09:21 2021]  afs_writepages+0x10d/0x140 [kafs]
[Mon Jun 14 21:09:21 2021]  do_writepages+0x34/0xc0
[Mon Jun 14 21:09:21 2021]  __filemap_fdatawrite_range+0xc5/0x100
[Mon Jun 14 21:09:21 2021]  file_write_and_wait_range+0x61/0xb0
[Mon Jun 14 21:09:21 2021]  afs_release+0x68/0x70 [kafs]
[Mon Jun 14 21:09:21 2021]  __fput+0x95/0x240
[Mon Jun 14 21:09:21 2021]  task_work_run+0x65/0xa0
[Mon Jun 14 21:09:21 2021]  exit_to_user_mode_prepare+0x111/0x120
[Mon Jun 14 21:09:21 2021]  syscall_exit_to_user_mode+0x28/0x140
[Mon Jun 14 21:09:21 2021]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Mon Jun 14 21:09:21 2021] RIP: 0033:0x7f39c1e1ad77
[Mon Jun 14 21:09:21 2021] RSP: 002b:00007ffdc10482a8 EFLAGS: 00000202 ORIG_RAX: 0000000000000003
[Mon Jun 14 21:09:21 2021] RAX: 0000000000000000 RBX: 000000000352a6b0 RCX: 00007f39c1e1ad77
[Mon Jun 14 21:09:21 2021] RDX: 00007f39c1ee68a0 RSI: 0000000003516640 RDI: 0000000000000003
[Mon Jun 14 21:09:21 2021] RBP: 0000000000000000 R08: 0000000000000000 R09: 00000000037e9c30
[Mon Jun 14 21:09:21 2021] R10: 00000000037e9c47 R11: 0000000000000202 R12: 00007f39c1ee74a0
[Mon Jun 14 21:09:21 2021] R13: 00007ffdc104a2bc R14: 0000000000000000 R15: 0000000000000000



Kind regards
Jose M Calhariz
#990020#10
Date:
2022-09-29 12:42:11 UTC
From:
To:
Jose,

Although the kafs-client package is necessary to make use of the Linux
kernel afs filesystem it is quite isolated.   The Linux afs filesystem
development is independent of any specific Linux distribution and bug
reports filed in the Debian bug tracker are not forwarded automatically.

If this issue is still present, please send a report to
linux-afs@lists.infradead.org.

Thank you.

Jeffrey Altman
#990020#15
Date:
2023-01-29 23:53:28 UTC
From:
To:
I had some problems subscribing to the list myself.  To get to the
mailmail page use the URL:

http://lists.infradead.org/mailman/listinfo/linux-afs

Bill