"connection1:0 detected conn error (1011)" open-iscsi 2.0-871 w/ CentOS 2.6.18-53
Sean S
2.6.18-53 kernel. Every couple of days I get the error:
connection1:0 detected conn error (1011)
session1: session recovery timed out after 400 sec
I compiled the open-iscsi 2.0-871 user tools and kernel modules from
source obtained from open-iscsi.org. I custom packaged the initrd to
contain the iscsistart binary and the kernel modules from v871. I've
zeroed out the noop timeout setting and the noop interval.
The disconnect is not reproducible, but does occur at random about
every other day. I'm assuming that the target (IET 1.4.19) is not the
issue as a second system that is using the target as an iscsi-root
drive continues to work correctly. What things should I be looking at?
I'm really struggling to understand why this happens, any suggestions
would be greatly appreciated.
Mike Christie
> I'm running an iscsi root partition for a CentOS machine running a
> 2.6.18-53 kernel. Every couple of days I get the error:
>
> connection1:0 detected conn error (1011)
> session1: session recovery timed out after 400 sec
>
Is there anything more to the log? Is there anything from iscsid?
Something about not being able to connect/reconnect to the target?
If you just see that, then it means there was some connection problem.
We do not know exactly what it was, but we disconnected the connection,
then tried to reconnect. We tried to reconnect for 400 seconds but could
not, so at that point we mark the session as bad and start to fail IO
until we can log back in.
It is normally due to a problem in the network if the target is ok.
Sean S
although the only log I'm really able to access post failure is dmesg.
Since I'm running a root iscsi, I couldn't get to /var/log/messages
which maybe was a little more verbose? What sort of network problems
might cause this? The "network" in this situation is a simple gigE
switch with about 3 or 4 systems on it. The target and initiator are
on the same subnet, nothing fancy. Is there some additional debug
you'd recommend turning on? Any tips or tricks when running with a
root iscsi drive?
Curiously, if I physically disconnect the ethernet from the initiator
while running, all I/O access is correctly paused without returning I/
O errors. If I then reconnect before the 400s is up things go back to
normal. I don't however see the "detected conn error (1011)" message
in this situation however. Not sure if that really means anything.
Thanks for the help
Mike Christie
info. When we get the conn error, it will print out a message if it is
due to the target dropping the connection and it will print out stack
trace so we can see exactly what piece of code is throwing the error.
On 07/13/2010 09:33 PM, Sean S wrote:
> Nothing else in the log from iscsid. No mention of a failed reconnect,
> although the only log I'm really able to access post failure is dmesg.
> Since I'm running a root iscsi, I couldn't get to /var/log/messages
> which maybe was a little more verbose? What sort of network problems
Yeah, by default the iscsid messages go there. iscsid should be spitting
out a cannot connect $some_error_value_or_string that would help tell us
why we cannot reach the target anymore.
> might cause this? The "network" in this situation is a simple gigE
> switch with about 3 or 4 systems on it. The target and initiator are
> on the same subnet, nothing fancy. Is there some additional debug
> you'd recommend turning on? Any tips or tricks when running with a
> root iscsi drive?
Not that I can think of at the iscsi layer.
>
> Curiously, if I physically disconnect the ethernet from the initiator
> while running, all I/O access is correctly paused without returning I/
> O errors. If I then reconnect before the 400s is up things go back to
> normal. I don't however see the "detected conn error (1011)" message
> in this situation however. Not sure if that really means anything.
You should see the conn error 1011 message if
1. you have nops on and they timeout and that causes us to log that error.
2. the network layer figures out there is a problem and notifies us. It
is possible that you pull a cable and plug it back in before the network
throws an error.
3. iscsi driver or protocol error. In this case we should relogin quickly.
Ulrich Windl
<1f2389e7-9717-4f82...@x21g2000yqa.googlegroups.com>:
> I'm running an iscsi root partition for a CentOS machine running a
> 2.6.18-53 kernel. Every couple of days I get the error:
>
> connection1:0 detected conn error (1011)
> session1: session recovery timed out after 400 sec
Hi!
I cannot answer your question, but that brings up something I wanted to talk about. Please apologize if something already exists, but I don't know:
In HP-UX 11.31 you can print "scan times" per device (i.e. LUN). Here's an example for a true FC-SAN:
Class I H/W Path ms_scan_time
===============================
lunpath 3 0/3/1/0.0x50001fe1500c1f28.0x0 0 min 0 sec 13 ms
lunpath 24 0/3/1/0.0x50001fe1500c1f28.0x4001000000000000 0 min 0 sec 88 ms
lunpath 73 0/3/1/0.0x50001fe1500c1f28.0x4002000000000000 0 min 0 sec 88 ms
lunpath 25 0/3/1/0.0x50001fe1500c1f28.0x4003000000000000 0 min 0 sec 88 ms
lunpath 74 0/3/1/0.0x50001fe1500c1f28.0x4009000000000000 0 min 0 sec 88 ms
lunpath 26 0/3/1/0.0x50001fe1500c1f28.0x4033000000000000 0 min 0 sec 88 ms
lunpath 88 0/3/1/0.0x50001fe1500c1f28.0x4037000000000000 0 min 0 sec 88 ms
lunpath 79 0/3/1/0.0x50001fe1500c1f28.0x403d000000000000 0 min 0 sec 91 ms
lunpath 27 0/3/1/0.0x50001fe1500c1f28.0x4047000000000000 0 min 0 sec 91 ms
[...]
lunpath 63 0/7/1/0.0x500308c001d83803.0x4001000000000000 0 min 0 sec 11 ms
lunpath 64 0/7/1/0.0x500308c001d83803.0x4002000000000000 0 min 0 sec 11 ms
lunpath 65 0/7/1/0.0x500308c001d83803.0x4003000000000000 0 min 0 sec 11 ms
lunpath 66 0/7/1/0.0x500308c001d83803.0x4004000000000000 0 min 0 sec 536 ms
If Linux/open-iscsi had something similar, one could periodically watch the times to find bottlenecks. AFAIK, the "scan time" in HP-UX is the round-trip delay for querying a LUN or a controller (a target?).
Ulrich
Ulrich Windl
<83cd8c40-2e84-4c52...@d8g2000yqf.googlegroups.com>:
> Nothing else in the log from iscsid. No mention of a failed reconnect,
> although the only log I'm really able to access post failure is dmesg.
> Since I'm running a root iscsi, I couldn't get to /var/log/messages
> which maybe was a little more verbose? What sort of network problems
> might cause this? The "network" in this situation is a simple gigE
Remember that syslogd can also write the log to a terminal or serial line. For SUSE Linux it's on tty10 (Ctrl+Alt+F10), but not very verbose. You could try to set it up similar with more verbosity.
[...]
Ulrich
Mike Christie
Did you want to find bottlenecks in the network or between the initiator
and actual device or initiator and target?
Erez, was adding some code where it exports the iscsi nop/ping times.
The nop/ping we send has a header of 48 bytes and no data payload. It
does not have do any disk/device IO. So this is nice for testing the
network.
Sean S
running with the patch. Any thoughts?
[<f8bf0876>] iscsi_conn_failure+0x10/0x69 [libiscsi]
[<f9bf202d>] iscsi_eh_abort+0x2f1/0x406 [libiscsi]
[<f885d378>] __scsi_try_to_abort_cmd+0x19/0x1a [scsi_mod]
[<f885e85d>] scsi_error_handler+0x24d/0x422 [scsi_mod]
[<c041f7ea>] complete+0x2b/0x3d
[<f885e610>] scsi_error_handler+0x0/0x422 [scsi_mod]
[<c0435f65>] kthread+0xc0/0xeb
[<c0435ea5>] kthread+0x0/0xeb
[<c0405c3b>] kernel_thread_helper+0x7/0x10
=======================
connection1:0 detected conn error (1011)
[<f8bf22fc>] iscsi_eh_target_reset+0xbb/0x218 [libiscsi]
[<c0605967>] _spin_lock_bh+0x8/0x18
[<f8bf0f78>] iscsi_eh_device_reset+0x1c5/0x1cf [libiscsi]
[<c054a6dd>] get_device+0xe/0x14
[<f885d764>] scsi_try_host_reset+0x3a/0x99 [scsi_mod]
[<f885e0e3>] scsi_eh_ready_devs+0x302/0x3e2 [scsi_mod]
[<f885e8dd>] scsi_error_handler+0x2cd/0x422 [scsi_mod]
[<c041f7ea>] complete+0x2b/0x3d
[<f885e610>] scsi_error_handler+0x0/0x422 [scsi_mod]
[<c0435f65>] kthread+0xc0/0xeb
[<c0435ea5>] kthread+0x0/0xeb
[<c0405c3b>] kernel_thread_helper+0x7/0x10
=======================
session1: session recovery timed out after 400 secs
sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
sd 0:0:0:0: SCSI error: return code = 0x00020000
end_request: I/O error, dev sda, sector 14283149
> 1KViewDownload
Mike Christie
> Thanks for the patch Mike. Below is the output from a failure when
> running with the patch. Any thoughts?
>
> [<f8bf0876>] iscsi_conn_failure+0x10/0x69 [libiscsi]
>
> [<f9bf202d>] iscsi_eh_abort+0x2f1/0x406 [libiscsi]
>
> [<f885d378>] __scsi_try_to_abort_cmd+0x19/0x1a [scsi_mod]
>
> [<f885e85d>] scsi_error_handler+0x24d/0x422 [scsi_mod]
>
> [<c041f7ea>] complete+0x2b/0x3d
>
> [<f885e610>] scsi_error_handler+0x0/0x422 [scsi_mod]
>
> [<c0435f65>] kthread+0xc0/0xeb
>
> [<c0435ea5>] kthread+0x0/0xeb
>
> [<c0405c3b>] kernel_thread_helper+0x7/0x10
>
Each scsi command has a timeout (see /sys/block/sdX/device/timeout). The
above dump shows that a scsi command is timing out. This causes the scsi
layer to have the driver, iscsi_tcp in this case, to try and abort the
command. It looks like the abort timed out too, and so the iscsi layer
decided to escalate the eh and failed the iscsi session/connection.
>
> session1: session recovery timed out after 400 secs
The iscsi layer tried to log back in for recovery/replacement timeout
seconds, but could not.
Did you see anything from iscsid about why it could not log in? iscsid
writes to /var/log/messages by default.
>
> sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
>
Because the replacement/recovery timeout fired, the iscsi layer decided
it was time to give up and tells the scsi layer the disks are not
recoverable, and so we these messages:
> sd 0:0:0:0: scsi: Device offlined - no ready after error recovery
>
Does the session/connection ever re-login (you would see some message in
/var/log/messages about connection X:Y is operational after recovery (Z
attempts)?
On the target box check out /var/log/messages. Is the target even up
still? Did it segfault?
Sean S
> writes to /var/log/messages by default.
> /var/log/messages about connection X:Y is operational after recovery (Z
> attempts)?
as iscsi root. Ulrich mentioned writing the log to a serial port, but
I haven't been able to set this up yet. Would there be an easier way
to get this info post failure?
> On the target box check out /var/log/messages. Is the target even up
> still? Did it segfault?
daemon (iSCSI Enterprise Target) is serving targets to two diskless
machines. One is the CentOS version that is the topic of this email.
The second is a Windows 2003 Server. Both the Win2003 server and
CentOS always run at the same time. The Win2003 server has never
encountered I/O issues with iSCSI, and continues to run after the
CentOS machine hits this problem.
Ulrich Windl
> Nachricht
<109cc690-901c-4e53...@l14g2000yql.googlegroups.
> com>:
[...]
> I'm unable to view /var/log/messages after the failure due to running
> as iscsi root. Ulrich mentioned writing the log to a serial port, but
> I haven't been able to set this up yet. Would there be an easier way
When using GRUB, use something like
[...]
#serial --unit=0 --speed=19200
terminal serial console
[...]
and add options "vga=normal console=tty0 console=ttyS0,19200" to the kernel command line, just like:
###Don't change this comment - YaST2 identifier: Original name: linux###
title SUSE Linux Enterprise Server 10 - 2.6.16.60-0.54.5 (smp)
root (hd0,0)
kernel /vmlinuz-2.6.16.60-0.54.5-smp root=/dev/system/root vga=normal console=tty0 console=ttyS0,19200 splash=silent showopts
initrd /initrd-2.6.16.60-0.54.5-smp
Ulrich
Mike Christie
>> Did you see anything from iscsid about why it could not log in? iscsid
>> writes to /var/log/messages by default.
>
>> Does the session/connection ever re-login (you would see some message in
>> /var/log/messages about connection X:Y is operational after recovery (Z
>> attempts)?
>
> I'm unable to view /var/log/messages after the failure due to running
> as iscsi root. Ulrich mentioned writing the log to a serial port, but
> I haven't been able to set this up yet. Would there be an easier way
> to get this info post failure?
I forgot you are doing root on iscsi.
How did you get those other kernel messages? If you can just get the
iscsid log info that is sent after lines like this
[<f8bf0876>] iscsi_conn_failure+0x10/0x69 [libiscsi]
[<f9bf202d>] iscsi_eh_abort+0x2f1/0x406 [libiscsi]
but before this line
session1: session recovery timed out after 400 secs
it would be helpful. I am just looking for something about iscsid
segfaulting or hanging or not being able to connect.
What version of open-iscsi-871 are you using is it 871.1 or .2 .3?
>
>
>> On the target box check out /var/log/messages. Is the target even up
>> still? Did it segfault?
>
> I don't believe anything is going wrong on the target. The target
Do you see anything in /var/log/messages for the target though?
Something about aborts or lun resets completing?
Sean S
> iscsid log info that is sent after lines like this
still retrieve some logging info. Unfortunately, what I sent was all
that I can get. If the drive ever successfully reconnects then I can
get to /var/log/messages and see the info you are looking for. I've
only ever had a successful reconnect when intentionally causing a
disconnect (i.e. pulling the ethernet cable and then reconnecting
it).
I don't know much about unix logging, but maybe there is a way to send
more of the logging messages to "dmesg" as that doesn't appear to need
disk access to be read.
> What version of open-iscsi-871 are you using is it 871.1 or .2 .3?
http://www.open-iscsi.org/bits/open-iscsi-2.0-871.tar.gz
It doesn't appear to have a minor version number. Should I be using
something else?
> Do you see anything in /var/log/messages for the target though?
> Something about aborts or lun resets completing?
past I've seen no messages from the target in /var/log/messages after
failures.
Ulrich Windl
> Nachricht
<f711789b-c411-4459...@w12g2000yqj.googlegroups.
> com>:
How did you get those other kernel messages? If you can just get the
> > iscsid log info that is sent after lines like this
>
> I'm able to issue the "dmesg" command after the drive is lost and
> still retrieve some logging info. Unfortunately, what I sent was all
> that I can get. If the drive ever successfully reconnects then I can
> get to /var/log/messages and see the info you are looking for. I've
> only ever had a successful reconnect when intentionally causing a
> disconnect (i.e. pulling the ethernet cable and then reconnecting
> it).
>
> I don't know much about unix logging, but maybe there is a way to send
> more of the logging messages to "dmesg" as that doesn't appear to need
> disk access to be read.
dmesg just print the kernel message buffer (/proc/kmsg), while syslog can capture messages from applications as well.
I have a sample for a syslog-ng configuration file:
destination d_tty_root { usertty("root"); };
destination d_console { file("/dev/ttyS0"); };
destination d_messages { file("/var/log/messages"); };
filter f_error {
level(alert .. err) and not match('S15.modem: initchat failed.');
};
filter f_kernel { level(alert .. err); };
filter f_auth { facility(auth, authpriv) and level(alert .. info); };
filter f_debug { level(alert .. debug); };
# send criticals messages to logged root user and /var/log/messages
log {
source(s_intern);
source(s_dev_log);
source(s_kernel);
filter(f_error);
destination(d_tty_root);
destination(d_messages);
};
# save auth-related messages
log {
source(s_dev_log);
source(s_kernel);
filter(f_auth);
destination(d_messages);
};
### Just to get you started. The older syslog is less powerful, but easier to configure.
Maybe this is interesting for you:
# 6) To send message to remote syslogd server :
# destination d_udp { udp("<remote IP address>" port(514)); };
# Example to send syslogs to syslogd located at 10.0.0.1 :
# destination d_udp1 { udp("10.0.0.1" port(514)); };
Maybe this helps a bit.
Regards,
Ulrich
Ulrich Windl
> um
16:46 in Nachricht <4C505EF50200...@gwsmtp1.uni-regensburg.de>
> :
>>> Sean S <sstr...@gmail.com> schrieb am 28.07.2010 um 16:34 in
> > Nachricht
> <f711789b-c411-4459...@w12g2000yqj.googlegroups.
> > com>:
> How did you get those other kernel messages? If you can just get the
> > > iscsid log info that is sent after lines like this
> >
> > I'm able to issue the "dmesg" command after the drive is lost and
> > still retrieve some logging info. Unfortunately, what I sent was all
> > that I can get. If the drive ever successfully reconnects then I can
> > get to /var/log/messages and see the info you are looking for. I've
> > only ever had a successful reconnect when intentionally causing a
> > disconnect (i.e. pulling the ethernet cable and then reconnecting
> > it).
> >
> > I don't know much about unix logging, but maybe there is a way to send
> > more of the logging messages to "dmesg" as that doesn't appear to need
> > disk access to be read.
>
> dmesg just print the kernel message buffer (/proc/kmsg), while syslog can
> capture messages from applications as well.
>
> I have a sample for a syslog-ng configuration file:
Samples for "sources" are missing, sorry:
source s_intern { internal(); };
source s_dev_log { unix-stream("/dev/log"); };
source s_kernel { file("/proc/kmsg"); };
Mike Christie
>
>> What version of open-iscsi-871 are you using is it 871.1 or .2 .3?
> I downloaded the "current semi-stable release":
> http://www.open-iscsi.org/bits/open-iscsi-2.0-871.tar.gz
> It doesn't appear to have a minor version number. Should I be using
> something else?
Yeah, try:
http://kernel.org/pub/linux/kernel/people/mnc/open-iscsi/releases/open-iscsi-2.0-871.3.tar.gz
It has a fix for recovery. There was a problem where recovery hung for
several minutes.
david elsen
thanks,
david
> Date: Wed, 28 Jul 2010 12:28:22 -0500
> From: mich...@cs.wisc.edu
> To: open-...@googlegroups.com
> CC: sstr...@gmail.com
> Subject: Re: "connection1:0 detected conn error (1011)" open-iscsi 2.0-871 w/ CentOS 2.6.18-53
> You received this message because you are subscribed to the Google Groups "open-iscsi" group.
> To post to this group, send email to open-...@googlegroups.com.
> To unsubscribe from this group, send email to open-iscsi+...@googlegroups.com.
> For more options, visit this group at http://groups.google.com/group/open-iscsi?hl=en.
>
Mike Christie
>
> How can I uninstall the iscsi-initiator from my system? I am trying to debug some issue and it looks like there is some conflict there.
If you are using the open-iscsi.org tarballs then it is a fun manual
process. You would basically have to read the Makefile and delete all
the programs it installed.
Do makefiles normally have a uinstall option? If so I can add one, or I
can add another script.
Kun Huang
would usually be removing all binaries introduced in
make install
Regards,
- Kun
Ulrich Windl
<AANLkTikX-+cTyxm9v7odjEV21sXjiJsMLUJnh=uaB...@mail.gmail.com>:
> make clean
>
> would usually be removing all binaries introduced in
>
> make install
No: "make clean" would remove the compiled or otherwise generated objects to leave only valuable sources around. As "mak install" copies generated objects to elewhere usually, "make clean" won't undo that (in the general case).
Ulrich
Mike Christie
>>>> Kun Huang<kunhua...@gmail.com> schrieb am 03.08.2010 um 04:03 in Nachricht
> <AANLkTikX-+cTyxm9v7odjEV21sXjiJsMLUJnh=uaB...@mail.gmail.com>:
>> make clean
>>
>> would usually be removing all binaries introduced in
>>
>> make install
>
> No: "make clean" would remove the compiled or otherwise generated objects to leave only valuable sources around. As "mak install" copies generated objects to elewhere usually, "make clean" won't undo that (in the general case).
>
How about "make uninstall" then?