Re: develoment workflow: how to avoid duplicate work ?
On Mon, Jun 04, 2018 at 06:27:43AM +0000, Nicholas Mc Guire wrote:
are you using kprobes to get this information or how did you trace these calls ? could you explain how you did that ? I assume that would be of interest to others as well not only me.
Nothing fancy, just added debug print statements to the release and ioctl methods of the pi433 driver. The ioctl method also has a 5s sleep so it takes some time to execute while the other thread calls close on the same file descriptor. The timing should be as follows: 0s thread1 and thread2 start 0s thread1 calls ioctl 1s thread2 calls close 1s thread2 close returns 5s thread1 ioctl returns Adding a dump_stack() call to both driver methods shows that ioctl is called directly: [236449.534358] [<8010ffd8>] (unwind_backtrace) from [<8010c240>] (show_stack+0x20/0x24) [236449.534378] [<8010c240>] (show_stack) from [<807840a4>] (dump_stack+0xd4/0x118) [236449.534413] [<807840a4>] (dump_stack) from [<7f5e5348>] (pi433_ioctl+0x64/0x324 [pi433]) [236449.534457] [<7f5e5348>] (pi433_ioctl [pi433]) from [<8029dbe0>] (do_vfs_ioctl+0xac/0x7c4) [236449.534472] [<8029dbe0>] (do_vfs_ioctl) from [<8029e33c>] (SyS_ioctl+0x44/0x6c) [236449.534488] [<8029e33c>] (SyS_ioctl) from [<80108060>] (ret_fast_syscall+0x0/0x28) while the release gets called from task_work_run: [236454.624185] [<8010ffd8>] (unwind_backtrace) from [<8010c240>] (show_stack+0x20/0x24) [236454.624204] [<8010c240>] (show_stack) from [<807840a4>] (dump_stack+0xd4/0x118) [236454.624240] [<807840a4>] (dump_stack) from [<7f5e508c>] (pi433_release+0x48/0xc0 [pi433]) [236454.624270] [<7f5e508c>] (pi433_release [pi433]) from [<8028bab0>] (__fput+0x9c/0x1e8) [236454.624288] [<8028bab0>] (__fput) from [<8028bc6c>] (____fput+0x18/0x1c) [236454.624304] [<8028bc6c>] (____fput) from [<8013bbf8>] (task_work_run+0xbc/0xe0) [236454.624322] [<8013bbf8>] (task_work_run) from [<8010b810>] (do_work_pending+0xcc/0xd0) [236454.624340] [<8010b810>] (do_work_pending) from [<80108094>] (slow_work_pending+0xc/0x20) -- Valentin
Nothing fancy, just added debug print statements to the release and ioctl methods of the pi433 driver. The ioctl method also has a 5s sleep so it takes some time to execute while the other thread calls close on the same file descriptor.
The timing should be as follows:
0s thread1 and thread2 start 0s thread1 calls ioctl 1s thread2 calls close 1s thread2 close returns 5s thread1 ioctl returns
Adding a dump_stack() call to both driver methods shows that ioctl is called directly:
[236449.534358] [<8010ffd8>] (unwind_backtrace) from [<8010c240>] (show_stack+0x20/0x24) [236449.534378] [<8010c240>] (show_stack) from [<807840a4>] (dump_stack+0xd4/0x118) [236449.534413] [<807840a4>] (dump_stack) from [<7f5e5348>] (pi433_ioctl+0x64/0x324 [pi433]) [236449.534457] [<7f5e5348>] (pi433_ioctl [pi433]) from [<8029dbe0>] (do_vfs_ioctl+0xac/0x7c4) [236449.534472] [<8029dbe0>] (do_vfs_ioctl) from [<8029e33c>] (SyS_ioctl+0x44/0x6c) [236449.534488] [<8029e33c>] (SyS_ioctl) from [<80108060>] (ret_fast_syscall+0x0/0x28)
while the release gets called from task_work_run:
[236454.624185] [<8010ffd8>] (unwind_backtrace) from [<8010c240>] (show_stack+0x20/0x24) [236454.624204] [<8010c240>] (show_stack) from [<807840a4>] (dump_stack+0xd4/0x118) [236454.624240] [<807840a4>] (dump_stack) from [<7f5e508c>] (pi433_release+0x48/0xc0 [pi433]) [236454.624270] [<7f5e508c>] (pi433_release [pi433]) from [<8028bab0>] (__fput+0x9c/0x1e8) [236454.624288] [<8028bab0>] (__fput) from [<8028bc6c>] (____fput+0x18/0x1c) [236454.624304] [<8028bc6c>] (____fput) from [<8013bbf8>] (task_work_run+0xbc/0xe0) [236454.624322] [<8013bbf8>] (task_work_run) from [<8010b810>] (do_work_pending+0xcc/0xd0) [236454.624340] [<8010b810>] (do_work_pending) from [<80108094>] (slow_work_pending+0xc/0x20)
Interesting. I don't know what's happening here, but the idea that release() would be delayed until all operations returned (as nice as it sounds) seems pretty odd to me. I'll not have time to experiment on this today, but this is definitely worth taking a look. Cheers, Hugo -- Hugo Lefeuvre (hle) | www.owl.eu.com 4096/ 9C4F C8BF A4B0 8FC5 48EB 56B8 1962 765B B9A8 BACA
participants (2)
-
Hugo Lefeuvre -
Valentin Vidic