iSCSI with fvdw

[Mewtos]

Hi fvdw,

first of all, thank you for all your work and attempts to make iscsi target work under 4.6.6.
I've tested the new kernel module on my nwsp2 and could succesfully initiate my iscsi targets with an ubuntu initiator and read data from the target. Yeah. :bananadance



But I have a problem with writing data on the iscsi target.
As soon as i write e.g. an 50mb file through my ubuntu iscsi-initiator on the target, my nwsp2 crahses.
Same thing happpens when i try to partitionate an iscsi-disk on the initiator.
It looks like, the kernel from my nwsp2 crashes, when data is written through iscsi from an initiator.


As i can see it, the CPU Usage on the nwsp2 approaches 100% when data is written trough an iscsi initiator and the kernel crashes 5-10 seconds after approaching it.
But i can't see, which service is creating this cpu-load and it isnt logged any error in dmesg or with the ietd debug mode. :scratch

cpu_usage.PNG

On my ubuntu initiator, i have the following error in syslog when the nwsp2 cpu usage is on 100%:

Code: Select all

Oct 31 20:41:23 srv001 kernel: [85962.908026]  connection4:0: ping timeout of 5 secs expired, recv timeout 5, last rx 4316380518, last ping 4316381772, now 4316383024
Oct 31 20:41:23 srv001 kernel: [85962.911841]  connection4:0: detected conn error (1022)
Oct 31 20:41:23 srv001 kernel: [85962.911848]  connection5:0: ping timeout of 5 secs expired, recv timeout 5, last rx 4316380518, last ping 4316381772, now 4316383024
Oct 31 20:41:23 srv001 kernel: [85962.912187]  connection5:0: detected conn error (1022)
Oct 31 20:41:23 srv001 kernel: [85962.912187]  connection6:0: ping timeout of 5 secs expired, recv timeout 5, last rx 4316380518, last ping 4316381772, now 4316383024
Oct 31 20:41:23 srv001 kernel: [85962.916033]  connection6:0: detected conn error (1022)
Oct 31 20:41:24 srv001 iscsid: Kernel reported iSCSI connection 4:0 error (1022 - Invalid or unknown error code) state (3)
Oct 31 20:41:24 srv001 iscsid: Kernel reported iSCSI connection 5:0 error (1022 - Invalid or unknown error code) state (3)
Oct 31 20:41:24 srv001 iscsid: Kernel reported iSCSI connection 6:0 error (1022 - Invalid or unknown error code) state (3)


Are you expiriencing the same problem here with writing data on an attached iscsi-disk?

Thanks & greetings,
Mewtos

[fvdw]

I tested it with a small file that was ok but using a 48 MB file indeed made the nas running the target crash , becomes inaccessible.
From the initiator I could still read data from the target. So that seems to be still running, I also could logout normally ion the initiator but reconnecting failed
No clue yet what the reason can be, need to do some more investigation, difficult because after reboot syslog is erased..lets see how to find some hints, I will come back on this

[fvdw]

No progress yet. Transferring small files goes ok but from about 2M size it freezes the nas running the target. It cannot be lack of memory because the nas has more then the file size. Must be something else. Difficulty is that the nas becomes in accessible and as result no info on why it crashes can be retrieved. I checked syslog but there is no info. We need dmesg output to find the function causing the problem. Further I have little time this moment because of work. But this must be possible to solve

[Mewtos]

Hi fvdw,

thanks for your information about the progess.
I'm trying diffrent configurations in ietd.conf from the manpage, but didn't get any further yet.

Same here with files bigger than 2mb.

Greetings,
Mewtos

[fvdw]

I managed to get some more info what going onby using the serial console (in fact I used the netconsole as it is easier then connecting the serial interface).

It looks like that the file write requests continue when transferring a file bigger then 2 MB to the target although on the initiator the transfer progress freezes.

in this printk that I have put into in the write request function in the filo-io.c code you can see that it seems to write files in blocks of 4096 byes blocks (4 sectors of 512 Bytes) and that the the size of the file goes to zero. After that the nas hangs and is inaccessible so no oops error.
size is the remaining size of the file to be written, count is number of bytes to write, ret is actual number of bytes written per loop

Code: Select all

[  278.755361] fvdw I/O write page_cache_size=4096 size=118784 count= 4096, ret = 4096
[  278.763322] fvdw I/O write page_cache_size=4096 size=114688 count= 4096, ret = 4096
[  278.771258] fvdw I/O write page_cache_size=4096 size=110592 count= 4096, ret = 4096
[  278.779148] fvdw I/O write page_cache_size=4096 size=106496 count= 4096, ret = 4096
[  278.787112] fvdw I/O write page_cache_size=4096 size=102400 count= 4096, ret = 4096
[  278.795051] fvdw I/O write page_cache_size=4096 size=98304 count= 4096, ret = 4096
[  278.802904] fvdw I/O write page_cache_size=4096 size=94208 count= 4096, ret = 4096
[  278.810747] fvdw I/O write page_cache_size=4096 size=90112 count= 4096, ret = 4096
[  278.818533] fvdw I/O write page_cache_size=4096 size=86016 count= 4096, ret = 4096
[  278.826391] fvdw I/O write page_cache_size=4096 size=81920 count= 4096, ret = 4096
[  278.834249] fvdw I/O write page_cache_size=4096 size=77824 count= 4096, ret = 4096
[  278.842129] fvdw I/O write page_cache_size=4096 size=73728 count= 4096, ret = 4096
[  278.849938] fvdw I/O write page_cache_size=4096 size=69632 count= 4096, ret = 4096
[  278.857811] fvdw I/O write page_cache_size=4096 size=65536 count= 4096, ret = 4096
[  278.865662] fvdw I/O write page_cache_size=4096 size=61440 count= 4096, ret = 4096
[  278.873516] fvdw I/O write page_cache_size=4096 size=57344 count= 4096, ret = 4096
[  278.881365] fvdw I/O write page_cache_size=4096 size=53248 count= 4096, ret = 4096
[  278.889175] fvdw I/O write page_cache_size=4096 size=49152 count= 4096, ret = 4096
[  278.897039] fvdw I/O write page_cache_size=4096 size=45056 count= 4096, ret = 4096
[  278.904898] fvdw I/O write page_cache_size=4096 size=40960 count= 4096, ret = 4096
[  278.912751] fvdw I/O write page_cache_size=4096 size=36864 count= 4096, ret = 4096
[  278.920597] fvdw I/O write page_cache_size=4096 size=32768 count= 4096, ret = 4096
[  278.928382] fvdw I/O write page_cache_size=4096 size=28672 count= 4096, ret = 4096
[  278.936238] fvdw I/O write page_cache_size=4096 size=24576 count= 4096, ret = 4096
[  278.944094] fvdw I/O write page_cache_size=4096 size=20480 count= 4096, ret = 4096
[  278.951949] fvdw I/O write page_cache_size=4096 size=16384 count= 4096, ret = 4096
[  278.959761] fvdw I/O write page_cache_size=4096 size=12288 count= 4096, ret = 4096
[  278.967619] fvdw I/O write page_cache_size=4096 size=8192 count= 4096, ret = 4096
[  278.975209] fvdw I/O write page_cache_size=4096 size=4096 count= 4096, ret = 4096

Whats going on here :scratch

[fvdw]

some progress, attached a version that seems to be able to transfer files upto 25MB.

ps it may be a litle slow because it has several print debedug lines which are send to dmesg and serial console (or net console)
Please test if you see the same behaviour.
What I notice that on end of file transfer cpu usage goes to 100% on the target for a while

--edit 22nov17

another version that seems to work on ext3 formatted target..but with two print statements in it as result max speed of writing to the target is 500 kB/s. If I take those out it hangs again, so still not perfect, need to find the timing problem
reading from the target goes with 2,5 MB/s even with the printk's

I wrote and read a file of 250 MB without failure and error

-edit24nov 17
I slightly modified version it is faster then the version of 22nov but noy yet lightning fast, I reach 5 MB/s using my windows pc as initiator

iscsi_trgt-24nov17-466-kirkwood.zip

[Mewtos]

Hi fvdw,

thanks for the new iscsi_trgt version and sorry for my late feedback.
I've loaded the new module, started iscsi-target and initiate a connection to the iSCSI Target.

I copied a 1.4GB File to the target without any problems, doing max 5 mb/s with my windows pc as initiator.
CPU on my nwsp2 was at 25% in the meantime.


Nice job, it works! :bananadance


Thanks and greetings
Mewtos

[fvdw]

nice :punk

This evening I tested it on my 5big2 and using windows PC as intiator and using blockio so writing to a real partition of one of the disks in the 5big2, there I reached writing speed of 70 MByte/s, reading goes even faster although I think the reading is influenced by the cache in the windows PC (file system used fat32, on ntfs it was 60 MByte/s)

nice figures