| [Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] |
On Mon, 2006-03-27 at 07:33 -0800, Rik Herrin wrote: > (This is the exact same email I sent 10 minutes ago. > I just forgot to add the tcpdump output.) > > "The problem with the above 2 is that Core-ISCSI is > trying to send 32k PDUs while IET only accepts 8K > PDUs." i forgot since iet which version, we correctly handle this. so i want to see u tcpdump trace for detail. if u adjust the ini parameter, it is ok well. but a tcpdump log before u adjusting this parameter will be useful. i need a log captured with "tcpdump -s1600 -w log" and send us the log, or bziped if it is large. ming > > So I replaced it with the following: > > CHANNEL="0 1 lo 127.0.0.1 3260 0 > AuthMethod=None;MaxRecvDataSegmentLength=8192 > nopout_timeout=5" > > which should send 8K PDUs instead. In either case, I > added a tcpdump of the login process at the end of my > email. I then ran the same dd as before which should > write 500 MB of sequential data onto the iSCSI target. > It's talking a very long time to dd 500M onto the > iSCSI target disc and looking at top, it gives me the > following: > > istd1 taking 99.9% CPU with them split up as 50.1% sy > and 49.9% wait > > Looking into /var/log/messages, I see messages such > as: > > Mar 27 17:25:21 localhost kernel: iCHANNEL[0] - No > defined iSCSI Authentication Methods, skipping > SecurityNegotiation phase. Mar 27 17:25:46 localhost > kernel: iscsi_login_rx_data:54: ***ERROR*** rx_data > returned -512, expecting 48. Mar 27 > 17:25:46 localhost kernel: > iscsi_initiator_start_negotiation:754: ***ERROR*** > iSCSI Login negotiation failed. Mar 27 > 17:25:46 localhost kernel: > iscsi_handle_authetication:108: ***ERROR*** > sock_recvmsg() returned 0 Mar 27 > 17:25:48 localhost kernel: iCHANNEL[0] - No defined > iSCSI Authentication Methods, skipping > SecurityNegotiation phase. > Mar 27 17:26:13 localhost kernel: > iscsi_login_rx_data:54: ***ERROR*** rx_data returned > -512, expecting 48. > Mar 27 17:26:13 localhost kernel: > iscsi_initiator_start_negotiation:754: ***ERROR*** > iSCSI Login negotiation failed. > Mar 27 17:26:13 localhost kernel: > iscsi_handle_authetication:108: ***ERROR*** > sock_recvmsg() returned 0 > Mar 27 17:26:15 localhost kernel: iCHANNEL[0] - No > defined iSCSI Authentication Methods, skipping > SecurityNegotiation phase. > ............. > > Could it be, as you mentioned in a previous mail, that > since IET doesn't get back to the initiator and tell > it that it's successfully written the data, the > core-iscsi initiator believes that the connection is > lost and tries to start a new session and fails > because there's already the old session and IET > doesn't support MCS? I'm off to try open-iscsi. > Thanks for your help. > > Rik Herrin > > TCP Dump of Login: > > 17:59:49.597309 IP localhost.localdomain.32771 > > localhost.localdomain.3260: S 1001746800:1001746800(0) > win 32767 <mss 16396,sackOK,timestamp 179287 > 0,nop,wscale 5> > 17:59:49.597760 IP localhost.localdomain.3260 > > localhost.localdomain.32771: S 990883816:990883816(0) > ack 1001746801 win 32767 <mss 16396,sackOK,timestamp > 179287 179287,nop,wscale 5> > 17:59:49.597789 IP localhost.localdomain.32771 > > localhost.localdomain.3260: . ack 1 win 1024 > <nop,nop,timestamp 179287 179287> > 17:59:49.597804 IP localhost.localdomain.32771 > > localhost.localdomain.3260: P 1:233(232) ack 1 win > 1024 <nop,nop,timestamp 179287 179287> > 17:59:49.597819 IP localhost.localdomain.3260 > > localhost.localdomain.32771: . ack 233 win 1058 > <nop,nop,timestamp 179287 179287> > 17:59:49.597352 IP localhost.localdomain.3260 > > localhost.localdomain.32771: P 1:109(108) ack 233 win > 1058 <nop,nop,timestamp 179287 179287> > 17:59:49.597498 IP localhost.localdomain.32771 > > localhost.localdomain.3260: . ack 109 win 1024 > <nop,nop,timestamp 179287 179287> > 17:59:49.597814 IP localhost.localdomain.32771 > > localhost.localdomain.3260: P 233:297(64) ack 109 win > 1024 <nop,nop,timestamp 179287 179287> > 17:59:49.597957 IP localhost.localdomain.3260 > > localhost.localdomain.32771: P 109:249(140) ack 297 > win 1058 <nop,nop,timestamp 179288 179287> > 17:59:49.598540 IP localhost.localdomain.32771 > > localhost.localdomain.3260: P 297:345(48) ack 249 win > 1024 <nop,nop,timestamp 179288 179288> > 17:59:49.598590 IP localhost.localdomain.3260 > > localhost.localdomain.32771: P 249:297(48) ack 345 win > 1058 <nop,nop,timestamp 179288 179288> > 17:59:49.598679 IP localhost.localdomain.32771 > > localhost.localdomain.3260: F 345:345(0) ack 297 win > 1024 <nop,nop,timestamp 179288 179288> > 17:59:49.598715 IP localhost.localdomain.32772 > > localhost.localdomain.3260: S 991579803:991579803(0) > win 32767 <mss 16396,sackOK,timestamp 179288 > 0,nop,wscale 5> > 17:59:49.598730 IP localhost.localdomain.3260 > > localhost.localdomain.32772: S > 1003662361:1003662361(0) ack 991579804 win 32767 <mss > 16396,sackOK,timestamp 179288 179288,nop,wscale 5> > 17:59:49.598746 IP localhost.localdomain.32772 > > localhost.localdomain.3260: . ack 1 win 1024 > <nop,nop,timestamp 179288 179288> > 17:59:49.598825 IP localhost.localdomain.32772 > > localhost.localdomain.3260: P 1:533(532) ack 1 win > 1024 <nop,nop,timestamp 179288 179288> > 17:59:49.598846 IP localhost.localdomain.3260 > > localhost.localdomain.32772: . ack 533 win 1058 > <nop,nop,timestamp 179288 179288> > 17:59:49.598893 IP localhost.localdomain.3260 > > localhost.localdomain.32771: F 297:297(0) ack 346 win > 1058 <nop,nop,timestamp 179289 179288> > 17:59:49.598902 IP localhost.localdomain.32771 > > localhost.localdomain.3260: . ack 298 win 1024 > <nop,nop,timestamp 179289 179289> > 17:59:49.599141 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 1:353(352) ack 533 win > 1058 <nop,nop,timestamp 179289 179288> > 17:59:49.599160 IP localhost.localdomain.32772 > > localhost.localdomain.3260: . ack 353 win 1058 > <nop,nop,timestamp 179289 179289> > 17:59:49.599520 IP localhost.localdomain.32772 > > localhost.localdomain.3260: P 533:581(48) ack 353 win > 1058 <nop,nop,timestamp 179289 179289> > 17:59:49.599592 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 353:401(48) ack 581 win > 1058 <nop,nop,timestamp 179289 179289> > 17:59:49.599604 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 401:437(36) ack 581 win > 1058 <nop,nop,timestamp 179289 179289> > 17:59:49.599707 IP localhost.localdomain.32772 > > localhost.localdomain.3260: P 581:629(48) ack 437 win > 1058 <nop,nop,timestamp 179289 179289> > 17:59:49.599750 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 437:485(48) ack 629 win > 1058 <nop,nop,timestamp 179289 179289> > 17:59:49.599759 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 485:549(64) ack 629 win > 1058 <nop,nop,timestamp 179289 179289> > 17:59:49.603000 IP localhost.localdomain.32772 > > localhost.localdomain.3260: P 629:677(48) ack 549 win > 1058 <nop,nop,timestamp 179293 179289> > 17:59:49.603069 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 549:597(48) ack 677 win > 1058 <nop,nop,timestamp 179293 179293> > 17:59:49.603240 IP localhost.localdomain.32772 > > localhost.localdomain.3260: P 677:725(48) ack 597 win > 1058 <nop,nop,timestamp 179293 179293> > 17:59:49.603298 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 597:645(48) ack 725 win > 1058 <nop,nop,timestamp 179293 179293> > 17:59:49.603313 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 645:653(8) ack 725 win > 1058 <nop,nop,timestamp 179293 179293> > 17:59:49.603447 IP localhost.localdomain.32772 > > localhost.localdomain.3260: P 725:773(48) ack 653 win > 1058 <nop,nop,timestamp 179293 179293> > 17:59:49.603511 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 653:701(48) ack 773 win > 1058 <nop,nop,timestamp 179293 179293> > 17:59:49.603525 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 701:705(4) ack 773 win > 1058 <nop,nop,timestamp 179293 179293> > 17:59:49.610514 IP localhost.localdomain.32772 > > localhost.localdomain.3260: P 773:821(48) ack 705 win > 1058 <nop,nop,timestamp 179300 179293> > 17:59:49.610723 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 705:753(48) ack 821 win > 1058 <nop,nop,timestamp 179300 179300> > 17:59:49.610744 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 753:785(32) ack 821 win > 1058 <nop,nop,timestamp 179300 179300> > 17:59:49.611513 IP localhost.localdomain.32772 > > localhost.localdomain.3260: P 821:869(48) ack 785 win > 1058 <nop,nop,timestamp 179301 179300> > 17:59:49.611615 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 785:833(48) ack 869 win > 1058 <nop,nop,timestamp 179301 179301> > 17:59:49.611635 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 833:4929(4096) ack 869 > win 1058 <nop,nop,timestamp 179301 179301> > 17:59:49.611660 IP localhost.localdomain.32772 > > localhost.localdomain.3260: . ack 4929 win 2082 > <nop,nop,timestamp 179301 179301> > 17:59:49.636795 IP localhost.localdomain.32772 > > localhost.localdomain.3260: P 869:917(48) ack 4929 win > 2082 <nop,nop,timestamp 179326 179301> > 17:59:49.636902 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 4929:4977(48) ack 917 > win 1058 <nop,nop,timestamp 179327 179326> > 17:59:49.636916 IP localhost.localdomain.3260 > > localhost.localdomain.32772: P 4977:4993(16) ack 917 > win 1058 <nop,nop,timestamp 179327 179326> > 17:59:49.677493 IP localhost.localdomain.32772 > > localhost.localdomain.3260: . ack 4993 win 2082 > <nop,nop,timestamp 179367 179327> > > --- Ming Zhang <mingz@xxxxxxxxxxx> wrote: > > > On Sun, 2006-03-26 at 11:47 -0800, Rik Herrin wrote: > > > > > My /etc/sysconfig/initiator looks like this. > > > > > > CHANNEL="0 1 lo 127.0.0.1 3260 0" > > > > > > It would give me a lot of messages such as: > > > > > > check_segment_length(1552) too lond data 15a 32768 > > > 8192 > > > check_segment_length(1552) too lond data 15b 32768 > > > 8192 > > > > looks like iet try to only accept pdu with 8K while > > ini send out 32K. > > could u send us a tcpdump capture of the login > > process? > > > > we solve this first. > > > > > iscsi_session_push_cmnd(1531) too large cmd_sn > > (56,1) > > > ... [and so forth] > > > > > > before finally completing: > > > > > > real 1m31.320s > > > user 0m0.001s > > > sys 0m0.139s > > > > > > Sometimes it finishes while at other times, it > > gives > > > the errors above and then goes into a loop trying > > to > > > reconnect and then disconnecting again: > > > > > > localhost kernel: iCHANNEL[0]_LU[0] - SCSI Task > > > Timeout with ITT: 0x00000264 > > > localhost kernel: iCHANNEL[0]_LU[0] - Forcing > > Session > > > Reinstatement for timed-out SCSI Task to ONLINE > > > Logical Unit > > > localhost kernel: iCHANNEL[0] - Performing Cleanup > > for > > > failed iSCSI CID: 0 to > > > iqn.2001-04.com.example:storage.disk2.sys1.xyz > > > localhost kernel: iCHANNEL[0] - Decremented iSCSI > > > connection count to 0 to node: > > > iqn.2001-04.com.example:storage.disk2.sys1.xyz > > > localhost kernel: iCHANNEL[0] - released iSCSI > > session > > > to node: > > > iqn.2001-04.com.example:storage.disk2.sys1.xyz > > > localhost kernel: iSCSI Core Stack[1] - > > Decremented > > > number of active iSCSI sessions to 0 > > > localhost kernel: iCHANNEL[0] - No defined iSCSI > > > Authentication Methods, skipping > > SecurityNegotiation > > > phase. > > > localhost kernel: iscsi_login_rx_data:54: > > ***ERROR*** > > > rx_data returned -512, expecting 48. > > > localhost kernel: > > > iscsi_initiator_start_negotiation:754: ***ERROR*** > > > iSCSI Login negotiation failed. > > > localhost kernel: iscsi_handle_authetication:108: > > > ***ERROR*** sock_recvmsg() returned 0 > > > localhost kernel: iCHANNEL[0] - No defined iSCSI > > > Authentication Methods, skipping > > SecurityNegotiation > > > phase. > > > localhost kernel: iscsi_login_rx_data:54: > > ***ERROR*** > > > rx_data returned -512, expecting 48. > > > localhost kernel: > > > iscsi_initiator_start_negotiation:754: ***ERROR*** > > > iSCSI Login negotiation failed. > > > localhost kernel: iscsi_handle_authetication:108: > > > ***ERROR*** sock_recvmsg() returned 0 > > > localhost kernel: iCHANNEL[0] - No defined iSCSI > > > Authentication Methods, skipping > > SecurityNegotiation > > > phase. > > > localhost kernel: iscsi_login_rx_data:54: > > ***ERROR*** > > > rx_data returned -512, expecting 48. > > > localhost kernel: > > > iscsi_initiator_start_negotiation:754: ***ERROR*** > > > iSCSI Login negotiation failed. > > > localhost kernel: iscsi_handle_authetication:108: > > > ***ERROR*** sock_recvmsg() returned 0 > > > localhost kernel: iCHANNEL[0] - No defined iSCSI > > > Authentication Methods, skipping > > SecurityNegotiation > > > phase. > > > localhost kernel: iscsi_login_rx_data:54: > > ***ERROR*** > > > rx_data returned -512, expecting 48. > > > localhost kernel: > > > iscsi_initiator_start_negotiation:754: ***ERROR*** > > > iSCSI Login negotiation failed. > > > localhost kernel: iscsi_handle_authetication:108: > > > ***ERROR*** sock_recvmsg() returned 0 > > > localhost kernel: iCHANNEL[0] - No defined iSCSI > > > Authentication Methods, skipping > > SecurityNegotiation > > > phase. > > > localhost kernel: iscsi_login_rx_data:54: > > ***ERROR*** > > > rx_data returned -512, expecting 48. > > > localhost kernel: > > > iscsi_initiator_start_negotiation:754: ***ERROR*** > > > iSCSI Login negotiation failed. > > > localhost kernel: iscsi_handle_authetication:108: > > > ***ERROR*** sock_recvmsg() returned 0 > > > > > > PS. I'll check out open-iscsi tomorrow morning and > > > tell you how it goes. > > > > > > --- Ming Zhang <mingz@xxxxxxxxxxx> wrote: > > > > > > > forgot to say, the reason i ask u to check > > > > open-iscsi is that we tested > > > > open-iscsi + iet on same box before, it is not > > ok, > > > > then after a certain > > > > version, open-iscsi can run ok with iet on same > > box, > > > > but nobody do > > > > extensive tests. > > > > > > > > ming > > > > > > > > On Sun, 2006-03-26 at 12:37 -0500, Ming Zhang > > wrote: > > > > > frankly, i do not know. i assumed they should > > be > > > > ok no matter whether > > > > > they are on same box or not. but from > > experience, > > > > it was not. > > > > > > > > > > maybe some kernel guru here can answer this > > > > question. > > > > > > > > > > ming > > > > > > > > > > > > > > > > > > > > On Sun, 2006-03-26 at 09:18 -0800, Rik Herrin > > > > wrote: > > > > > > I'm running them on the same machine to see > > the > > > > > > maximum throughput and to see what type of > > > > bottleneck > > > > > > the disk subsystem will give me. I'm also > > > > waiting for > > > > > > a 4-port 1GbE Intel NIC to make sure that > > the > > > > network > > > > > > doesn't end up being the bottleneck. Do you > > > > think > > > > > > there's any reason for them running on the > > same > > > > > > machine to cause a problem? > > > > > > > > > > > > Rik > > > > > > > > > > > > --- Ming Zhang <mingz@xxxxxxxxxxx> wrote: > > > > > > > > > > > > > ps, any point to run them at same box? ;) > > > > > > > > > > > > > > ming > > > > > > > > > > > > > > On Sun, 2006-03-26 at 08:30 -0800, Rik > > Herrin > > > > wrote: > > > > > > > > I am going to try it with open-iscsi and > > > > > > > core-iscsi to > > > > > > > > see if this issue is initiator-specific > > or > > > > IET > > > > > > > > specific. In the meantime, I configured > > a > > > > 4-disk > > > > > > > RAID > > > > > > > > 0 SATA configuration and set it as the > > > > device > > > > > > > exported > > > > > > > > by IET. Without the iSCSI layer > > (without > > > > running > > > > > > > > either ietd or iscsi-linux), I saw write > > > > > > > throughput of > > > > > > > > about 212 MB/s. When I started IET and > > > > > > > linux-iscsi > > > > > > > > and ran the sequential write test, I am > > now > > > > > > > getting > > > > > > > > the following errors: > > > === message truncated === > > > __________________________________________________ > Do You Yahoo!? > Tired of spam? Yahoo! Mail has the best spam protection around > http://mail.yahoo.com ------------------------------------------------------- This SF.Net email is sponsored by xPML, a groundbreaking scripting language that extends applications into web and mobile media. Attend the live webcast and join the prime developer group breaking into this new coding territory! http://sel.as-us.falkag.net/sel?cmd=lnk&kid=110944&bid=241720&dat=121642 _______________________________________________ linux-iscsi-users mailing list linux-iscsi-users@xxxxxxxxxxxxxxxxxxxxx https://lists.sourceforge.net/lists/listinfo/linux-iscsi-users
[IP Storage] [IETF] [Linux SCSI] [iSCSI Book] [Linux Resources] [Yosemite News] [Photo] [Home] [IETF Announcements] [IETF Discussion] [SCSI Hardware]