From: "Pali Rohár" <pali.rohar@gmail.com>
To: Andrey Konovalov <andreyknvl@google.com>
Cc: Dmitry Torokhov <dmitry.torokhov@gmail.com>,
Hans de Goede <hdegoede@redhat.com>,
Mathias Gottschlag <mgottschlag@gmail.com>,
Shailendra Verma <shailendra.capricorn@gmail.com>,
Rusty Russell <rusty@rustcorp.com.au>,
"Luis R. Rodriguez" <mcgrof@suse.com>,
Thomas Hellstrom <thellstrom@vmware.com>,
linux-input@vger.kernel.org, linux-kernel@vger.kernel.org,
Dmitry Vyukov <dvyukov@google.com>,
Kostya Serebryany <kcc@google.com>,
Alexander Potapenko <glider@google.com>,
ktsan@googlegroups.com
Subject: Re: Potential data race in psmouse_interrupt
Date: Wed, 29 Jul 2015 13:53:26 +0200 [thread overview]
Message-ID: <20150729115326.GE13518@pali> (raw)
In-Reply-To: <CAAeHK+xyvq3XnN2FZuO35i+DBDYoi1OFWvHmAdZmC=k7kq9q5Q@mail.gmail.com>
Hi! This log looks like there can be race condition in initialization
code, but not in receiving ALPS packets after initialization...
On Thursday 23 July 2015 15:31:46 Andrey Konovalov wrote:
> Hi Pali,
>
> There are a few reports in psmouse-base.c/alps.c code as well.
> Here is a couple of them that are printed one right after another.
> The second one tells about a race on ps2dev->cmdcnt.
>
> ==================================================================
> ThreadSanitizer: data-race in ps2_handle_ack
>
> Write of size 8 by thread T6 (K6):
> [<ffffffff819c0b83>] ps2_handle_ack+0xf3/0x180 drivers/input/serio/libps2.c:322
> [<ffffffff819d55d7>] psmouse_interrupt+0x207/0x690
> drivers/input/mouse/psmouse-base.c:317
> [<ffffffff819bcf46>] serio_interrupt+0x66/0xb0 drivers/input/serio/serio.c:1008
> [<ffffffff819be820>] i8042_interrupt+0x240/0x4d0
> drivers/input/serio/i8042.c:541
> [<ffffffff810f03b2>] handle_irq_event_percpu+0x62/0x2a0 kernel/irq/handle.c:143
> [<ffffffff810f0692>] handle_irq_event+0xa2/0xf0 kernel/irq/handle.c:192
> [<ffffffff810f5414>] handle_edge_irq+0x104/0x380 kernel/irq/chip.c:608
> [< inlined >] handle_irq+0xf6/0x220 generic_handle_irq_desc
> include/linux/irqdesc.h:146
> [<ffffffff81009f86>] handle_irq+0xf6/0x220 arch/x86/kernel/irq_64.c:81
> [<ffffffff810093ce>] do_IRQ+0x5e/0x110 arch/x86/kernel/irq.c:223
> [<ffffffff81e728ab>] ret_from_intr+0x0/0x1f arch/x86/entry/entry_64.S:601
> [< inlined >] irq_exit+0x98/0xa0 invoke_softirq kernel/softirq.c:350
> [<ffffffff8108edd8>] irq_exit+0x98/0xa0 kernel/softirq.c:391
> [< inlined >] smp_apic_timer_interrupt+0x63/0x80 exiting_irq
> ./arch/x86/include/asm/apic.h:655
> [<ffffffff8105c503>] smp_apic_timer_interrupt+0x63/0x80
> arch/x86/kernel/apic/apic.c:915
> [<ffffffff81e72b9b>] apic_timer_interrupt+0x6b/0x70
> arch/x86/entry/entry_64.S:782
> [<ffffffff81086fe3>] _do_fork+0x133/0x500 kernel/fork.c:1719
> [<ffffffff810873ec>] kernel_thread+0x3c/0x60 kernel/fork.c:1772
> [<ffffffff810a71dc>] __call_usermodehelper+0x5c/0x90 kernel/kmod.c:317
> [<ffffffff810adcf9>] process_one_work+0x2a9/0x6d0 kernel/workqueue.c:2036
> [<ffffffff810aeddf>] worker_thread+0xbf/0x710 kernel/workqueue.c:2170
> [<ffffffff810b700c>] kthread+0x15c/0x180 kernel/kthread.c:207
> [<ffffffff81e7215f>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:526
> DBG: cpu = ffff88053fd9fe68
> DBG: cpu id = 3
>
> Previous read of size 8 by thread T397 (K394):
> [<ffffffff819c0cf2>] ps2_sendbyte+0xe2/0x210 drivers/input/serio/libps2.c:45
> [<ffffffff819c1109>] __ps2_command+0x159/0x660 drivers/input/serio/libps2.c:214
> [<ffffffff819c1645>] ps2_command+0x35/0x60 drivers/input/serio/libps2.c:260
> [<ffffffff819dd412>] alps_rpt_cmd+0x42/0xe0
> drivers/input/mouse/alps.c:1665 (discriminator 1)
> [<ffffffff819e12b6>] alps_identify+0x36/0xc80 drivers/input/mouse/alps.c:2690
> [<ffffffff819e3498>] alps_detect+0x28/0x150 drivers/input/mouse/alps.c:2960
> [< inlined >] psmouse_extensions+0x25e/0x4e0 psmouse_do_detect
> drivers/input/mouse/psmouse-base.c:752
> [<ffffffff819d60fe>] psmouse_extensions+0x25e/0x4e0
> drivers/input/mouse/psmouse-base.c:870
> [<ffffffff819d662d>] psmouse_switch_protocol+0x2ad/0x330
> drivers/input/mouse/psmouse-base.c:1467
> [<ffffffff819d7656>] psmouse_connect+0x2e6/0x450
> drivers/input/mouse/psmouse-base.c:1554 (discriminator 4)
> [< inlined >] serio_driver_probe+0x57/0x80
> serio_connect_driver drivers/input/serio/serio.c:65
> [<ffffffff819bd1a7>] serio_driver_probe+0x57/0x80
> drivers/input/serio/serio.c:796
> [< inlined >] driver_probe_device+0x1da/0x460 really_probe
> drivers/base/dd.c:308
> [<ffffffff81813d4a>] driver_probe_device+0x1da/0x460 drivers/base/dd.c:414
> [<ffffffff81814094>] __driver_attach+0xc4/0xd0 drivers/base/dd.c:612
> [<ffffffff81810b63>] bus_for_each_dev+0x93/0xe0 drivers/base/bus.c:314
> [<ffffffff81813583>] driver_attach+0x33/0x50 drivers/base/dd.c:631
> [< inlined >] serio_handle_event+0x2d3/0x3b0
> serio_attach_driver drivers/input/serio/serio.c:826
> [<ffffffff819bdb13>] serio_handle_event+0x2d3/0x3b0
> drivers/input/serio/serio.c:245
> [<ffffffff810adcf9>] process_one_work+0x2a9/0x6d0 kernel/workqueue.c:2036
> [<ffffffff810aeddf>] worker_thread+0xbf/0x710 kernel/workqueue.c:2170
> [<ffffffff810b700c>] kthread+0x15c/0x180 kernel/kthread.c:207
> [<ffffffff81e7215f>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:526
> DBG: cpu = 0
>
> DBG: addr: ffff88019a923a58
> DBG: first offset: 0, second offset: 0
> DBG: T6 clock: {T6: 2264295, T397: 174118}
> DBG: T397 clock: {T397: 174122}
> ==================================================================
> ==================================================================
> ThreadSanitizer: data-race in __ps2_command
>
> Read of size 1 by thread T397 (K394):
> [<ffffffff819c1220>] __ps2_command+0x270/0x660
> drivers/input/serio/libps2.c:230 (discriminator 21)
> [<ffffffff819c1645>] ps2_command+0x35/0x60 drivers/input/serio/libps2.c:260
> [<ffffffff819dd47e>] alps_rpt_cmd+0xae/0xe0 drivers/input/mouse/alps.c:1674
> [<ffffffff819e12b6>] alps_identify+0x36/0xc80 drivers/input/mouse/alps.c:2690
> [<ffffffff819e3498>] alps_detect+0x28/0x150 drivers/input/mouse/alps.c:2960
> [< inlined >] psmouse_extensions+0x25e/0x4e0 psmouse_do_detect
> drivers/input/mouse/psmouse-base.c:752
> [<ffffffff819d60fe>] psmouse_extensions+0x25e/0x4e0
> drivers/input/mouse/psmouse-base.c:870
> [<ffffffff819d662d>] psmouse_switch_protocol+0x2ad/0x330
> drivers/input/mouse/psmouse-base.c:1467
> [<ffffffff819d7656>] psmouse_connect+0x2e6/0x450
> drivers/input/mouse/psmouse-base.c:1554 (discriminator 4)
> [< inlined >] serio_driver_probe+0x57/0x80
> serio_connect_driver drivers/input/serio/serio.c:65
> [<ffffffff819bd1a7>] serio_driver_probe+0x57/0x80
> drivers/input/serio/serio.c:796
> [< inlined >] driver_probe_device+0x1da/0x460 really_probe
> drivers/base/dd.c:308
> [<ffffffff81813d4a>] driver_probe_device+0x1da/0x460 drivers/base/dd.c:414
> [<ffffffff81814094>] __driver_attach+0xc4/0xd0 drivers/base/dd.c:612
> [<ffffffff81810b63>] bus_for_each_dev+0x93/0xe0 drivers/base/bus.c:314
> [<ffffffff81813583>] driver_attach+0x33/0x50 drivers/base/dd.c:631
> [< inlined >] serio_handle_event+0x2d3/0x3b0
> serio_attach_driver drivers/input/serio/serio.c:826
> [<ffffffff819bdb13>] serio_handle_event+0x2d3/0x3b0
> drivers/input/serio/serio.c:245
> [<ffffffff810adcf9>] process_one_work+0x2a9/0x6d0 kernel/workqueue.c:2036
> [<ffffffff810aeddf>] worker_thread+0xbf/0x710 kernel/workqueue.c:2170
> [<ffffffff810b700c>] kthread+0x15c/0x180 kernel/kthread.c:207
> [<ffffffff81e7215f>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:526
> DBG: cpu = ffff88053fc9fe68
> DBG: cpu id = 1
>
> Previous write of size 1 by thread T6 (K6):
> [<ffffffff819c09a6>] ps2_handle_response+0x46/0x130
> drivers/input/serio/libps2.c:346
> [<ffffffff819d58a4>] psmouse_interrupt+0x4d4/0x690
> drivers/input/mouse/psmouse-base.c:321
> [<ffffffff819bcf46>] serio_interrupt+0x66/0xb0 drivers/input/serio/serio.c:1008
> [<ffffffff819be820>] i8042_interrupt+0x240/0x4d0
> drivers/input/serio/i8042.c:541
> [<ffffffff810f03b2>] handle_irq_event_percpu+0x62/0x2a0 kernel/irq/handle.c:143
> [<ffffffff810f0692>] handle_irq_event+0xa2/0xf0 kernel/irq/handle.c:192
> [<ffffffff810f5414>] handle_edge_irq+0x104/0x380 kernel/irq/chip.c:608
> [< inlined >] handle_irq+0xf6/0x220 generic_handle_irq_desc
> include/linux/irqdesc.h:146
> [<ffffffff81009f86>] handle_irq+0xf6/0x220 arch/x86/kernel/irq_64.c:81
> [<ffffffff810093ce>] do_IRQ+0x5e/0x110 arch/x86/kernel/irq.c:223
> [<ffffffff81e728ab>] ret_from_intr+0x0/0x1f arch/x86/entry/entry_64.S:601
> [<ffffffff81e72b9b>] apic_timer_interrupt+0x6b/0x70
> arch/x86/entry/entry_64.S:782
> [< inlined >] kvm_clock_get_cycles+0x3e/0x50 kvm_clock_read
> arch/x86/kernel/kvmclock.c:85
> [<ffffffff8106e74e>] kvm_clock_get_cycles+0x3e/0x50
> arch/x86/kernel/kvmclock.c:92
> [< inlined >] ktime_get_with_offset+0x99/0x180
> timekeeping_get_delta kernel/time/timekeeping.c:210
> [< inlined >] ktime_get_with_offset+0x99/0x180
> timekeeping_get_ns kernel/time/timekeeping.c:306
> [<ffffffff81114da9>] ktime_get_with_offset+0x99/0x180
> kernel/time/timekeeping.c:720
> [< inlined >] copy_process.part.44+0x773/0x2c40
> ktime_get_boottime include/linux/timekeeping.h:183
> [< inlined >] copy_process.part.44+0x773/0x2c40
> ktime_get_boot_ns include/linux/timekeeping.h:214
> [<ffffffff810848b3>] copy_process.part.44+0x773/0x2c40 kernel/fork.c:1363
> [< inlined >] _do_fork+0x103/0x500 copy_process kernel/fork.c:1261
> [<ffffffff81086fb3>] _do_fork+0x103/0x500 kernel/fork.c:1709
> [<ffffffff810873ec>] kernel_thread+0x3c/0x60 kernel/fork.c:1772
> [<ffffffff810a71dc>] __call_usermodehelper+0x5c/0x90 kernel/kmod.c:317
> [<ffffffff810adcf9>] process_one_work+0x2a9/0x6d0 kernel/workqueue.c:2036
> [<ffffffff810aeddf>] worker_thread+0xbf/0x710 kernel/workqueue.c:2170
> [<ffffffff810b700c>] kthread+0x15c/0x180 kernel/kthread.c:207
> [<ffffffff81e7215f>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:526
> DBG: cpu = 0
>
> DBG: addr: ffff88019a923a68
> DBG: first offset: 0, second offset: 0
> DBG: T397 clock: {T397: 175738, T6: 2266233}
> DBG: T6 clock: {T6: 2266336}
> ==================================================================
>
> On Thu, Jul 23, 2015 at 3:08 PM, Pali Rohár <pali.rohar@gmail.com> wrote:
> > On Wednesday 22 July 2015 15:14:42 Andrey Konovalov wrote:
> >> Hi!
> >>
> >> We are working on a dynamic data race detector for Linux kernel called
> >> KernelThreadSanitizer (ktsan) (https://github.com/google/ktsan/wiki).
> >>
> >> Here is a report we got while running ktsan (upstream revision
> >> 21bdb584af8cca7c6df3c44cba268be050a234eb).
> >>
> >> ==================================================================
> >> ThreadSanitizer: data-race in psmouse_interrupt
> >>
> >> Write of size 1 by thread T1 (K1):
> >> [<ffffffff819d5272>] psmouse_interrupt+0xd2/0x690
> >> drivers/input/mouse/psmouse-base.c:337
> >> [<ffffffff819bcd16>] serio_interrupt+0x66/0xb0 drivers/input/serio/serio.c:1008
> >> [<ffffffff819be5f0>] i8042_interrupt+0x240/0x4d0
> >> drivers/input/serio/i8042.c:541
> >> [<ffffffff810f03b2>] handle_irq_event_percpu+0x62/0x2a0 kernel/irq/handle.c:143
> >> [<ffffffff810f0692>] handle_irq_event+0xa2/0xf0 kernel/irq/handle.c:192
> >> [<ffffffff810f5414>] handle_edge_irq+0x104/0x380 kernel/irq/chip.c:608
> >> [< inlined >] handle_irq+0xf6/0x220 generic_handle_irq_desc
> >> include/linux/irqdesc.h:146
> >> [<ffffffff81009f86>] handle_irq+0xf6/0x220 arch/x86/kernel/irq_64.c:81
> >> [<ffffffff810093ce>] do_IRQ+0x5e/0x110 arch/x86/kernel/irq.c:223
> >> [<ffffffff81e726ab>] ret_from_intr+0x0/0x1f arch/x86/entry/entry_64.S:601
> >> [< inlined >] irq_exit+0x98/0xa0 invoke_softirq kernel/softirq.c:350
> >> [<ffffffff8108edd8>] irq_exit+0x98/0xa0 kernel/softirq.c:391
> >> [< inlined >] smp_apic_timer_interrupt+0x63/0x80 exiting_irq
> >> ./arch/x86/include/asm/apic.h:655
> >> [<ffffffff8105c503>] smp_apic_timer_interrupt+0x63/0x80
> >> arch/x86/kernel/apic/apic.c:915
> >> [<ffffffff81e7299b>] apic_timer_interrupt+0x6b/0x70
> >> arch/x86/entry/entry_64.S:782
> >> [<ffffffff8153223d>] kvasprintf+0x5d/0x90 lib/kasprintf.c:24
> >> [<ffffffff815322be>] kasprintf+0x4e/0x70 lib/kasprintf.c:40
> >> [< inlined >] module_add_driver+0x8f/0x180 make_driver_name
> >> drivers/base/module.c:18
> >> [<ffffffff8183059f>] module_add_driver+0x8f/0x180 drivers/base/module.c:63
> >> [<ffffffff81812c94>] bus_add_driver+0x204/0x340 drivers/base/bus.c:713
> >> [<ffffffff81814e2b>] driver_register+0xdb/0x190 drivers/base/driver.c:168
> >> [<ffffffff81a5ed16>] __hid_register_driver+0xb6/0x100
> >> drivers/hid/hid-core.c:2677
> >> [<ffffffff825ab67d>] apple_driver_init+0x24/0x31 drivers/hid/hid-apple.c:574
> >> [<ffffffff81000339>] do_one_initcall+0xb9/0x220 init/main.c:798
> >> [< inlined >] kernel_init_freeable+0x2ca/0x397
> >> do_initcall_level init/main.c:863
> >> [< inlined >] kernel_init_freeable+0x2ca/0x397 do_initcalls
> >> init/main.c:871
> >> [< inlined >] kernel_init_freeable+0x2ca/0x397 do_basic_setup
> >> init/main.c:890
> >> [<ffffffff8253d919>] kernel_init_freeable+0x2ca/0x397 init/main.c:1013
> >> [<ffffffff81e5ad66>] kernel_init+0x16/0x140 init/main.c:941
> >> [<ffffffff81e71f5f>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:526
> >> DBG: cpu = ffff88053fd9fe68
> >> DBG: cpu id = 3
> >>
> >> Previous read of size 1 by thread T509 (K506):
> >> [< inlined >] cypress_send_ext_cmd+0x193/0x500
> >> cypress_ps2_read_cmd_status drivers/input/mouse/cypress_ps2.c:123
> >> [<ffffffff819e6b23>] cypress_send_ext_cmd+0x193/0x500
> >> drivers/input/mouse/cypress_ps2.c:192
> >> [<ffffffff819e6f5a>] cypress_detect+0x2a/0xb0
> >> drivers/input/mouse/cypress_ps2.c:208
> >> [<ffffffff819d5e66>] psmouse_extensions+0x1f6/0x4e0
> >> drivers/input/mouse/psmouse-base.c:849 (discriminator 1)
> >> [<ffffffff819d63fd>] psmouse_switch_protocol+0x2ad/0x330
> >> drivers/input/mouse/psmouse-base.c:1467
> >> [<ffffffff819d7426>] psmouse_connect+0x2e6/0x450
> >> drivers/input/mouse/psmouse-base.c:1554 (discriminator 4)
> >> [< inlined >] serio_driver_probe+0x57/0x80
> >> serio_connect_driver drivers/input/serio/serio.c:65
> >> [<ffffffff819bcf77>] serio_driver_probe+0x57/0x80
> >> drivers/input/serio/serio.c:796
> >> [< inlined >] driver_probe_device+0x1da/0x460 really_probe
> >> drivers/base/dd.c:308
> >> [<ffffffff81813b1a>] driver_probe_device+0x1da/0x460 drivers/base/dd.c:414
> >> [<ffffffff81813e64>] __driver_attach+0xc4/0xd0 drivers/base/dd.c:612
> >> [<ffffffff81810933>] bus_for_each_dev+0x93/0xe0 drivers/base/bus.c:314
> >> [<ffffffff81813353>] driver_attach+0x33/0x50 drivers/base/dd.c:631
> >> [< inlined >] serio_handle_event+0x2d3/0x3b0
> >> serio_attach_driver drivers/input/serio/serio.c:826
> >> [<ffffffff819bd8e3>] serio_handle_event+0x2d3/0x3b0
> >> drivers/input/serio/serio.c:245
> >> [<ffffffff810adcf9>] process_one_work+0x2a9/0x6d0 kernel/workqueue.c:2036
> >> [<ffffffff810aeddf>] worker_thread+0xbf/0x710 kernel/workqueue.c:2170
> >> [<ffffffff810b700c>] kthread+0x15c/0x180 kernel/kthread.c:207
> >> [<ffffffff81e71f5f>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:526
> >> DBG: cpu = 0
> >>
> >> DBG: addr: ffff88019d703909
> >> DBG: first offset: 1, second offset: 1
> >> DBG: T1 clock: {T1: 17075020, T509: 142163}
> >> DBG: T509 clock: {T509: 142167}
> >> ==================================================================
> >>
> >> It seems that accessing 'psmouse->pktcnt' in
> >> 'psmouse->packet[psmouse->pktcnt++] = data' in 'psmouse_interrupt()'
> >> is racing with 'wait_event_timeout(ps2dev->wait, (psmouse->pktcnt >=
> >> pktsize), msecs_to_jiffies(CYTP_CMD_TIMEOUT))' in
> >> 'cypress_ps2_read_cmd_status()'.
> >> If that's the case, it's possible that 'psmouse->pktcnt' is
> >> incremented, but no data is written yet, so '(psmouse->pktcnt >=
> >> pktsize)' will evaluate to true and the following 'memcpy' will access
> >> invalid data.
> >>
> >> Could you confirm if this is a real data race?
> >>
> >> Thanks in advance!
> >>
> >
> > Hi Andrey,
> >
> > I would like to ask you, did not you noticed some problem from Sanitizer
> > with psmouse-base.c and alps.c code?
> >
> > There is unknown problem when alps.c receive invalid data from
> > psmouse_interrupt/serio_interrupt/i8042_interrupt.
> >
> > And when I read your email with race condition & accesing invalid data
> > in cypress driver. I'm thinking if there cannot be something like that.
> >
> > --
> > Pali Rohár
> > pali.rohar@gmail.com
--
Pali Rohár
pali.rohar@gmail.com
WARNING: multiple messages have this Message-ID (diff)
From: "Pali Rohár" <pali.rohar@gmail.com>
To: Andrey Konovalov <andreyknvl@google.com>
Cc: Dmitry Torokhov <dmitry.torokhov@gmail.com>,
Hans de Goede <hdegoede@redhat.com>,
Mathias Gottschlag <mgottschlag@gmail.com>,
Shailendra Verma <shailendra.capricorn@gmail.com>,
Rusty Russell <rusty@rustcorp.com.au>,
"Luis R. Rodriguez" <mcgrof@suse.com>,
Thomas Hellstrom <thellstrom@vmware.com>,
linux-input@vger.kernel.org, linux-kernel@vger.kernel.org,
Dmitry Vyukov <dvyukov@google.com>,
Kostya Serebryany <kcc@google.com>,
Alexander Potapenko <glider@google.com>,
ktsan@googlegroups.com
Subject: Re: Potential data race in psmouse_interrupt
Date: Wed, 29 Jul 2015 13:53:26 +0200 [thread overview]
Message-ID: <20150729115326.GE13518@pali> (raw)
In-Reply-To: <CAAeHK+xyvq3XnN2FZuO35i+DBDYoi1OFWvHmAdZmC=k7kq9q5Q@mail.gmail.com>
Hi! This log looks like there can be race condition in initialization
code, but not in receiving ALPS packets after initialization...
On Thursday 23 July 2015 15:31:46 Andrey Konovalov wrote:
> Hi Pali,
>
> There are a few reports in psmouse-base.c/alps.c code as well.
> Here is a couple of them that are printed one right after another.
> The second one tells about a race on ps2dev->cmdcnt.
>
> ==================================================================
> ThreadSanitizer: data-race in ps2_handle_ack
>
> Write of size 8 by thread T6 (K6):
> [<ffffffff819c0b83>] ps2_handle_ack+0xf3/0x180 drivers/input/serio/libps2.c:322
> [<ffffffff819d55d7>] psmouse_interrupt+0x207/0x690
> drivers/input/mouse/psmouse-base.c:317
> [<ffffffff819bcf46>] serio_interrupt+0x66/0xb0 drivers/input/serio/serio.c:1008
> [<ffffffff819be820>] i8042_interrupt+0x240/0x4d0
> drivers/input/serio/i8042.c:541
> [<ffffffff810f03b2>] handle_irq_event_percpu+0x62/0x2a0 kernel/irq/handle.c:143
> [<ffffffff810f0692>] handle_irq_event+0xa2/0xf0 kernel/irq/handle.c:192
> [<ffffffff810f5414>] handle_edge_irq+0x104/0x380 kernel/irq/chip.c:608
> [< inlined >] handle_irq+0xf6/0x220 generic_handle_irq_desc
> include/linux/irqdesc.h:146
> [<ffffffff81009f86>] handle_irq+0xf6/0x220 arch/x86/kernel/irq_64.c:81
> [<ffffffff810093ce>] do_IRQ+0x5e/0x110 arch/x86/kernel/irq.c:223
> [<ffffffff81e728ab>] ret_from_intr+0x0/0x1f arch/x86/entry/entry_64.S:601
> [< inlined >] irq_exit+0x98/0xa0 invoke_softirq kernel/softirq.c:350
> [<ffffffff8108edd8>] irq_exit+0x98/0xa0 kernel/softirq.c:391
> [< inlined >] smp_apic_timer_interrupt+0x63/0x80 exiting_irq
> ./arch/x86/include/asm/apic.h:655
> [<ffffffff8105c503>] smp_apic_timer_interrupt+0x63/0x80
> arch/x86/kernel/apic/apic.c:915
> [<ffffffff81e72b9b>] apic_timer_interrupt+0x6b/0x70
> arch/x86/entry/entry_64.S:782
> [<ffffffff81086fe3>] _do_fork+0x133/0x500 kernel/fork.c:1719
> [<ffffffff810873ec>] kernel_thread+0x3c/0x60 kernel/fork.c:1772
> [<ffffffff810a71dc>] __call_usermodehelper+0x5c/0x90 kernel/kmod.c:317
> [<ffffffff810adcf9>] process_one_work+0x2a9/0x6d0 kernel/workqueue.c:2036
> [<ffffffff810aeddf>] worker_thread+0xbf/0x710 kernel/workqueue.c:2170
> [<ffffffff810b700c>] kthread+0x15c/0x180 kernel/kthread.c:207
> [<ffffffff81e7215f>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:526
> DBG: cpu = ffff88053fd9fe68
> DBG: cpu id = 3
>
> Previous read of size 8 by thread T397 (K394):
> [<ffffffff819c0cf2>] ps2_sendbyte+0xe2/0x210 drivers/input/serio/libps2.c:45
> [<ffffffff819c1109>] __ps2_command+0x159/0x660 drivers/input/serio/libps2.c:214
> [<ffffffff819c1645>] ps2_command+0x35/0x60 drivers/input/serio/libps2.c:260
> [<ffffffff819dd412>] alps_rpt_cmd+0x42/0xe0
> drivers/input/mouse/alps.c:1665 (discriminator 1)
> [<ffffffff819e12b6>] alps_identify+0x36/0xc80 drivers/input/mouse/alps.c:2690
> [<ffffffff819e3498>] alps_detect+0x28/0x150 drivers/input/mouse/alps.c:2960
> [< inlined >] psmouse_extensions+0x25e/0x4e0 psmouse_do_detect
> drivers/input/mouse/psmouse-base.c:752
> [<ffffffff819d60fe>] psmouse_extensions+0x25e/0x4e0
> drivers/input/mouse/psmouse-base.c:870
> [<ffffffff819d662d>] psmouse_switch_protocol+0x2ad/0x330
> drivers/input/mouse/psmouse-base.c:1467
> [<ffffffff819d7656>] psmouse_connect+0x2e6/0x450
> drivers/input/mouse/psmouse-base.c:1554 (discriminator 4)
> [< inlined >] serio_driver_probe+0x57/0x80
> serio_connect_driver drivers/input/serio/serio.c:65
> [<ffffffff819bd1a7>] serio_driver_probe+0x57/0x80
> drivers/input/serio/serio.c:796
> [< inlined >] driver_probe_device+0x1da/0x460 really_probe
> drivers/base/dd.c:308
> [<ffffffff81813d4a>] driver_probe_device+0x1da/0x460 drivers/base/dd.c:414
> [<ffffffff81814094>] __driver_attach+0xc4/0xd0 drivers/base/dd.c:612
> [<ffffffff81810b63>] bus_for_each_dev+0x93/0xe0 drivers/base/bus.c:314
> [<ffffffff81813583>] driver_attach+0x33/0x50 drivers/base/dd.c:631
> [< inlined >] serio_handle_event+0x2d3/0x3b0
> serio_attach_driver drivers/input/serio/serio.c:826
> [<ffffffff819bdb13>] serio_handle_event+0x2d3/0x3b0
> drivers/input/serio/serio.c:245
> [<ffffffff810adcf9>] process_one_work+0x2a9/0x6d0 kernel/workqueue.c:2036
> [<ffffffff810aeddf>] worker_thread+0xbf/0x710 kernel/workqueue.c:2170
> [<ffffffff810b700c>] kthread+0x15c/0x180 kernel/kthread.c:207
> [<ffffffff81e7215f>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:526
> DBG: cpu = 0
>
> DBG: addr: ffff88019a923a58
> DBG: first offset: 0, second offset: 0
> DBG: T6 clock: {T6: 2264295, T397: 174118}
> DBG: T397 clock: {T397: 174122}
> ==================================================================
> ==================================================================
> ThreadSanitizer: data-race in __ps2_command
>
> Read of size 1 by thread T397 (K394):
> [<ffffffff819c1220>] __ps2_command+0x270/0x660
> drivers/input/serio/libps2.c:230 (discriminator 21)
> [<ffffffff819c1645>] ps2_command+0x35/0x60 drivers/input/serio/libps2.c:260
> [<ffffffff819dd47e>] alps_rpt_cmd+0xae/0xe0 drivers/input/mouse/alps.c:1674
> [<ffffffff819e12b6>] alps_identify+0x36/0xc80 drivers/input/mouse/alps.c:2690
> [<ffffffff819e3498>] alps_detect+0x28/0x150 drivers/input/mouse/alps.c:2960
> [< inlined >] psmouse_extensions+0x25e/0x4e0 psmouse_do_detect
> drivers/input/mouse/psmouse-base.c:752
> [<ffffffff819d60fe>] psmouse_extensions+0x25e/0x4e0
> drivers/input/mouse/psmouse-base.c:870
> [<ffffffff819d662d>] psmouse_switch_protocol+0x2ad/0x330
> drivers/input/mouse/psmouse-base.c:1467
> [<ffffffff819d7656>] psmouse_connect+0x2e6/0x450
> drivers/input/mouse/psmouse-base.c:1554 (discriminator 4)
> [< inlined >] serio_driver_probe+0x57/0x80
> serio_connect_driver drivers/input/serio/serio.c:65
> [<ffffffff819bd1a7>] serio_driver_probe+0x57/0x80
> drivers/input/serio/serio.c:796
> [< inlined >] driver_probe_device+0x1da/0x460 really_probe
> drivers/base/dd.c:308
> [<ffffffff81813d4a>] driver_probe_device+0x1da/0x460 drivers/base/dd.c:414
> [<ffffffff81814094>] __driver_attach+0xc4/0xd0 drivers/base/dd.c:612
> [<ffffffff81810b63>] bus_for_each_dev+0x93/0xe0 drivers/base/bus.c:314
> [<ffffffff81813583>] driver_attach+0x33/0x50 drivers/base/dd.c:631
> [< inlined >] serio_handle_event+0x2d3/0x3b0
> serio_attach_driver drivers/input/serio/serio.c:826
> [<ffffffff819bdb13>] serio_handle_event+0x2d3/0x3b0
> drivers/input/serio/serio.c:245
> [<ffffffff810adcf9>] process_one_work+0x2a9/0x6d0 kernel/workqueue.c:2036
> [<ffffffff810aeddf>] worker_thread+0xbf/0x710 kernel/workqueue.c:2170
> [<ffffffff810b700c>] kthread+0x15c/0x180 kernel/kthread.c:207
> [<ffffffff81e7215f>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:526
> DBG: cpu = ffff88053fc9fe68
> DBG: cpu id = 1
>
> Previous write of size 1 by thread T6 (K6):
> [<ffffffff819c09a6>] ps2_handle_response+0x46/0x130
> drivers/input/serio/libps2.c:346
> [<ffffffff819d58a4>] psmouse_interrupt+0x4d4/0x690
> drivers/input/mouse/psmouse-base.c:321
> [<ffffffff819bcf46>] serio_interrupt+0x66/0xb0 drivers/input/serio/serio.c:1008
> [<ffffffff819be820>] i8042_interrupt+0x240/0x4d0
> drivers/input/serio/i8042.c:541
> [<ffffffff810f03b2>] handle_irq_event_percpu+0x62/0x2a0 kernel/irq/handle.c:143
> [<ffffffff810f0692>] handle_irq_event+0xa2/0xf0 kernel/irq/handle.c:192
> [<ffffffff810f5414>] handle_edge_irq+0x104/0x380 kernel/irq/chip.c:608
> [< inlined >] handle_irq+0xf6/0x220 generic_handle_irq_desc
> include/linux/irqdesc.h:146
> [<ffffffff81009f86>] handle_irq+0xf6/0x220 arch/x86/kernel/irq_64.c:81
> [<ffffffff810093ce>] do_IRQ+0x5e/0x110 arch/x86/kernel/irq.c:223
> [<ffffffff81e728ab>] ret_from_intr+0x0/0x1f arch/x86/entry/entry_64.S:601
> [<ffffffff81e72b9b>] apic_timer_interrupt+0x6b/0x70
> arch/x86/entry/entry_64.S:782
> [< inlined >] kvm_clock_get_cycles+0x3e/0x50 kvm_clock_read
> arch/x86/kernel/kvmclock.c:85
> [<ffffffff8106e74e>] kvm_clock_get_cycles+0x3e/0x50
> arch/x86/kernel/kvmclock.c:92
> [< inlined >] ktime_get_with_offset+0x99/0x180
> timekeeping_get_delta kernel/time/timekeeping.c:210
> [< inlined >] ktime_get_with_offset+0x99/0x180
> timekeeping_get_ns kernel/time/timekeeping.c:306
> [<ffffffff81114da9>] ktime_get_with_offset+0x99/0x180
> kernel/time/timekeeping.c:720
> [< inlined >] copy_process.part.44+0x773/0x2c40
> ktime_get_boottime include/linux/timekeeping.h:183
> [< inlined >] copy_process.part.44+0x773/0x2c40
> ktime_get_boot_ns include/linux/timekeeping.h:214
> [<ffffffff810848b3>] copy_process.part.44+0x773/0x2c40 kernel/fork.c:1363
> [< inlined >] _do_fork+0x103/0x500 copy_process kernel/fork.c:1261
> [<ffffffff81086fb3>] _do_fork+0x103/0x500 kernel/fork.c:1709
> [<ffffffff810873ec>] kernel_thread+0x3c/0x60 kernel/fork.c:1772
> [<ffffffff810a71dc>] __call_usermodehelper+0x5c/0x90 kernel/kmod.c:317
> [<ffffffff810adcf9>] process_one_work+0x2a9/0x6d0 kernel/workqueue.c:2036
> [<ffffffff810aeddf>] worker_thread+0xbf/0x710 kernel/workqueue.c:2170
> [<ffffffff810b700c>] kthread+0x15c/0x180 kernel/kthread.c:207
> [<ffffffff81e7215f>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:526
> DBG: cpu = 0
>
> DBG: addr: ffff88019a923a68
> DBG: first offset: 0, second offset: 0
> DBG: T397 clock: {T397: 175738, T6: 2266233}
> DBG: T6 clock: {T6: 2266336}
> ==================================================================
>
> On Thu, Jul 23, 2015 at 3:08 PM, Pali Rohár <pali.rohar@gmail.com> wrote:
> > On Wednesday 22 July 2015 15:14:42 Andrey Konovalov wrote:
> >> Hi!
> >>
> >> We are working on a dynamic data race detector for Linux kernel called
> >> KernelThreadSanitizer (ktsan) (https://github.com/google/ktsan/wiki).
> >>
> >> Here is a report we got while running ktsan (upstream revision
> >> 21bdb584af8cca7c6df3c44cba268be050a234eb).
> >>
> >> ==================================================================
> >> ThreadSanitizer: data-race in psmouse_interrupt
> >>
> >> Write of size 1 by thread T1 (K1):
> >> [<ffffffff819d5272>] psmouse_interrupt+0xd2/0x690
> >> drivers/input/mouse/psmouse-base.c:337
> >> [<ffffffff819bcd16>] serio_interrupt+0x66/0xb0 drivers/input/serio/serio.c:1008
> >> [<ffffffff819be5f0>] i8042_interrupt+0x240/0x4d0
> >> drivers/input/serio/i8042.c:541
> >> [<ffffffff810f03b2>] handle_irq_event_percpu+0x62/0x2a0 kernel/irq/handle.c:143
> >> [<ffffffff810f0692>] handle_irq_event+0xa2/0xf0 kernel/irq/handle.c:192
> >> [<ffffffff810f5414>] handle_edge_irq+0x104/0x380 kernel/irq/chip.c:608
> >> [< inlined >] handle_irq+0xf6/0x220 generic_handle_irq_desc
> >> include/linux/irqdesc.h:146
> >> [<ffffffff81009f86>] handle_irq+0xf6/0x220 arch/x86/kernel/irq_64.c:81
> >> [<ffffffff810093ce>] do_IRQ+0x5e/0x110 arch/x86/kernel/irq.c:223
> >> [<ffffffff81e726ab>] ret_from_intr+0x0/0x1f arch/x86/entry/entry_64.S:601
> >> [< inlined >] irq_exit+0x98/0xa0 invoke_softirq kernel/softirq.c:350
> >> [<ffffffff8108edd8>] irq_exit+0x98/0xa0 kernel/softirq.c:391
> >> [< inlined >] smp_apic_timer_interrupt+0x63/0x80 exiting_irq
> >> ./arch/x86/include/asm/apic.h:655
> >> [<ffffffff8105c503>] smp_apic_timer_interrupt+0x63/0x80
> >> arch/x86/kernel/apic/apic.c:915
> >> [<ffffffff81e7299b>] apic_timer_interrupt+0x6b/0x70
> >> arch/x86/entry/entry_64.S:782
> >> [<ffffffff8153223d>] kvasprintf+0x5d/0x90 lib/kasprintf.c:24
> >> [<ffffffff815322be>] kasprintf+0x4e/0x70 lib/kasprintf.c:40
> >> [< inlined >] module_add_driver+0x8f/0x180 make_driver_name
> >> drivers/base/module.c:18
> >> [<ffffffff8183059f>] module_add_driver+0x8f/0x180 drivers/base/module.c:63
> >> [<ffffffff81812c94>] bus_add_driver+0x204/0x340 drivers/base/bus.c:713
> >> [<ffffffff81814e2b>] driver_register+0xdb/0x190 drivers/base/driver.c:168
> >> [<ffffffff81a5ed16>] __hid_register_driver+0xb6/0x100
> >> drivers/hid/hid-core.c:2677
> >> [<ffffffff825ab67d>] apple_driver_init+0x24/0x31 drivers/hid/hid-apple.c:574
> >> [<ffffffff81000339>] do_one_initcall+0xb9/0x220 init/main.c:798
> >> [< inlined >] kernel_init_freeable+0x2ca/0x397
> >> do_initcall_level init/main.c:863
> >> [< inlined >] kernel_init_freeable+0x2ca/0x397 do_initcalls
> >> init/main.c:871
> >> [< inlined >] kernel_init_freeable+0x2ca/0x397 do_basic_setup
> >> init/main.c:890
> >> [<ffffffff8253d919>] kernel_init_freeable+0x2ca/0x397 init/main.c:1013
> >> [<ffffffff81e5ad66>] kernel_init+0x16/0x140 init/main.c:941
> >> [<ffffffff81e71f5f>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:526
> >> DBG: cpu = ffff88053fd9fe68
> >> DBG: cpu id = 3
> >>
> >> Previous read of size 1 by thread T509 (K506):
> >> [< inlined >] cypress_send_ext_cmd+0x193/0x500
> >> cypress_ps2_read_cmd_status drivers/input/mouse/cypress_ps2.c:123
> >> [<ffffffff819e6b23>] cypress_send_ext_cmd+0x193/0x500
> >> drivers/input/mouse/cypress_ps2.c:192
> >> [<ffffffff819e6f5a>] cypress_detect+0x2a/0xb0
> >> drivers/input/mouse/cypress_ps2.c:208
> >> [<ffffffff819d5e66>] psmouse_extensions+0x1f6/0x4e0
> >> drivers/input/mouse/psmouse-base.c:849 (discriminator 1)
> >> [<ffffffff819d63fd>] psmouse_switch_protocol+0x2ad/0x330
> >> drivers/input/mouse/psmouse-base.c:1467
> >> [<ffffffff819d7426>] psmouse_connect+0x2e6/0x450
> >> drivers/input/mouse/psmouse-base.c:1554 (discriminator 4)
> >> [< inlined >] serio_driver_probe+0x57/0x80
> >> serio_connect_driver drivers/input/serio/serio.c:65
> >> [<ffffffff819bcf77>] serio_driver_probe+0x57/0x80
> >> drivers/input/serio/serio.c:796
> >> [< inlined >] driver_probe_device+0x1da/0x460 really_probe
> >> drivers/base/dd.c:308
> >> [<ffffffff81813b1a>] driver_probe_device+0x1da/0x460 drivers/base/dd.c:414
> >> [<ffffffff81813e64>] __driver_attach+0xc4/0xd0 drivers/base/dd.c:612
> >> [<ffffffff81810933>] bus_for_each_dev+0x93/0xe0 drivers/base/bus.c:314
> >> [<ffffffff81813353>] driver_attach+0x33/0x50 drivers/base/dd.c:631
> >> [< inlined >] serio_handle_event+0x2d3/0x3b0
> >> serio_attach_driver drivers/input/serio/serio.c:826
> >> [<ffffffff819bd8e3>] serio_handle_event+0x2d3/0x3b0
> >> drivers/input/serio/serio.c:245
> >> [<ffffffff810adcf9>] process_one_work+0x2a9/0x6d0 kernel/workqueue.c:2036
> >> [<ffffffff810aeddf>] worker_thread+0xbf/0x710 kernel/workqueue.c:2170
> >> [<ffffffff810b700c>] kthread+0x15c/0x180 kernel/kthread.c:207
> >> [<ffffffff81e71f5f>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:526
> >> DBG: cpu = 0
> >>
> >> DBG: addr: ffff88019d703909
> >> DBG: first offset: 1, second offset: 1
> >> DBG: T1 clock: {T1: 17075020, T509: 142163}
> >> DBG: T509 clock: {T509: 142167}
> >> ==================================================================
> >>
> >> It seems that accessing 'psmouse->pktcnt' in
> >> 'psmouse->packet[psmouse->pktcnt++] = data' in 'psmouse_interrupt()'
> >> is racing with 'wait_event_timeout(ps2dev->wait, (psmouse->pktcnt >=
> >> pktsize), msecs_to_jiffies(CYTP_CMD_TIMEOUT))' in
> >> 'cypress_ps2_read_cmd_status()'.
> >> If that's the case, it's possible that 'psmouse->pktcnt' is
> >> incremented, but no data is written yet, so '(psmouse->pktcnt >=
> >> pktsize)' will evaluate to true and the following 'memcpy' will access
> >> invalid data.
> >>
> >> Could you confirm if this is a real data race?
> >>
> >> Thanks in advance!
> >>
> >
> > Hi Andrey,
> >
> > I would like to ask you, did not you noticed some problem from Sanitizer
> > with psmouse-base.c and alps.c code?
> >
> > There is unknown problem when alps.c receive invalid data from
> > psmouse_interrupt/serio_interrupt/i8042_interrupt.
> >
> > And when I read your email with race condition & accesing invalid data
> > in cypress driver. I'm thinking if there cannot be something like that.
> >
> > --
> > Pali Rohár
> > pali.rohar@gmail.com
--
Pali Rohár
pali.rohar@gmail.com
--
To unsubscribe from this list: send the line "unsubscribe linux-input" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
next prev parent reply other threads:[~2015-07-29 11:53 UTC|newest]
Thread overview: 19+ messages / expand[flat|nested] mbox.gz Atom feed top
[not found] <CAAeHK+wZ=fXCRDUvkQdSmFWxU1fqN5suF=P1kL_CT1L8p3ybDg@mail.gmail.com>
2015-07-22 13:14 ` Fwd: Potential data race in psmouse_interrupt Andrey Konovalov
2015-07-22 16:52 ` Dmitry Torokhov
2015-07-23 13:08 ` Pali Rohár
2015-07-23 13:31 ` Andrey Konovalov
2015-07-23 13:31 ` Andrey Konovalov
2015-07-29 11:53 ` Pali Rohár [this message]
2015-07-29 11:53 ` Pali Rohár
2015-08-28 17:34 ` Dmitry Vyukov
2015-08-28 17:51 ` Dmitry Torokhov
2015-08-28 18:08 ` Dmitry Vyukov
2015-08-28 18:32 ` Dmitry Torokhov
2015-08-28 18:34 ` Dmitry Torokhov
2015-09-01 18:46 ` Dmitry Vyukov
2015-09-04 16:56 ` Dmitry Torokhov
2015-09-04 19:32 ` Dmitry Vyukov
2015-09-04 20:27 ` Dmitry Torokhov
2015-09-05 13:21 ` Dmitry Vyukov
2015-09-07 14:06 ` Dmitry Vyukov
2015-09-07 14:06 ` Dmitry Vyukov
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20150729115326.GE13518@pali \
--to=pali.rohar@gmail.com \
--cc=andreyknvl@google.com \
--cc=dmitry.torokhov@gmail.com \
--cc=dvyukov@google.com \
--cc=glider@google.com \
--cc=hdegoede@redhat.com \
--cc=kcc@google.com \
--cc=ktsan@googlegroups.com \
--cc=linux-input@vger.kernel.org \
--cc=linux-kernel@vger.kernel.org \
--cc=mcgrof@suse.com \
--cc=mgottschlag@gmail.com \
--cc=rusty@rustcorp.com.au \
--cc=shailendra.capricorn@gmail.com \
--cc=thellstrom@vmware.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.