Recenly I have enabled debugging in iscsid using '-d 8' option in the
init script. Since enabling this, I have been hitting iscsiadm command
hangs every once in a while. When this happens, an iscsiadm command
hangs (the hang usually happens with login and '-m session -P 3'
commands) and this causes all subsequent iscsiadm commands hang. I
have looked at syslog to see where iscsid stops responding but it is
defferent every time. One time, the following were the last syslog
entries from iscsid:

Oct  2 23:51:50 ian_ser_2 iscsid: send PDU began for hdr 48 bytes and
data 472 bytes
Oct  2 23:51:50 ian_ser_2 iscsid: in kwritev
Oct  2 23:51:50 ian_ser_2 iscsid: wrote 48 bytes of PDU header
Oct  2 23:51:50 ian_ser_2 iscsid: in kwritev
Oct  2 23:51:50 ian_ser_2 iscsid: wrote 472 bytes of PDU data
Oct  2 23:51:50 ian_ser_2 iscsid: in ksend_pdu_end
Oct  2 23:51:50 ian_ser_2 iscsid: in __kipc_call
Oct  2 23:51:50 ian_ser_2 iscsid: in kwritev
Oct  2 23:51:50 ian_ser_2 iscsid: in nlpayload_read
Oct  2 23:51:50 ian_ser_2 iscsid: in nlpayload_read
Oct  2 23:51:50 ian_ser_2 iscsid: send PDU finished for conn 696:0
Oct  2 23:51:50 ian_ser_2 iscsid: thread removed
Oct  2 23:51:50 ian_ser_2 iscsid: poll result 1
Oct  2 23:51:50 ian_ser_2 iscsid: in ctldev_handle
Oct  2 23:51:50 ian_ser_2 iscsid: in nl_read
Oct  2 23:51:50 ian_ser_2 iscsid: ctldev_handle got event type 101
Oct  2 23:51:50 ian_ser_2 iscsid: get conn context 0x80d1698
Oct  2 23:51:50 ian_ser_2 iscsid: message real length is 420 bytes,
recv_handle 0x80d1f98
Oct  2 23:51:50 ian_ser_2 iscsid: in nlpayload_read
Oct  2 23:51:50 ian_ser_2 iscsid: sched conn context 0x80d1698 event
1, tmo 0
Oct  2 23:51:50 ian_ser_2 iscsid: thread 0x80d1698 schedule: delay 0
state 3
Oct  2 23:51:50 ian_ser_2 iscsid: exec thread 080d1698 callback
Oct  2 23:51:50 ian_ser_2 iscsid: in krecv_pdu_begin
Oct  2 23:51:50 ian_ser_2 iscsid: recv PDU began, pdu handle
0x0x80d1fd0
Oct  2 23:51:50 ian_ser_2 iscsid: in kread
Oct  2 23:51:50 ian_ser_2 iscsid: read 48 bytes of PDU header
Oct  2 23:51:50 ian_ser_2 iscsid: read 48 PDU header bytes, opcode
0x23, dlength 300, data 0x80cd20c, max 8192
Oct  2 23:51:50 ian_ser_2 iscsid: in kread
Oct  2 23:51:50 ian_ser_2 iscsid: read 300 bytes of PDU data
Oct  2 23:51:50 ian_ser_2 iscsid: finished reading login PDU, 48 hdr,
0 ah, 300 data, 0 pad
Oct  2 23:51:50 ian_ser_2 iscsid: login current stage 1, next stage 3,
transit 0x80
Oct  2 23:51:50 ian_ser_2 iscsid: >    TargetPortalGroupTag=1
Oct  2 23:51:50 ian_ser_2 iscsid: >    HeaderDigest=None

And these were the last entries another time

Oct  5 09:43:14 kevin_ser3 iscsid: in kwritev
Oct  5 09:43:14 kevin_ser3 iscsid: in nlpayload_read
Oct  5 09:43:14 kevin_ser3 iscsid: in nlpayload_read
Oct  5 09:43:14 kevin_ser3 iscsid: set operational parameter 1 to:
Oct  5 09:43:14 kevin_ser3 iscsid: iqn.1993-08.org.debian:
01:f0de76895ed6
Oct  5 09:43:14 kevin_ser3 iscsid: in kset_host_param
Oct  5 09:43:14 kevin_ser3 iscsid: in __kipc_call
Oct  5 09:43:14 kevin_ser3 iscsid: in kwritev
Oct  5 09:43:14 kevin_ser3 iscsid: in nlpayload_read
Oct  5 09:43:14 kevin_ser3 iscsid: in nlpayload_read
Oct  5 09:43:14 kevin_ser3 iscsid: set operational parameter 2 to:
Oct  5 09:43:14 kevin_ser3 iscsid: default
Oct  5 09:43:14 kevin_ser3 iscsid: in kset_host_param
Oct  5 09:43:14 kevin_ser3 iscsid: in __kipc_call
Oct  5 09:43:14 kevin_ser3 iscsid: in kwritev
Oct  5 09:43:14 kevin_ser3 iscsid: in nlpayload_read
Oct  5 09:43:14 kevin_ser3 iscsid: in nlpayload_read
Oct  5 09:43:14 kevin_ser3 iscsid: set operational parameter 0 to:
Oct  5 09:43:14 kevin_ser3 iscsid: default
Oct  5 09:43:14 kevin_ser3 iscsid: in kstart_conn
Oct  5 09:43:14 kevin_ser3 iscsid: in __kipc_call
Oct  5 09:43:14 kevin_ser3 iscsid: in kwritev
Oct  5 09:43:14 kevin_ser3 iscsid: in nlpayload_read
Oct  5 09:43:14 kevin_ser3 iscsid: in nlpayload_read
Oct  5 09:43:14 kevin_ser3 iscsid: scanning host201
Oct  5 09:43:14 kevin_ser3 iscsid: scanning host201 from pid 29240
Oct  5 09:43:14 kevin_ser3 iscsid: connection199:0 is operational now

However, I attached gdb to the iscsid process each time the hang
happened and everytime the trace was like this:

(gdb) where
#0  0xb7f2d410 in __kernel_vsyscall ()
#1  0xb7eaf9bb in semop () from /lib/tls/i686/cmov/libc.so.6
#2  0x08052358 in dolog (prio=-1208836060, fmt=0x0,
    ap=0x1 <Address 0x1 out of bounds>) at log.c:265
#3  0x08052466 in log_debug (level=4, fmt=0x806f49c "%s: rsp to fd
%d")
    at log.c:306
#4  0x0806648c in mgmt_ipc_write_rsp (qtask=0x8110830,
err=MGMT_IPC_OK)
    at mgmt_ipc.c:450
#5  0x08066b6f in mgmt_ipc_session_info (qtask=0x8110830) at
mgmt_ipc.c:166
#6  0x0806685a in event_loop (ipc=0x8072760, control_fd=6,
mgmt_ipc_fd=4,
    isns_fd=-1) at mgmt_ipc.c:570
#7  0x080686dd in main (argc=3, argv=0xbfaf48f4) at iscsid.c:503

It looks like iscsid hung while trying to acquire a lock using semop()
as part of dolog() and the semop() never returned. Once this happens,
if we issue more iscsiadm commands, they also hang and debugging with
gdb shows that iscsid does not process these iscsiadm requests anymore
(or maybe iscsid does not look for a request anymore). To come out of
the situation, I killed the two iscsid processes, did a '/etc/init.d/
open-iscsi start' and a '/etc/init.d/open-iscsi restart'.

It thus looks like, enabling debug logging with '-d 8' puts enormous
pressure on the log daemon and at some point it becomes irresponsive
(the log daemon probably releases the semaphore, so it is crucial for
the iscsid that the log daemon is running), casuing iscsid to hang
while trying to log as part of processing a iscsiadm command. Or,
there could be some other problem that is causing it. Any suggestions/
comments would be appreciated.

My System Configuration:
iscsiadm version: 2.0-870.3
operation system: Ubuntu 8.04.3
Kernel: 2.6.24-24-generic

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups 
"open-iscsi" group.
To post to this group, send email to open-iscsi@googlegroups.com
To unsubscribe from this group, send email to 
open-iscsi+unsubscr...@googlegroups.com
For more options, visit this group at http://groups.google.com/group/open-iscsi
-~----------~----~----~----~------~----~------~--~---

Reply via email to