linux-ide.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
From: Albert Lee <albertcc@tw.ibm.com>
To: Jeff Garzik <jgarzik@pobox.com>
Cc: Bartlomiej Zolnierkiewicz <bzolnier@gmail.com>,
	Doug Maxey <dwm@maxeymade.com>,
	IDE Linux <linux-ide@vger.kernel.org>
Subject: Re: [PATCH 1/2] libata: Fix race condition in ata_pio_task()
Date: Mon, 27 Jun 2005 17:40:45 +0800	[thread overview]
Message-ID: <42BFC99D.60304@tw.ibm.com> (raw)
In-Reply-To: <42BB826A.6040209@tw.ibm.com>

[-- Attachment #1: Type: text/plain, Size: 817 bytes --]

Jeff,

> 
> 
> This is patch 1/2. (The previous subject is incorrect. Resend it here.)
> Problem:
>    'assert(qc != NULL)' failed in ata_pio_block() and ata_pio_complete().
> 
> Root cause:
>    Race condition in ata_pio_task() when accessing 'ap->pio_task_state' 
> after ata_qc_complete():
> If the next command is queued after ata_qc_complete() and before 
> ata_pio_task() checks 'ap->pio_task_state',
> 'ap->pio_task_state' might have been changed from PIO_ST_IDLE to PIO_ST 
> by ata_qc_issue_prot().
> This will cause ata_pio_task() to run extra steps even if the command is 
> finished.
> The extra steps race with the next command and causing trouble.
> 

Attached please find the detailed debug trace with annotation for the problem.
Hopefully it can help to make the problem description clearer.


Albert

[-- Attachment #2: debug_trace.txt --]
[-- Type: text/plain, Size: 6606 bytes --]

<3>ata_scsi_dump_cdb: CDB (1:0,0,0) be 00 00 04 0c b4 00 00 01
<3>ata_scsi_translate: ENTER
<3>ata_dev_select: ENTER, ata1: device 0, wait 1
<3>ata_tf_load_pio: feat 0x0 nsect 0x0 lba 0x0 0x0 0x20
<3>ata_tf_load_pio: device 0xA0
<3>ata_exec_command_pio: ata1: cmd 0xA0
<3>ata_scsi_translate: EXIT
<3>atapi_packet_task: busy wait
<3>atapi_packet_task: send cdb
<3>atapi_packet_task: EXIT
<3>ata_pio_task: pio_task_state 4
<3>ata_pio_block: ENTER
<3>__atapi_pio_bytes: data read
<3>ata_pio_block: EXIT 2
<3>ata_pio_task: pio_task_state 5
<3>ata_pio_complete: ENTER
<3>ata_qc_complete: ENTER
<3>__ata_qc_complete: ENTER
<3>__ata_qc_complete: EXIT
<3>ata_qc_complete: EXIT      
 
<== Oops! ata_pio_complete() does not return yet, and the next command comes in!
    The missing ata_pio_complete() will cause trouble later.

<3>ata_scsi_dump_cdb: CDB (1:0,1,0) be 00 00 04 0d 24 00 00 01
<3>ata_scsi_translate: ENTER
<3>ata_dev_select: ENTER, ata1: device 1, wait 1
<3>ata_tf_load_pio: feat 0x0 nsect 0x0 lba 0x0 0x0 0x20
<3>ata_tf_load_pio: device 0xB0
<3>ata_exec_command_pio: ata1: cmd 0xA0
<3>ata_scsi_translate: EXIT
<3>atapi_packet_task: busy wait
<3>atapi_packet_task: send cdb
<3>atapi_packet_task: EXIT
<3>ata_pio_task: pio_task_state 4
<3>ata_pio_block: ENTER
<3>__atapi_pio_bytes: data read
<3>ata_pio_block: EXIT 2
<3>ata_pio_task: pio_task_state 5
<3>ata_pio_complete: ENTER
<3>ata_qc_complete: ENTER
<3>__ata_qc_complete: ENTER
<3>__ata_qc_complete: EXIT
<3>ata_qc_complete: EXIT
<3>ata_pio_complete: EXIT

<== This "READ CD" completed normally.

<3>ata_scsi_dump_cdb: CDB (1:0,1,0) be 00 00 04 0d 24 00 00 01
<3>ata_scsi_translate: ENTER
<3>ata_dev_select: ENTER, ata1: device 1, wait 1
<3>ata_tf_load_pio: feat 0x0 nsect 0x0 lba 0x0 0x0 0x20
<3>ata_tf_load_pio: device 0xB0
<3>ata_exec_command_pio: ata1: cmd 0xA0
<3>ata_scsi_translate: EXIT
<3>atapi_packet_task: busy wait
<3>atapi_packet_task: send cdb
<3>atapi_packet_task: EXIT
<3>ata_pio_task: pio_task_state 4
<3>ata_pio_block: ENTER
<3>__atapi_pio_bytes: data read
<3>ata_pio_block: EXIT 2
<3>ata_pio_task: pio_task_state 5
<3>ata_pio_complete: ENTER
<3>ata_qc_complete: ENTER
<3>__ata_qc_complete: ENTER
<3>__ata_qc_complete: EXIT
<3>ata_qc_complete: EXIT
<3>ata_pio_complete: EXIT

<== This "READ CD" completed normally.

<3>ata_scsi_dump_cdb: CDB (1:0,0,0) be 00 00 04 0c b6 00 00 01
<3>ata_scsi_translate: ENTER
<3>ata_dev_select: ENTER, ata1: device 0, wait 1
<3>ata_tf_load_pio: feat 0x0 nsect 0x0 lba 0x0 0x0 0x20
<3>ata_tf_load_pio: device 0xA0
<3>ata_exec_command_pio: ata1: cmd 0xA0
<3>ata_scsi_translate: EXIT
<3>atapi_packet_task: busy wait
<3>atapi_packet_task: send cdb
<3>atapi_packet_task: EXIT
<3>ata_pio_task: pio_task_state 4
<3>ata_pio_block: ENTER
<3>ata_pio_complete: EXIT   <== The previous missing ata_pio_complete().
                            <== Since pio_task_state was changed to 4 now, 
                            <== it will queue an extra ata_pio_task() and
                            <== starts racing with the current command.
<3>ata_pio_task: pio_task_state 4   (Oop! Extra ata_pio_task() queued!)
<3>ata_pio_block: ENTER
<3>__atapi_pio_bytes: data read
<3>__atapi_pio_bytes: ata1: padding 2336 bytes  (Oop! extra data read!)
<3>ata_pio_block: EXIT 2
<3>ata_pio_task: pio_task_state 5
<3>ata_pio_complete: ENTER
<3>ata_qc_complete: ENTER
<3>__ata_qc_complete: ENTER
<3>__ata_qc_complete: EXIT
<3>ata_qc_complete: EXIT
<3>ata_pio_complete: EXIT

<== The ata_pio_complete() was called twice!

<3>ata_scsi_dump_cdb: CDB (1:0,1,0) be 00 00 04 0d 26 00 00 01
<3>ata_scsi_translate: ENTER
<3>ata_dev_select: ENTER, ata1: device 1, wait 1
<3>ata_tf_load_pio: feat 0x0 nsect 0x0 lba 0x0 0x0 0x20
<3>ata_tf_load_pio: device 0xB0
<3>ata_exec_command_pio: ata1: cmd 0xA0
<3>ata_scsi_translate: EXIT
<3>atapi_packet_task: busy wait
<3>atapi_packet_task: send cdb
<3>atapi_packet_task: EXIT
<3>ata_pio_task: pio_task_state 4
<3>ata_pio_block: ENTER
<3>__atapi_pio_bytes: data read
<3>ata_pio_block: EXIT 2
<3>ata_pio_task: pio_task_state 5
<3>ata_pio_complete: ENTER
<3>ata_qc_complete: ENTER
<3>__ata_qc_complete: ENTER
<3>__ata_qc_complete: EXIT
<3>ata_qc_complete: EXIT
<3>ata_pio_complete: EXIT
<3>ata_scsi_dump_cdb: CDB (1:0,0,0) be 00 00 04 0c b6 00 00 01
<3>ata_scsi_translate: ENTER
<3>ata_dev_select: ENTER, ata1: device 0, wait 1
<3>ata_tf_load_pio: feat 0x0 nsect 0x0 lba 0x0 0x0 0x20
<3>ata_tf_load_pio: device 0xA0
<3>ata_exec_command_pio: ata1: cmd 0xA0
<3>ata_scsi_translate: EXIT
<3>atapi_packet_task: busy wait
<3>atapi_packet_task: send cdb
<3>atapi_packet_task: EXIT
<3>ata_pio_task: pio_task_state 4
<3>ata_pio_block: ENTER
<3>__atapi_pio_bytes: data read
<3>ata_pio_block: EXIT 2
<3>ata_pio_task: pio_task_state 5
<3>ata_pio_complete: ENTER
<3>ata_qc_complete: ENTER
<3>__ata_qc_complete: ENTER
<3>__ata_qc_complete: EXIT
<3>ata_qc_complete: EXIT
<3>ata_pio_complete: EXIT
<3>ata_scsi_dump_cdb: CDB (1:0,1,0) be 00 00 04 0d 26 00 00 01
<3>ata_scsi_translate: ENTER
<3>ata_dev_select: ENTER, ata1: device 1, wait 1
<3>ata_tf_load_pio: feat 0x0 nsect 0x0 lba 0x0 0x0 0x20
<3>ata_tf_load_pio: device 0xB0
<3>ata_exec_command_pio: ata1: cmd 0xA0
<3>ata_scsi_translate: EXIT
<3>atapi_packet_task: busy wait
<3>atapi_packet_task: send cdb
<3>atapi_packet_task: EXIT
<3>ata_pio_task: pio_task_state 4
<3>ata_pio_block: ENTER
<3>__atapi_pio_bytes: data read
<3>ata_pio_block: EXIT 2
<3>ata_pio_task: pio_task_state 5
<3>ata_pio_complete: ENTER
<3>ata_qc_complete: ENTER
<3>__ata_qc_complete: ENTER
<3>__ata_qc_complete: EXIT
<3>ata_qc_complete: EXIT
<3>ata_pio_complete: EXIT
<3>ata_pio_block: EXIT 2     

<== stopped in kdb. tcp/ip stack is victim.

[12]kdb> bt
Stack traceback for pid 13774
0xc000000123f60210    13774    13509  1   12   R  0xc000000123f606c0 *hxecom
          SP(esp)            PC(eip)      Function(args)
0xc0000001220eb4e0  0xc0000000002fff60  .skb_release_data +0x120
0xc0000001220eb4e0  0xc0000000002ffb74 (lr) .kfree_skbmem +0x20
0xc0000001220eb570  0xc0000000002ffb74  .kfree_skbmem +0x20
0xc0000001220eb600  0xc0000000002ffce8  .__kfree_skb +0x148
0xc0000001220eb6b0  0xc000000000339e2c  .tcp_recvmsg +0x6e8
0xc0000001220eb830  0xc0000000003631b8  .inet_recvmsg +0x58
--- Exception: c0000001220eb9d8:  NO_SYMBOL or Userspace
0xc0000001220ebb20  0xc00000021fcd1b80  NO_SYMBOL or Userspace +0x58
0xc0000001220ebb20  0xc0000000000cd2cc (lr) .fget +0x2c
0xc00000000006ffa0  0x7c2004ac38000000  NO_SYMBOL or Userspace
    kdb: Not a kernel-space address 0x60000000e81c0048 
0x60000000e81c0038  0x0000000000000000  
<Stack contents outside of kernel space.  60000000e81c0038>


      reply	other threads:[~2005-06-27  9:41 UTC|newest]

Thread overview: 5+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2005-06-23  8:48 [PATCH 0/2] libata: PIO race condition fixes Albert Lee
2005-06-23  9:09 ` Albert Lee
2005-06-23  9:13 ` [PATCH 2/2] libata: Remove 'case ATA_PROT_ATAPI' in ata_host_intr() Albert Lee
2005-06-24  3:47 ` [PATCH 1/2] libata: Fix race condition in ata_pio_task() Albert Lee
2005-06-27  9:40   ` Albert Lee [this message]

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=42BFC99D.60304@tw.ibm.com \
    --to=albertcc@tw.ibm.com \
    --cc=bzolnier@gmail.com \
    --cc=dwm@maxeymade.com \
    --cc=jgarzik@pobox.com \
    --cc=linux-ide@vger.kernel.org \
    /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 a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).