Hi Jeff,
Unfortunately it still happens even without IRQ sharing.
2005-05-25_14:54:01.79454 kern.err: ata1: command 0x35 timeout, stat 0x50 host_stat 0x1
2005-05-25_14:54:04.10684 kern.err: Slab corruption: start=c19d02fc, len=344
2005-05-25_14:54:04.10985 kern.err: Redzone: 0x5a2cf071/0x5a2cf071.
2005-05-25_14:54:04.10987 kern.err: Last user: [<c03b29f9>](scsi_put_command+0x49/0x80)
2005-05-25_14:54:04.10989 kern.err: 010: 6b 6b 6b 6b 6b 6b 6b 6b 08 0a 9d c1 6b 6b 6b 6b
It's 'use after free', someone seems to store 4-byte word into offset 0x18.
This word seems to be a kernel pointer (0xc19d0a08).
I may be mistaken, but I think it is a scsi_cmnd.eh_entry.next.
It seems that scsi_cmnd was freed (see below) and scsi_cmnd offset 0x18
is eh_entry:
struct list_head {
struct list_head *next, *prev;
};
struct scsi_cmnd {
int sc_magic;
struct scsi_device *device;
unsigned short state;
unsigned short owner;
struct scsi_request *sc_request;
struct list_head list; /* scsi_cmnd participates in queue lists */
struct list_head eh_entry; /* entry for the host eh_cmd_q */
2005-05-25_14:54:04.10991 kern.err: Prev obj: start=c19d0198, len=344
2005-05-25_14:54:04.10993 kern.err: Redzone: 0x5a2cf071/0x5a2cf071.
2005-05-25_14:54:04.10995 kern.err: Last user: [<c03b29f9>](scsi_put_command+0x49/0x80)
2005-05-25_14:54:04.10996 kern.err: 000: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
2005-05-25_14:54:04.10998 kern.err: 010: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
2005-05-25_14:54:04.11002 kern.err: Next obj: start=c19d0460, len=344
2005-05-25_14:54:04.11004 kern.err: Redzone: 0x5a2cf071/0x5a2cf071.
2005-05-25_14:54:04.11006 kern.err: Last user: [<c03b29f9>](scsi_put_command+0x49/0x80)
2005-05-25_14:54:04.11007 kern.err: 000: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
2005-05-25_14:54:04.11009 kern.err: 010: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
Looks like "Last user scsi_put_command+0x49" corresponds to list_empty(),
although asm output is a bit strange. Judge for yourself:
void scsi_put_command(struct scsi_cmnd *cmd)
{
struct scsi_device *sdev = cmd->device;
struct Scsi_Host *shost = sdev->host;
unsigned long flags;
/* serious error if the command hasn't come from a device list */
spin_lock_irqsave(&cmd->device->list_lock, flags);
BUG_ON(list_empty(&cmd->list));
list_del_init(&cmd->list);
spin_unlock(&cmd->device->list_lock);
/* changing locks here, don't need to restore the irq state */
spin_lock(&shost->free_list_lock);
asm("#0");
if (unlikely(list_empty(&shost->free_list))) { <==============
asm("#1");
list_add(&cmd->list, &shost->free_list);
cmd = NULL;
}
spin_unlock_irqrestore(&shost->free_list_lock, flags);
if (likely(cmd != NULL))
kmem_cache_free(shost->cmd_pool->slab, cmd);
put_device(&sdev->sdev_gendev);
}
Corresponding asm:
#APP
#0
#NO_APP
leal 20(%esi), %edx
movl 20(%esi), %eax
cmpl %edx, %eax
je .L132
.L127:
#APP
pushl %edi ; popfl
#NO_APP
testl %ebx, %ebx
je .L130
pushl %ebx
movl 16(%esi), %eax
movl (%eax), %ecx
pushl %ecx
call kmem_cache_free
popl %eax <========================== scsi_put_command+0x49
popl %edx
.L130:
movl -16(%ebp), %eax
addl $400, %eax
movl %eax, 8(%ebp)
leal -12(%ebp), %esp
popl %ebx
popl %esi
popl %edi
popl %ebp
jmp put_device
.L132:
#APP
#1
#NO_APP
Hope this helps.
--
vda
Does the attached patch change things?
Jeff
On Thursday 26 May 2005 10:47, Jeff Garzik wrote:
> Does the attached patch change things?
Yes. As soon as first ata error occurs:
22:01:59.006541500 kern.err: ata1: command 0x25 timeout, stat 0x50 host_stat 0x1
22:01:59.007252500 kern.alert: Unable to handle kernel paging request at virtual address 6b6b6b6b
22:01:59.008197500 kern.alert: printing eip:
22:01:59.009304500 kern.info: c03b5d7a
22:01:59.010231500 kern.alert: *pde = 00000000
22:01:59.010919500 kern.alert: Oops: 0000 [#1]
22:01:59.011948500 kern.info: Modules linked in: snd_pcm_oss snd_mixer_oss snd_intel8x0 snd_ac97_codec snd_pcm snd_timer snd soundcore snd_page_alloc ipt_REDIRECT ipt_MASQUERADE ipt_multiport ipt_state iptable_nat ip_conntrack iptable_filter cls_u32 sch_htb iptable_mangle autofs ip_tables
22:01:59.012521500 kern.info: CPU: 0
22:01:59.013618500 kern.info: EIP: 0060:[<c03b5d7a>] Not tainted VLI
22:01:59.014569500 kern.info: EFLAGS: 00010202 (2.6.12-rc2-cl)
22:01:59.015709500 kern.info: EIP is at scsi_try_to_abort_cmd+0xa/0x50
22:01:59.016749500 kern.info: eax: 6b6b6b6b ebx: c19d0460 ecx: c19d0460 edx: c19d0478
22:01:59.017802500 kern.info: esi: c19cffb4 edi: c19cffb4 ebp: c19cff84 esp: c19cff80
22:01:59.018791500 kern.info: ds: 007b es: 007b ss: 0068
22:01:59.019865500 kern.info: Process scsi_eh_0 (pid: 478, threadinfo=c19cf000 task=c1968530)
22:01:59.020918500 kern.info: Stack: c19d0460 c19cff9c c03b5eb7 c19d0460 c19d0478 c19cffb4 00000246 c19cffc8
22:01:59.021945500 kern.info: c03b6a92 c19cffb4 c19cffac c19cffac c19cffac c19d0478 c19d0478 c19cffd4
22:01:59.023051500 kern.info: dfc1507c 00000000 c19cffec c03b6b16 dfc1507c 00000000 00000000 c19cffdc
22:01:59.023907500 kern.info: Call Trace:
22:01:59.025073500 kern.info: [<c0103cc5>] show_stack+0x75/0x90
22:01:59.027613500 kern.info: [<c0103e19>] show_registers+0x119/0x190
22:01:59.028311500 kern.info: [<c0103ff5>] die+0xb5/0x130
22:01:59.029231500 kern.info: [<c0110728>] do_page_fault+0x458/0x6d6
22:01:59.030303500 kern.info: [<c01038ef>] error_code+0x4f/0x60
22:01:59.031213500 kern.info: [<c03b5eb7>] scsi_eh_abort_cmds+0x37/0x90
22:01:59.032241500 kern.info: [<c03b6a92>] scsi_invoke_strategy_handler+0xd2/0xf0
22:01:59.033137500 kern.info: [<c03b6b16>] scsi_error_handler+0x66/0xd0
22:01:59.033840500 kern.info: [<c0100cc5>] kernel_thread_helper+0x5/0x10
22:01:59.034854500 kern.info: Code: 00 00 00 5d c3 8b 43 38 89 43 34 8b 4d 0c 51 53 e8 1c ff ff ff 58 5a eb 88 90 8d b4 26 00 00 00 00 55 89 e5 8b 4d 08 53 8b 41 04 <8b> 00 8b 40 5c 8b 40 20 85 c0 ba 03 20 00 00 74 23 8b 59 2c 85
We hit use-after-free here:
static int scsi_try_to_abort_cmd(struct scsi_cmnd *scmd)
{
unsigned long flags;
int rtn = FAILED;
if (!scmd->device->host->hostt->eh_abort_handler)
return rtn;
Seems like struct scsi_cmnd pointed by scmd is filled by slab poisoning pattern:
000007d0 <scsi_try_to_abort_cmd>:
7d0: 55 push %ebp
7d1: 89 e5 mov %esp,%ebp
7d3: 8b 4d 08 mov 0x8(%ebp),%ecx ecx = scmd
7d6: 53 push %ebx
7d7: 8b 41 04 mov 0x4(%ecx),%eax eax = scmd->device (0x6b6b6b6b6)
7da: 8b 00 mov (%eax),%eax trying to get scmd->device->host, BOOM
7dc: 8b 40 5c mov 0x5c(%eax),%eax
7df: 8b 40 20 mov 0x20(%eax),%eax
7e2: 85 c0 test %eax,%eax
7e4: ba 03 20 00 00 mov $0x2003,%edx
7e9: 74 23 je 80e <scsi_try_to_abort_cmd+0x3e>
--
vda