Target reboot -> iscsiadm rescan Stuck

442 views
Skip to first unread message

myselfa...@gmail.com

unread,
Apr 3, 2014, 4:42:09 AM4/3/14
to open-...@googlegroups.com, yonata...@emc.com
Hi,

In a scenario where we reboot a remote target and then run "iscsiadm -m session --rescan" on the initiator,
iscsiadm starts taking around 85% CPU, and any other iscsiadm command we send afterwards also gets stuck (probably waiting on a mutex), and the "rescan" iscsiadm process can't be killed (niether with kill -9 or -11), so it's probably stuck in the kernel.

Is this a known/fixed issue?

Logs: Just ask. We have plenty.

open-iscsi version: 2.0.873 (from Debian)

Have a nice day
:)

Mike Christie

unread,
Apr 11, 2014, 3:10:40 AM4/11/14
to open-...@googlegroups.com, myselfa...@gmail.com, yonata...@emc.com
On 04/03/2014 03:42 AM, myselfa...@gmail.com wrote:
> Hi,
>
> In a scenario where we reboot a remote target and then run "iscsiadm -m
> session --rescan" on the initiator,
> iscsiadm starts taking around 85% CPU, and any other iscsiadm command we
> send afterwards also gets stuck (probably waiting on a mutex), and the
> "rescan" iscsiadm process can't be killed (niether with kill -9 or -11),
> so it's probably stuck in the kernel.
>
> Is this a known/fixed issue?
>

New. iscsiadm just writes to the scan/rescan sysfs files so yeah
probably stuck in the kernel. I am not seeing this problem. When you run
the rescan command is the target still down? Have we logged back in yet?

Could you run the following command when you hit the problem:

dmesg -c; echo w >/proc/sysrq-trigger; dmesg -c >waiting-tasks.txt.

It will dump the stack traces in /var/log/messages, so we can see where
we are stuck in the iscsi/scsi scan code.


> Logs: Just ask. We have plenty.
>
> open-iscsi version: 2.0.873 (from Debian)
>

What kernel version is this?

Mike Christie

unread,
Apr 11, 2014, 3:11:33 AM4/11/14
to open-...@googlegroups.com, myselfa...@gmail.com, yonata...@emc.com
Could you also send the /var/log/messages?

Mike Christie

unread,
Apr 14, 2014, 1:07:08 PM4/14/14
to Cale, Yonatan, open-...@googlegroups.com, myselfa...@gmail.com
On 04/13/2014 07:29 AM, Cale, Yonatan wrote:

> # cat waiting-tasks.txt
> SysRq : Show Blocked State
> task PC stack pid father
> iscsid D 0000000000000000 0 2842 1 0x00000000
> ffff880137f83918 0000000000000086 ffff88010e3be2d0 ffff880137f82010
> 0000000000004000 ffff88013b2b8c40 ffff880137f83fd8 ffff880137f83fd8
> 0000000000000000 ffff88013b2b8c40 ffffffff81a0b020 ffff88013b2b8ed0
> Call Trace:
> [<ffffffff81273a97>] ? kobject_put+0x27/0x60
> [<ffffffff812dc447>] ? put_device+0x17/0x20
> [<ffffffff8103418f>] ? complete+0x4f/0x60
> [<ffffffff815ed07f>] schedule+0x3f/0x60
> [<ffffffff815eda02>] __mutex_lock_slowpath+0x102/0x180
> [<ffffffff815edf0b>] mutex_lock+0x2b/0x50
> [<ffffffffa0011a97>] __iscsi_unbind_session+0x67/0x160 [scsi_transport_iscsi]
> [<ffffffffa0011ca1>] iscsi_remove_session+0x111/0x1f0 [scsi_transport_iscsi]
> [<ffffffffa0011d96>] iscsi_destroy_session+0x16/0x60 [scsi_transport_iscsi]
> [<ffffffffa002573d>] iscsi_session_teardown+0x9d/0xd0 [libiscsi]
> [<ffffffffa0032300>] iscsi_sw_tcp_session_destroy+0x50/0x70 [iscsi_tcp]
> [<ffffffffa0012c9d>] iscsi_if_rx+0x7dd/0xaa0 [scsi_transport_iscsi]
> [<ffffffff814f50ee>] netlink_unicast+0x2ae/0x2c0
> [<ffffffff814d11dc>] ? memcpy_fromiovec+0x7c/0xa0
> [<ffffffff814f5aae>] netlink_sendmsg+0x33e/0x380
> [<ffffffff814c55f8>] sock_sendmsg+0xe8/0x120
> [<ffffffff811078bf>] ? do_lookup+0xcf/0x360
> [<ffffffff8111ad6f>] ? mntput+0x1f/0x40
> [<ffffffff81107012>] ? path_put+0x22/0x30
> [<ffffffff814c512b>] ? move_addr_to_kernel+0x6b/0x70
> [<ffffffff814d13a1>] ? verify_iovec+0x51/0x100
> [<ffffffff814c683f>] __sys_sendmsg+0x3df/0x3f0
> [<ffffffff810f8419>] ? kmem_cache_free+0xe9/0xf0
> [<ffffffff81100dac>] ? cp_new_stat+0xfc/0x120
> [<ffffffff814c6a79>] sys_sendmsg+0x49/0x80
> [<ffffffff815ef86b>] system_call_fastpath+0x16/0x1b

Ok, that was more interesting than I expected. If you are not running a
iscsiadm logout command, then it looks like the target returned a error
code indicating that target is not coming back. iscsid handled this by
trying to remove the target and we are stuck in there. This and the scan
command should be fast at this time because it looks like the
replacement/recovery timeout has expired:

session1: session recovery timed out after 120 secs
session2: session recovery timed out after 120 secs

At this time, all IO is just fast failed so we are not waiting for IO
and any time we need that mutex it should be quick.

1. Can you send me a tcpdump trace? I am guessing that you do not want
the session to be deleted during this time, so we need the trace to see
what error code is leading to this.

2. I am wondering if the hang is because the device is offlined when
this happened. I did not try that case. I will setup that kernel and try
here.

Mike Christie

unread,
Apr 17, 2014, 1:53:20 PM4/17/14
to Cale, Yonatan, open-...@googlegroups.com, myselfa...@gmail.com
Thanks. This makes sense and more what I was expecting.

iscsiadm is stuck on the scan completion. It might have sent some
inquiry and maybe report luns (can't tell from the below how far we
got). While this scan is going on a couple mutexes are held. This is why
if you did try a logout command later we would see the other hang you sent.

For why we are hanging in the scan, could you send enable iscsi logging
when you run the iscsiadm rescan command:

echo 1 > /sys/module/libiscsi/paramters/debug_libiscsi_conn
echo 1 > /sys/module/libiscsi/paramters/debug_libiscsi_session
echo 1 > /sys/module/libiscsi/paramters/debug_libiscsi_eh
echo 1 > /sys/module/libiscsi_tcp/paramters/debug_libiscsi_tcp
echo 1 > /sys/module/iscsi_tcp/paramters/debug_iscsi_tcp

Could you also enable scsi scan logging? If you do not know how to do
that, I attached the scsi_logging_level script from the s390 tools
(works on any arch). Just run

scsi_logging_level --scan 7 -s



On 4/17/14, 6:14 AM, Cale, Yonatan wrote:
> Hi Mike,
>
> Regarding the analysis of waiting-tasks.txt, I'd like to add some information about the issue:
>
> After running the "rescan" that gets stuck, any other iscsiadm command we try running - gets stuck too. I'm guessing that this is because the first command locks some mutex that all other commands wait on. (I didn't verify this, it's mainly a guess)
>
> I'm guessing that the command you analyzed in the previous mail is not the original "rescan" but something else that was run later, or in other words, I think it's not the root cause.
>
> Here are 2 example stack traces (from 2 different runs) that I believe belong to the stuck iscsiadm process:
>
> {
> iscsiadm R running task 0 4597 1 0x00000004
> ffff88009bab38b8 ffffffff815ec84c ffff88009bab37d8 ffff88009bab2010
> 0000000000004000 ffff88009ba1d5c0 ffff88009bab3fd8 ffff88009bab3fd8
> 0000000000000000 ffff88009ba1d5c0 ffff88013b088c40 ffff88009ba1d858
> Call Trace:
> [<ffffffff815ec84c>] ? __schedule+0x3fc/0x8d0
> [<ffffffff8103c765>] ? wake_up_process+0x15/0x20
> [<ffffffff810488b5>] ? raise_softirq_irqoff+0x95/0xb0
> [<ffffffff81279536>] ? number+0x316/0x340
> [<ffffffff8126df97>] ? cfq_set_request+0x257/0x470
> [<ffffffffa0028002>] ? iscsi_queuecommand+0x102/0x4f0 [libiscsi]
> [<ffffffff81051c4b>] ? lock_timer_base+0x3b/0x70
> [<ffffffff810e1d3d>] free_percpu+0x9d/0x130
> [<ffffffff810e22b9>] ? pcpu_alloc+0x1e9/0x900
> [<ffffffff81273bda>] ? kobject_release+0x4a/0xa0
> [<ffffffff8127400d>] ? kobject_set_name_vargs+0x6d/0x80
> [<ffffffff8112e0b6>] ? bio_phys_segments+0x26/0x30
> [<ffffffff8125ca20>] ? blk_rq_bio_prep+0x30/0xc0
> [<ffffffff8125f795>] ? blk_put_queue+0x15/0x20
> [<ffffffff81310a8f>] ? scsi_device_dev_release_usercontext+0x17f/0x1d0
> [<ffffffff8125f61c>] ? blk_alloc_queue_node+0x6c/0x1b0
> [<ffffffff8125fcb4>] ? blk_init_queue_node+0x34/0x80
> [<ffffffff812739b7>] ? kobject_init+0x37/0xa0
> [<ffffffff8130cd26>] ? scsi_execute_req+0xa6/0x140
> [<ffffffff8130e0f9>] ? scsi_probe_and_add_lun+0x289/0xce0
> [<ffffffff810cbb5d>] ? free_one_page+0x20d/0x410
> [<ffffffff815f01ce>] ? apic_timer_interrupt+0xe/0x20
> [<ffffffff81273bed>] ? kobject_release+0x5d/0xa0
> [<ffffffff8130f168>] ? __scsi_scan_target+0x3d8/0x620
> [<ffffffff81279d5b>] ? vsscanf+0x2ab/0x790
> [<ffffffff8130fa28>] ? scsi_scan_target+0xc8/0xd0
> [<ffffffffa00111b6>] ? iscsi_user_scan_session+0x156/0x1a0 [scsi_transport_iscsi]
> [<ffffffffa0011060>] ? iscsi_host_for_each_session+0x20/0x20 [scsi_transport_iscsi]
> [<ffffffff812dcc73>] ? device_for_each_child+0x53/0x80
> [<ffffffffa001103d>] ? iscsi_user_scan+0x2d/0x30 [scsi_transport_iscsi]
> [<ffffffff813105cc>] ? store_scan+0xec/0x120
> [<ffffffff8110b568>] ? do_filp_open+0x48/0xa0
> [<ffffffff812dbdc0>] ? dev_attr_store+0x20/0x30
> [<ffffffff81162f31>] ? sysfs_write_file+0xd1/0x150
> [<ffffffff810fcf3b>] ? vfs_write+0xcb/0x170
> [<ffffffff810fd0e5>] ? sys_write+0x55/0x90
> [<ffffffff815ef86b>] ? system_call_fastpath+0x16/0x1b
> }
>
> {
> iscsiadm R running task 0 2845 1 0x00000004
> ffff8800682078b8 ffffffff815ec84c ffff8800682077d8 ffff880068206010
> 0000000000004000 ffff8800680e8c40 ffff880068207fd8 ffff880068207fd8
> 0000000000000000 ffff8800680e8c40 ffff88013b088c40 ffff8800680e8ed8
> Call Trace:
> [<ffffffff815ec84c>] ? __schedule+0x3fc/0x8d0
> [<ffffffff8103c765>] ? wake_up_process+0x15/0x20
> [<ffffffff810488b5>] ? raise_softirq_irqoff+0x95/0xb0
> [<ffffffff81279536>] ? number+0x316/0x340
> [<ffffffff8126df97>] ? cfq_set_request+0x257/0x470
> [<ffffffff8130c02d>] ? scsi_setup_blk_pc_cmnd+0x12d/0x160
> [<ffffffff81304eb1>] ? scsi_dispatch_cmd+0xf1/0x210
> [<ffffffff815ecdc5>] ? _cond_resched+0x35/0x50
> [<ffffffff815ece1b>] ? wait_for_common+0x3b/0x180
> [<ffffffff8128ae8a>] ? percpu_counter_destroy+0x1a/0x30
> [<ffffffff812760c9>] ? prop_local_destroy_percpu+0x9/0x10
> [<ffffffff810e22b9>] ? pcpu_alloc+0x1e9/0x900
> [<ffffffff81273bda>] ? kobject_release+0x4a/0xa0
> [<ffffffff81273fcd>] ? kobject_set_name_vargs+0x2d/0x80
> [<ffffffff812dca69>] ? dev_set_name+0x69/0x70
> [<ffffffff8125ca20>] ? blk_rq_bio_prep+0x30/0xc0
> [<ffffffff8125f795>] ? blk_put_queue+0x15/0x20
> [<ffffffff81310a8f>] ? scsi_device_dev_release_usercontext+0x17f/0x1d0
> [<ffffffff8125f61c>] ? blk_alloc_queue_node+0x6c/0x1b0
> [<ffffffff8125fcb4>] ? blk_init_queue_node+0x34/0x80
> [<ffffffff8125fd13>] ? blk_init_queue+0x13/0x20
> [<ffffffff812e3e55>] ? transport_setup_device+0x15/0x20
> [<ffffffff8130cd26>] ? scsi_execute_req+0xa6/0x140
> [<ffffffff8130e0f9>] ? scsi_probe_and_add_lun+0x289/0xce0
> [<ffffffff810cbb5d>] ? free_one_page+0x20d/0x410
> [<ffffffff815f01ce>] ? apic_timer_interrupt+0xe/0x20
> [<ffffffff81273bed>] ? kobject_release+0x5d/0xa0
> [<ffffffff8130f168>] ? __scsi_scan_target+0x3d8/0x620
> [<ffffffff81279d5b>] ? vsscanf+0x2ab/0x790
> [<ffffffff8130fa28>] ? scsi_scan_target+0xc8/0xd0
> [<ffffffffa00111b6>] ? iscsi_user_scan_session+0x156/0x1a0 [scsi_transport_iscsi]
> [<ffffffffa0011060>] ? iscsi_host_for_each_session+0x20/0x20 [scsi_transport_iscsi]
> [<ffffffff812dcc73>] ? device_for_each_child+0x53/0x80
> [<ffffffffa001103d>] ? iscsi_user_scan+0x2d/0x30 [scsi_transport_iscsi]
> [<ffffffff813105cc>] ? store_scan+0xec/0x120
> [<ffffffff8110b568>] ? do_filp_open+0x48/0xa0
> [<ffffffff812dbdc0>] ? dev_attr_store+0x20/0x30
> [<ffffffff81162f31>] ? sysfs_write_file+0xd1/0x150
> [<ffffffff810fcf3b>] ? vfs_write+0xcb/0x170
> [<ffffffff810fd0e5>] ? sys_write+0x55/0x90
> [<ffffffff815ef86b>] ? system_call_fastpath+0x16/0x1b
> }
> They have a lot of similarities but also differences. I provided 2 traces hoping that it will be more informative for you.
>
> They were obtained by running:
> echo t > /proc/sysrq-trigger
> dmesg > dmesg.txt
>
> I know that it's the stuck process because I ran "killall iscsid" first, and because "dmesg.txt" only contains one "iscsiadm" process.
>
> Does this make sense?
>
> -----Original Message-----
> From: Cale, Yonatan
> Sent: Wednesday, April 16, 2014 7:22 PM
> To: 'Mike Christie'
> Cc: open-...@googlegroups.com; myselfa...@gmail.com
> Subject: RE: Target reboot -> iscsiadm rescan Stuck
>
> Hi,
>
> Attached is a compressed tcpdump capture (iscsiadm_spreboot_3.gz, ~300kb), Some detailes about it:
> It was obtained by running " tcpdump icmp and src or dst 10.76.18.174 or src or dst 10.76.18.175 -i any -w iscsiadm_spreboot_3".
> My local iscsi port IPs are 10.76.18.174 & 10.76.18.175.
> The target iscsi IPs are 10.76.18.31 & 10.76.18.33.
> Chronological order:
> -Start capture
> -A few seconds later, reboot SP A (one of the iscsi targets) -A long time (~10 minutes) later, the bug happens (I notice it because iscsiadm starts taking 85% CPU) -A few seconds later, stop capture
>
> I'm mentioning the order mainly to point out that the bug happens in the last few seconds of the capture
>
> And thank you for sitting on this bug with me.
> :)
scsi_logging_level

Mike Christie

unread,
Apr 17, 2014, 1:56:59 PM4/17/14
to open-...@googlegroups.com, Cale, Yonatan, myselfa...@gmail.com
On 04/17/2014 12:53 PM, Mike Christie wrote:
>
> scsi_logging_level --scan 7 -s

Actually could you also enable error logging too?

scsi_logging_level --scan 7 --error 7 -s

Mike Christie

unread,
Apr 21, 2014, 5:38:08 PM4/21/14
to Cale, Yonatan, open-...@googlegroups.com, myselfa...@gmail.com
Do you have some module that is hooking into the scsi layer or iscsi
modules? Just wondering what the "sim_try_to_abort_cmd" call is. Where
are you hooking in? Have you also modified the iscsi tools?

During this test, is the target able to respond to iscsi level IO, but
just not scsi commands? I see iscsi nops are successful, but the scsi
scan related commands like REPORT_LUNS are never replied to by the
target. The scsi error handler then runs. Some aborts work, but
eventually we do not get a response to one, and that results in the
device getting offlined. I then see something is trying to delete the
session (the upstream iscsi tools would normally not do this).

It then looks like we hit a bug in the scsi layer. The scsi layer keeps
trying to send a inquiry, but because we are deleting the session, the
iscsi layer fails the command with DID_TRANSPORT_FAILFAST. This then
goes on for minutes until you stop taking the trace.

To debug this some more, we will need to get some scsi layer tracing.
Did you run that scsi_logging_level command? Could you also check the
current kernel?


On 04/20/2014 05:18 AM, Cale, Yonatan wrote:
> Hi Mike, are the logs supposed to come out in /var/log/messages?
> If so, here's the "messages" file.
> The problem happened between " Sun Apr 20 09:59:04 UTC 2014 " and " Sun Apr 20 10:06:50 UTC 2014", I would guess around 10:02
> Good luck, you have like infinite log lines to look at :P
>
>
> -----Original Message-----
> From: Mike Christie [mailto:mich...@cs.wisc.edu]
> Sent: Thursday, April 17, 2014 8:57 PM
> To: open-...@googlegroups.com
> Cc: Cale, Yonatan; myselfa...@gmail.com
> Subject: Re: Target reboot -> iscsiadm rescan Stuck
>

Mike Christie

unread,
Apr 24, 2014, 2:11:23 AM4/24/14
to Cale, Yonatan, open-...@googlegroups.com, myselfa...@gmail.com
On 04/23/2014 02:35 AM, Cale, Yonatan wrote:
> Hi again,
>
> You said: "I then see something is trying to delete the session (the upstream iscsi tools would normally not do this). [...]It then looks like we hit a bug in the scsi layer."
>
> We DO perform iscsiadm commands like "logout" and "delete" (these commands are done automatically).
> Do you think that if we stop doing them (or change our usage somehow) then this will solve the problem?

If it fixes the problem then it is just working around some issue in the
scsi layer. I am not sure since we need some more scsi layer logging as
it does not look like a iscsi layer issue.

Have you tried more recent kernels btw? I have tested the offline/eh
running type of case you tested with upstream and 3.8 and it works ok
for me. I am not able to replicate the exact failure where a scsi scan
related command is the one that times out.

> Changing how we use open-iscsi is definitely an option for us as a solution for this issue.
>
> -----Original Message-----
> From: Cale, Yonatan
> Sent: Tuesday, April 22, 2014 12:11 PM
> To: 'Mike Christie'
> Cc: open-...@googlegroups.com; myselfa...@gmail.com
> Subject: RE: Target reboot -> iscsiadm rescan Stuck
>
> Hi Mike,
> Answers are in your message below:
>
> -----Original Message-----
> From: Mike Christie [mailto:mich...@cs.wisc.edu]
> Sent: Tuesday, April 22, 2014 12:38 AM
> To: Cale, Yonatan
> Cc: open-...@googlegroups.com; myselfa...@gmail.com
> Subject: Re: Target reboot -> iscsiadm rescan Stuck
>
>> Do you have some module that is hooking into the scsi layer or iscsi modules? Just wondering what the "sim_try_to_abort_cmd" call is. Where are you hooking in?
> "sim" is our module that handles iscsi data-path. We hook for notifications in order to know if we should cancel a command (we didn't find this in open-iscsi, this is a little off-topic, but does open-iscsi know how to abort commands by itself?) I think this sould have nothing to do with the iscsiadm control path. I'll verify this with our sim guys (they are on vacation).
>
>> Have you also modified the iscsi tools?
> No. I'll verify this too, but it's highly unlikely.
>
>> During this test, is the target able to respond to iscsi level IO, but just not scsi commands? I see iscsi nops are successful, but the scsi scan related commands like REPORT_LUNS are never replied to by the target. The scsi error handler then runs. Some aborts work, but eventually we do not get a response to one, and that results in the device getting offlined. I then see something is trying to delete the session (the upstream iscsi tools would normally not do this).
> The target is a VNX being (partially) rebooted. I don't know for sure what it can/can't do during that reboot, but I think it can't answer NOP commands either:
> I did some investigation of the tcpdump I sent you, and I can see that at some point (packet #1682, time~=38sec), there are no more packets FROM 10.76.18.23, which is the IP of the VNX-SP that I am rebooting. This includes NOP iSCSI commands which are also not sent anymore.
>
>> It then looks like we hit a bug in the scsi layer. The scsi layer keeps trying to send a inquiry, but because we are deleting the session, the iscsi layer fails the command with DID_TRANSPORT_FAILFAST. This then goes on for minutes until you stop taking the trace.
>
>> To debug this some more, we will need to get some scsi layer tracing.
>> Did you run that scsi_logging_level command?
> I did " scsi_logging_level --scan 7 --error 7 -s" (Unless I made a mistake? Do you think this command wasn't run?)
>
>> Could you also check the current kernel?
> I don't understand what you are asking for. The kernel version? 3.0.56
>

Mike Christie

unread,
Apr 24, 2014, 2:14:30 AM4/24/14
to Cale, Yonatan, open-...@googlegroups.com, myselfa...@gmail.com
On 04/22/2014 02:10 AM, Cale, Yonatan wrote:
> Hi Mike,
> Answers are in your message below:
>
> -----Original Message-----
> From: Mike Christie [mailto:mich...@cs.wisc.edu]
> Sent: Tuesday, April 22, 2014 12:38 AM
> To: Cale, Yonatan
> Cc: open-...@googlegroups.com; myselfa...@gmail.com
> Subject: Re: Target reboot -> iscsiadm rescan Stuck
>
>> Do you have some module that is hooking into the scsi layer or iscsi modules? Just wondering what the "sim_try_to_abort_cmd" call is. Where are you hooking in?
> "sim" is our module that handles iscsi data-path. We hook for notifications in order to know if we should cancel a command (we didn't find this in open-iscsi, this is a little off-topic, but does open-iscsi know how to abort commands by itself?)

I do not think it does what you are asking. The iscsi layer implements
some scsi_host_template callouts to abort a command or do a lun or
target reset. When the scsi command timer fires, the scsi layer will
call those callouts to have the iscsi layer send the TMF.


> I think this sould have nothing to do with the iscsiadm control path. I'll verify this with our sim guys (they are on vacation).
>
>> Have you also modified the iscsi tools?
> No. I'll verify this too, but it's highly unlikely.
>
>> During this test, is the target able to respond to iscsi level IO, but just not scsi commands? I see iscsi nops are successful, but the scsi scan related commands like REPORT_LUNS are never replied to by the target. The scsi error handler then runs. Some aborts work, but eventually we do not get a response to one, and that results in the device getting offlined. I then see something is trying to delete the session (the upstream iscsi tools would normally not do this).
> The target is a VNX being (partially) rebooted. I don't know for sure what it can/can't do during that reboot, but I think it can't answer NOP commands either:
> I did some investigation of the tcpdump I sent you, and I can see that at some point (packet #1682, time~=38sec), there are no more packets FROM 10.76.18.23, which is the IP of the VNX-SP that I am rebooting. This includes NOP iSCSI commands which are also not sent anymore.
>
>> It then looks like we hit a bug in the scsi layer. The scsi layer keeps trying to send a inquiry, but because we are deleting the session, the iscsi layer fails the command with DID_TRANSPORT_FAILFAST. This then goes on for minutes until you stop taking the trace.
>
>> To debug this some more, we will need to get some scsi layer tracing.
>> Did you run that scsi_logging_level command?
> I did " scsi_logging_level --scan 7 --error 7 -s" (Unless I made a mistake? Do you think this command wasn't run?)
>

I did not see any extra scsi layer scanning in the log you sent.

>> Could you also check the current kernel?
> I don't understand what you are asking for. The kernel version? 3.0.56
>

I just meant try a newer kernel like 3.14.

Mike Christie

unread,
Apr 24, 2014, 3:03:39 PM4/24/14
to Cale, Yonatan, open-...@googlegroups.com, myselfa...@gmail.com
On 04/22/2014 04:10 AM, Cale, Yonatan wrote:
> -----Original Message-----
> From: Mike Christie [mailto:mich...@cs.wisc.edu]
> Sent: Tuesday, April 22, 2014 12:38 AM
> To: Cale, Yonatan
> Cc: open-...@googlegroups.com; myselfa...@gmail.com
> Subject: Re: Target reboot -> iscsiadm rescan Stuck
>
>> Do you have some module that is hooking into the scsi layer or iscsi modules? Just wondering what the "sim_try_to_abort_cmd" call is. Where are you hooking in?
> "sim" is our module that handles iscsi data-path. We hook for notifications in order to know if we should cancel a command


Hey, does your sim module that handles the data path just monitor or do
you handle error codes that the iscsi modules returns. The problem is
that the iscsi layer is trying to fail a scsi scan related command, but
whatever layer is above it (I thought it was just the scsi layer like
normal in my other response) just keeps retrying it. Does your module do
anything to IO failed with

#define DID_TRANSPORT_FAILFAST 0x0f /* Transport class fastfailed the io */

from the queuecommand path? Is it the one forcing the retry? That would
explain why we do not see anything from the scsi scan layer debug printks.

If not, then it is the scsi or block layer and we will have to add some
printks in there.

Cale, Yonatan

unread,
Apr 24, 2014, 7:56:55 AM4/24/14
to Mike Christie, open-...@googlegroups.com, myselfa...@gmail.com
Attached is the end of "var/log/messages" from a new reproduction.
Before reproducing, I ran:
{
scsi_logging_level --scan 7 --error 7 -s

echo 1 > /sys/module/libiscsi/parameters/debug_libiscsi_conn
echo 1 > /sys/module/libiscsi/parameters/debug_libiscsi_session
echo 1 > /sys/module/libiscsi/parameters/debug_libiscsi_eh
echo 1 > /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
echo 1 > /sys/module/iscsi_tcp/parameters/debug_iscsi_tcp
}

The SP-reboot was initiated a few minutes before the end. (3 minutes?)

-----Original Message-----
From: Cale, Yonatan
Sent: Thursday, April 24, 2014 12:57 PM
To: 'Mike Christie'
Cc: open-...@googlegroups.com; myselfa...@gmail.com
Subject: RE: Target reboot -> iscsiadm rescan Stuck

Hi,

About moving to a newer kernel, this is an issue for us and we'd rather avoid it. I can tell you that if you didn't reproduce the bug, it's not necessarily because you have a different kernel. This bug is not very easy to reproduce. It happens ~sometimes~ (about 1/3 of the times), and it seems to happen with "VNX5300 - 05.32.000.5.208" (and not another VNX we have). I can't define/prove the specific version/behavior that is needed to reproduce this but I definitely understand if it doesn't happen in your labs.

I will run the test again with the " scsi_logging_level --scan 7 --error 7 -s". Are the logs supposed to come out in dmesg?

Btw, I talked to our "sim" module guys, no changes from what I said before.
messages_end.gz

Cale, Yonatan

unread,
Apr 24, 2014, 5:57:06 AM4/24/14
to Mike Christie, open-...@googlegroups.com, myselfa...@gmail.com
Hi,

About moving to a newer kernel, this is an issue for us and we'd rather avoid it. I can tell you that if you didn't reproduce the bug, it's not necessarily because you have a different kernel. This bug is not very easy to reproduce. It happens ~sometimes~ (about 1/3 of the times), and it seems to happen with "VNX5300 - 05.32.000.5.208" (and not another VNX we have). I can't define/prove the specific version/behavior that is needed to reproduce this but I definitely understand if it doesn't happen in your labs.

I will run the test again with the " scsi_logging_level --scan 7 --error 7 -s". Are the logs supposed to come out in dmesg?

Btw, I talked to our "sim" module guys, no changes from what I said before.

Cale, Yonatan

unread,
Apr 23, 2014, 5:35:36 AM4/23/14
to Mike Christie, open-...@googlegroups.com, myselfa...@gmail.com
Hi again,

You said: "I then see something is trying to delete the session (the upstream iscsi tools would normally not do this). [...]It then looks like we hit a bug in the scsi layer."

We DO perform iscsiadm commands like "logout" and "delete" (these commands are done automatically).
Do you think that if we stop doing them (or change our usage somehow) then this will solve the problem?
Changing how we use open-iscsi is definitely an option for us as a solution for this issue.

-----Original Message-----
From: Cale, Yonatan
Sent: Tuesday, April 22, 2014 12:11 PM
To: 'Mike Christie'
Cc: open-...@googlegroups.com; myselfa...@gmail.com
Subject: RE: Target reboot -> iscsiadm rescan Stuck

Hi Mike,
Answers are in your message below:

-----Original Message-----
From: Mike Christie [mailto:mich...@cs.wisc.edu]
Sent: Tuesday, April 22, 2014 12:38 AM
To: Cale, Yonatan
Cc: open-...@googlegroups.com; myselfa...@gmail.com
Subject: Re: Target reboot -> iscsiadm rescan Stuck

>Do you have some module that is hooking into the scsi layer or iscsi modules? Just wondering what the "sim_try_to_abort_cmd" call is. Where are you hooking in?
"sim" is our module that handles iscsi data-path. We hook for notifications in order to know if we should cancel a command (we didn't find this in open-iscsi, this is a little off-topic, but does open-iscsi know how to abort commands by itself?) I think this sould have nothing to do with the iscsiadm control path. I'll verify this with our sim guys (they are on vacation).

>Have you also modified the iscsi tools?
No. I'll verify this too, but it's highly unlikely.

>During this test, is the target able to respond to iscsi level IO, but just not scsi commands? I see iscsi nops are successful, but the scsi scan related commands like REPORT_LUNS are never replied to by the target. The scsi error handler then runs. Some aborts work, but eventually we do not get a response to one, and that results in the device getting offlined. I then see something is trying to delete the session (the upstream iscsi tools would normally not do this).
The target is a VNX being (partially) rebooted. I don't know for sure what it can/can't do during that reboot, but I think it can't answer NOP commands either:
I did some investigation of the tcpdump I sent you, and I can see that at some point (packet #1682, time~=38sec), there are no more packets FROM 10.76.18.23, which is the IP of the VNX-SP that I am rebooting. This includes NOP iSCSI commands which are also not sent anymore.

>It then looks like we hit a bug in the scsi layer. The scsi layer keeps trying to send a inquiry, but because we are deleting the session, the iscsi layer fails the command with DID_TRANSPORT_FAILFAST. This then goes on for minutes until you stop taking the trace.

>To debug this some more, we will need to get some scsi layer tracing.
>Did you run that scsi_logging_level command?
I did " scsi_logging_level --scan 7 --error 7 -s" (Unless I made a mistake? Do you think this command wasn't run?)

>Could you also check the current kernel?

Cale, Yonatan

unread,
Apr 13, 2014, 8:29:49 AM4/13/14
to Mike Christie, open-...@googlegroups.com, myselfa...@gmail.com
Hi,
Good to hear from you Mike :)

First of all, let me correct myself that it's not exactly a "Target reboot" that causes the problem, it happens when reboot a VNX SP (rebooting a port we are connected to) and run "rescan". I'm suspecting that the problem happens when the SP gets back up (not when it goes down).

Regarding your questions, here are the prints and logs:

Kernel version:
3.0.56

--------------------------------------

# cat /var/log/messages
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: imklog 5.8.11, log source = /proc/kmsg started.
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 rsyslogd: [origin software="rsyslogd" swVersion="5.8.11" x-pid="2793" x-info="http://www.rsyslog.com"] start
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Initializing cgroup subsys cpu
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Linux version 3.0.56-k3 (kr...@debcs02.lss.emc.com) (gcc version 4.3.2 (Debian 4.3.2-1.1) ) #11 SMP Tue May 21 13:50:27 IDT 2013
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Command line: root=/dev/sda7 ro console=ttyS0,115200n81 console=tty0 rootflags=data=ordered crashkernel=64M
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Disabled fast string operations
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-provided physical RAM map:
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 0000000000000000 - 000000000009f800 (usable)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 000000000009f800 - 00000000000a0000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000000ca000 - 00000000000cc000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000000dc000 - 0000000000100000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 0000000000100000 - 00000000bfef0000 (usable)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000bfef0000 - 00000000bfeff000 (ACPI data)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000bfeff000 - 00000000bff00000 (ACPI NVS)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000bff00000 - 00000000c0000000 (usable)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000e0000000 - 00000000f0000000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000fec00000 - 00000000fec10000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000fffe0000 - 0000000100000000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 0000000100000000 - 0000000140000000 (usable)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: NX (Execute Disable) protection: active
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: DMI present.
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Hypervisor detected: VMware
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: No AGP bridge found
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: last_pfn = 0x140000 max_arch_pfn = 0x400000000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: x86 PAT enabled: cpu 0, old 0x0, new 0x7010600070106
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: last_pfn = 0xc0000 max_arch_pfn = 0x400000000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: found SMP MP-table at [ffff8800000f6bf0] f6bf0
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: init_memory_mapping: 0000000000000000-00000000c0000000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: init_memory_mapping: 0000000100000000-0000000140000000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Reserving 64MB of memory at 832MB for crashkernel (System RAM: 5120MB)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Zone PFN ranges:
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: DMA 0x00000010 -> 0x00001000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: DMA32 0x00001000 -> 0x00100000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Normal 0x00100000 -> 0x00140000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Movable zone start PFN for each node
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: early_node_map[4] active PFN ranges
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: 0: 0x00000010 -> 0x0000009f
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: 0: 0x00000100 -> 0x000bfef0
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: 0: 0x000bff00 -> 0x000c0000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: 0: 0x00100000 -> 0x00140000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Intel MultiProcessor Specification v1.4
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: MPTABLE: OEM ID: INTEL
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: MPTABLE: Product ID: 440BX
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: MPTABLE: APIC at: 0xFEE00000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Processor #0 (Bootup-CPU)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Processor #1
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: IOAPIC[0]: apic_id 2, version 17, address 0xfec00000, GSI 0-23
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Processors: 2
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: SMP: Allowing 2 CPUs, 0 hotplug CPUs
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Allocating PCI resources starting at c0000000 (gap: c0000000:20000000)
ESC[
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: imklog 5.8.11, log source = /proc/kmsg started.
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 rsyslogd: [origin software="rsyslogd" swVersion="5.8.11" x-pid="2793" x-info="http://www.rsyslog.com"] start
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Initializing cgroup subsys cpu
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Linux version 3.0.56-k3 (kr...@debcs02.lss.emc.com) (gcc version 4.3.2 (Debian 4.3.2-1.1) ) #11 SMP Tue May 21 13:50:27 IDT 2013
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Command line: root=/dev/sda7 ro console=ttyS0,115200n81 console=tty0 rootflags=data=ordered crashkernel=64M
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Disabled fast string operations
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-provided physical RAM map:
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 0000000000000000 - 000000000009f800 (usable)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 000000000009f800 - 00000000000a0000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000000ca000 - 00000000000cc000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000000dc000 - 0000000000100000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 0000000000100000 - 00000000bfef0000 (usable)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000bfef0000 - 00000000bfeff000 (ACPI data)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000bfeff000 - 00000000bff00000 (ACPI NVS)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000bff00000 - 00000000c0000000 (usable)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000e0000000 - 00000000f0000000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000fec00000 - 00000000fec10000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 00000000fffe0000 - 0000000100000000 (reserved)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: BIOS-e820: 0000000100000000 - 0000000140000000 (usable)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: NX (Execute Disable) protection: active
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: DMI present.
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Hypervisor detected: VMware
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: No AGP bridge found
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: last_pfn = 0x140000 max_arch_pfn = 0x400000000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: x86 PAT enabled: cpu 0, old 0x0, new 0x7010600070106
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: last_pfn = 0xc0000 max_arch_pfn = 0x400000000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: found SMP MP-table at [ffff8800000f6bf0] f6bf0
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: init_memory_mapping: 0000000000000000-00000000c0000000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: init_memory_mapping: 0000000100000000-0000000140000000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Reserving 64MB of memory at 832MB for crashkernel (System RAM: 5120MB)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Zone PFN ranges:
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: DMA 0x00000010 -> 0x00001000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: DMA32 0x00001000 -> 0x00100000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Normal 0x00100000 -> 0x00140000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Movable zone start PFN for each node
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: early_node_map[4] active PFN ranges
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: 0: 0x00000010 -> 0x0000009f
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: 0: 0x00000100 -> 0x000bfef0
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: 0: 0x000bff00 -> 0x000c0000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: 0: 0x00100000 -> 0x00140000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Intel MultiProcessor Specification v1.4
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: MPTABLE: OEM ID: INTEL
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: MPTABLE: Product ID: 440BX
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: MPTABLE: APIC at: 0xFEE00000
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Processor #0 (Bootup-CPU)
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Processor #1
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: IOAPIC[0]: apic_id 2, version 17, address 0xfec00000, GSI 0-23
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Processors: 2
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: SMP: Allowing 2 CPUs, 0 hotplug CPUs
Apr 13 09:34:32 RecoverPoint-0x531ea7f42f6bb648-RPA2 kernel: Allocating PCI resources starting at c0000000 (gap: c0000000:20000000)
...skipping...
Apr 13 11:27:13 rp kernel: [<ffffffff81035bd7>] ? dequeue_task_fair+0x1a7/0x290
Apr 13 11:27:13 rp kernel: [<ffffffff8103586e>] ? set_next_entity+0x3e/0x80
Apr 13 11:27:13 rp kernel: [<ffffffffa02d36f0>] ? sim_task_threadfn+0x2b0/0x2b0 [sim]
Apr 13 11:27:13 rp kernel: [<ffffffff815ec84c>] ? __schedule+0x3fc/0x8d0
Apr 13 11:27:13 rp kernel: [<ffffffff8103c5e8>] ? try_to_wake_up+0x208/0x330
Apr 13 11:27:13 rp kernel: [<ffffffff8103c722>] ? default_wake_function+0x12/0x20
Apr 13 11:27:13 rp kernel: [<ffffffff8103114a>] ? __wake_up_common+0x5a/0x90
Apr 13 11:27:13 rp kernel: [<ffffffff81063b60>] ? wake_up_bit+0x40/0x40
Apr 13 11:27:13 rp kernel: [<ffffffffa02d36f0>] ? sim_task_threadfn+0x2b0/0x2b0 [sim]
Apr 13 11:27:13 rp kernel: [<ffffffff8106363e>] ? kthread+0x9e/0xb0
Apr 13 11:27:13 rp kernel: [<ffffffff815f0914>] ? kernel_thread_helper+0x4/0x10
Apr 13 11:27:13 rp kernel: [<ffffffff810635a0>] ? kthread_worker_fn+0x140/0x140
Apr 13 11:27:13 rp kernel: [<ffffffff815f0910>] ? gs_change+0xb/0xb
Apr 13 11:27:13 rp kernel: sim_task1 D 0000000000000000 0 3766 2 0x00000000
Apr 13 11:27:13 rp kernel: ffff88010fc87cd0 0000000000000046 00000008000007ff ffff88010fc86010
Apr 13 11:27:13 rp kernel: 0000000000004000 ffff88013b292ae0 ffff88010fc87fd8 ffff88010fc87fd8
Apr 13 11:27:13 rp kernel: 0000000000000000 ffff88013b292ae0 ffffffff81a0b020 ffff88013b292d70
Apr 13 11:27:13 rp kernel: Call Trace:
Apr 13 11:27:13 rp kernel: [<ffffffff815ef10e>] ? common_interrupt+0xe/0x13
Apr 13 11:27:13 rp kernel: [<ffffffff815f01ce>] ? apic_timer_interrupt+0xe/0x20
Apr 13 11:27:13 rp kernel: [<ffffffff815ef10e>] ? common_interrupt+0xe/0x13
Apr 13 11:27:13 rp kernel: [<ffffffff815ed07f>] schedule+0x3f/0x60
Apr 13 11:27:13 rp kernel: [<ffffffffa02d3655>] sim_task_threadfn+0x215/0x2b0 [sim]
Apr 13 11:27:13 rp kernel: [<ffffffff81035bd7>] ? dequeue_task_fair+0x1a7/0x290
Apr 13 11:27:13 rp kernel: [<ffffffff8103586e>] ? set_next_entity+0x3e/0x80
Apr 13 11:27:13 rp kernel: [<ffffffffa02d3440>] ? sim_abort_handler_handle_wakeup+0x330/0x330 [sim]
Apr 13 11:27:13 rp kernel: [<ffffffff815ec84c>] ? __schedule+0x3fc/0x8d0
Apr 13 11:27:13 rp kernel: [<ffffffff8103c5e8>] ? try_to_wake_up+0x208/0x330
Apr 13 11:27:13 rp kernel: [<ffffffff8103c722>] ? default_wake_function+0x12/0x20
Apr 13 11:27:13 rp kernel: [<ffffffff8103114a>] ? __wake_up_common+0x5a/0x90
Apr 13 11:27:13 rp kernel: [<ffffffff81063b60>] ? wake_up_bit+0x40/0x40
Apr 13 11:27:13 rp kernel: [<ffffffffa02d3440>] ? sim_abort_handler_handle_wakeup+0x330/0x330 [sim]
Apr 13 11:27:13 rp kernel: [<ffffffff8106363e>] ? kthread+0x9e/0xb0
Apr 13 11:27:13 rp kernel: [<ffffffff815f0914>] ? kernel_thread_helper+0x4/0x10
Apr 13 11:27:13 rp kernel: [<ffffffff810635a0>] ? kthread_worker_fn+0x140/0x140
Apr 13 11:27:13 rp kernel: [<ffffffff815f0910>] ? gs_change+0xb/0xb
Apr 13 11:27:13 rp kernel: sim_abort_handl D 0000000000000000 0 3767 2 0x00000000
Apr 13 11:27:13 rp kernel: ffff88010fc89cd0 0000000000000046 ffff88010fc89be0 ffff88010fc88010
Apr 13 11:27:13 rp kernel: 0000000000004000 ffff88013b293d40 ffff88010fc89fd8 ffff88010fc89fd8
Apr 13 11:27:13 rp kernel: 0000000000000000 ffff88013b293d40 ffff88013b1ed5c0 ffff88013b293fd0
Apr 13 11:27:13 rp kernel: Call Trace:
Apr 13 11:27:13 rp kernel: [<ffffffff8127bdc8>] ? sprintf+0x68/0x70
Apr 13 11:27:13 rp kernel: [<ffffffff815ed07f>] schedule+0x3f/0x60
Apr 13 11:27:13 rp kernel: [<ffffffffa02d3865>] sim_abort_handler_threadfn+0x175/0x220 [sim]
Apr 13 11:27:13 rp kernel: [<ffffffff81035bd7>] ? dequeue_task_fair+0x1a7/0x290
Apr 13 11:27:13 rp kernel: [<ffffffff8103586e>] ? set_next_entity+0x3e/0x80
Apr 13 11:27:13 rp kernel: [<ffffffffa02d36f0>] ? sim_task_threadfn+0x2b0/0x2b0 [sim]
Apr 13 11:27:13 rp kernel: [<ffffffff815ec84c>] ? __schedule+0x3fc/0x8d0
Apr 13 11:27:13 rp kernel: [<ffffffff8103c5e8>] ? try_to_wake_up+0x208/0x330
Apr 13 11:27:13 rp kernel: [<ffffffff8103c722>] ? default_wake_function+0x12/0x20
Apr 13 11:27:13 rp kernel: [<ffffffff8103114a>] ? __wake_up_common+0x5a/0x90
Apr 13 11:27:13 rp kernel: [<ffffffff81063b60>] ? wake_up_bit+0x40/0x40
Apr 13 11:27:13 rp kernel: [<ffffffffa02d36f0>] ? sim_task_threadfn+0x2b0/0x2b0 [sim]
Apr 13 11:27:13 rp kernel: [<ffffffff8106363e>] ? kthread+0x9e/0xb0
Apr 13 11:27:13 rp kernel: [<ffffffff815f0914>] ? kernel_thread_helper+0x4/0x10
Apr 13 11:27:13 rp kernel: [<ffffffff810635a0>] ? kthread_worker_fn+0x140/0x140
Apr 13 11:27:13 rp kernel: [<ffffffff815f0910>] ? gs_change+0xb/0xb
Apr 13 11:27:13 rp kernel: [<ffffffffa0012c9d>] iscsi_if_rx+0x7dd/0xaa0 [scsi_transport_iscsi]
Apr 13 11:27:13 rp kernel: [<ffffffff814f50ee>] netlink_unicast+0x2ae/0x2c0
Apr 13 11:27:13 rp kernel: [<ffffffff814d11dc>] ? memcpy_fromiovec+0x7c/0xa0
Apr 13 11:27:13 rp kernel: [<ffffffff814f5aae>] netlink_sendmsg+0x33e/0x380
Apr 13 11:27:13 rp kernel: [<ffffffff814c55f8>] sock_sendmsg+0xe8/0x120
Apr 13 11:27:13 rp kernel: [<ffffffff811078bf>] ? do_lookup+0xcf/0x360
Apr 13 11:27:13 rp kernel: [<ffffffff8111ad6f>] ? mntput+0x1f/0x40
Apr 13 11:27:13 rp kernel: [<ffffffff81107012>] ? path_put+0x22/0x30
Apr 13 11:27:13 rp kernel: [<ffffffff814c512b>] ? move_addr_to_kernel+0x6b/0x70
Apr 13 11:27:13 rp kernel: [<ffffffff814d13a1>] ? verify_iovec+0x51/0x100
Apr 13 11:27:13 rp kernel: [<ffffffff814c683f>] __sys_sendmsg+0x3df/0x3f0
Apr 13 11:27:13 rp kernel: [<ffffffff810f8419>] ? kmem_cache_free+0xe9/0xf0
Apr 13 11:27:13 rp kernel: [<ffffffff81100dac>] ? cp_new_stat+0xfc/0x120
Apr 13 11:27:13 rp kernel: [<ffffffff814c6a79>] sys_sendmsg+0x49/0x80
Apr 13 11:27:13 rp kernel: [<ffffffff815ef86b>] system_call_fastpath+0x16/0x1b
Apr 13 11:27:13 rp kernel: kwdw_thread D 0000000000000000 0 3687 2 0x00000000
Apr 13 11:27:13 rp kernel: ffff880139145cb0 0000000000000046 000000001b000058 ffff880139144010
Apr 13 11:27:13 rp kernel: 0000000000004000 ffff88013b290c40 ffff880139145fd8 ffff880139145fd8
Apr 13 11:27:13 rp kernel: 0000000000000000 ffff88013b290c40 ffffffff81a0b020 ffff88013b290ed0
Apr 13 11:27:13 rp kernel: Call Trace:
Apr 13 11:27:13 rp kernel: [<ffffffffa006ef80>] ? vlink_generate_kernel_bug+0x20/0x20 [var_link]
Apr 13 11:27:13 rp kernel: [<ffffffff815ed07f>] schedule+0x3f/0x60
Apr 13 11:27:13 rp kernel: [<ffffffff815ed54d>] schedule_timeout+0x28d/0x2d0
Apr 13 11:27:13 rp kernel: [<ffffffffa006f8b4>] ? vlink_check_for_async_reboot+0x14/0x80 [var_link]
Apr 13 11:27:13 rp kernel: [<ffffffff81035bd7>] ? dequeue_task_fair+0x1a7/0x290
Apr 13 11:27:13 rp kernel: [<ffffffffa006ef80>] ? vlink_generate_kernel_bug+0x20/0x20 [var_link]
Apr 13 11:27:13 rp kernel: [<ffffffff815ee5ca>] __down+0x6a/0xb0
Apr 13 11:27:13 rp kernel: [<ffffffff8106926b>] down+0x4b/0x50
Apr 13 11:27:13 rp kernel: [<ffffffffa006efcb>] kwdw_threadfn+0x4b/0x90 [var_link]
Apr 13 11:27:13 rp kernel: [<ffffffff8103c5e8>] ? try_to_wake_up+0x208/0x330
Apr 13 11:27:13 rp kernel: [<ffffffff8103c722>] ? default_wake_function+0x12/0x20
Apr 13 11:27:13 rp kernel: [<ffffffff8103114a>] ? __wake_up_common+0x5a/0x90
Apr 13 11:27:13 rp kernel: [<ffffffffa006ef80>] ? vlink_generate_kernel_bug+0x20/0x20 [var_link]
Apr 13 11:27:13 rp kernel: [<ffffffffa006ef80>] ? vlink_generate_kernel_bug+0x20/0x20 [var_link]
Apr 13 11:27:13 rp kernel: [<ffffffff815ed07f>] ? schedule+0x3f/0x60
Apr 13 11:27:13 rp kernel: [<ffffffff8106363e>] ? kthread+0x9e/0xb0
Apr 13 11:27:13 rp kernel: [<ffffffff815f0914>] kernel_thread_helper+0x4/0x10
Apr 13 11:27:13 rp kernel: [<ffffffff810635a0>] ? kthread_worker_fn+0x140/0x140
Apr 13 11:27:13 rp kernel: [<ffffffff815f0910>] ? gs_change+0xb/0xb
Apr 13 11:27:13 rp kernel: st_thread D 0000000000000000 0 3754 2 0x00000000
Apr 13 11:27:13 rp kernel: ffff88011d8afcb0 0000000000000046 ffff880129f4c000 ffff88011d8ae010
Apr 13 11:27:13 rp kernel: 0000000000004000 ffff88013b291ea0 ffff88011d8affd8 ffff88011d8affd8
Apr 13 11:27:13 rp kernel: 0000000000000000 ffff88013b291ea0 ffffffff81a0b020 ffff88013b292130
Apr 13 11:27:13 rp kernel: Call Trace:
Apr 13 11:27:13 rp kernel: [<ffffffffa0099e12>] ? st_chk_mem_demanding_work_lst+0x42/0x2c0 [st]
Apr 13 11:27:13 rp kernel: [<ffffffff8103594f>] ? pick_next_task_fair+0x5f/0x140
Apr 13 11:27:13 rp kernel: [<ffffffffa009a2c0>] ? st_chk_mem_bound_work_lst+0x230/0x230 [st]
Apr 13 11:27:13 rp kernel: [<ffffffff815ecc48>] ? __schedule+0x7f8/0x8d0
Apr 13 11:27:13 rp kernel: [<ffffffff815ef10e>] ? common_interrupt+0xe/0x13
Apr 13 11:27:13 rp kernel: [<ffffffffa009a2c0>] ? st_chk_mem_bound_work_lst+0x230/0x230 [st]
Apr 13 11:27:13 rp kernel: [<ffffffff815ed07f>] schedule+0x3f/0x60
Apr 13 11:27:13 rp kernel: [<ffffffff815ed54d>] schedule_timeout+0x28d/0x2d0
Apr 13 11:27:13 rp kernel: [<ffffffffa00999c0>] ? st_send_huge_write_ctio_work_lst_data+0x20/0x200 [st]
Apr 13 11:27:13 rp kernel: [<ffffffff815ef10e>] ? common_interrupt+0xe/0x13
Apr 13 11:27:13 rp kernel: [<ffffffffa009a2c0>] ? st_chk_mem_bound_work_lst+0x230/0x230 [st]
Apr 13 11:27:13 rp kernel: [<ffffffff815ee5ca>] __down+0x6a/0xb0

--------------------------------------

# dmesg -c; echo w >/proc/sysrq-trigger; dmesg -c >waiting-tasks.txt.
Initializing cgroup subsys cpu
Linux version 3.0.56-k3 (kr...@debcs02.lss.emc.com) (gcc version 4.3.2 (Debian 4. 3.2-1.1) ) #11 SMP Tue May 21 13:50:27 IDT 2013
Command line: root=/dev/sda7 ro console=ttyS0,115200n81 console=tty0 rootflags=d ata=ordered crashkernel=64M
Disabled fast string operations
BIOS-provided physical RAM map:
BIOS-e820: 0000000000000000 - 000000000009f800 (usable)
BIOS-e820: 000000000009f800 - 00000000000a0000 (reserved)
BIOS-e820: 00000000000ca000 - 00000000000cc000 (reserved)
BIOS-e820: 00000000000dc000 - 0000000000100000 (reserved)
BIOS-e820: 0000000000100000 - 00000000bfef0000 (usable)
BIOS-e820: 00000000bfef0000 - 00000000bfeff000 (ACPI data)
BIOS-e820: 00000000bfeff000 - 00000000bff00000 (ACPI NVS)
BIOS-e820: 00000000bff00000 - 00000000c0000000 (usable)
BIOS-e820: 00000000e0000000 - 00000000f0000000 (reserved)
BIOS-e820: 00000000fec00000 - 00000000fec10000 (reserved)
BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved)
BIOS-e820: 00000000fffe0000 - 0000000100000000 (reserved)
BIOS-e820: 0000000100000000 - 0000000140000000 (usable)
NX (Execute Disable) protection: active
DMI present.
DMI: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 06/22/2012
Hypervisor detected: VMware
e820 update range: 0000000000000000 - 0000000000010000 (usable) ==> (reserved)
e820 remove range: 00000000000a0000 - 0000000000100000 (usable)
No AGP bridge found
last_pfn = 0x140000 max_arch_pfn = 0x400000000
MTRR default type: uncachable
MTRR fixed ranges enabled:
00000-9FFFF write-back
A0000-BFFFF uncachable
C0000-CFFFF write-protect
D0000-EFFFF uncachable
F0000-FFFFF write-protect
MTRR variable ranges enabled:
0 base 00C0000000 mask FFC0000000 uncachable
1 base 0000000000 mask FF00000000 write-back
2 base 0100000000 mask FFC0000000 write-back
3 disabled
4 disabled
5 disabled
6 disabled
7 disabled
x86 PAT enabled: cpu 0, old 0x0, new 0x7010600070106
e820 update range: 00000000c0000000 - 0000000100000000 (usable) ==> (reserved)
last_pfn = 0xc0000 max_arch_pfn = 0x400000000
found SMP MP-table at [ffff8800000f6bf0] f6bf0
initial memory mapped : 0 - 20000000
Base memory trampoline at [ffff88000009d000] 9d000 size 8192
init_memory_mapping: 0000000000000000-00000000c0000000
0000000000 - 00c0000000 page 2M
kernel direct mapping tables up to 0xbfffffff @ [mem 0x1fffc000-0x1fffffff]
init_memory_mapping: 0000000100000000-0000000140000000
0100000000 - 0140000000 page 2M
kernel direct mapping tables up to 0x13fffffff @ [mem 0xbfffe000-0xbfffffff]
Reserving 64MB of memory at 832MB for crashkernel (System RAM: 5120MB)
[ffffea0000000000-ffffea0004ffffff] PMD -> [ffff88013b600000-ffff88013f5fffff] on node 0
Zone PFN ranges:
DMA 0x00000010 -> 0x00001000
DMA32 0x00001000 -> 0x00100000
Normal 0x00100000 -> 0x00140000
Movable zone start PFN for each node
early_node_map[4] active PFN ranges
0: 0x00000010 -> 0x0000009f
0: 0x00000100 -> 0x000bfef0
0: 0x000bff00 -> 0x000c0000
0: 0x00100000 -> 0x00140000
On node 0 totalpages: 1048447
DMA zone: 64 pages used for memmap
DMA zone: 2 pages reserved
DMA zone: 3917 pages, LIFO batch:0
DMA32 zone: 16320 pages used for memmap
DMA32 zone: 766000 pages, LIFO batch:31
Normal zone: 4096 pages used for memmap
Normal zone: 258048 pages, LIFO batch:31
Intel MultiProcessor Specification v1.4
MPTABLE: OEM ID: INTEL
MPTABLE: Product ID: 440BX
MPTABLE: APIC at: 0xFEE00000
Processor #0 (Bootup-CPU)
Processor #1
IOAPIC[0]: apic_id 2, version 17, address 0xfec00000, GSI 0-23
Processors: 2
SMP: Allowing 2 CPUs, 0 hotplug CPUs
nr_irqs_gsi: 40
Allocating PCI resources starting at c0000000 (gap: c0000000:20000000)
setup_percpu: NR_CPUS:32 nr_cpumask_bits:32 nr_cpu_ids:2 nr_node_ids:1
PERCPU: Embedded 24 pages/cpu @ffff88013fc00000 s69440 r8192 d20672 u1048576
pcpu-alloc: s69440 r8192 d20672 u1048576 alloc=1*2097152
pcpu-alloc: [0] 0 1
Built 1 zonelists in Zone order, mobility grouping on. Total pages: 1027965
Kernel command line: root=/dev/sda7 ro console=ttyS0,115200n81 console=tty0 root flags=data=ordered crashkernel=64M
PID hash table entries: 4096 (order: 3, 32768 bytes)
Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes)
Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes)
xsave/xrstor: enabled xstate_bv 0x7, cntxt size 0x340
Checking aperture...
No AGP bridge found
Memory: 3978028k/5242880k available (6094k kernel code, 1049092k absent, 215760k reserved, 4613k data, 664k init)
SLUB: Genslabs=15, HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
Hierarchical RCU implementation.
CONFIG_RCU_FANOUT set to non-default value of 32
NR_IRQS:4352 nr_irqs:512 16
Console: colour VGA+ 80x25
console [tty0] enabled
console [ttyS0] enabled
TSC freq read from hypervisor : 2400.000 MHz
Detected 2400.000 MHz processor.
Calibrating delay loop (skipped) preset value.. 4800.00 BogoMIPS (lpj=2400000)
pid_max: default: 32768 minimum: 301
Mount-cache hash table entries: 256
Initializing cgroup subsys cpuacct
Disabled fast string operations
CPU: Physical Processor ID: 0
ENERGY_PERF_BIAS: Set to 'normal', was 'performance'
ENERGY_PERF_BIAS: View and update with x86_energy_perf_policy(8)
mce: CPU supports 0 MCE banks
Freeing SMP alternatives: 24k freed
ftrace: allocating 20100 entries in 79 pages
ExtINT not setup in hardware but reported by MP table
..TIMER: vector=0x30 apic1=0 pin1=2 apic2=0 pin2=0
CPU0: Intel(R) Xeon(R) CPU E5-2665 0 @ 2.40GHz stepping 07
Performance Events: SandyBridge events, core PMU driver.
... version: 1
... bit width: 48
... generic registers: 4
... value mask: 0000ffffffffffff
... max period: 000000007fffffff
... fixed-purpose events: 0
... event mask: 000000000000000f
Booting Node 0, Processors #1 Ok.
smpboot cpu 1: start_ip = 9d000
Disabled fast string operations
mce: CPU supports 0 MCE banks
Skipped synchronization checks as TSC is reliable.
Brought up 2 CPUs
Total of 2 processors activated (9600.00 BogoMIPS).
x86 PAT enabled: cpu 0, old 0x0, new 0x7010600070106
x86 PAT enabled: cpu 1, old 0x0, new 0x7010600070106
NET: Registered protocol family 16
PCI: Using configuration type 1 for base access
bio: create slab <bio-0> at 0
vgaarb: loaded
SCSI subsystem initialized
libata version 3.00 loaded.
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
PCI: Probing PCI hardware
PCI: Probing PCI hardware (bus 00)
pci 0000:00:00.0: [8086:7190] type 0 class 0x000600
pci 0000:00:01.0: [8086:7191] type 1 class 0x000604
pci 0000:00:07.0: [8086:7110] type 0 class 0x000601
pci 0000:00:07.1: [8086:7111] type 0 class 0x000101
pci 0000:00:07.1: reg 20: [io 0x10c0-0x10cf]
pci 0000:00:07.3: [8086:7113] type 0 class 0x000680
pci 0000:00:07.3: quirk: [io 0x1000-0x103f] claimed by PIIX4 ACPI
pci 0000:00:07.3: quirk: [io 0x1040-0x104f] claimed by PIIX4 SMB
pci 0000:00:07.7: [15ad:0740] type 0 class 0x000880
pci 0000:00:07.7: reg 10: [io 0x1080-0x10bf]
pci 0000:00:07.7: reg 14: [mem 0xd0000000-0xd0001fff 64bit]
pci 0000:00:0f.0: [15ad:0405] type 0 class 0x000300
pci 0000:00:0f.0: reg 10: [io 0x10d0-0x10df]
pci 0000:00:0f.0: reg 14: [mem 0xd8000000-0xdbffffff pref]
pci 0000:00:0f.0: reg 18: [mem 0xd0800000-0xd0ffffff]
pci 0000:00:0f.0: reg 30: [mem 0x00000000-0x00007fff pref]
pci 0000:00:10.0: [1000:0030] type 0 class 0x000100
pci 0000:00:10.0: reg 10: [io 0x1400-0x14ff]
pci 0000:00:10.0: reg 14: [mem 0xd0040000-0xd005ffff 64bit]
pci 0000:00:10.0: reg 1c: [mem 0xd0020000-0xd003ffff 64bit]
pci 0000:00:10.0: reg 30: [mem 0x00000000-0x00003fff pref]
pci 0000:00:11.0: [15ad:0790] type 1 class 0x000604
pci 0000:00:15.0: [15ad:07a0] type 1 class 0x000604
pci 0000:00:15.0: PME# supported from D0 D3hot D3cold
pci 0000:00:15.0: PME# disabled
pci 0000:00:15.1: [15ad:07a0] type 1 class 0x000604
pci 0000:00:15.1: PME# supported from D0 D3hot D3cold
pci 0000:00:15.1: PME# disabled
pci 0000:00:15.2: [15ad:07a0] type 1 class 0x000604
pci 0000:00:15.2: PME# supported from D0 D3hot D3cold
pci 0000:00:15.2: PME# disabled
pci 0000:00:15.3: [15ad:07a0] type 1 class 0x000604
pci 0000:00:15.3: PME# supported from D0 D3hot D3cold
pci 0000:00:15.3: PME# disabled
pci 0000:00:15.4: [15ad:07a0] type 1 class 0x000604
pci 0000:00:15.4: PME# supported from D0 D3hot D3cold
pci 0000:00:15.4: PME# disabled
pci 0000:00:15.5: [15ad:07a0] type 1 class 0x000604
pci 0000:00:15.5: PME# supported from D0 D3hot D3cold
pci 0000:00:15.5: PME# disabled
pci 0000:00:15.6: [15ad:07a0] type 1 class 0x000604
pci 0000:00:15.6: PME# supported from D0 D3hot D3cold
pci 0000:00:15.6: PME# disabled
pci 0000:00:15.7: [15ad:07a0] type 1 class 0x000604
pci 0000:00:15.7: PME# supported from D0 D3hot D3cold
pci 0000:00:15.7: PME# disabled
pci 0000:00:16.0: [15ad:07a0] type 1 class 0x000604
pci 0000:00:16.0: PME# supported from D0 D3hot D3cold
pci 0000:00:16.0: PME# disabled
pci 0000:00:16.1: [15ad:07a0] type 1 class 0x000604
pci 0000:00:16.1: PME# supported from D0 D3hot D3cold
pci 0000:00:16.1: PME# disabled
pci 0000:00:16.2: [15ad:07a0] type 1 class 0x000604
pci 0000:00:16.2: PME# supported from D0 D3hot D3cold
pci 0000:00:16.2: PME# disabled
pci 0000:00:16.3: [15ad:07a0] type 1 class 0x000604
pci 0000:00:16.3: PME# supported from D0 D3hot D3cold
pci 0000:00:16.3: PME# disabled
pci 0000:00:16.4: [15ad:07a0] type 1 class 0x000604
pci 0000:00:16.4: PME# supported from D0 D3hot D3cold
pci 0000:00:16.4: PME# disabled
pci 0000:00:16.5: [15ad:07a0] type 1 class 0x000604
pci 0000:00:16.5: PME# supported from D0 D3hot D3cold
pci 0000:00:16.5: PME# disabled
pci 0000:00:16.6: [15ad:07a0] type 1 class 0x000604
pci 0000:00:16.6: PME# supported from D0 D3hot D3cold
pci 0000:00:16.6: PME# disabled
pci 0000:00:16.7: [15ad:07a0] type 1 class 0x000604
pci 0000:00:16.7: PME# supported from D0 D3hot D3cold
pci 0000:00:16.7: PME# disabled
pci 0000:00:17.0: [15ad:07a0] type 1 class 0x000604
pci 0000:00:17.0: PME# supported from D0 D3hot D3cold
pci 0000:00:17.0: PME# disabled
pci 0000:00:17.1: [15ad:07a0] type 1 class 0x000604
pci 0000:00:17.1: PME# supported from D0 D3hot D3cold
pci 0000:00:17.1: PME# disabled
pci 0000:00:17.2: [15ad:07a0] type 1 class 0x000604
pci 0000:00:17.2: PME# supported from D0 D3hot D3cold
pci 0000:00:17.2: PME# disabled
pci 0000:00:17.3: [15ad:07a0] type 1 class 0x000604
pci 0000:00:17.3: PME# supported from D0 D3hot D3cold
pci 0000:00:17.3: PME# disabled
pci 0000:00:17.4: [15ad:07a0] type 1 class 0x000604
pci 0000:00:17.4: PME# supported from D0 D3hot D3cold
pci 0000:00:17.4: PME# disabled
pci 0000:00:17.5: [15ad:07a0] type 1 class 0x000604
pci 0000:00:17.5: PME# supported from D0 D3hot D3cold
pci 0000:00:17.5: PME# disabled
pci 0000:00:17.6: [15ad:07a0] type 1 class 0x000604
pci 0000:00:17.6: PME# supported from D0 D3hot D3cold
pci 0000:00:17.6: PME# disabled
pci 0000:00:17.7: [15ad:07a0] type 1 class 0x000604
pci 0000:00:17.7: PME# supported from D0 D3hot D3cold
pci 0000:00:17.7: PME# disabled
pci 0000:00:18.0: [15ad:07a0] type 1 class 0x000604
pci 0000:00:18.0: PME# supported from D0 D3hot D3cold
pci 0000:00:18.0: PME# disabled
pci 0000:00:18.1: [15ad:07a0] type 1 class 0x000604
pci 0000:00:18.1: PME# supported from D0 D3hot D3cold
pci 0000:00:18.1: PME# disabled
pci 0000:00:18.2: [15ad:07a0] type 1 class 0x000604
pci 0000:00:18.2: PME# supported from D0 D3hot D3cold
pci 0000:00:18.2: PME# disabled
pci 0000:00:18.3: [15ad:07a0] type 1 class 0x000604
pci 0000:00:18.3: PME# supported from D0 D3hot D3cold
pci 0000:00:18.3: PME# disabled
pci 0000:00:18.4: [15ad:07a0] type 1 class 0x000604
pci 0000:00:18.4: PME# supported from D0 D3hot D3cold
pci 0000:00:18.4: PME# disabled
pci 0000:00:18.5: [15ad:07a0] type 1 class 0x000604
pci 0000:00:18.5: PME# supported from D0 D3hot D3cold
pci 0000:00:18.5: PME# disabled
pci 0000:00:18.6: [15ad:07a0] type 1 class 0x000604
pci 0000:00:18.6: PME# supported from D0 D3hot D3cold
pci 0000:00:18.6: PME# disabled
pci 0000:00:18.7: [15ad:07a0] type 1 class 0x000604
pci 0000:00:18.7: PME# supported from D0 D3hot D3cold
pci 0000:00:18.7: PME# disabled
pci 0000:00:01.0: PCI bridge to [bus 01-01]
pci 0000:00:01.0: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:01.0: bridge window [mem 0xfff00000-0x000fffff] (disabled)
pci 0000:00:01.0: bridge window [mem 0xfff00000-0x000fffff pref] (disabled)
pci 0000:00:11.0: PCI bridge to [bus 02-02] (subtractive decode)
pci 0000:00:11.0: bridge window [io 0x2000-0x3fff]
pci 0000:00:11.0: bridge window [mem 0xd1900000-0xd23fffff]
pci 0000:00:11.0: bridge window [mem 0xdc400000-0xdc9fffff 64bit pref]
pci 0000:00:11.0: bridge window [io 0x0000-0xffff] (subtractive decode)
pci 0000:00:11.0: bridge window [mem 0x00000000-0xffffffffff] (subtractive dec ode)
pci 0000:03:00.0: [15ad:07b0] type 0 class 0x000200
pci 0000:03:00.0: reg 10: [mem 0xd2404000-0xd2404fff]
pci 0000:03:00.0: reg 14: [mem 0xd2403000-0xd2403fff]
pci 0000:03:00.0: reg 18: [mem 0xd2400000-0xd2401fff]
pci 0000:03:00.0: reg 1c: [io 0x4000-0x400f]
pci 0000:03:00.0: reg 30: [mem 0x00000000-0x0000ffff pref]
pci 0000:03:00.0: supports D1 D2
pci 0000:03:00.0: PME# supported from D0 D1 D2 D3hot D3cold
pci 0000:03:00.0: PME# disabled
pci 0000:03:00.0: disabling ASPM on pre-1.1 PCIe device. You can enable it with 'pcie_aspm=force'
pci 0000:00:15.0: PCI bridge to [bus 03-03]
pci 0000:00:15.0: bridge window [io 0x4000-0x4fff]
pci 0000:00:15.0: bridge window [mem 0xd2400000-0xd24fffff]
pci 0000:00:15.0: bridge window [mem 0xd4400000-0xd44fffff 64bit pref]
pci 0000:00:15.1: PCI bridge to [bus 04-04]
pci 0000:00:15.1: bridge window [io 0x8000-0x8fff]
pci 0000:00:15.1: bridge window [mem 0xd2800000-0xd28fffff]
pci 0000:00:15.1: bridge window [mem 0xd4800000-0xd48fffff 64bit pref]
pci 0000:00:15.2: PCI bridge to [bus 05-05]
pci 0000:00:15.2: bridge window [io 0xc000-0xcfff]
pci 0000:00:15.2: bridge window [mem 0xd2c00000-0xd2cfffff]
pci 0000:00:15.2: bridge window [mem 0xdcb00000-0xdcbfffff 64bit pref]
pci 0000:00:15.3: PCI bridge to [bus 06-06]
pci 0000:00:15.3: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:15.3: bridge window [mem 0xd3000000-0xd30fffff]
pci 0000:00:15.3: bridge window [mem 0xdcd00000-0xdcdfffff 64bit pref]
pci 0000:00:15.4: PCI bridge to [bus 07-07]
pci 0000:00:15.4: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:15.4: bridge window [mem 0xd3400000-0xd34fffff]
pci 0000:00:15.4: bridge window [mem 0xdcf00000-0xdcffffff 64bit pref]
pci 0000:00:15.5: PCI bridge to [bus 08-08]
pci 0000:00:15.5: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:15.5: bridge window [mem 0xd3800000-0xd38fffff]
pci 0000:00:15.5: bridge window [mem 0xdd100000-0xdd1fffff 64bit pref]
pci 0000:00:15.6: PCI bridge to [bus 09-09]
pci 0000:00:15.6: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:15.6: bridge window [mem 0xd3c00000-0xd3cfffff]
pci 0000:00:15.6: bridge window [mem 0xdd300000-0xdd3fffff 64bit pref]
pci 0000:00:15.7: PCI bridge to [bus 0a-0a]
pci 0000:00:15.7: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:15.7: bridge window [mem 0xd4000000-0xd40fffff]
pci 0000:00:15.7: bridge window [mem 0xdd500000-0xdd5fffff 64bit pref]
pci 0000:0b:00.0: [15ad:07b0] type 0 class 0x000200
pci 0000:0b:00.0: reg 10: [mem 0xd2504000-0xd2504fff]
pci 0000:0b:00.0: reg 14: [mem 0xd2503000-0xd2503fff]
pci 0000:0b:00.0: reg 18: [mem 0xd2500000-0xd2501fff]
pci 0000:0b:00.0: reg 1c: [io 0x5000-0x500f]
pci 0000:0b:00.0: reg 30: [mem 0x00000000-0x0000ffff pref]
pci 0000:0b:00.0: supports D1 D2
pci 0000:0b:00.0: PME# supported from D0 D1 D2 D3hot D3cold
pci 0000:0b:00.0: PME# disabled
pci 0000:0b:00.0: disabling ASPM on pre-1.1 PCIe device. You can enable it with 'pcie_aspm=force'
pci 0000:00:16.0: PCI bridge to [bus 0b-0b]
pci 0000:00:16.0: bridge window [io 0x5000-0x5fff]
pci 0000:00:16.0: bridge window [mem 0xd2500000-0xd25fffff]
pci 0000:00:16.0: bridge window [mem 0xd4500000-0xd45fffff 64bit pref]
pci 0000:00:16.1: PCI bridge to [bus 0c-0c]
pci 0000:00:16.1: bridge window [io 0x9000-0x9fff]
pci 0000:00:16.1: bridge window [mem 0xd2900000-0xd29fffff]
pci 0000:00:16.1: bridge window [mem 0xd4900000-0xd49fffff 64bit pref]
pci 0000:00:16.2: PCI bridge to [bus 0d-0d]
pci 0000:00:16.2: bridge window [io 0xd000-0xdfff]
pci 0000:00:16.2: bridge window [mem 0xd2d00000-0xd2dfffff]
pci 0000:00:16.2: bridge window [mem 0xd4b00000-0xd4bfffff 64bit pref]
pci 0000:00:16.3: PCI bridge to [bus 0e-0e]
pci 0000:00:16.3: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:16.3: bridge window [mem 0xd3100000-0xd31fffff]
pci 0000:00:16.3: bridge window [mem 0xd4d00000-0xd4dfffff 64bit pref]
pci 0000:00:16.4: PCI bridge to [bus 0f-0f]
pci 0000:00:16.4: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:16.4: bridge window [mem 0xd3500000-0xd35fffff]
pci 0000:00:16.4: bridge window [mem 0xd4f00000-0xd4ffffff 64bit pref]
pci 0000:00:16.5: PCI bridge to [bus 10-10]
pci 0000:00:16.5: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:16.5: bridge window [mem 0xd3900000-0xd39fffff]
pci 0000:00:16.5: bridge window [mem 0xd5100000-0xd51fffff 64bit pref]
pci 0000:00:16.6: PCI bridge to [bus 11-11]
pci 0000:00:16.6: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:16.6: bridge window [mem 0xd3d00000-0xd3dfffff]
pci 0000:00:16.6: bridge window [mem 0xd5300000-0xd53fffff 64bit pref]
pci 0000:00:16.7: PCI bridge to [bus 12-12]
pci 0000:00:16.7: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:16.7: bridge window [mem 0xd4100000-0xd41fffff]
pci 0000:00:16.7: bridge window [mem 0xd5500000-0xd55fffff 64bit pref]
pci 0000:13:00.0: [15ad:07b0] type 0 class 0x000200
pci 0000:13:00.0: reg 10: [mem 0xd2604000-0xd2604fff]
pci 0000:13:00.0: reg 14: [mem 0xd2603000-0xd2603fff]
pci 0000:13:00.0: reg 18: [mem 0xd2600000-0xd2601fff]
pci 0000:13:00.0: reg 1c: [io 0x6000-0x600f]
pci 0000:13:00.0: reg 30: [mem 0x00000000-0x0000ffff pref]
pci 0000:13:00.0: supports D1 D2
pci 0000:13:00.0: PME# supported from D0 D1 D2 D3hot D3cold
pci 0000:13:00.0: PME# disabled
pci 0000:13:00.0: disabling ASPM on pre-1.1 PCIe device. You can enable it with 'pcie_aspm=force'
pci 0000:00:17.0: PCI bridge to [bus 13-13]
pci 0000:00:17.0: bridge window [io 0x6000-0x6fff]
pci 0000:00:17.0: bridge window [mem 0xd2600000-0xd26fffff]
pci 0000:00:17.0: bridge window [mem 0xd4600000-0xd46fffff 64bit pref]
pci 0000:00:17.1: PCI bridge to [bus 14-14]
pci 0000:00:17.1: bridge window [io 0xa000-0xafff]
pci 0000:00:17.1: bridge window [mem 0xd2a00000-0xd2afffff]
pci 0000:00:17.1: bridge window [mem 0xdca00000-0xdcafffff 64bit pref]
pci 0000:00:17.2: PCI bridge to [bus 15-15]
pci 0000:00:17.2: bridge window [io 0xe000-0xefff]
pci 0000:00:17.2: bridge window [mem 0xd2e00000-0xd2efffff]
pci 0000:00:17.2: bridge window [mem 0xdcc00000-0xdccfffff 64bit pref]
pci 0000:00:17.3: PCI bridge to [bus 16-16]
pci 0000:00:17.3: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:17.3: bridge window [mem 0xd3200000-0xd32fffff]
pci 0000:00:17.3: bridge window [mem 0xdce00000-0xdcefffff 64bit pref]
pci 0000:00:17.4: PCI bridge to [bus 17-17]
pci 0000:00:17.4: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:17.4: bridge window [mem 0xd3600000-0xd36fffff]
pci 0000:00:17.4: bridge window [mem 0xdd000000-0xdd0fffff 64bit pref]
pci 0000:00:17.5: PCI bridge to [bus 18-18]
pci 0000:00:17.5: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:17.5: bridge window [mem 0xd3a00000-0xd3afffff]
pci 0000:00:17.5: bridge window [mem 0xdd200000-0xdd2fffff 64bit pref]
pci 0000:00:17.6: PCI bridge to [bus 19-19]
pci 0000:00:17.6: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:17.6: bridge window [mem 0xd3e00000-0xd3efffff]
pci 0000:00:17.6: bridge window [mem 0xdd400000-0xdd4fffff 64bit pref]
pci 0000:00:17.7: PCI bridge to [bus 1a-1a]
pci 0000:00:17.7: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:17.7: bridge window [mem 0xd4200000-0xd42fffff]
pci 0000:00:17.7: bridge window [mem 0xdd600000-0xdd6fffff 64bit pref]
pci 0000:1b:00.0: [15ad:07b0] type 0 class 0x000200
pci 0000:1b:00.0: reg 10: [mem 0xd2705000-0xd2705fff]
pci 0000:1b:00.0: reg 14: [mem 0xd2704000-0xd2704fff]
pci 0000:1b:00.0: reg 18: [mem 0xd2702000-0xd2703fff]
pci 0000:1b:00.0: reg 1c: [io 0x7000-0x700f]
pci 0000:1b:00.0: reg 30: [mem 0x00000000-0x0000ffff pref]
pci 0000:1b:00.0: supports D1 D2
pci 0000:1b:00.0: PME# supported from D0 D1 D2 D3hot D3cold
pci 0000:1b:00.0: PME# disabled
pci 0000:1b:00.0: disabling ASPM on pre-1.1 PCIe device. You can enable it with 'pcie_aspm=force'
pci 0000:00:18.0: PCI bridge to [bus 1b-1b]
pci 0000:00:18.0: bridge window [io 0x7000-0x7fff]
pci 0000:00:18.0: bridge window [mem 0xd2700000-0xd27fffff]
pci 0000:00:18.0: bridge window [mem 0xd4700000-0xd47fffff 64bit pref]
pci 0000:00:18.1: PCI bridge to [bus 1c-1c]
pci 0000:00:18.1: bridge window [io 0xb000-0xbfff]
pci 0000:00:18.1: bridge window [mem 0xd2b00000-0xd2bfffff]
pci 0000:00:18.1: bridge window [mem 0xd4a00000-0xd4afffff 64bit pref]
pci 0000:00:18.2: PCI bridge to [bus 1d-1d]
pci 0000:00:18.2: bridge window [io 0xf000-0xffff]
pci 0000:00:18.2: bridge window [mem 0xd2f00000-0xd2ffffff]
pci 0000:00:18.2: bridge window [mem 0xd4c00000-0xd4cfffff 64bit pref]
pci 0000:00:18.3: PCI bridge to [bus 1e-1e]
pci 0000:00:18.3: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:18.3: bridge window [mem 0xd3300000-0xd33fffff]
pci 0000:00:18.3: bridge window [mem 0xd4e00000-0xd4efffff 64bit pref]
pci 0000:00:18.4: PCI bridge to [bus 1f-1f]
pci 0000:00:18.4: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:18.4: bridge window [mem 0xd3700000-0xd37fffff]
pci 0000:00:18.4: bridge window [mem 0xd5000000-0xd50fffff 64bit pref]
pci 0000:00:18.5: PCI bridge to [bus 20-20]
pci 0000:00:18.5: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:18.5: bridge window [mem 0xd3b00000-0xd3bfffff]
pci 0000:00:18.5: bridge window [mem 0xd5200000-0xd52fffff 64bit pref]
pci 0000:00:18.6: PCI bridge to [bus 21-21]
pci 0000:00:18.6: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:18.6: bridge window [mem 0xd3f00000-0xd3ffffff]
pci 0000:00:18.6: bridge window [mem 0xd5400000-0xd54fffff 64bit pref]
pci 0000:00:18.7: PCI bridge to [bus 22-22]
pci 0000:00:18.7: bridge window [io 0xf000-0x0000] (disabled)
pci 0000:00:18.7: bridge window [mem 0xd4300000-0xd43fffff]
pci 0000:00:18.7: bridge window [mem 0xd5600000-0xd56fffff 64bit pref]
vgaarb: device added: PCI:0000:00:0f.0,decodes=io+mem,owns=io+mem,locks=none
pci 0000:00:07.0: PIIX/ICH IRQ router [8086:7110]
PCI: pci_cache_line_size set to 64 bytes
reserve RAM buffer: 000000000009f800 - 000000000009ffff
reserve RAM buffer: 00000000bfef0000 - 00000000bfffffff
PCI: max bus depth: 1 pci_try_num: 2
pci 0000:00:0f.0: BAR 6: assigned [mem 0xc0000000-0xc0007fff pref]
pci 0000:00:10.0: BAR 6: assigned [mem 0xc0008000-0xc000bfff pref]
pci 0000:00:18.7: BAR 7: can't assign io (size 0x1000)
pci 0000:00:18.6: BAR 7: can't assign io (size 0x1000)
pci 0000:00:18.5: BAR 7: can't assign io (size 0x1000)
pci 0000:00:18.4: BAR 7: can't assign io (size 0x1000)
pci 0000:00:18.3: BAR 7: can't assign io (size 0x1000)
pci 0000:00:17.7: BAR 7: can't assign io (size 0x1000)
pci 0000:00:17.6: BAR 7: can't assign io (size 0x1000)
pci 0000:00:17.5: BAR 7: can't assign io (size 0x1000)
pci 0000:00:17.4: BAR 7: can't assign io (size 0x1000)
pci 0000:00:17.3: BAR 7: can't assign io (size 0x1000)
pci 0000:00:16.7: BAR 7: can't assign io (size 0x1000)
pci 0000:00:16.6: BAR 7: can't assign io (size 0x1000)
pci 0000:00:16.5: BAR 7: can't assign io (size 0x1000)
pci 0000:00:16.4: BAR 7: can't assign io (size 0x1000)
pci 0000:00:16.3: BAR 7: can't assign io (size 0x1000)
pci 0000:00:15.7: BAR 7: can't assign io (size 0x1000)
pci 0000:00:15.6: BAR 7: can't assign io (size 0x1000)
pci 0000:00:15.5: BAR 7: can't assign io (size 0x1000)
pci 0000:00:15.4: BAR 7: can't assign io (size 0x1000)
pci 0000:00:15.3: BAR 7: can't assign io (size 0x1000)
pci 0000:00:01.0: PCI bridge to [bus 01-01]
pci 0000:00:01.0: bridge window [io disabled]
pci 0000:00:01.0: bridge window [mem disabled]
pci 0000:00:01.0: bridge window [mem pref disabled]
pci 0000:00:11.0: PCI bridge to [bus 02-02]
pci 0000:00:11.0: bridge window [io 0x2000-0x3fff]
pci 0000:00:11.0: bridge window [mem 0xd1900000-0xd23fffff]
pci 0000:00:11.0: bridge window [mem 0xdc400000-0xdc9fffff 64bit pref]
pci 0000:03:00.0: BAR 6: assigned [mem 0xd4400000-0xd440ffff pref]
pci 0000:00:15.0: PCI bridge to [bus 03-03]
pci 0000:00:15.0: bridge window [io 0x4000-0x4fff]
pci 0000:00:15.0: bridge window [mem 0xd2400000-0xd24fffff]
pci 0000:00:15.0: bridge window [mem 0xd4400000-0xd44fffff 64bit pref]
pci 0000:00:15.1: PCI bridge to [bus 04-04]
pci 0000:00:15.1: bridge window [io 0x8000-0x8fff]
pci 0000:00:15.1: bridge window [mem 0xd2800000-0xd28fffff]
pci 0000:00:15.1: bridge window [mem 0xd4800000-0xd48fffff 64bit pref]
pci 0000:00:15.2: PCI bridge to [bus 05-05]
pci 0000:00:15.2: bridge window [io 0xc000-0xcfff]
pci 0000:00:15.2: bridge window [mem 0xd2c00000-0xd2cfffff]
pci 0000:00:15.2: bridge window [mem 0xdcb00000-0xdcbfffff 64bit pref]
pci 0000:00:15.3: PCI bridge to [bus 06-06]
pci 0000:00:15.3: bridge window [io disabled]
pci 0000:00:15.3: bridge window [mem 0xd3000000-0xd30fffff]
pci 0000:00:15.3: bridge window [mem 0xdcd00000-0xdcdfffff 64bit pref]
pci 0000:00:15.4: PCI bridge to [bus 07-07]
pci 0000:00:15.4: bridge window [io disabled]
pci 0000:00:15.4: bridge window [mem 0xd3400000-0xd34fffff]
pci 0000:00:15.4: bridge window [mem 0xdcf00000-0xdcffffff 64bit pref]
pci 0000:00:15.5: PCI bridge to [bus 08-08]
pci 0000:00:15.5: bridge window [io disabled]
pci 0000:00:15.5: bridge window [mem 0xd3800000-0xd38fffff]
pci 0000:00:15.5: bridge window [mem 0xdd100000-0xdd1fffff 64bit pref]
pci 0000:00:15.6: PCI bridge to [bus 09-09]
pci 0000:00:15.6: bridge window [io disabled]
pci 0000:00:15.6: bridge window [mem 0xd3c00000-0xd3cfffff]
pci 0000:00:15.6: bridge window [mem 0xdd300000-0xdd3fffff 64bit pref]
pci 0000:00:15.7: PCI bridge to [bus 0a-0a]
pci 0000:00:15.7: bridge window [io disabled]
pci 0000:00:15.7: bridge window [mem 0xd4000000-0xd40fffff]
pci 0000:00:15.7: bridge window [mem 0xdd500000-0xdd5fffff 64bit pref]
pci 0000:0b:00.0: BAR 6: assigned [mem 0xd4500000-0xd450ffff pref]
pci 0000:00:16.0: PCI bridge to [bus 0b-0b]
pci 0000:00:16.0: bridge window [io 0x5000-0x5fff]
pci 0000:00:16.0: bridge window [mem 0xd2500000-0xd25fffff]
pci 0000:00:16.0: bridge window [mem 0xd4500000-0xd45fffff 64bit pref]
pci 0000:00:16.1: PCI bridge to [bus 0c-0c]
pci 0000:00:16.1: bridge window [io 0x9000-0x9fff]
pci 0000:00:16.1: bridge window [mem 0xd2900000-0xd29fffff]
pci 0000:00:16.1: bridge window [mem 0xd4900000-0xd49fffff 64bit pref]
pci 0000:00:16.2: PCI bridge to [bus 0d-0d]
pci 0000:00:16.2: bridge window [io 0xd000-0xdfff]
pci 0000:00:16.2: bridge window [mem 0xd2d00000-0xd2dfffff]
pci 0000:00:16.2: bridge window [mem 0xd4b00000-0xd4bfffff 64bit pref]
pci 0000:00:16.3: PCI bridge to [bus 0e-0e]
pci 0000:00:16.3: bridge window [io disabled]
pci 0000:00:16.3: bridge window [mem 0xd3100000-0xd31fffff]
pci 0000:00:16.3: bridge window [mem 0xd4d00000-0xd4dfffff 64bit pref]
pci 0000:00:16.4: PCI bridge to [bus 0f-0f]
pci 0000:00:16.4: bridge window [io disabled]
pci 0000:00:16.4: bridge window [mem 0xd3500000-0xd35fffff]
pci 0000:00:16.4: bridge window [mem 0xd4f00000-0xd4ffffff 64bit pref]
pci 0000:00:16.5: PCI bridge to [bus 10-10]
pci 0000:00:16.5: bridge window [io disabled]
pci 0000:00:16.5: bridge window [mem 0xd3900000-0xd39fffff]
pci 0000:00:16.5: bridge window [mem 0xd5100000-0xd51fffff 64bit pref]
pci 0000:00:16.6: PCI bridge to [bus 11-11]
pci 0000:00:16.6: bridge window [io disabled]
pci 0000:00:16.6: bridge window [mem 0xd3d00000-0xd3dfffff]
pci 0000:00:16.6: bridge window [mem 0xd5300000-0xd53fffff 64bit pref]
pci 0000:00:16.7: PCI bridge to [bus 12-12]
pci 0000:00:16.7: bridge window [io disabled]
pci 0000:00:16.7: bridge window [mem 0xd4100000-0xd41fffff]
pci 0000:00:16.7: bridge window [mem 0xd5500000-0xd55fffff 64bit pref]
pci 0000:13:00.0: BAR 6: assigned [mem 0xd4600000-0xd460ffff pref]
pci 0000:00:17.0: PCI bridge to [bus 13-13]
pci 0000:00:17.0: bridge window [io 0x6000-0x6fff]
pci 0000:00:17.0: bridge window [mem 0xd2600000-0xd26fffff]
pci 0000:00:17.0: bridge window [mem 0xd4600000-0xd46fffff 64bit pref]
pci 0000:00:17.1: PCI bridge to [bus 14-14]
pci 0000:00:17.1: bridge window [io 0xa000-0xafff]
pci 0000:00:17.1: bridge window [mem 0xd2a00000-0xd2afffff]
pci 0000:00:17.1: bridge window [mem 0xdca00000-0xdcafffff 64bit pref]
pci 0000:00:17.2: PCI bridge to [bus 15-15]
pci 0000:00:17.2: bridge window [io 0xe000-0xefff]
pci 0000:00:17.2: bridge window [mem 0xd2e00000-0xd2efffff]
pci 0000:00:17.2: bridge window [mem 0xdcc00000-0xdccfffff 64bit pref]
pci 0000:00:17.3: PCI bridge to [bus 16-16]
pci 0000:00:17.3: bridge window [io disabled]
pci 0000:00:17.3: bridge window [mem 0xd3200000-0xd32fffff]
pci 0000:00:17.3: bridge window [mem 0xdce00000-0xdcefffff 64bit pref]
pci 0000:00:17.4: PCI bridge to [bus 17-17]
pci 0000:00:17.4: bridge window [io disabled]
pci 0000:00:17.4: bridge window [mem 0xd3600000-0xd36fffff]
pci 0000:00:17.4: bridge window [mem 0xdd000000-0xdd0fffff 64bit pref]
pci 0000:00:17.5: PCI bridge to [bus 18-18]
pci 0000:00:17.5: bridge window [io disabled]
pci 0000:00:17.5: bridge window [mem 0xd3a00000-0xd3afffff]
pci 0000:00:17.5: bridge window [mem 0xdd200000-0xdd2fffff 64bit pref]
pci 0000:00:17.6: PCI bridge to [bus 19-19]
pci 0000:00:17.6: bridge window [io disabled]
pci 0000:00:17.6: bridge window [mem 0xd3e00000-0xd3efffff]
pci 0000:00:17.6: bridge window [mem 0xdd400000-0xdd4fffff 64bit pref]
pci 0000:00:17.7: PCI bridge to [bus 1a-1a]
pci 0000:00:17.7: bridge window [io disabled]
pci 0000:00:17.7: bridge window [mem 0xd4200000-0xd42fffff]
pci 0000:00:17.7: bridge window [mem 0xdd600000-0xdd6fffff 64bit pref]
pci 0000:1b:00.0: BAR 6: assigned [mem 0xd4700000-0xd470ffff pref]
pci 0000:00:18.0: PCI bridge to [bus 1b-1b]
pci 0000:00:18.0: bridge window [io 0x7000-0x7fff]
pci 0000:00:18.0: bridge window [mem 0xd2700000-0xd27fffff]
pci 0000:00:18.0: bridge window [mem 0xd4700000-0xd47fffff 64bit pref]
pci 0000:00:18.1: PCI bridge to [bus 1c-1c]
pci 0000:00:18.1: bridge window [io 0xb000-0xbfff]
pci 0000:00:18.1: bridge window [mem 0xd2b00000-0xd2bfffff]
pci 0000:00:18.1: bridge window [mem 0xd4a00000-0xd4afffff 64bit pref]
pci 0000:00:18.2: PCI bridge to [bus 1d-1d]
pci 0000:00:18.2: bridge window [io 0xf000-0xffff]
pci 0000:00:18.2: bridge window [mem 0xd2f00000-0xd2ffffff]
pci 0000:00:18.2: bridge window [mem 0xd4c00000-0xd4cfffff 64bit pref]
pci 0000:00:18.3: PCI bridge to [bus 1e-1e]
pci 0000:00:18.3: bridge window [io disabled]
pci 0000:00:18.3: bridge window [mem 0xd3300000-0xd33fffff]
pci 0000:00:18.3: bridge window [mem 0xd4e00000-0xd4efffff 64bit pref]
pci 0000:00:18.4: PCI bridge to [bus 1f-1f]
pci 0000:00:18.4: bridge window [io disabled]
pci 0000:00:18.4: bridge window [mem 0xd3700000-0xd37fffff]
pci 0000:00:18.4: bridge window [mem 0xd5000000-0xd50fffff 64bit pref]
pci 0000:00:18.5: PCI bridge to [bus 20-20]
pci 0000:00:18.5: bridge window [io disabled]
pci 0000:00:18.5: bridge window [mem 0xd3b00000-0xd3bfffff]
pci 0000:00:18.5: bridge window [mem 0xd5200000-0xd52fffff 64bit pref]
pci 0000:00:18.6: PCI bridge to [bus 21-21]
pci 0000:00:18.6: bridge window [io disabled]
pci 0000:00:18.6: bridge window [mem 0xd3f00000-0xd3ffffff]
pci 0000:00:18.6: bridge window [mem 0xd5400000-0xd54fffff 64bit pref]
pci 0000:00:18.7: PCI bridge to [bus 22-22]
pci 0000:00:18.7: bridge window [io disabled]
pci 0000:00:18.7: bridge window [mem 0xd4300000-0xd43fffff]
pci 0000:00:18.7: bridge window [mem 0xd5600000-0xd56fffff 64bit pref]
pci 0000:00:01.0: setting latency timer to 64
pci 0000:00:15.0: setting latency timer to 64
pci 0000:00:15.1: setting latency timer to 64
pci 0000:00:15.2: setting latency timer to 64
pci 0000:00:15.3: setting latency timer to 64
pci 0000:00:15.4: setting latency timer to 64
pci 0000:00:15.5: setting latency timer to 64
pci 0000:00:15.6: setting latency timer to 64
pci 0000:00:15.7: setting latency timer to 64
pci 0000:00:16.0: setting latency timer to 64
pci 0000:00:16.1: setting latency timer to 64
pci 0000:00:16.2: setting latency timer to 64
pci 0000:00:16.3: setting latency timer to 64
pci 0000:00:16.4: setting latency timer to 64
pci 0000:00:16.5: setting latency timer to 64
pci 0000:00:16.6: setting latency timer to 64
pci 0000:00:16.7: setting latency timer to 64
pci 0000:00:17.0: setting latency timer to 64
pci 0000:00:17.1: setting latency timer to 64
pci 0000:00:17.2: setting latency timer to 64
pci 0000:00:17.3: setting latency timer to 64
pci 0000:00:17.4: setting latency timer to 64
pci 0000:00:17.5: setting latency timer to 64
pci 0000:00:17.6: setting latency timer to 64
pci 0000:00:17.7: setting latency timer to 64
pci 0000:00:18.0: setting latency timer to 64
pci 0000:00:18.1: setting latency timer to 64
pci 0000:00:18.2: setting latency timer to 64
pci 0000:00:18.3: setting latency timer to 64
pci 0000:00:18.4: setting latency timer to 64
pci 0000:00:18.5: setting latency timer to 64
pci 0000:00:18.6: setting latency timer to 64
pci 0000:00:18.7: setting latency timer to 64
pci_bus 0000:00: resource 0 [io 0x0000-0xffff]
pci_bus 0000:00: resource 1 [mem 0x00000000-0xffffffffff]
pci_bus 0000:02: resource 0 [io 0x2000-0x3fff]
pci_bus 0000:02: resource 1 [mem 0xd1900000-0xd23fffff]
pci_bus 0000:02: resource 2 [mem 0xdc400000-0xdc9fffff 64bit pref]
pci_bus 0000:02: resource 4 [io 0x0000-0xffff]
pci_bus 0000:02: resource 5 [mem 0x00000000-0xffffffffff]
pci_bus 0000:03: resource 0 [io 0x4000-0x4fff]
pci_bus 0000:03: resource 1 [mem 0xd2400000-0xd24fffff]
pci_bus 0000:03: resource 2 [mem 0xd4400000-0xd44fffff 64bit pref]
pci_bus 0000:04: resource 0 [io 0x8000-0x8fff]
pci_bus 0000:04: resource 1 [mem 0xd2800000-0xd28fffff]
pci_bus 0000:04: resource 2 [mem 0xd4800000-0xd48fffff 64bit pref]
pci_bus 0000:05: resource 0 [io 0xc000-0xcfff]
pci_bus 0000:05: resource 1 [mem 0xd2c00000-0xd2cfffff]
pci_bus 0000:05: resource 2 [mem 0xdcb00000-0xdcbfffff 64bit pref]
pci_bus 0000:06: resource 1 [mem 0xd3000000-0xd30fffff]
pci_bus 0000:06: resource 2 [mem 0xdcd00000-0xdcdfffff 64bit pref]
pci_bus 0000:07: resource 1 [mem 0xd3400000-0xd34fffff]
pci_bus 0000:07: resource 2 [mem 0xdcf00000-0xdcffffff 64bit pref]
pci_bus 0000:08: resource 1 [mem 0xd3800000-0xd38fffff]
pci_bus 0000:08: resource 2 [mem 0xdd100000-0xdd1fffff 64bit pref]
pci_bus 0000:09: resource 1 [mem 0xd3c00000-0xd3cfffff]
pci_bus 0000:09: resource 2 [mem 0xdd300000-0xdd3fffff 64bit pref]
pci_bus 0000:0a: resource 1 [mem 0xd4000000-0xd40fffff]
pci_bus 0000:0a: resource 2 [mem 0xdd500000-0xdd5fffff 64bit pref]
pci_bus 0000:0b: resource 0 [io 0x5000-0x5fff]
pci_bus 0000:0b: resource 1 [mem 0xd2500000-0xd25fffff]
pci_bus 0000:0b: resource 2 [mem 0xd4500000-0xd45fffff 64bit pref]
pci_bus 0000:0c: resource 0 [io 0x9000-0x9fff]
pci_bus 0000:0c: resource 1 [mem 0xd2900000-0xd29fffff]
pci_bus 0000:0c: resource 2 [mem 0xd4900000-0xd49fffff 64bit pref]
pci_bus 0000:0d: resource 0 [io 0xd000-0xdfff]
pci_bus 0000:0d: resource 1 [mem 0xd2d00000-0xd2dfffff]
pci_bus 0000:0d: resource 2 [mem 0xd4b00000-0xd4bfffff 64bit pref]
pci_bus 0000:0e: resource 1 [mem 0xd3100000-0xd31fffff]
pci_bus 0000:0e: resource 2 [mem 0xd4d00000-0xd4dfffff 64bit pref]
pci_bus 0000:0f: resource 1 [mem 0xd3500000-0xd35fffff]
pci_bus 0000:0f: resource 2 [mem 0xd4f00000-0xd4ffffff 64bit pref]
pci_bus 0000:10: resource 1 [mem 0xd3900000-0xd39fffff]
pci_bus 0000:10: resource 2 [mem 0xd5100000-0xd51fffff 64bit pref]
pci_bus 0000:11: resource 1 [mem 0xd3d00000-0xd3dfffff]
pci_bus 0000:11: resource 2 [mem 0xd5300000-0xd53fffff 64bit pref]
pci_bus 0000:12: resource 1 [mem 0xd4100000-0xd41fffff]
pci_bus 0000:12: resource 2 [mem 0xd5500000-0xd55fffff 64bit pref]
pci_bus 0000:13: resource 0 [io 0x6000-0x6fff]
pci_bus 0000:13: resource 1 [mem 0xd2600000-0xd26fffff]
pci_bus 0000:13: resource 2 [mem 0xd4600000-0xd46fffff 64bit pref]
pci_bus 0000:14: resource 0 [io 0xa000-0xafff]
pci_bus 0000:14: resource 1 [mem 0xd2a00000-0xd2afffff]
pci_bus 0000:14: resource 2 [mem 0xdca00000-0xdcafffff 64bit pref]
pci_bus 0000:15: resource 0 [io 0xe000-0xefff]
pci_bus 0000:15: resource 1 [mem 0xd2e00000-0xd2efffff]
pci_bus 0000:15: resource 2 [mem 0xdcc00000-0xdccfffff 64bit pref]
pci_bus 0000:16: resource 1 [mem 0xd3200000-0xd32fffff]
pci_bus 0000:16: resource 2 [mem 0xdce00000-0xdcefffff 64bit pref]
pci_bus 0000:17: resource 1 [mem 0xd3600000-0xd36fffff]
pci_bus 0000:17: resource 2 [mem 0xdd000000-0xdd0fffff 64bit pref]
pci_bus 0000:18: resource 1 [mem 0xd3a00000-0xd3afffff]
pci_bus 0000:18: resource 2 [mem 0xdd200000-0xdd2fffff 64bit pref]
pci_bus 0000:19: resource 1 [mem 0xd3e00000-0xd3efffff]
pci_bus 0000:19: resource 2 [mem 0xdd400000-0xdd4fffff 64bit pref]
pci_bus 0000:1a: resource 1 [mem 0xd4200000-0xd42fffff]
pci_bus 0000:1a: resource 2 [mem 0xdd600000-0xdd6fffff 64bit pref]
pci_bus 0000:1b: resource 0 [io 0x7000-0x7fff]
pci_bus 0000:1b: resource 1 [mem 0xd2700000-0xd27fffff]
pci_bus 0000:1b: resource 2 [mem 0xd4700000-0xd47fffff 64bit pref]
pci_bus 0000:1c: resource 0 [io 0xb000-0xbfff]
pci_bus 0000:1c: resource 1 [mem 0xd2b00000-0xd2bfffff]
pci_bus 0000:1c: resource 2 [mem 0xd4a00000-0xd4afffff 64bit pref]
pci_bus 0000:1d: resource 0 [io 0xf000-0xffff]
pci_bus 0000:1d: resource 1 [mem 0xd2f00000-0xd2ffffff]
pci_bus 0000:1d: resource 2 [mem 0xd4c00000-0xd4cfffff 64bit pref]
pci_bus 0000:1e: resource 1 [mem 0xd3300000-0xd33fffff]
pci_bus 0000:1e: resource 2 [mem 0xd4e00000-0xd4efffff 64bit pref]
pci_bus 0000:1f: resource 1 [mem 0xd3700000-0xd37fffff]
pci_bus 0000:1f: resource 2 [mem 0xd5000000-0xd50fffff 64bit pref]
pci_bus 0000:20: resource 1 [mem 0xd3b00000-0xd3bfffff]
pci_bus 0000:20: resource 2 [mem 0xd5200000-0xd52fffff 64bit pref]
pci_bus 0000:21: resource 1 [mem 0xd3f00000-0xd3ffffff]
pci_bus 0000:21: resource 2 [mem 0xd5400000-0xd54fffff 64bit pref]
pci_bus 0000:22: resource 1 [mem 0xd4300000-0xd43fffff]
pci_bus 0000:22: resource 2 [mem 0xd5600000-0xd56fffff 64bit pref]
NET: Registered protocol family 2
IP route cache hash table entries: 131072 (order: 8, 1048576 bytes)
TCP established hash table entries: 262144 (order: 10, 4194304 bytes)
TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
TCP: Hash tables configured (established 262144 bind 65536)
TCP reno registered
UDP hash table entries: 2048 (order: 4, 65536 bytes)
UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes)
NET: Registered protocol family 1
RPC: Registered named UNIX socket transport module.
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
RPC: Registered tcp NFSv4.1 backchannel transport module.
pci 0000:00:00.0: Limiting direct PCI/PCI transfers
pci 0000:00:0f.0: Boot video device
PCI: CLS 32 bytes, default 64
PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
Placing 64MB software IO TLB between ffff8800bbef0000 - ffff8800bfef0000
software IO TLB at phys 0xbbef0000 - 0xbfef0000
Switching to clocksource tsc
Switched to NOHz mode on CPU #0
Switched to NOHz mode on CPU #1
platform rtc_cmos: registered platform RTC device (no PNP device found)
audit: initializing netlink socket (disabled)
type=2000 audit(1397382155.497:1): initialized
VFS: Disk quotas dquot_6.5.2
Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
fuse init (API version 7.16)
msgmni has been set to 7769
Block layer SCSI generic (bsg) driver version 0.4 loaded (major 254)
io scheduler noop registered
io scheduler deadline registered
io scheduler cfq registered (default)
Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
serial8250: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
ipmi message handler version 39.2
ipmi device interface
IPMI System Interface driver.
ipmi_si: Adding default-specified kcs state machine
ipmi_si: Trying default-specified kcs state machine at i/o address 0xca2, slave address 0x0, irq 0
ipmi_si: Interface detection failed
ipmi_si: Adding default-specified smic state machine
ipmi_si: Trying default-specified smic state machine at i/o address 0xca9, slave address 0x0, irq 0
ipmi_si: Interface detection failed
ipmi_si: Adding default-specified bt state machine
ipmi_si: Trying default-specified bt state machine at i/o address 0xe4, slave ad dress 0x0, irq 0
ipmi_si: Interface detection failed
ipmi_si: Unable to find any System Interface(s)
IPMI Watchdog: driver initialized
Copyright (C) 2004 MontaVista Software - IPMI Powerdown via sys_reboot.
Floppy drive(s): fd0 is 1.44M
FDC 0 is a post-1991 82077
loop: module loaded
Uniform Multi-Platform E-IDE driver
piix 0000:00:07.1: IDE controller (0x8086:0x7111 rev 0x01)
piix 0000:00:07.1: not 100% native mode: will probe irqs later
ide0: BM-DMA at 0x10c0-0x10c7
ide1: BM-DMA at 0x10c8-0x10cf
Probing IDE interface ide0...
Probing IDE interface ide1...
hdc: VMware Virtual IDE CDROM Drive, ATAPI CD/DVD-ROM drive
hdc: host max PIO4 wanted PIO255(auto-tune) selected PIO4
hdc: UDMA/33 mode selected
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
ide1 at 0x170-0x177,0x376 on irq 15
ide_generic: please use "probe_mask=0x3f" module parameter for probing all legac y ISA IDE ports
ide-gd driver 1.18
ide-cd driver 5.00
ide-cd: hdc: ATAPI 1X DVD-ROM DVD-R/RAM CD-R/RW drive, 32kB Cache
cdrom: Uniform CD-ROM driver Revision: 3.20
Adaptec aacraid driver 1.1-7[28000]-ms
megaraid cmm: 2.20.2.7 (Release Date: Sun Jul 16 00:01:03 EST 2006)
megaraid: 2.20.5.1 (Release Date: Thu Nov 16 15:32:35 EST 2006)
megasas: 00.00.05.38-rc1 Wed. May. 11 17:00:00 PDT 2011
mpt2sas version 08.100.00.02 loaded
VMware PVSCSI driver - version 1.0.1.0-k
e1000: Intel(R) PRO/1000 Network Driver - version 7.3.21-k8-NAPI
e1000: Copyright (c) 1999-2006 Intel Corporation.
e1000e: Intel(R) PRO/1000 Network Driver - 1.3.10-k2
e1000e: Copyright(c) 1999 - 2011 Intel Corporation.
Intel(R) Gigabit Ethernet Network Driver - version 3.0.6-k2
Copyright (c) 2007-2011 Intel Corporation.
ixgbe: Intel(R) 10 Gigabit PCI Express Network Driver - version 3.3.8-k2
ixgbe: Copyright (c) 1999-2011 Intel Corporation.
pcnet32: pcnet32.c:v1.35 21.Apr.2008 tsbo...@alpha.franken.de
e100: Intel(R) PRO/100 Network Driver, 3.5.24-k2-NAPI
e100: Copyright(c) 1999-2006 Intel Corporation
usbcore: registered new interface driver catc
catc: v2.8:CATC EL1210A NetMate USB Ethernet driver
usbcore: registered new interface driver kaweth
pegasus: v0.6.14 (2006/09/27), Pegasus/Pegasus II USB Ethernet driver
usbcore: registered new interface driver pegasus
rtl8150: v0.6.2 (2004/08/27):rtl8150 based usb-ethernet driver
usbcore: registered new interface driver rtl8150
usbcore: registered new interface driver asix
usbcore: registered new interface driver cdc_ether
usbcore: registered new interface driver net1080
usbcore: registered new interface driver zaurus
Fusion MPT base driver 3.04.19
Copyright (c) 1999-2008 LSI Corporation
Fusion MPT SPI Host driver 3.04.19
mptspi 0000:00:10.0: PCI->APIC IRQ transform: INT A -> IRQ 17
mptbase: ioc0: Initiating bringup
ioc0: LSI53C1030 B0: Capabilities={Initiator}
scsi0 : ioc0: LSI53C1030 B0, FwRev=01032920h, Ports=1, MaxQ=128, IRQ=17
Fusion MPT FC Host driver 3.04.19
scsi 0:0:0:0: Direct-Access VMware Virtual disk 1.0 PQ: 0 ANSI: 2
scsi target0:0:0: Beginning Domain Validation
scsi target0:0:0: Domain Validation skipping write tests
scsi target0:0:0: Ending Domain Validation
scsi target0:0:0: FAST-40 WIDE SCSI 80.0 MB/s ST (25 ns, offset 127)
sd 0:0:0:0: [sda] 167772160 512-byte logical blocks: (85.8 GB/80.0 GiB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 61 00 00 00
sd 0:0:0:0: [sda] Cache data unavailable
sd 0:0:0:0: [sda] Assuming drive cache: write through
sd 0:0:0:0: Attached scsi generic sg0 type 0
sd 0:0:0:0: [sda] Cache data unavailable
sd 0:0:0:0: [sda] Assuming drive cache: write through
Fusion MPT SAS Host driver 3.04.19
sda: sda1 sda2 sda3 sda4 < sda5 sda6 sda7 sda8 sda9 sda10 >
Fusion MPT misc device (ioctl) driver 3.04.19
mptctl: Registered with Fusion MPT base driver
mptctl: /dev/mptctl @ (major,minor=10,220)
ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
uhci_hcd: USB Universal Host Controller Interface driver
Initializing USB Mass Storage driver...
usbcore: registered new interface driver usb-storage
USB Mass Storage support registered.
sd 0:0:0:0: [sda] Cache data unavailable
sd 0:0:0:0: [sda] Assuming drive cache: write through
usbcore: registered new interface driver usbserial
USB Serial support registered for generic
usbcore: registered new interface driver usbserial_generic
usbserial: USB Serial Driver core
serio: i8042 KBD port at 0x60,0x64 irq 1
serio: i8042 AUX port at 0x60,0x64 irq 12
mousedev: PS/2 mouse device common for all mice
sd 0:0:0:0: [sda] Attached SCSI disk
i2c /dev entries driver
cpuidle: using governor ladder
cpuidle: using governor menu
usbcore: registered new interface driver usbhid
usbhid: USB HID core driver
Netfilter messages via NETLINK v0.30.
nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
ip_set: protocol 6
ip_tables: (C) 2000-2006 Netfilter Core Team
TCP cubic registered
TCP scalable registered
TCP illinois registered
NET: Registered protocol family 10
ip6_tables: (C) 2000-2006 Netfilter Core Team
NET: Registered protocol family 17
Registering the dns_resolver key type
input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/inpu t0
input: ImPS/2 Generic Wheel Mouse as /devices/platform/i8042/serio1/input/input1
EXT3-fs (sda7): recovery required on readonly filesystem
EXT3-fs (sda7): write access will be enabled during recovery
EXT3-fs: barriers not enabled
kjournald starting. Commit interval 5 seconds
EXT3-fs (sda7): recovery complete
EXT3-fs (sda7): mounted filesystem with ordered data mode
VFS: Mounted root (ext3 filesystem) readonly on device 8:7.
Freeing unused kernel memory: 664k freed
Write protecting the kernel read-only data: 10240k
Freeing unused kernel memory: 28k freed
Freeing unused kernel memory: 1520k freed
EXT3-fs (sda7): using internal journal
VMware vmxnet3 virtual NIC driver - version 1.1.32.0-NAPI
vmxnet3 0000:03:00.0: PCI->APIC IRQ transform: INT A -> IRQ 18
vmxnet3 0000:03:00.0: setting latency timer to 64
features: sg csum vlan jf tso lro tsoIPv6 highDMA
vmxnet3 0000:03:00.0: irq 40 for MSI/MSI-X
vmxnet3 0000:03:00.0: irq 41 for MSI/MSI-X
vmxnet3 0000:03:00.0: irq 42 for MSI/MSI-X
# of Tx queues : 2, # of Rx queues : 2
RSS is enabled.
eth0: NIC Link is Up 10000 Mbps
vmxnet3 0000:0b:00.0: PCI->APIC IRQ transform: INT A -> IRQ 19
vmxnet3 0000:0b:00.0: setting latency timer to 64
features: sg csum vlan jf tso lro tsoIPv6 highDMA
vmxnet3 0000:0b:00.0: irq 43 for MSI/MSI-X
vmxnet3 0000:0b:00.0: irq 44 for MSI/MSI-X
vmxnet3 0000:0b:00.0: irq 45 for MSI/MSI-X
# of Tx queues : 2, # of Rx queues : 2
RSS is enabled.
eth1: NIC Link is Up 10000 Mbps
vmxnet3 0000:13:00.0: PCI->APIC IRQ transform: INT A -> IRQ 16
vmxnet3 0000:13:00.0: setting latency timer to 64
features: sg csum vlan jf tso lro tsoIPv6 highDMA
vmxnet3 0000:13:00.0: irq 46 for MSI/MSI-X
vmxnet3 0000:13:00.0: irq 47 for MSI/MSI-X
vmxnet3 0000:13:00.0: irq 48 for MSI/MSI-X
# of Tx queues : 2, # of Rx queues : 2
RSS is enabled.
eth2: NIC Link is Up 10000 Mbps
vmxnet3 0000:1b:00.0: PCI->APIC IRQ transform: INT A -> IRQ 17
vmxnet3 0000:1b:00.0: setting latency timer to 64
features: sg csum vlan jf tso lro tsoIPv6 highDMA
vmxnet3 0000:1b:00.0: irq 49 for MSI/MSI-X
vmxnet3 0000:1b:00.0: irq 50 for MSI/MSI-X
vmxnet3 0000:1b:00.0: irq 51 for MSI/MSI-X
# of Tx queues : 2, # of Rx queues : 2
RSS is enabled.
eth3: NIC Link is Up 10000 Mbps
EXT3-fs: barriers not enabled
kjournald starting. Commit interval 5 seconds
EXT3-fs (sda1): using internal journal
EXT3-fs (sda1): mounted filesystem with ordered data mode
EXT3-fs: barriers not enabled
kjournald starting. Commit interval 5 seconds
EXT3-fs (sda2): using internal journal
EXT3-fs (sda2): mounted filesystem with ordered data mode
EXT3-fs: barriers not enabled
kjournald starting. Commit interval 5 seconds
EXT3-fs (sda3): using internal journal
EXT3-fs (sda3): mounted filesystem with ordered data mode
EXT3-fs: barriers not enabled
kjournald starting. Commit interval 5 seconds
EXT3-fs (sda6): using internal journal
EXT3-fs (sda6): mounted filesystem with ordered data mode
EXT3-fs: barriers not enabled
kjournald starting. Commit interval 5 seconds
EXT3-fs (sda5): using internal journal
EXT3-fs (sda5): mounted filesystem with ordered data mode
eth0: intr type 3, mode 0, 3 vectors allocated
RSS indirection table :
0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1
eth0: NIC Link is Up 10000 Mbps
eth1: intr type 3, mode 0, 3 vectors allocated
RSS indirection table :
0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1
eth1: NIC Link is Up 10000 Mbps
eth2: intr type 3, mode 0, 3 vectors allocated
RSS indirection table :
0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1
eth2: NIC Link is Up 10000 Mbps
eth3: intr type 3, mode 0, 3 vectors allocated
RSS indirection table :
0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1 0 1
eth3: NIC Link is Up 10000 Mbps
Loading iSCSI transport class v2.0-870.
iscsi: registered transport (tcp)
vmmemctl: started kernel thread pid=3181
VMware memory control driver initialized
[3284]: VMCI: shared components initialized.
Probing for vmci/PCI.
vmci 0000:00:07.7: PCI->APIC IRQ transform: INT A -> IRQ 16
Found vmci/PCI at 0x1080, irq 16.
VMCI: using capabilities 0xc.
[3284]: VMCI: Host capability check passed.
vmci 0000:00:07.7: irq 52 for MSI/MSI-X
vmci 0000:00:07.7: irq 53 for MSI/MSI-X
Registered vmci device.
[3284]: VMCI: Using guest personality
[3284]: VMCI: host components initialized.
[3284]: VMCI: Module registered (name=vmci,major=10,minor=58).
[3284]: VMCI: Using host personality
[3284]: VMCI: Module (name=vmci) is initialized
eth1: no IPv6 routers present
eth3: no IPv6 routers present
eth0: no IPv6 routers present
eth2: no IPv6 routers present
var_link: module_layout: kernel tainted.
Disabling lock debugging due to kernel taint
kl_log_limit_init : numOfLogs=0, doesn't limit logs
st: module license 'Proprietary' taints kernel.
kl_log_limit_init : numOfLogs=0, doesn't limit logs
kl_log_limit_init : numOfLogs=0, doesn't limit logs
kl_log_limit_init : numOfLogs=0, doesn't limit logs
kl_log_limit_init : numOfLogs=0, doesn't limit logs
scst init KLR
kl_log_limit_init : numOfLogs=0, doesn't limit logs
iscsi_scst init KLR
kl_log_limit_init : numOfLogs=0, doesn't limit logs
kl_log_limit_init : numOfLogs=0, doesn't limit logs
scsi1 : iSCSI Initiator over TCP/IP
scsi 1:0:0:0: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 1:0:0:0: Attached scsi generic sg1 type 0
scsi 1:0:0:1: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 1:0:0:1: Attached scsi generic sg2 type 0
scsi 1:0:0:2: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 1:0:0:2: Attached scsi generic sg3 type 0
scsi 1:0:0:3: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 1:0:0:3: Attached scsi generic sg4 type 0
scsi 1:0:0:4: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 1:0:0:4: Attached scsi generic sg5 type 0
scsi 1:0:0:5: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 1:0:0:5: Attached scsi generic sg6 type 0
scsi 1:0:0:6: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 1:0:0:6: Attached scsi generic sg7 type 0
scsi 1:0:0:7: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 1:0:0:7: Attached scsi generic sg8 type 0
scsi 1:0:0:8: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 1:0:0:8: Attached scsi generic sg9 type 0
scsi 1:0:0:9: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 1:0:0:9: Attached scsi generic sg10 type 0
scsi2 : iSCSI Initiator over TCP/IP
scsi 2:0:0:0: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 2:0:0:0: Attached scsi generic sg11 type 0
scsi 2:0:0:1: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 2:0:0:1: Attached scsi generic sg12 type 0
scsi 2:0:0:2: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 2:0:0:2: Attached scsi generic sg13 type 0
scsi 2:0:0:3: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 2:0:0:3: Attached scsi generic sg14 type 0
scsi 2:0:0:4: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 2:0:0:4: Attached scsi generic sg15 type 0
scsi 2:0:0:5: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 2:0:0:5: Attached scsi generic sg16 type 0
scsi 2:0:0:6: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 2:0:0:6: Attached scsi generic sg17 type 0
scsi 2:0:0:7: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 2:0:0:7: Attached scsi generic sg18 type 0
scsi 2:0:0:8: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 2:0:0:8: Attached scsi generic sg19 type 0
scsi 2:0:0:9: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 2:0:0:9: Attached scsi generic sg20 type 0
scsi3 : iSCSI Initiator over TCP/IP
scsi 3:0:0:0: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 3:0:0:0: Attached scsi generic sg21 type 0
scsi 3:0:0:1: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 3:0:0:1: Attached scsi generic sg22 type 0
scsi 3:0:0:2: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 3:0:0:2: Attached scsi generic sg23 type 0
scsi 3:0:0:3: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 3:0:0:3: Attached scsi generic sg24 type 0
scsi 3:0:0:4: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 3:0:0:4: Attached scsi generic sg25 type 0
scsi 3:0:0:5: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 3:0:0:5: Attached scsi generic sg26 type 0
scsi 3:0:0:6: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 3:0:0:6: Attached scsi generic sg27 type 0
scsi 3:0:0:7: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 3:0:0:7: Attached scsi generic sg28 type 0
scsi 3:0:0:8: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 3:0:0:8: Attached scsi generic sg29 type 0
scsi 3:0:0:9: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 3:0:0:9: Attached scsi generic sg30 type 0
scsi4 : iSCSI Initiator over TCP/IP
scsi 4:0:0:0: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 4:0:0:0: Attached scsi generic sg31 type 0
scsi 4:0:0:1: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 4:0:0:1: Attached scsi generic sg32 type 0
scsi 4:0:0:2: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 4:0:0:2: Attached scsi generic sg33 type 0
scsi 4:0:0:3: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 4:0:0:3: Attached scsi generic sg34 type 0
scsi 4:0:0:4: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 4:0:0:4: Attached scsi generic sg35 type 0
scsi 4:0:0:5: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 4:0:0:5: Attached scsi generic sg36 type 0
scsi 4:0:0:6: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 4:0:0:6: Attached scsi generic sg37 type 0
scsi 4:0:0:7: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 4:0:0:7: Attached scsi generic sg38 type 0
scsi 4:0:0:8: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 4:0:0:8: Attached scsi generic sg39 type 0
scsi 4:0:0:9: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 4:0:0:9: Attached scsi generic sg40 type 0
scsi5 : iSCSI Initiator over TCP/IP
scsi 5:0:0:0: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 5:0:0:0: Attached scsi generic sg41 type 0
scsi 5:0:0:1: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 5:0:0:1: Attached scsi generic sg42 type 0
scsi 5:0:0:2: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 5:0:0:2: Attached scsi generic sg43 type 0
scsi 5:0:0:3: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 5:0:0:3: Attached scsi generic sg44 type 0
scsi 5:0:0:4: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 5:0:0:4: Attached scsi generic sg45 type 0
scsi 5:0:0:5: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 5:0:0:5: Attached scsi generic sg46 type 0
scsi 5:0:0:6: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 5:0:0:6: Attached scsi generic sg47 type 0
scsi 5:0:0:7: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 5:0:0:7: Attached scsi generic sg48 type 0
scsi 5:0:0:8: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 5:0:0:8: Attached scsi generic sg49 type 0
scsi 5:0:0:9: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 5:0:0:9: Attached scsi generic sg50 type 0
scsi6 : iSCSI Initiator over TCP/IP
scsi 6:0:0:0: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 6:0:0:0: Attached scsi generic sg51 type 0
scsi 6:0:0:1: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 6:0:0:1: Attached scsi generic sg52 type 0
scsi 6:0:0:2: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 6:0:0:2: Attached scsi generic sg53 type 0
scsi 6:0:0:3: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 6:0:0:3: Attached scsi generic sg54 type 0
scsi 6:0:0:4: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 6:0:0:4: Attached scsi generic sg55 type 0
scsi 6:0:0:5: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 6:0:0:5: Attached scsi generic sg56 type 0
scsi 6:0:0:6: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 6:0:0:6: Attached scsi generic sg57 type 0
scsi 6:0:0:7: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 6:0:0:7: Attached scsi generic sg58 type 0
scsi 6:0:0:8: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 6:0:0:8: Attached scsi generic sg59 type 0
scsi 6:0:0:9: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 6:0:0:9: Attached scsi generic sg60 type 0
scsi7 : iSCSI Initiator over TCP/IP
scsi 7:0:0:0: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 7:0:0:0: Attached scsi generic sg61 type 0
scsi 7:0:0:1: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 7:0:0:1: Attached scsi generic sg62 type 0
scsi 7:0:0:2: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 7:0:0:2: Attached scsi generic sg63 type 0
scsi 7:0:0:3: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 7:0:0:3: Attached scsi generic sg64 type 0
scsi 7:0:0:4: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 7:0:0:4: Attached scsi generic sg65 type 0
scsi 7:0:0:5: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 7:0:0:5: Attached scsi generic sg66 type 0
scsi 7:0:0:6: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 7:0:0:6: Attached scsi generic sg67 type 0
scsi 7:0:0:7: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 7:0:0:7: Attached scsi generic sg68 type 0
scsi 7:0:0:8: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 7:0:0:8: Attached scsi generic sg69 type 0
scsi 7:0:0:9: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 7:0:0:9: Attached scsi generic sg70 type 0
scsi8 : iSCSI Initiator over TCP/IP
scsi 8:0:0:0: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 8:0:0:0: Attached scsi generic sg71 type 0
scsi 8:0:0:1: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 8:0:0:1: Attached scsi generic sg72 type 0
scsi 8:0:0:2: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 8:0:0:2: Attached scsi generic sg73 type 0
scsi 8:0:0:3: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 8:0:0:3: Attached scsi generic sg74 type 0
scsi 8:0:0:4: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 8:0:0:4: Attached scsi generic sg75 type 0
scsi 8:0:0:5: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 8:0:0:5: Attached scsi generic sg76 type 0
scsi 8:0:0:6: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 8:0:0:6: Attached scsi generic sg77 type 0
scsi 8:0:0:7: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 8:0:0:7: Attached scsi generic sg78 type 0
scsi 8:0:0:8: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 8:0:0:8: Attached scsi generic sg79 type 0
scsi 8:0:0:9: Direct-Access DGC RAID 5 0532 PQ: 0 ANSI: 4
scsi 8:0:0:9: Attached scsi generic sg80 type 0
#1 - isdh_task_mgmt_fn:803 ***WARNING***: other mgmt command arrived 6 not handl ed in isdh dev handler
#1 - isdh_task_mgmt_fn:803 ***WARNING***: other mgmt command arrived 10 not hand led in isdh dev handler
#1 - isdh_task_mgmt_fn:803 ***WARNING***: other mgmt command arrived 6 not handl ed in isdh dev handler
#1 - isdh_task_mgmt_fn:803 ***WARNING***: other mgmt command arrived 10 not hand led in isdh dev handler
#0 - isdh_send_ctio:1759 ***ERROR***: scst_set_cmd_error_status opcode=0x55 stat us=0x2
#0 - isdh_send_ctio:1759 ***ERROR***: scst_set_cmd_error_status opcode=0x55 stat us=0x2
connection1:0: ping timeout of 5 secs expired, recv timeout 5, last rx 43004917 87, last ping 4300493024, now 4300501787
connection1:0: detected conn error (1011)
connection2:0: ping timeout of 5 secs expired, recv timeout 5, last rx 43004917 86, last ping 4300496786, now 4300501792
connection2:0: detected conn error (1011)
connection6:0: ping timeout of 5 secs expired, recv timeout 5, last rx 43004917 87, last ping 4300496787, now 4300501792
connection6:0: detected conn error (1011)
connection5:0: ping timeout of 5 secs expired, recv timeout 5, last rx 43004917 89, last ping 4300496789, now 4300501792
connection5:0: detected conn error (1011)
connection1:0: detected conn error (1021)
#0 - conn_rsp_timer_fn:543 ***ERROR***: Timeout 30 sec sending data/waiting for reply to/from initiator iqn.1992-04.com.emc:cx.apm00112004768.a9 (SID 6000000000 080), closing connection
#1 - isdh_task_mgmt_fn:803 ***WARNING***: other mgmt command arrived 6 not handl ed in isdh dev handler
#1 - isdh_task_mgmt_fn:803 ***WARNING***: other mgmt command arrived 10 not hand led in isdh dev handler
#0 - conn_rsp_timer_fn:543 ***ERROR***: Timeout 30 sec sending data/waiting for reply to/from initiator iqn.1992-04.com.emc:cx.apm00112004768.a9 (SID 4000000000 080), closing connection
#1 - isdh_task_mgmt_fn:803 ***WARNING***: other mgmt command arrived 6 not handl ed in isdh dev handler
#1 - isdh_task_mgmt_fn:803 ***WARNING***: other mgmt command arrived 10 not hand led in isdh dev handler
session1: session recovery timed out after 120 secs
session2: session recovery timed out after 120 secs
scsi 1:0:0:0: Device offlined - not ready after error recovery
scsi 1:0:0:0: rejecting I/O to offline device
scsi 1:0:0:0: rejecting I/O to offline device

--------------------------------------
kwdw_thread D 0000000000000000 0 3687 2 0x00000000
ffff880139145cb0 0000000000000046 000000001b000058 ffff880139144010
0000000000004000 ffff88013b290c40 ffff880139145fd8 ffff880139145fd8
0000000000000000 ffff88013b290c40 ffffffff81a0b020 ffff88013b290ed0
Call Trace:
[<ffffffffa006ef80>] ? vlink_generate_kernel_bug+0x20/0x20 [var_link]
[<ffffffff815ed07f>] schedule+0x3f/0x60
[<ffffffff815ed54d>] schedule_timeout+0x28d/0x2d0
[<ffffffffa006f8b4>] ? vlink_check_for_async_reboot+0x14/0x80 [var_link]
[<ffffffff81035bd7>] ? dequeue_task_fair+0x1a7/0x290
[<ffffffffa006ef80>] ? vlink_generate_kernel_bug+0x20/0x20 [var_link]
[<ffffffff815ee5ca>] __down+0x6a/0xb0
[<ffffffff8106926b>] down+0x4b/0x50
[<ffffffffa006efcb>] kwdw_threadfn+0x4b/0x90 [var_link]
[<ffffffff8103c5e8>] ? try_to_wake_up+0x208/0x330
[<ffffffff8103c722>] ? default_wake_function+0x12/0x20
[<ffffffff8103114a>] ? __wake_up_common+0x5a/0x90
[<ffffffffa006ef80>] ? vlink_generate_kernel_bug+0x20/0x20 [var_link]
[<ffffffffa006ef80>] ? vlink_generate_kernel_bug+0x20/0x20 [var_link]
[<ffffffff815ed07f>] ? schedule+0x3f/0x60
[<ffffffff8106363e>] ? kthread+0x9e/0xb0
[<ffffffff815f0914>] kernel_thread_helper+0x4/0x10
[<ffffffff810635a0>] ? kthread_worker_fn+0x140/0x140
[<ffffffff815f0910>] ? gs_change+0xb/0xb
st_thread D 0000000000000000 0 3754 2 0x00000000
ffff88011d8afcb0 0000000000000046 ffff880129f4c000 ffff88011d8ae010
0000000000004000 ffff88013b291ea0 ffff88011d8affd8 ffff88011d8affd8
0000000000000000 ffff88013b291ea0 ffffffff81a0b020 ffff88013b292130
Call Trace:
[<ffffffffa0099e12>] ? st_chk_mem_demanding_work_lst+0x42/0x2c0 [st]
[<ffffffff8103594f>] ? pick_next_task_fair+0x5f/0x140
[<ffffffffa009a2c0>] ? st_chk_mem_bound_work_lst+0x230/0x230 [st]
[<ffffffff815ecc48>] ? __schedule+0x7f8/0x8d0
[<ffffffff815ef10e>] ? common_interrupt+0xe/0x13
[<ffffffffa009a2c0>] ? st_chk_mem_bound_work_lst+0x230/0x230 [st]
[<ffffffff815ed07f>] schedule+0x3f/0x60
[<ffffffff815ed54d>] schedule_timeout+0x28d/0x2d0
[<ffffffffa00999c0>] ? st_send_huge_write_ctio_work_lst_data+0x20/0x200 [st]
[<ffffffff815ef10e>] ? common_interrupt+0xe/0x13
[<ffffffffa009a2c0>] ? st_chk_mem_bound_work_lst+0x230/0x230 [st]
[<ffffffff815ee5ca>] __down+0x6a/0xb0
[<ffffffff8106926b>] down+0x4b/0x50
[<ffffffffa009a360>] st_threadfn+0xa0/0x170 [st]
[<ffffffff8103c5e8>] ? try_to_wake_up+0x208/0x330
[<ffffffff8103c722>] ? default_wake_function+0x12/0x20
[<ffffffff8103114a>] ? __wake_up_common+0x5a/0x90
[<ffffffffa009a2c0>] ? st_chk_mem_bound_work_lst+0x230/0x230 [st]
[<ffffffffa009a2c0>] ? st_chk_mem_bound_work_lst+0x230/0x230 [st]
[<ffffffff815ed07f>] ? schedule+0x3f/0x60
[<ffffffff8106363e>] ? kthread+0x9e/0xb0
[<ffffffff815f0914>] kernel_thread_helper+0x4/0x10
[<ffffffff810635a0>] ? kthread_worker_fn+0x140/0x140
[<ffffffff815f0910>] ? gs_change+0xb/0xb
st_threadfn_sta D 0000000000000000 0 3755 2 0x00000000
ffff88011b0b1cd0 0000000000000046 1ed2df2db110d536 ffff88011b0b0010
0000000000004000 ffff88013b294fa0 ffff88011b0b1fd8 ffff88011b0b1fd8
0000000000000001 ffff88013b294fa0 ffff88013b08bd40 ffff88013b295230
Call Trace:
[<ffffffff810345f7>] ? enqueue_task+0x37/0x50
[<ffffffffa009a430>] ? st_threadfn+0x170/0x170 [st]
[<ffffffff815ed07f>] schedule+0x3f/0x60
[<ffffffffa009a4c5>] st_threadfn_status+0x95/0x1a0 [st]
[<ffffffff81035bd7>] ? dequeue_task_fair+0x1a7/0x290
[<ffffffff8103586e>] ? set_next_entity+0x3e/0x80
[<ffffffffa009a430>] ? st_threadfn+0x170/0x170 [st]
[<ffffffff815ec84c>] ? __schedule+0x3fc/0x8d0
[<ffffffff8103c5e8>] ? try_to_wake_up+0x208/0x330
[<ffffffff8103c722>] ? default_wake_function+0x12/0x20
[<ffffffff8103114a>] ? __wake_up_common+0x5a/0x90
[<ffffffff81063b60>] ? wake_up_bit+0x40/0x40
[<ffffffffa009a430>] ? st_threadfn+0x170/0x170 [st]
[<ffffffff8106363e>] ? kthread+0x9e/0xb0
[<ffffffff815f0914>] ? kernel_thread_helper+0x4/0x10
[<ffffffff810635a0>] ? kthread_worker_fn+0x140/0x140
[<ffffffff815f0910>] ? gs_change+0xb/0xb
sll_dump_thread D 0000000000000000 0 3761 2 0x00000000
ffff88010f477cb0 0000000000000046 00000000000001ec ffff88010f476010
0000000000004000 ffff88013b2955c0 ffff88010f477fd8 ffff88010f477fd8
0000000000000000 ffff88013b2955c0 ffffffff81a0b020 ffff88013b295850
Call Trace:
[<ffffffffa0156280>] ? KL_INFO+0x190/0x1c0 [sll]
[<ffffffffa014f890>] ? sll_wakeup_dump_thread+0x40/0x40 [sll]
[<ffffffff815ed07f>] schedule+0x3f/0x60
[<ffffffff815ed54d>] schedule_timeout+0x28d/0x2d0
[<ffffffffa014f890>] ? sll_wakeup_dump_thread+0x40/0x40 [sll]
[<ffffffff815ee5ca>] __down+0x6a/0xb0
[<ffffffff8106926b>] down+0x4b/0x50
[<ffffffffa014f8d2>] sll_dump_threadfn+0x42/0x180 [sll]
[<ffffffff8103c5e8>] ? try_to_wake_up+0x208/0x330
[<ffffffff8103c722>] ? default_wake_function+0x12/0x20
[<ffffffff8103114a>] ? __wake_up_common+0x5a/0x90
[<ffffffffa014f890>] ? sll_wakeup_dump_thread+0x40/0x40 [sll]
[<ffffffffa014f890>] ? sll_wakeup_dump_thread+0x40/0x40 [sll]
[<ffffffff8106363e>] ? kthread+0x9e/0xb0
[<ffffffff815f0914>] kernel_thread_helper+0x4/0x10
[<ffffffff810635a0>] ? kthread_worker_fn+0x140/0x140
[<ffffffff815f0910>] ? gs_change+0xb/0xb
sim_task0 D 0000000000000000 0 3764 2 0x00000000
ffff88010fc83cd0 0000000000000046 00000008000007ff ffff88010fc82010
0000000000004000 ffff88013b290000 ffff88010fc83fd8 ffff88010fc83fd8
0000000000000000 ffff88013b290000 ffff88013b292ae0 ffff88013b290290
Call Trace:
[<ffffffff815ef10e>] ? common_interrupt+0xe/0x13
[<ffffffff815ef10e>] ? common_interrupt+0xe/0x13
[<ffffffff815eec9e>] ? _raw_spin_unlock_irqrestore+0xe/0x10
[<ffffffff815ed07f>] schedule+0x3f/0x60
[<ffffffffa02d3655>] sim_task_threadfn+0x215/0x2b0 [sim]
[<ffffffff81035bd7>] ? dequeue_task_fair+0x1a7/0x290
[<ffffffff8103586e>] ? set_next_entity+0x3e/0x80
[<ffffffffa02d3440>] ? sim_abort_handler_handle_wakeup+0x330/0x330 [sim]
[<ffffffff815ec84c>] ? __schedule+0x3fc/0x8d0
[<ffffffff8103c5e8>] ? try_to_wake_up+0x208/0x330
[<ffffffff8103c722>] ? default_wake_function+0x12/0x20
[<ffffffff8103114a>] ? __wake_up_common+0x5a/0x90
[<ffffffff81063b60>] ? wake_up_bit+0x40/0x40
[<ffffffffa02d3440>] ? sim_abort_handler_handle_wakeup+0x330/0x330 [sim]
[<ffffffff8106363e>] ? kthread+0x9e/0xb0
[<ffffffff815f0914>] ? kernel_thread_helper+0x4/0x10
[<ffffffff810635a0>] ? kthread_worker_fn+0x140/0x140
[<ffffffff815f0910>] ? gs_change+0xb/0xb
sim_abort_handl D 0000000000000000 0 3765 2 0x00000000
ffff88010fc85cd0 0000000000000046 ffff88010fc85be0 ffff88010fc84010
0000000000004000 ffff88013b2924c0 ffff88010fc85fd8 ffff88010fc85fd8
0000000000000000 ffff88013b2924c0 ffff88013b1ed5c0 ffff88013b292750
Call Trace:
[<ffffffff8127bdc8>] ? sprintf+0x68/0x70
[<ffffffff815ed07f>] schedule+0x3f/0x60
[<ffffffffa02d3865>] sim_abort_handler_threadfn+0x175/0x220 [sim]
[<ffffffff81035bd7>] ? dequeue_task_fair+0x1a7/0x290
[<ffffffff8103586e>] ? set_next_entity+0x3e/0x80
[<ffffffffa02d36f0>] ? sim_task_threadfn+0x2b0/0x2b0 [sim]
[<ffffffff815ec84c>] ? __schedule+0x3fc/0x8d0
[<ffffffff8103c5e8>] ? try_to_wake_up+0x208/0x330
[<ffffffff8103c722>] ? default_wake_function+0x12/0x20
[<ffffffff8103114a>] ? __wake_up_common+0x5a/0x90
[<ffffffff81063b60>] ? wake_up_bit+0x40/0x40
[<ffffffffa02d36f0>] ? sim_task_threadfn+0x2b0/0x2b0 [sim]
[<ffffffff8106363e>] ? kthread+0x9e/0xb0
[<ffffffff815f0914>] ? kernel_thread_helper+0x4/0x10
[<ffffffff810635a0>] ? kthread_worker_fn+0x140/0x140
[<ffffffff815f0910>] ? gs_change+0xb/0xb
sim_task1 D 0000000000000000 0 3766 2 0x00000000
ffff88010fc87cd0 0000000000000046 00000008000007ff ffff88010fc86010
0000000000004000 ffff88013b292ae0 ffff88010fc87fd8 ffff88010fc87fd8
0000000000000000 ffff88013b292ae0 ffffffff81a0b020 ffff88013b292d70
Call Trace:
[<ffffffff815ef10e>] ? common_interrupt+0xe/0x13
[<ffffffff815f01ce>] ? apic_timer_interrupt+0xe/0x20
[<ffffffff815ef10e>] ? common_interrupt+0xe/0x13
[<ffffffff815ed07f>] schedule+0x3f/0x60
[<ffffffffa02d3655>] sim_task_threadfn+0x215/0x2b0 [sim]
[<ffffffff81035bd7>] ? dequeue_task_fair+0x1a7/0x290
[<ffffffff8103586e>] ? set_next_entity+0x3e/0x80
[<ffffffffa02d3440>] ? sim_abort_handler_handle_wakeup+0x330/0x330 [sim]
[<ffffffff815ec84c>] ? __schedule+0x3fc/0x8d0
[<ffffffff8103c5e8>] ? try_to_wake_up+0x208/0x330
[<ffffffff8103c722>] ? default_wake_function+0x12/0x20
[<ffffffff8103114a>] ? __wake_up_common+0x5a/0x90
[<ffffffff81063b60>] ? wake_up_bit+0x40/0x40
[<ffffffffa02d3440>] ? sim_abort_handler_handle_wakeup+0x330/0x330 [sim]
[<ffffffff8106363e>] ? kthread+0x9e/0xb0
[<ffffffff815f0914>] ? kernel_thread_helper+0x4/0x10
[<ffffffff810635a0>] ? kthread_worker_fn+0x140/0x140
[<ffffffff815f0910>] ? gs_change+0xb/0xb
sim_abort_handl D 0000000000000000 0 3767 2 0x00000000
ffff88010fc89cd0 0000000000000046 ffff88010fc89be0 ffff88010fc88010
0000000000004000 ffff88013b293d40 ffff88010fc89fd8 ffff88010fc89fd8
0000000000000000 ffff88013b293d40 ffff88013b1ed5c0 ffff88013b293fd0
Call Trace:
[<ffffffff8127bdc8>] ? sprintf+0x68/0x70
[<ffffffff815ed07f>] schedule+0x3f/0x60
[<ffffffffa02d3865>] sim_abort_handler_threadfn+0x175/0x220 [sim]
[<ffffffff81035bd7>] ? dequeue_task_fair+0x1a7/0x290
[<ffffffff8103586e>] ? set_next_entity+0x3e/0x80
[<ffffffffa02d36f0>] ? sim_task_threadfn+0x2b0/0x2b0 [sim]
[<ffffffff815ec84c>] ? __schedule+0x3fc/0x8d0
[<ffffffff8103c5e8>] ? try_to_wake_up+0x208/0x330
[<ffffffff8103c722>] ? default_wake_function+0x12/0x20
[<ffffffff8103114a>] ? __wake_up_common+0x5a/0x90
[<ffffffff81063b60>] ? wake_up_bit+0x40/0x40
[<ffffffffa02d36f0>] ? sim_task_threadfn+0x2b0/0x2b0 [sim]
[<ffffffff8106363e>] ? kthread+0x9e/0xb0
[<ffffffff815f0914>] ? kernel_thread_helper+0x4/0x10
[<ffffffff810635a0>] ? kthread_worker_fn+0x140/0x140
[<ffffffff815f0910>] ? gs_change+0xb/0xb



-----Original Message-----
From: Mike Christie [mailto:mich...@cs.wisc.edu]
Sent: Friday, April 11, 2014 10:12 AM
To: open-...@googlegroups.com
Cc: myselfa...@gmail.com; Cale, Yonatan
Subject: Re: Target reboot -> iscsiadm rescan Stuck

Cale, Yonatan

unread,
Apr 20, 2014, 6:18:58 AM4/20/14
to Mike Christie, open-...@googlegroups.com, myselfa...@gmail.com
Hi Mike, are the logs supposed to come out in /var/log/messages?
If so, here's the "messages" file.
The problem happened between " Sun Apr 20 09:59:04 UTC 2014 " and " Sun Apr 20 10:06:50 UTC 2014", I would guess around 10:02
Good luck, you have like infinite log lines to look at :P


-----Original Message-----
From: Mike Christie [mailto:mich...@cs.wisc.edu]
Sent: Thursday, April 17, 2014 8:57 PM
To: open-...@googlegroups.com
Cc: Cale, Yonatan; myselfa...@gmail.com
Subject: Re: Target reboot -> iscsiadm rescan Stuck

messages.gz

Cale, Yonatan

unread,
Apr 16, 2014, 12:22:19 PM4/16/14
to Mike Christie, open-...@googlegroups.com, myselfa...@gmail.com
Hi,

Attached is a compressed tcpdump capture (iscsiadm_spreboot_3.gz, ~300kb),
Some detailes about it:
It was obtained by running " tcpdump icmp and src or dst 10.76.18.174 or src or dst 10.76.18.175 -i any -w iscsiadm_spreboot_3".
My local iscsi port IPs are 10.76.18.174 & 10.76.18.175.
The target iscsi IPs are 10.76.18.31 & 10.76.18.33.
Chronological order:
-Start capture
-A few seconds later, reboot SP A (one of the iscsi targets)
-A long time (~10 minutes) later, the bug happens (I notice it because iscsiadm starts taking 85% CPU)
-A few seconds later, stop capture

I'm mentioning the order mainly to point out that the bug happens in the last few seconds of the capture

And thank you for sitting on this bug with me.
:)

-----Original Message-----
From: Mike Christie [mailto:mich...@cs.wisc.edu]
Sent: Monday, April 14, 2014 8:07 PM
Subject: Re: Target reboot -> iscsiadm rescan Stuck

iscsiadm_spreboot_3.gz

Cale, Yonatan

unread,
Apr 17, 2014, 7:14:28 AM4/17/14
to Mike Christie, open-...@googlegroups.com, myselfa...@gmail.com
-----Original Message-----
From: Cale, Yonatan
Sent: Wednesday, April 16, 2014 7:22 PM
To: 'Mike Christie'
Cc: open-...@googlegroups.com; myselfa...@gmail.com
Subject: RE: Target reboot -> iscsiadm rescan Stuck

Hi,

Attached is a compressed tcpdump capture (iscsiadm_spreboot_3.gz, ~300kb), Some detailes about it:
It was obtained by running " tcpdump icmp and src or dst 10.76.18.174 or src or dst 10.76.18.175 -i any -w iscsiadm_spreboot_3".
My local iscsi port IPs are 10.76.18.174 & 10.76.18.175.
The target iscsi IPs are 10.76.18.31 & 10.76.18.33.
Chronological order:
-Start capture
-A few seconds later, reboot SP A (one of the iscsi targets) -A long time (~10 minutes) later, the bug happens (I notice it because iscsiadm starts taking 85% CPU) -A few seconds later, stop capture

I'm mentioning the order mainly to point out that the bug happens in the last few seconds of the capture

And thank you for sitting on this bug with me.
:)

-----Original Message-----
From: Mike Christie [mailto:mich...@cs.wisc.edu]
Sent: Monday, April 14, 2014 8:07 PM
To: Cale, Yonatan
Cc: open-...@googlegroups.com; myselfa...@gmail.com
Subject: Re: Target reboot -> iscsiadm rescan Stuck

Cale, Yonatan

unread,
Apr 27, 2014, 11:38:03 AM4/27/14
to Mike Christie, open-...@googlegroups.com, myselfa...@gmail.com
Hi,
Our sim module is above the scsi layer (not between the iscsi&scsi layers), so I think this already rules out this guess.

What we do is something like this:
-Send scsi command
-If we didn't get a response after X seconds,
--Abort the command (perhaps many times, if the abort fails)

So.. We add some prints somewhere new?

I'd like to say again, that this bug happens with one version of VNX but not with another version. Do you think that might give us a hint?

Mike Christie

unread,
Apr 27, 2014, 9:11:23 PM4/27/14
to Cale, Yonatan, open-...@googlegroups.com, myselfa...@gmail.com
On 4/27/14, 10:38 AM, Cale, Yonatan wrote:
> Hi,
> Our sim module is above the scsi layer (not between the iscsi&scsi layers), so I think this already rules out this guess.
>
> What we do is something like this:
> -Send scsi command
> -If we didn't get a response after X seconds,
> --Abort the command (perhaps many times, if the abort fails)
>
> So.. We add some prints somewhere new?
>

I should have written *you* have to add some printks in the scsi/block
layer :) As iscsi maintainer I am happy to help all vendors on iscsi
related issue as you have seen in this thread, but I work for Fusion-io
on their FC/SRP/iSCSI target, ION, so I do not have time to debug all
kernel layers for a multi-billion dollar company like EMC :)

If I hit this problem with our product, I would look over the scsi scan
code since we see those commands time out. I would look at the scsi scan
code and see how it handled time out failures for report luns and inquirys.

Probably what the problem is, is that scsi layer tried to send a report
luns, that timedout due to your target not responding for whatever
reason, the scsi layer handled that by thinking that it failed because
target does not support report luns and not due it just timing out, and
scsi layer dropped down to a sequential scan as a result. So all those
inquirys in the logs are not retries but instead the scsi layer trying
to see if a lu is behind lun0, lun1, lun2....... lun(N = MAX_UNSIGNED_INT).

If that is not the problem, I would add debug code to the
scsi_request_fn/scsi_dispatch_cmd and
scsi_done/scsi_softirq_done/scsi_decide_disposition/scsi_finish_command/scsi_io_completion
to see why those inquirys are retried when they should be failed.


> I'd like to say again, that this bug happens with one version of VNX but not with another version. Do you think that might give us a hint?
>

Yes. I would guess your other VNX versions reply to the scsi scan
related IO, so we do not fall into this problem where the scsi scan IO
timedout, and IO is now endlessly retried or we drop down a sequential
scan. Again, if I worked for EMC, I would have compared the logs for
different versions to see what behavior changed.

Hope this helps. If you have even the slightest hunch it is a iscsi code
problem come back and bug me, because I really do not care what vendor
you are from when fixing iscsi bugs.

Cale, Yonatan

unread,
Apr 29, 2014, 10:02:28 AM4/29/14
to Mike Christie, open-...@googlegroups.com, myselfa...@gmail.com
Hi,
I understand this problem is probably unrelated to your product, so you're not supposed to start debugging it, that makes sense (and also makes me sad :P )
So first of all thank you (and fusion-io) for sitting with me on this so far, it's not something trivial for me to expect.
I'd like to understand your iscsi-related analysis so far, so that I can continue the investigation by myself, if that's ok.
So:
You assume that an unanswered "report LUNs" that was sent from the scsi layer -> caused the scsi layer to inquiry each of the ~infinite possible LUNs separately.
-Can you tell me what "iscsiadm" calls - that is getting stuck? For example, are you calling "report LUNs" that the scsi layer is refusing to answer?
-In the "messages_end" log I sent you, it has ~infinite "session1: iscsi_queuecommand iscsi: cmd 0x12 is not queued" prints. What is this? Is this related to the scsi layer querying all LUNs as you suggested? (If not then why do you think the problem is in the scsi layer?)

In other words, I'm asking what's going on right over the scsi layer (with iscsiadm) and just below the scsi layer (iscsi layer), both are components that you probably know well - so that I can be on-target with my continued investigation.

So thanks again, and wish me luck
:)
Yonatan

Mike Christie

unread,
Apr 29, 2014, 12:46:49 PM4/29/14
to open-...@googlegroups.com, Cale, Yonatan, myselfa...@gmail.com
On 04/29/2014 09:02 AM, Cale, Yonatan wrote:
> Hi,
> I understand this problem is probably unrelated to your product, so you're not supposed to start debugging it, that makes sense (and also makes me sad :P )
> So first of all thank you (and fusion-io) for sitting with me on this so far, it's not something trivial for me to expect.
> I'd like to understand your iscsi-related analysis so far, so that I can continue the investigation by myself, if that's ok.
> So:
> You assume that an unanswered "report LUNs" that was sent from the scsi layer -> caused the scsi layer to inquiry each of the ~infinite possible LUNs separately.

Yes. In the logs we see:

Apr 24 10:31:04 rp kernel: session1: iscsi_prep_scsi_cmd_pdu iscsi prep
[read cid 0 sc ffff880138c37800 cdb 0xa0 itt 0x40 len 131080 bidi_len 0
cmdsn 2844 win 255]

The cdb indicates this is a REPORT_LUNs command.

Apr 24 10:31:11 rp kernel: session1: iscsi_eh_cmd_timed_out scsi cmd
ffff880138c37800 timedout

We then see the scsi command timeout has expired. The scsi layer is
calling into the drivers timeout handler function.

Apr 24 10:31:14 rp kernel: connection1:0: detected conn error (1011)

For some reason we lost the tcp connection.


Apr 24 10:33:15 rp kernel: session1: session recovery timed out after
120 secs

We could not log back into the target, and the replacement/recovery
timeout fired, so we are now going to fail all IO. This means the
REPORT_LUNs we were trying to execute is going to be failed and all new
IO will be failed.

Apr 24 10:33:15 rp kernel: session1: iscsi_queuecommand iscsi: cmd 0xa0
is not queued (983040)

Here is where the scsi layer gets stuck and just starts sending endless
inquirys. Because the recovery/replacement timeout expired we fail
everything with DID_TRANSPORT_FAILFAST.


In the logs, we sometimes see slightly different patterns where when the
command times out, we might get a little farther in the scsi eh process
and the device might get offlined by the scsi layer, then we hit the
endless inquirys.




> -Can you tell me what "iscsiadm" calls - that is getting stuck? For example, are you calling "report LUNs" that the scsi layer is refusing to answer?
>

When you run the iscsiadm rescan command, iscsiadm just does

echo - - - > /sys/class/scsi_host/hostX/scan

This ends up calling

linux-kernel-source/drivers/scsi/scsi_scan.c:scan_target(). And here in
__scsi_scan_target we see that scsi-ml will try a
scsi_report_lun_scan(). If that fails then it drops down to
scsi_sequential_lun_scan(). That function is just a loop that does
scsi_probe_and_add_lun where probing is just sending a inquiry for every
possible LUN from 1 to max_lun which for iscsi_tcp is the max unsigned int.


-In the "messages_end" log I sent you, it has ~infinite "session1:
iscsi_queuecommand iscsi: cmd 0x12 is not queued" prints. What is this?
Is this related to the scsi layer querying all LUNs as you suggested?
(If not then why do you think the problem is in the scsi layer?)
>

See above. Does it make sense? If not let me know.

> In other words, I'm asking what's going on right over the scsi layer (with iscsiadm) and just below the scsi layer (iscsi layer), both are components that you probably know well - so that I can be on-target with my continued investigation.
>
> So thanks again, and wish me luck
> :)

Good luck. I am pretty sure it is the scan issue I described, so you
should be ok. It will be a good first step into open source and sending
patches upstream.

If you look in scsi_report_lun_scan(), check out:


if (result) {
/*
* The device probably does not support a REPORT LUN command
*/
ret = 1;
goto out_err;
}

I think instead of always assuming that for any old result value, we
might want to check for specific values. Just add a printk to print the
result value. It is probably DID_TRANSPORT_FAILFAST or
DID_TRANSPORT_DISRUPTED or DID_NO_CONNECT.


You probably also want to see if in the cases it works if the
REPORT_LUNs is successful, or if the iscsi layer is figuring out the
session is bad before you do the rescan command.

Cale, Yonatan

unread,
Jun 1, 2014, 2:06:05 PM6/1/14
to Mike Christie, open-...@googlegroups.com, myselfa...@gmail.com
Hi again Mike,
I'd like to update you on this topic.
The short story is that it probably isn't an infinite loop in "scsi_sequential_lun_scan". I can't "prove" that it is or isn't in the scsi or iscsi layer, so please decide based on your own judgment if you'd like to take part in the investigation. Obviously I'd be glad to hear from you. :)

Evidence:

1)
I added printk's to scsi_sequential_lun_scan:
{{{

static void scsi_sequential_lun_scan(struct scsi_target *starget,
int bflags, int scsi_level, int rescan)
{
...
printk(KERN_INFO "caley debug: scsi scan: Sequential scan of"
"%s, max_dev_lun=%d, bflags=%d\n", dev_name(&starget->dev), max_dev_lun, bflags);
...
for (lun = 1; lun < max_dev_lun; ++lun)
{
probe_result = scsi_probe_and_add_lun(starget, lun, NULL, NULL, rescan, NULL);
printk(KERN_INFO "caley debug: scsi_probe_and_add_lun (lun=%d, rescan=%d) = %d", lun, rescan, probe_result);
if ((probe_result != SCSI_SCAN_LUN_PRESENT) &&
!sparse_lun)
return;
}
}}}

And the output after a run is 2 of these prints:
caley debug: scsi scan: Sequential scan oftarget0:0:0, max_dev_lun=1,
bflags=0

Showing that the "for" loop that was expected to be infinite - doesn't run at all (!!)


2)
Here is part of a core dump, giving us the stack trace of the (probably) stuck iscsiadm process, while it is stuck:
{
#6 [ffff880094b6f8d0] memcpy at ffffffff8127d0b0
/emc/krnl/kernels/linux-3.0.56/arch/x86/lib/memcpy_64.S: 159
#7 [ffff880094b6f8d0] vsnprintf at ffffffff8127b997
/emc/krnl/kernels/linux-3.0.56/lib/vsprintf.c: 1202
#8 [ffff880094b6f940] kvasprintf at ffffffff8127ebae
/emc/krnl/kernels/linux-3.0.56/lib/kasprintf.c: 31
#9 [ffff880094b6f990] kobject_set_name_vargs at ffffffff81273fcd
/emc/krnl/kernels/linux-3.0.56/lib/kobject.c: 225
#10 [ffff880094b6f9b0] dev_set_name at ffffffff812dca69
/emc/krnl/kernels/linux-3.0.56/drivers/base/core.c: 814
#11 [ffff880094b6fa90] scsi_sysfs_device_initialize at ffffffff81310c18
/emc/krnl/kernels/linux-3.0.56/drivers/scsi/scsi_sysfs.c: 1082
#12 [ffff880094b6fad0] scsi_alloc_sdev at ffffffff8130dc62
/emc/krnl/kernels/linux-3.0.56/drivers/scsi/scsi_scan.c: 306
#13 [ffff880094b6fb10] scsi_probe_and_add_lun at ffffffff8130e82d
/emc/krnl/kernels/linux-3.0.56/drivers/scsi/scsi_scan.c: 1044
#14 [ffff880094b6fc40] __scsi_scan_target at ffffffff8130f168
/emc/krnl/kernels/linux-3.0.56/drivers/scsi/scsi_scan.c: 1224
#15 [ffff880094b6fd30] scsi_scan_target at ffffffff8130fa28
/emc/krnl/kernels/linux-3.0.56/drivers/scsi/scsi_scan.c: 1650
#16 [ffff880094b6fd70] iscsi_user_scan_session at ffffffffa00111b6
[scsi_transport_iscsi]
}

My point in this stack is that "scsi_sequential_lun_scan" is not called at all. "scsi_probe_and_add_lun" is called directly from "__scsi_scan_target".

Later I also added some print in " scsi_probe_and_add_lun" and it is definitely not called ~infinit'ish times. I can also say that every time it started to run, it finished running.

Do you agree that this rules out the scsi layer bug? Where would you continue to investigate? Do you have another guess regarding where the bug is hiding?
Any thoughts are most welcome.
Yonatan

-----Original Message-----
From: Mike Christie [mailto:mich...@cs.wisc.edu]
Sent: Tuesday, April 29, 2014 7:47 PM
To: open-...@googlegroups.com

Mike Christie

unread,
Jun 1, 2014, 2:59:54 PM6/1/14
to open-...@googlegroups.com, Cale, Yonatan, myselfa...@gmail.com
On 06/01/2014 01:03 PM, Cale, Yonatan wrote:
> Hi again Mike,
> I'd like to update you on this topic.
> The short story is that it probably isn't an infinite loop in "scsi_sequential_lun_scan". I can't "prove" that it is or isn't in the scsi or iscsi layer, so please decide based on your own judgment if you'd like to take part in the investigation. Obviously I'd be glad to hear from you. :)
>
> Evidence:
>
> 1)
> I added printk's to scsi_sequential_lun_scan:
> {{{
>
> static void scsi_sequential_lun_scan(struct scsi_target *starget,
> int bflags, int scsi_level, int rescan)
> {
> ...
> printk(KERN_INFO "caley debug: scsi scan: Sequential scan of"
> "%s, max_dev_lun=%d, bflags=%d\n", dev_name(&starget->dev), max_dev_lun, bflags);
> ...
> for (lun = 1; lun < max_dev_lun; ++lun)
> {
> probe_result = scsi_probe_and_add_lun(starget, lun, NULL, NULL, rescan, NULL);
> printk(KERN_INFO "caley debug: scsi_probe_and_add_lun (lun=%d, rescan=%d) = %d", lun, rescan, probe_result);
> if ((probe_result != SCSI_SCAN_LUN_PRESENT) &&
> !sparse_lun)
> return;
> }
> }}}
>
> And the output after a run is 2 of these prints:
> caley debug: scsi scan: Sequential scan oftarget0:0:0, max_dev_lun=1,
> bflags=0


How are you getting max_dev_lun=1? Do you build your kernel without
CONFIG_SCSI_MULTI_LUN, or did you modify iscsi_tcp's max lun?
I am not sure how you can say it always completes when in the above
trace we are stuck in scsi_probe_and_add_lun. If we are not really stuck
in there (not sure if it is just a bad trace because you said you saw
the sequential scan printk so we must have moved past that initial probe
and add lun call), then where are we stuck in the
scsi_scan_target/__scsi_scan_target code path? Did you already stick
some printks in there to narrow it down? If not, then do that.

During this test, before you do the rescan command, are there
luns/devices setup on the initiator side? I mean is there a scsi_device
for LUN0 already setup or did you delete the luns/scsi_devices at some
time before you did the rescan?

If there is a lun0 already present, then you should add printks to
scsi_probe_and_add_lun to see why it was not found and we are going down
the code path to add it. scsi_probe_and_add_lun should have returned
SCSI_SCAN_LUN_PRESENT.

Cale, Yonatan

unread,
Jun 3, 2014, 7:47:32 AM6/3/14
to Mike Christie, open-...@googlegroups.com, myselfa...@gmail.com
Hi,

Regarding debug prints in "__scsi_scan_target", here is what I added:
{{{
static void __scsi_scan_target(struct device *parent, unsigned int channel,
...
printk(KERN_INFO "__scsi_scan_target --> scsi_probe_and_add_lun: lun (%d) != SCAN_WILD_CARD, rescan=%d \n", lun, rescan);
scsi_probe_and_add_lun(starget, lun, NULL, NULL, rescan, NULL);
...
/*
* Scan LUN 0, if there is some response, scan further. Ideally, we
* would not configure LUN 0 until all LUNs are scanned.
*/
printk(KERN_INFO "__scsi_scan_target --> scsi_probe_and_add_lun: before scanning LUN 0, rescan=%d \n", rescan);
res = scsi_probe_and_add_lun(starget, 0, &bflags, NULL, rescan, NULL);
printk(KERN_INFO "__scsi_scan_target --> scsi_probe_and_add_lun: scanning LUN 0: rescan=%d, res=%d \n", lun, res);
...
}}}

The output contains the following messages (a few times) (the first+last prints here are new, the third one I'll explain in a moment..):
{
dmesg.0:__scsi_scan_target --> scsi_probe_and_add_lun: before scanning LUN 0, rescan=0
dmesg.0:caley debug: scsi_probe_and_add_lun start, lun=0, rescan=0
dmesg.0:caley debug: scsi_probe_and_add_lun out_free_sdev, res=0
dmesg.0:__scsi_scan_target --> scsi_probe_and_add_lun: scanning LUN 0: rescan=-1, res=0
}

Regarding the third print ("...scsi_probe_and_add_lun out_free_sdev..."), I added it just before the LAST return at the bottom line of " scsi_probe_and_add_lun". Since it always appears in the log right after " scsi_probe_and_add_lun start", I concluded that the function always finished.
I agree that this does not add up very well with having the trace *currently in side* of "scsi_probe_and_add_lun".
Perhaps a timing issue of "when were the logs taken vs when was the trace taken" ? It would be more likely if we'd have an infinite loop (that is half time in the function and half time out of it)
Perhaps a bad stack trace? I don't think so, the "scsi_probe_and_add_lun" keeps appearing in stack traces I'm getting.

Regarding having "max_dev_lun=1":
MAX_SCSI_LUNS is defined as 512, as usual.
CONFIG_SCSI_MULTI_LUN - I'm not sure, I doubt we changed the default to "don't work with multi lun". I think that this "max_dev_lun=1" might be coming from earlier in the function, a lot of code there changes it. Anyway it seems to be less relevant since it's not causing an infinite loop as was expected and also because "scsi_sequential_lun_scan" doesn't even appear in the stack trace. (If you'd like, I'll run a test to check what it is defined to anyway).


-----Original Message-----
From: Mike Christie [mailto:mich...@cs.wisc.edu]
Sent: Sunday, June 01, 2014 10:00 PM
To: open-...@googlegroups.com
Cc: Cale, Yonatan; myselfa...@gmail.com
Subject: Re: Target reboot -> iscsiadm rescan Stuck

Mike Christie

unread,
Jun 3, 2014, 10:30:02 AM6/3/14
to open-...@googlegroups.com, Cale, Yonatan, myselfa...@gmail.com
On 6/3/14, 6:46 AM, Cale, Yonatan wrote:
> Hi,
>
> Regarding debug prints in "__scsi_scan_target", here is what I added:

I meant add more. We are trying to debug why the scan does not complete.
For the printks you added below it does not tell us where we are stuck
in the scan process. It could have got stuck after the printks you added
there.

Also, did you even hang in that run you provided the log output for
below? It looks like the probe and add for LUN0 returned
SCSI_SCAN_NO_RESPONSE, so it looks like in that run you did not drop
down to the report luns and sequential scan code like you did in some
other runs.

You need to just add some printks or do a kprobe module or figure out
how to turn on scsi scan logging or a combo of both.

Mike Christie

unread,
Jun 3, 2014, 10:46:28 AM6/3/14
to open-...@googlegroups.com, Cale, Yonatan, myselfa...@gmail.com
On 6/3/14, 9:29 AM, Mike Christie wrote:
> On 6/3/14, 6:46 AM, Cale, Yonatan wrote:
>> Hi,
>>
>> Regarding debug prints in "__scsi_scan_target", here is what I added:
>
> I meant add more. We are trying to debug why the scan does not complete.
> For the printks you added below it does not tell us where we are stuck
> in the scan process. It could have got stuck after the printks you added
> there.
>
> Also, did you even hang in that run you provided the log output for
> below? It looks like the probe and add for LUN0 returned
> SCSI_SCAN_NO_RESPONSE, so it looks like in that run you did not drop
> down to the report luns and sequential scan code like you did in some
> other runs.
>
> You need to just add some printks or do a kprobe module or figure out
> how to turn on scsi scan logging or a combo of both.
>

Ignore the above. I thought you were telling me the printks you added in
response to the mail I said to add more printks. As I reread the mail,
it sounds like you are just trying to tell me why you think
scsi_probe_and_add_lun always completes.

Going forward you just need to add more printks or enable more logging
or do a kprobe module or some combo of both, so you can narrow down
where in the scan process we are getting stuck.

yonatan cale

unread,
Jun 3, 2014, 3:09:59 PM6/3/14
to Mike Christie, open-...@googlegroups.com, Cale, Yonatan
Ok, let me just make sure I'm with you on the same page,
We want to check where we are getting stuck in "scsi_scan_target" (in scsi_scan.c) and in the functions that it calls (and they call). Right? (we are not debugging any other functions right now)

Mike Christie

unread,
Jun 3, 2014, 6:29:35 PM6/3/14
to open-...@googlegroups.com, yonatan cale, Cale, Yonatan
On 06/03/2014 02:09 PM, yonatan cale wrote:
> Ok, let me just make sure I'm with you on the same page,
> We want to check where we are getting stuck in "scsi_scan_target" (in
> scsi_scan.c) and in the functions that it calls (and they call). Right?

Yes.

> (we are not debugging any other functions right now)
>

If you want to make it a little more complicated we could also try to
figure out why when the initiator fails a inqiury with
DID_TRANSPORT_FAILED the scsi layer does not seem to fail the command.
This was part of the mystery where I thought it might not be a retry and
was really the sequential scan code going crazy, but you ruled that out.
I think the fact we see inquirys over and over in the logs is still
related to the problem we are debugging.

For this you would need to add debugging to the queueing and completion
code which would be more complex, so I am not sure if you want to just
start with the scanning code.
> --
> You received this message because you are subscribed to the Google
> Groups "open-iscsi" group.
> To unsubscribe from this group and stop receiving emails from it, send
> an email to open-iscsi+...@googlegroups.com
> <mailto:open-iscsi+...@googlegroups.com>.
> To post to this group, send email to open-...@googlegroups.com
> <mailto:open-...@googlegroups.com>.
> Visit this group at http://groups.google.com/group/open-iscsi.
> For more options, visit https://groups.google.com/d/optout.

Reply all
Reply to author
Forward
0 new messages