Re: how to handle (and get out victorious) 1 minute disconnection againts a target.

[Mike Christie]

On 03/27/2013 07:17 PM, alejandro...@gmail.com wrote:
> Hi guys, im new to the list, and i apologise in advance to write this,
> but i've been reading a lot and i dont seem to find an answer to an
> specific question i have.
>
> We are using Netapp to deploy nova volume to our openstack KVM
> instances, this means :
>
> #1 We have lots of phisical servers running kvm virtual instances
> #2 this physical servers connect against our netapp appliances through iSCSI
> #3 we attach this iscsi sessions to the instances for them to see it as
> a new block device ( the instances dont see it as an scsi session, just
> the phisical server )
>
> The thing is, we want to be able to handle a 1 minute disconnection
> caused either by a storage reboot or a network outage ( both, no more
> than a minute o minute and a half )

What do you mean by handle? Retried in the iscsi/scsi layer? Failed to
upper levels like multipath or some clustering software?

Are you using dm-multipath with iscsi?

Section 8. Advanced Configuration of the iscsi README might be helpful.

> What i want to understand and i dont seem to ( again, sorry ) is ...
>

Tell me if you are using dm-multipath and what you want to do. I can
then answer the questions below.

> #1 what parameter/s to touch from the open-iscsi config on the physical
> host to handle that amount of time the dissconection
> #2 in the mean time, supposing i've touched thos parameters, all the
> data that needs to be writen and wont, were is it cached on the physical
> server side? in ram ? in our local disk ?
> #3 and those retries, i imagine i will see exactly the same in the
> physical and virtual side, are reflected till the connection is
> reestablished, as I/O wait just increasing, and CPU waiting for the
> write to finish ?
>
> Hope i made myself clear, and sorri if all my questions were answered
> and i wasnt able to find it.
> I'll wait for all your help to understand a little more.
>
> Thank you very much.
>
> --
> 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.
> To post to this group, send email to open-...@googlegroups.com.
> Visit this group at http://groups.google.com/group/open-iscsi?hl=en.
> For more options, visit https://groups.google.com/groups/opt_out.
>
>

[Alejandro Comisario]

Hi mike, sorry for the incompletion on my post.

No, im not using multipath, each physical node is connected directly to a lun in a storage.

What i want i think, is the iscsi layer to retry all cmd till we reconnect, so that the virtual machines inside that host that are ussing those luns, just see I/O wait increasing till the reconnection is made.

i have this params in the initiator side :

node.startup = automatic

node.session.timeo.replacement_timeout = 120

node.conn[0].timeo.login_timeout = 15

node.conn[0].timeo.logout_timeout = 15

node.conn[0].timeo.noop_out_interval = 5

node.conn[0].timeo.noop_out_timeout = 5

node.session.err_timeo.abort_timeout = 15

node.session.err_timeo.lu_reset_timeout = 20

node.session.initial_login_retry_max = 8

node.session.cmds_max = 128

node.session.queue_depth = 32

node.session.xmit_thread_priority = -20

node.session.iscsi.InitialR2T = No

node.session.iscsi.ImmediateData = Yes

node.session.iscsi.FirstBurstLength = 262144

node.session.iscsi.MaxBurstLength = 16776192

node.conn[0].iscsi.MaxRecvDataSegmentLength = 262144

discovery.sendtargets.iscsi.MaxRecvDataSegmentLength = 32768

node.session.iscsi.FastAbort = Yes

As i read, having :

node.conn[0].timeo.noop_out_interval = 5

node.conn[0].timeo.noop_out_timeout = 5

node.session.timeo.replacement_timeout = 120

Mean that after trying every 5 secs a ping against the target, and after having no reply in 5 secs, it will trigger the HR that will wait ( and queue cmds ) replacement_timeout secconds before failing to the upper layers.

So, just increasing replacement_timeout seconds, i will get the desired behavior ?

I just want to handle a 5 min / 10 min network / storage outage without my luns going READ-ONLY on the vms side because i have failed all the commands.

Thank you !

[Michael Christie]

On Mar 29, 2013, at 4:30 PM, Alejandro Comisario <alejandro...@gmail.com> wrote:
> node.session.timeo.replacement_timeout = 120
>
> Mean that after trying every 5 secs a ping against the target, and after having no reply in 5 secs, it will trigger the HR that will wait ( and queue cmds ) replacement_timeout secconds before failing to the upper layers.
> So, just increasing replacement_timeout seconds, i will get the desired behavior ?

Yes. Just set the replacement_timeout to how long you want the iscsi layer to reconnect before it fails IO to upper layers.

[Alejandro Comisario]

Mike, i think something is wrong and i dont seem to know what, because still, im getting I/O errors reported to the filesystem layer after 120 seconds, but i dont know if its from the iscsi side or other configuration is involved, this is what we negotiated with the target :

root@DC2-r16-22vms:/var/log# iscsiadm -m node -T iqn.1992-08.com.netapp:sn.1574861693

# BEGIN RECORD 2.0-871

node.name = iqn.1992-08.com.netapp:sn.1574861693

node.tpgt = 2000

node.startup = automatic

iface.hwaddress = <empty>

iface.ipaddress = <empty>

iface.iscsi_ifacename = default

iface.net_ifacename = <empty>

iface.transport_name = tcp

iface.initiatorname = <empty>

node.discovery_address = 10.1.1.160

node.discovery_port = 3260

node.discovery_type = send_targets

node.session.initial_cmdsn = 0

node.session.initial_login_retry_max = 8

node.session.xmit_thread_priority = -20

node.session.cmds_max = 128

node.session.queue_depth = 32

node.session.auth.authmethod = None

node.session.auth.username = <empty>

node.session.auth.password = <empty>

node.session.auth.username_in = <empty>

node.session.auth.password_in = <empty>

node.session.timeo.replacement_timeout = 600

node.session.err_timeo.abort_timeout = 15

node.session.err_timeo.lu_reset_timeout = 20

node.session.err_timeo.host_reset_timeout = 60

node.session.iscsi.FastAbort = Yes

node.session.iscsi.InitialR2T = No

node.session.iscsi.ImmediateData = Yes

node.session.iscsi.FirstBurstLength = 262144

node.session.iscsi.MaxBurstLength = 16776192

node.session.iscsi.DefaultTime2Retain = 0

node.session.iscsi.DefaultTime2Wait = 2

node.session.iscsi.MaxConnections = 1

node.session.iscsi.MaxOutstandingR2T = 1

node.session.iscsi.ERL = 0

node.conn[0].address = 10.1.1.160

node.conn[0].port = 3260

node.conn[0].startup = manual

node.conn[0].tcp.window_size = 524288

node.conn[0].tcp.type_of_service = 0

node.conn[0].timeo.logout_timeout = 15

node.conn[0].timeo.login_timeout = 15

node.conn[0].timeo.auth_timeout = 45

node.conn[0].timeo.noop_out_interval = 5

node.conn[0].timeo.noop_out_timeout = 5

node.conn[0].iscsi.MaxRecvDataSegmentLength = 262144

node.conn[0].iscsi.HeaderDigest = None

node.conn[0].iscsi.DataDigest = None

node.conn[0].iscsi.IFMarker = No

node.conn[0].iscsi.OFMarker = No

# END RECORD

We issued a dd against the ext4 LUN mounted, but after 120 seconds we see this errors in /var/log/syslog :

Apr  4 10:33:41 DC2-r16-22vms iscsid: Kernel reported iSCSI connection 3:0 error (1011) state (3)

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018502] INFO: task jbd2/sdc1-8:100283 blocked for more than 120 seconds.

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018505] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018507] jbd2/sdc1-8     D ffffffff81806240     0 100283      2 0x00000000

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018512]  ffff881015d39ac0 0000000000000046 ffff881015d39a60 ffffffff8103ecf9

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018517]  ffff881015d39fd8 ffff881015d39fd8 ffff881015d39fd8 00000000000137c0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018521]  ffff881018a7dc00 ffff881016224500 ffff881015d39a90 ffff88203ee14080

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018525] Call Trace:

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018535]  [<ffffffff8103ecf9>] ? default_spin_lock_flags+0x9/0x10

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018541]  [<ffffffff811182c0>] ? __lock_page+0x70/0x70

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018546]  [<ffffffff8165b0cf>] schedule+0x3f/0x60

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018548]  [<ffffffff8165b17f>] io_schedule+0x8f/0xd0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018551]  [<ffffffff811182ce>] sleep_on_page+0xe/0x20

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018554]  [<ffffffff8165b99f>] __wait_on_bit+0x5f/0x90

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018557]  [<ffffffff81118438>] wait_on_page_bit+0x78/0x80

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018563]  [<ffffffff8108bd60>] ? autoremove_wake_function+0x40/0x40

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018566]  [<ffffffff8111854c>] filemap_fdatawait_range+0x10c/0x1a0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018570]  [<ffffffff8111860b>] filemap_fdatawait+0x2b/0x30

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018577]  [<ffffffff81261f50>] journal_finish_inode_data_buffers+0x70/0x170

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018580]  [<ffffffff81262845>] jbd2_journal_commit_transaction+0x665/0x1240

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018586]  [<ffffffff81057cbe>] ? update_shares+0xce/0x100

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018589]  [<ffffffff8108bd20>] ? add_wait_queue+0x60/0x60

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018592]  [<ffffffff812670eb>] kjournald2+0xbb/0x220

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018595]  [<ffffffff8108bd20>] ? add_wait_queue+0x60/0x60

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018597]  [<ffffffff81267030>] ? commit_timeout+0x10/0x10

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018600]  [<ffffffff8108b27c>] kthread+0x8c/0xa0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018604]  [<ffffffff81667734>] kernel_thread_helper+0x4/0x10

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018607]  [<ffffffff8108b1f0>] ? flush_kthread_worker+0xa0/0xa0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018610]  [<ffffffff81667730>] ? gs_change+0x13/0x13

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018612] INFO: task flush-8:32:100286 blocked for more than 120 seconds.

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018614] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018615] flush-8:32      D ffffffff81806240     0 100286      2 0x00000000

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018619]  ffff8810171f5460 0000000000000046 ffff8810171f5420 ffff88200ec70758

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018622]  ffff8810171f5fd8 ffff8810171f5fd8 ffff8810171f5fd8 00000000000137c0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018626]  ffff881018aa8000 ffff881016221700 ffff8810171f5430 ffff88203ee54080

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018630] Call Trace:

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018632]  [<ffffffff8165b0cf>] schedule+0x3f/0x60

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018634]  [<ffffffff8165b17f>] io_schedule+0x8f/0xd0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018640]  [<ffffffff812f4396>] get_request_wait+0xf6/0x1d0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018643]  [<ffffffff8108bd20>] ? add_wait_queue+0x60/0x60

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018646]  [<ffffffff812f529f>] blk_queue_bio+0x7f/0x380

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018650]  [<ffffffff812f2044>] generic_make_request.part.50+0x74/0xb0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018653]  [<ffffffff812f2458>] generic_make_request+0x68/0x70

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018656]  [<ffffffff812f24e5>] submit_bio+0x85/0x110

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018662]  [<ffffffff8121de69>] ext4_io_submit+0x29/0x60

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018665]  [<ffffffff8121e038>] io_submit_add_bh+0x198/0x1d0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018669]  [<ffffffff8121e1ee>] ext4_bio_write_page+0x17e/0x230

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018672]  [<ffffffff81219b49>] mpage_da_submit_io+0x4b9/0x590

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018676]  [<ffffffff8121be2e>] mpage_da_map_and_submit+0x17e/0x360

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018679]  [<ffffffff8121c070>] mpage_add_bh_to_extent+0x60/0xe0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018682]  [<ffffffff8121c3e9>] write_cache_pages_da+0x2f9/0x450

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018685]  [<ffffffff8121c890>] ext4_da_writepages+0x350/0x630

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018689]  [<ffffffff81122c16>] ? generic_writepages+0x56/0x70

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018693]  [<ffffffff81123ad1>] do_writepages+0x21/0x40

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018697]  [<ffffffff811a27b0>] writeback_single_inode+0x180/0x430

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018700]  [<ffffffff811a2e76>] writeback_sb_inodes+0x1b6/0x270

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018703]  [<ffffffff811a2fce>] __writeback_inodes_wb+0x9e/0xd0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018706]  [<ffffffff811a327b>] wb_writeback+0x27b/0x330

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018710]  [<ffffffff811a42e8>] wb_do_writeback+0x198/0x1d0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018713]  [<ffffffff811a43a3>] bdi_writeback_thread+0x83/0x2a0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018715]  [<ffffffff811a4320>] ? wb_do_writeback+0x1d0/0x1d0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018718]  [<ffffffff8108b27c>] kthread+0x8c/0xa0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018721]  [<ffffffff81667734>] kernel_thread_helper+0x4/0x10

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018724]  [<ffffffff8108b1f0>] ? flush_kthread_worker+0xa0/0xa0

Apr  4 10:37:17 DC2-r16-22vms kernel: [71981.018726]  [<ffffffff81667730>] ? gs_change+0x13/0x13

Apr  4 10:37:49 DC2-r16-22vms kernel: [72013.378420] EXT4-fs (sdc1): error count: 4

Apr  4 10:37:49 DC2-r16-22vms kernel: [72013.378423] EXT4-fs (sdc1): initial error at 1365011101: ext4_da_writepages:2317

Apr  4 10:37:49 DC2-r16-22vms kernel: [72013.378426] EXT4-fs (sdc1): last error at 1365011431: ext4_put_super:819

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.960932]  session3: session recovery timed out after 600 secs

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968896]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968902]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968905]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968907]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968910]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968912]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968915]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968918]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968921]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968923]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968926]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968929]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968931]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968934]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968936]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968939]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968942]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968945]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968948]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968950]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968954]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968957]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968960]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968963]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968966]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968969]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968981]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968992] sd 8:0:0:1: [sdc] Unhandled error code

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.968996] sd 8:0:0:1: [sdc]  Result: hostbyte=DID_TRANSPORT_FAILFAST driverbyte=DRIVER_OK

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969005]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969011] sd 8:0:0:1: [sdc] CDB: Write(10): 2a 00 00 1d 38 00 00 04 00 00

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969028] end_request: recoverable transport error, dev sdc, sector 1914880

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969034]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969037]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969040] Buffer I/O error on device sdc1, logical block 239104

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969045]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969047] Buffer I/O error on device sdc1, logical block 239105

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969051] Buffer I/O error on device sdc1, logical block 239106

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969056]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969063]  session3: iscsi_queuecommand iscsi: cmd 0x2a is not queued (983040)

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969067] Buffer I/O error on device sdc1, logical block 239107

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969070] Buffer I/O error on device sdc1, logical block 239108

Apr  4 10:43:42 DC2-r16-22vms kernel: [72365.969074] Buffer I/O error on device sdc1, logical block 239109

Do you see whats weird ? need to be configured ? or is missconfigured ?

[Alejandro Comisario]

And to clarify the below tests, we simulate the disconnection against the target with an "iptables" rule to DROP all connections against the target.

[Mike Christie]

On 04/04/2013 12:59 PM, Alejandro Comisario wrote:
> Mike, i think something is wrong and i dont seem to know what, because
> still, im getting I/O errors reported to the filesystem layer after 120
> seconds, but i dont know if its from the iscsi side or other
> configuration is involved, this is what we negotiated with the target :
>
> root@DC2-r16-22vms:/var/log# iscsiadm -m node -T
> iqn.1992-08.com.netapp:sn.1574861693
> # BEGIN RECORD 2.0-871
>

These values are what we request from the target. iscsiadm -m session -P
2 is what we are currently using.


> node.session.timeo.replacement_timeout = 600

replacement timeout though is not something we negotiate with the
target, so we should be using that value.

>
> We issued a dd against the ext4 LUN mounted, but after 120 seconds we
> see this errors in /var/log/syslog :


>
> Apr 4 10:33:41 DC2-r16-22vms iscsid: Kernel reported iSCSI connection
> 3:0 error (1011) state (3)

Here we see the initial error. When this happens we start the
replacement_timeout/recovery_timeout timer.

> Apr 4 10:37:17 DC2-r16-22vms kernel: [71981.018502] INFO: task
> jbd2/sdc1-8:100283 blocked for more than 120 seconds.
> Apr 4 10:37:17 DC2-r16-22vms kernel: [71981.018505] "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.

This and the trace after it is not a error. It is just a warning. There
is a hung_task_timeout_secs timer as you see below. If a IO does not
complete for that amount of seconds the kernel will send this warning.
If you expect IO to hang for longer periods then you should change that
value like is describes below.

> last error at 1365011431: ext4_put_super:819
> Apr 4 10:43:42 DC2-r16-22vms kernel: [72365.960932] session3: session
> recovery timed out after 600 secs

Here is where we see IO errors. You set the timer to 600 secs and so
about 10 minutes after we see the connection error above we see this.
This is and the messages after is what indicates real IO errors.