From 09621501932e6026bce7a45653e84233e2913549 Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Thu, 26 Mar 2015 16:34:35 +0100 Subject: [PATCH 01/17] nop: increase logging if more than one NOP is in flight Signed-off-by: Peter Lieven --- lib/nop.c | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/lib/nop.c b/lib/nop.c index 993ed77..2a8c0dc 100644 --- a/lib/nop.c +++ b/lib/nop.c @@ -83,7 +83,9 @@ iscsi_nop_out_async(struct iscsi_context *iscsi, iscsi_command_cb cb, } iscsi->nops_in_flight++; - ISCSI_LOG(iscsi, 6, "NOP Out Send (nops_in_flight: %d)", iscsi->nops_in_flight); + ISCSI_LOG(iscsi, (iscsi->nops_in_flight > 1) ? 1 : 6, + "NOP Out Send (nops_in_flight: %d, pdu->cmdsn %08x, maxcmdsn %08x)", + iscsi->nops_in_flight, pdu->cmdsn, iscsi->maxcmdsn); return 0; } @@ -137,9 +139,9 @@ iscsi_process_nop_out_reply(struct iscsi_context *iscsi, struct iscsi_pdu *pdu, { struct iscsi_data data; - iscsi->nops_in_flight = 0; + ISCSI_LOG(iscsi, (iscsi->nops_in_flight > 1) ? 1 : 6, "NOP Out Reply received"); - ISCSI_LOG(iscsi, 6, "NOP Out Reply received"); + iscsi->nops_in_flight = 0; if (pdu->callback == NULL) { return 0; From b76c8a703ec50a0addd6dbb5d4ceef2befacc4e9 Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Thu, 26 Mar 2015 16:45:03 +0100 Subject: [PATCH 02/17] socket: honour ISCSI_PDU_IMMEDIATE in iscsi_which_events Signed-off-by: Peter Lieven --- lib/socket.c | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/lib/socket.c b/lib/socket.c index d73859c..ec75309 100644 --- a/lib/socket.c +++ b/lib/socket.c @@ -386,7 +386,10 @@ iscsi_which_events(struct iscsi_context *iscsi) if (iscsi->outqueue_current != NULL || (iscsi->outqueue != NULL && !iscsi->is_corked && - iscsi_serial32_compare(iscsi->outqueue->cmdsn, iscsi->maxcmdsn) <= 0)) { + (iscsi_serial32_compare(iscsi->outqueue->cmdsn, iscsi->maxcmdsn) <= 0 || + iscsi->outqueue->outdata.data[0] & ISCSI_PDU_IMMEDIATE) + ) + ) { events |= POLLOUT; } return events; From 2a57cea180bf0e9c98a29556327581b34612562e Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Thu, 26 Mar 2015 16:51:18 +0100 Subject: [PATCH 03/17] socket: queue immediate PDUs at front of outqueue Signed-off-by: Peter Lieven --- lib/socket.c | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/lib/socket.c b/lib/socket.c index ec75309..a5fbae0 100644 --- a/lib/socket.c +++ b/lib/socket.c @@ -92,9 +92,17 @@ iscsi_add_to_outqueue(struct iscsi_context *iscsi, struct iscsi_pdu *pdu) /* queue pdus in ascending order of CmdSN. * ensure that pakets with the same CmdSN are kept in FIFO order. + * immediate PDUs are queued in front of queue with the CmdSN + * of the first element in the outqueue. */ + + if (pdu->outdata.data[0] & ISCSI_PDU_IMMEDIATE) { + pdu->cmdsn = current->cmdsn; + } + do { if (iscsi_serial32_compare(pdu->cmdsn, current->cmdsn) < 0 || + (pdu->outdata.data[0] & ISCSI_PDU_IMMEDIATE && !(current->outdata.data[0] & ISCSI_PDU_IMMEDIATE)) || pdu->flags & ISCSI_PDU_URGENT_DELIVERY) { /* insert PDU before the current */ if (last != NULL) { From ff67986b550ff428af753365ee06eb0997bc4bd0 Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Thu, 26 Mar 2015 16:56:50 +0100 Subject: [PATCH 04/17] login: drop iscsi_logout_async_internal now that immediate PDUs are queued at the head of outqueue we do no longer need the immediate delivery hack. Signed-off-by: Peter Lieven --- include/iscsi-private.h | 4 ---- lib/login.c | 13 +++---------- lib/pdu.c | 6 +++--- 3 files changed, 6 insertions(+), 17 deletions(-) diff --git a/include/iscsi-private.h b/include/iscsi-private.h index ca2ee36..e9e419c 100644 --- a/include/iscsi-private.h +++ b/include/iscsi-private.h @@ -371,10 +371,6 @@ uint32_t iscsi_itt_post_increment(struct iscsi_context *iscsi); void iscsi_timeout_scan(struct iscsi_context *iscsi); -int -iscsi_logout_async_internal(struct iscsi_context *iscsi, iscsi_command_cb cb, - void *private_data, uint32_t flags); - #ifdef __cplusplus } #endif diff --git a/lib/login.c b/lib/login.c index 33d20a2..835675f 100644 --- a/lib/login.c +++ b/lib/login.c @@ -1236,8 +1236,8 @@ iscsi_process_login_reply(struct iscsi_context *iscsi, struct iscsi_pdu *pdu, } int -iscsi_logout_async_internal(struct iscsi_context *iscsi, iscsi_command_cb cb, - void *private_data, uint32_t flags) +iscsi_logout_async(struct iscsi_context *iscsi, iscsi_command_cb cb, + void *private_data) { struct iscsi_pdu *pdu; @@ -1252,7 +1252,7 @@ iscsi_logout_async_internal(struct iscsi_context *iscsi, iscsi_command_cb cb, ISCSI_PDU_LOGOUT_REQUEST, ISCSI_PDU_LOGOUT_RESPONSE, iscsi_itt_post_increment(iscsi), - ISCSI_PDU_DROP_ON_RECONNECT|ISCSI_PDU_CORK_WHEN_SENT|flags); + ISCSI_PDU_DROP_ON_RECONNECT|ISCSI_PDU_CORK_WHEN_SENT); if (pdu == NULL) { iscsi_set_error(iscsi, "Out-of-memory: Failed to allocate " "logout pdu."); @@ -1285,13 +1285,6 @@ iscsi_logout_async_internal(struct iscsi_context *iscsi, iscsi_command_cb cb, return 0; } -int -iscsi_logout_async(struct iscsi_context *iscsi, iscsi_command_cb cb, - void *private_data) -{ - return iscsi_logout_async_internal(iscsi, cb, private_data, 0); -} - int iscsi_process_logout_reply(struct iscsi_context *iscsi, struct iscsi_pdu *pdu, struct iscsi_in_pdu *in) diff --git a/lib/pdu.c b/lib/pdu.c index 3d0b5c4..3c4bc3a 100644 --- a/lib/pdu.c +++ b/lib/pdu.c @@ -365,7 +365,7 @@ int iscsi_process_reject(struct iscsi_context *iscsi, if (reason == ISCSI_REJECT_WAITING_FOR_LOGOUT) { ISCSI_LOG(iscsi, 1, "target rejects request with reason: %s", iscsi_reject_reason_str(reason)); - iscsi_logout_async_internal(iscsi, iscsi_reconnect_after_logout, NULL, ISCSI_PDU_URGENT_DELIVERY); + iscsi_logout_async(iscsi, iscsi_reconnect_after_logout, NULL); return 0; } @@ -435,7 +435,7 @@ iscsi_process_pdu(struct iscsi_context *iscsi, struct iscsi_in_pdu *in) ISCSI_LOG(iscsi, 2, "dropping connection to fix errors with broken DELL Equallogic firmware 7.x"); return -1; } - iscsi_logout_async_internal(iscsi, iscsi_reconnect_after_logout, NULL, ISCSI_PDU_URGENT_DELIVERY); + iscsi_logout_async(iscsi, iscsi_reconnect_after_logout, NULL); return 0; case 0x2: ISCSI_LOG(iscsi, 2, "target will drop this connection. Time2Wait is %u seconds", param2); @@ -447,7 +447,7 @@ iscsi_process_pdu(struct iscsi_context *iscsi, struct iscsi_in_pdu *in) return 0; case 0x4: ISCSI_LOG(iscsi, 2, "target requests parameter renogitiation."); - iscsi_logout_async_internal(iscsi, iscsi_reconnect_after_logout, NULL, ISCSI_PDU_DROP_ON_RECONNECT); + iscsi_logout_async(iscsi, iscsi_reconnect_after_logout, NULL); return 0; default: ISCSI_LOG(iscsi, 1, "unhandled async event %u: param1 %u param2 %u param3 %u", event, param1, param2, param3); From cb6667a5dcaebca1574824b30c7e56230a0488df Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Thu, 26 Mar 2015 17:00:20 +0100 Subject: [PATCH 05/17] drop ISCSI_PDU_URGENT_DELIVERY its not needed anymore Signed-off-by: Peter Lieven --- include/iscsi-private.h | 5 ----- lib/socket.c | 3 +-- 2 files changed, 1 insertion(+), 7 deletions(-) diff --git a/include/iscsi-private.h b/include/iscsi-private.h index e9e419c..4304168 100644 --- a/include/iscsi-private.h +++ b/include/iscsi-private.h @@ -229,11 +229,6 @@ struct iscsi_pdu { #define ISCSI_PDU_DROP_ON_RECONNECT 0x00000004 /* stop sending after this PDU has been sent */ #define ISCSI_PDU_CORK_WHEN_SENT 0x00000008 -/* put this immediate delivery PDU in front of outqueue. - * This is currently only used for immediate logout requests - * as answer to an async logout event. */ -#define ISCSI_PDU_URGENT_DELIVERY 0x00000010 - uint32_t flags; diff --git a/lib/socket.c b/lib/socket.c index a5fbae0..1ca2bfe 100644 --- a/lib/socket.c +++ b/lib/socket.c @@ -102,8 +102,7 @@ iscsi_add_to_outqueue(struct iscsi_context *iscsi, struct iscsi_pdu *pdu) do { if (iscsi_serial32_compare(pdu->cmdsn, current->cmdsn) < 0 || - (pdu->outdata.data[0] & ISCSI_PDU_IMMEDIATE && !(current->outdata.data[0] & ISCSI_PDU_IMMEDIATE)) || - pdu->flags & ISCSI_PDU_URGENT_DELIVERY) { + (pdu->outdata.data[0] & ISCSI_PDU_IMMEDIATE && !(current->outdata.data[0] & ISCSI_PDU_IMMEDIATE))) { /* insert PDU before the current */ if (last != NULL) { last->next=pdu; From 5c4bd85b80825a6706a90e5c3792b8bccb4cc257 Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Fri, 27 Mar 2015 09:53:23 +0100 Subject: [PATCH 06/17] nop: clear immediate flag in iscsi_nop_out_async originally NOPs where used to detect failures in the transport layer. This is e.g. implemented in qemu since a few years now. Recently I found a few vServers with hanging I/O where the NOP mechanism could not detect the error. The reason is most likely due to a bug in the target, however if NOPs increase the CmdSN this could help to detect such failures. If there are requests hanging and the OS stops I/O before CmdSN > MaxCmdSN we can currently send NOPs forever and they might still be answered. If a NOP increases the CmdSN we will enter a point where CmdSN is greater than MaxCmdSN. This is, of course, not the ideal check, but it might detect some types of errors. Ideally we would send out a Test-Unit-Ready command with attr=ordered, but that requires a new API and/or modification of the tool that uses libiscsi. This here comes with no modification for the userspace. Signed-off-by: Peter Lieven --- lib/nop.c | 9 +++------ 1 file changed, 3 insertions(+), 6 deletions(-) diff --git a/lib/nop.c b/lib/nop.c index 2a8c0dc..f6ba56f 100644 --- a/lib/nop.c +++ b/lib/nop.c @@ -46,9 +46,6 @@ iscsi_nop_out_async(struct iscsi_context *iscsi, iscsi_command_cb cb, return -1; } - /* immediate flag */ - iscsi_pdu_set_immediate(pdu); - /* flags */ iscsi_pdu_set_pduflags(pdu, 0x80); @@ -58,12 +55,11 @@ iscsi_nop_out_async(struct iscsi_context *iscsi, iscsi_command_cb cb, /* lun */ iscsi_pdu_set_lun(pdu, 0); - /* cmdsn is not increased if Immediate delivery*/ iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn); - pdu->cmdsn = iscsi->cmdsn; + pdu->cmdsn = iscsi->cmdsn++; /* exp statsn */ - iscsi_pdu_set_expstatsn(pdu, iscsi->statsn+1); + iscsi_pdu_set_expstatsn(pdu, iscsi->statsn + 1); pdu->callback = cb; pdu->private_data = private_data; @@ -141,6 +137,7 @@ iscsi_process_nop_out_reply(struct iscsi_context *iscsi, struct iscsi_pdu *pdu, ISCSI_LOG(iscsi, (iscsi->nops_in_flight > 1) ? 1 : 6, "NOP Out Reply received"); + iscsi_adjust_maxexpcmdsn(iscsi, in); iscsi->nops_in_flight = 0; if (pdu->callback == NULL) { From cc54f4938b97cdc037ea8597bb25441766a3bf52 Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Fri, 27 Mar 2015 10:38:33 +0100 Subject: [PATCH 07/17] nop: add some more SN debugging Signed-off-by: Peter Lieven --- lib/nop.c | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-) diff --git a/lib/nop.c b/lib/nop.c index f6ba56f..4be9211 100644 --- a/lib/nop.c +++ b/lib/nop.c @@ -80,8 +80,8 @@ iscsi_nop_out_async(struct iscsi_context *iscsi, iscsi_command_cb cb, iscsi->nops_in_flight++; ISCSI_LOG(iscsi, (iscsi->nops_in_flight > 1) ? 1 : 6, - "NOP Out Send (nops_in_flight: %d, pdu->cmdsn %08x, maxcmdsn %08x)", - iscsi->nops_in_flight, pdu->cmdsn, iscsi->maxcmdsn); + "NOP Out Send (nops_in_flight: %d, pdu->cmdsn %08x, pdu->itt %08x, maxcmdsn %08x, expcmdsn %08x)", + iscsi->nops_in_flight, pdu->cmdsn, pdu->itt, iscsi->maxcmdsn, iscsi->expcmdsn); return 0; } @@ -135,9 +135,12 @@ iscsi_process_nop_out_reply(struct iscsi_context *iscsi, struct iscsi_pdu *pdu, { struct iscsi_data data; - ISCSI_LOG(iscsi, (iscsi->nops_in_flight > 1) ? 1 : 6, "NOP Out Reply received"); - iscsi_adjust_maxexpcmdsn(iscsi, in); + + ISCSI_LOG(iscsi, (iscsi->nops_in_flight > 1) ? 1 : 6, + "NOP Out Reply received (pdu->itt %08x, maxcmdsn %08x, expcmdsn %08x)", + pdu->itt, iscsi->maxcmdsn, iscsi->expcmdsn); + iscsi->nops_in_flight = 0; if (pdu->callback == NULL) { From 9d6f0690f8bf16b596eacdd6775acae852e9cc8c Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Fri, 27 Mar 2015 11:08:37 +0100 Subject: [PATCH 08/17] iscsi-perf: add NOPs to the perf stream and account for timeouts Signed-off-by: Peter Lieven --- utils/iscsi-perf.c | 32 ++++++++++++++++++++++++++++++-- 1 file changed, 30 insertions(+), 2 deletions(-) diff --git a/utils/iscsi-perf.c b/utils/iscsi-perf.c index a9a84c3..ed10e11 100644 --- a/utils/iscsi-perf.c +++ b/utils/iscsi-perf.c @@ -24,6 +24,7 @@ #include #include #include +#include #include "iscsi.h" #include "scsi-lowlevel.h" @@ -33,7 +34,11 @@ #define VERSION "0.1" +#define NOP_INTERVAL 5 +#define MAX_NOP_FAILURES 3 + const char *initiator = "iqn.2010-11.libiscsi:iscsi-perf"; +int proc_alarm = 0; int max_in_flight = 32; int blocks_per_io = 8; uint64_t runtime = 0; @@ -202,8 +207,17 @@ void usage(void) { exit(1); } -void sig_handler (int signum _U_) { - finished = 1; +void sig_handler (int signum ) { + if (signum == SIGALRM) { + if (proc_alarm) { + fprintf(stderr, "\n\nABORT: Last alarm was not processed.\n"); + exit(10); + } + proc_alarm = 1; + alarm(NOP_INTERVAL); + } else { + finished = 1; + } } int main(int argc, char *argv[]) @@ -340,6 +354,7 @@ int main(int argc, char *argv[]) sigaction(SIGINT, &sa, NULL); sigaction(SIGTERM, &sa, NULL); + sigaction(SIGALRM, &sa, NULL); printf("\n"); @@ -347,10 +362,21 @@ int main(int argc, char *argv[]) fill_read_queue(&client); + alarm(NOP_INTERVAL); + while (client.in_flight && !client.err_cnt) { pfd[0].fd = iscsi_get_fd(client.iscsi); pfd[0].events = iscsi_which_events(client.iscsi); + if (proc_alarm) { + if (iscsi_get_nops_in_flight(client.iscsi) > MAX_NOP_FAILURES) { + fprintf(stderr, "\n\nABORT: NOP timeout.\n"); + exit(10); + } + iscsi_nop_out_async(client.iscsi, NULL, NULL, 0, NULL); + proc_alarm = 0; + } + if (poll(&pfd[0], 1, -1) < 0) { continue; } @@ -359,6 +385,8 @@ int main(int argc, char *argv[]) break; } } + + alarm(0); progress(&client); From b9dc3749c90b5ea3b31a688e7d03156c5e35d892 Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Fri, 27 Mar 2015 12:18:58 +0100 Subject: [PATCH 09/17] iscsi-perf: add a switch to send requests of random size Signed-off-by: Peter Lieven --- utils/iscsi-perf.c | 47 +++++++++++++++++++++++++++++++++------------- 1 file changed, 34 insertions(+), 13 deletions(-) diff --git a/utils/iscsi-perf.c b/utils/iscsi-perf.c index ed10e11..30c5bb2 100644 --- a/utils/iscsi-perf.c +++ b/utils/iscsi-perf.c @@ -48,6 +48,7 @@ struct client { int finished; int in_flight; int random; + int random_blocks; struct iscsi_context *iscsi; struct scsi_iovec perf_iov; @@ -60,6 +61,8 @@ struct client { uint64_t first_ns; uint64_t iops; uint64_t last_iops; + uint64_t bytes; + uint64_t last_bytes; int ignore_errors; int busy_cnt; @@ -97,40 +100,44 @@ void progress(struct client *client) { if (runtime) _runtime = runtime - _runtime; printf ("\r"); - uint64_t aiops = 1000000000UL * (client->iops) / (now - client->first_ns); + uint64_t aiops = 1000000000.0 * (client->iops) / (now - client->first_ns); + uint64_t ambps = 1000000000.0 * (client->bytes) / (now - client->first_ns); if (!_runtime) { finished = 1; printf ("iops average %" PRIu64 " (%" PRIu64 " MB/s) ", aiops, (aiops * blocks_per_io * client->blocksize) >> 20); } else { uint64_t iops = 1000000000UL * (client->iops - client->last_iops) / (now - client->last_ns); + uint64_t mbps = 1000000000UL * (client->bytes - client->last_bytes) / (now - client->last_ns); printf ("%02" PRIu64 ":%02" PRIu64 ":%02" PRIu64 " - ", _runtime / 3600, (_runtime % 3600) / 60, _runtime % 60); - printf ("lba %" PRIu64 ", iops current %" PRIu64 " (%" PRIu64 " MB/s), ", client->pos, iops, (iops * blocks_per_io * client->blocksize) >> 20); - printf ("iops average %" PRIu64 " (%" PRIu64 " MB/s), in_flight %d, busy %d ", aiops, (aiops * blocks_per_io * client->blocksize) >> 20, client->in_flight, client->busy_cnt); + printf ("lba %" PRIu64 ", iops current %" PRIu64 " (%" PRIu64 " MB/s), ", client->pos, iops, mbps >> 20); + printf ("iops average %" PRIu64 " (%" PRIu64 " MB/s), in_flight %d, busy %d ", aiops, ambps >> 20, client->in_flight, client->busy_cnt); } fflush(stdout); client->last_ns = now; client->last_iops = client->iops; + client->last_bytes = client->bytes; } void cb(struct iscsi_context *iscsi _U_, int status, void *command_data, void *private_data) { struct client *client = (struct client *)private_data; struct scsi_task *task = command_data, *task2 = NULL; + struct scsi_read16_cdb *read16_cdb = NULL; + + read16_cdb = scsi_cdb_unmarshall(task, SCSI_OPCODE_READ16); + if (read16_cdb == NULL) { + fprintf(stderr, "Failed to unmarshall READ16 CDB.\n"); + client->err_cnt++; + goto out; + } if (status == SCSI_STATUS_BUSY || (status == SCSI_STATUS_CHECK_CONDITION && task->sense.key == SCSI_SENSE_UNIT_ATTENTION)) { - struct scsi_read16_cdb *read16_cdb = NULL; if (client->retry_cnt++ > 4 * max_in_flight) { fprintf(stderr, "maxium number of command retries reached...\n"); client->err_cnt++; goto out; } - read16_cdb = scsi_cdb_unmarshall(task, SCSI_OPCODE_READ16); - if (read16_cdb == NULL) { - fprintf(stderr, "Failed to unmarshall READ16 CDB.\n"); - client->err_cnt++; - goto out; - } task2 = iscsi_read16_task(client->iscsi, client->lun, read16_cdb->lba, read16_cdb->transfer_length * client->blocksize, @@ -148,6 +155,7 @@ void cb(struct iscsi_context *iscsi _U_, int status, void *command_data, void *p client->err_cnt++; } else if (status == SCSI_STATUS_GOOD) { client->retry_cnt = 0; + client->bytes += read16_cdb->transfer_length * client->blocksize; } else { fprintf(stderr, "Read16 failed with %s\n", iscsi_get_error(iscsi)); if (!client->ignore_errors) { @@ -186,6 +194,10 @@ void fill_read_queue(struct client *client) if (num_blocks > blocks_per_io) { num_blocks = blocks_per_io; } + + if (client->random_blocks) { + num_blocks = rand() % num_blocks + 1; + } task = iscsi_read16_task(client->iscsi, client->lun, client->pos, @@ -236,6 +248,7 @@ int main(int argc, char *argv[]) {"blocks", required_argument, NULL, 'b'}, {"runtime", required_argument, NULL, 't'}, {"random", no_argument, NULL, 'r'}, + {"random-blocks", no_argument, NULL, 'R'}, {"ignore-errors", no_argument, NULL, 'n'}, {0, 0, 0, 0} }; @@ -247,7 +260,7 @@ int main(int argc, char *argv[]) printf("iscsi-perf version %s - (c) 2014-2015 by Peter Lieven \n\n", VERSION); - while ((c = getopt_long(argc, argv, "i:m:b:t:nr", long_options, + while ((c = getopt_long(argc, argv, "i:m:b:t:nrR", long_options, &option_index)) != -1) { switch (c) { case 'i': @@ -268,6 +281,9 @@ int main(int argc, char *argv[]) case 'r': client.random = 1; break; + case 'R': + client.random_blocks = 1; + break; default: fprintf(stderr, "Unrecognized option '%c'\n\n", c); usage(); @@ -338,8 +354,13 @@ int main(int argc, char *argv[]) printf("capacity is %" PRIu64 " blocks or %" PRIu64 " byte (%" PRIu64 " MB)\n", client.num_blocks, client.num_blocks * client.blocksize, (client.num_blocks * client.blocksize) >> 20); - printf("performing %s READ with %d parallel requests\nfixed transfer size of %d blocks (%d byte)\n", - client.random ? "random" : "sequential", max_in_flight, blocks_per_io, blocks_per_io * client.blocksize); + printf("performing %s READ with %d parallel requests\n", client.random ? "RANDOM" : "SEQUENTIAL", max_in_flight); + + if (client.random_blocks) { + printf("RANDOM transfer size of 1 - %d blocks (%d - %d byte)\n", blocks_per_io, client.blocksize, blocks_per_io * client.blocksize); + } else { + printf("FIXED transfer size of %d blocks (%d byte)\n", blocks_per_io, blocks_per_io * client.blocksize); + } if (runtime) { printf("will run for %" PRIu64 " seconds.\n", runtime); From 7fd58eca21396f4494f2cfc9568cc5b35ab79310 Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Fri, 27 Mar 2015 13:16:42 +0100 Subject: [PATCH 10/17] pdu: a target NOP-In may indiciate a changes MaxCmdSN or ExpCmdSN RFC3720 10.19. NOP-In NOP-In is either sent by a target as a response to a NOP-Out, as a "ping" to an initiator, or as a means to carry a changed ExpCmdSN and/or MaxCmdSN if another PDU will not be available for a long time (as determined by the target). ... Signed-off-by: Peter Lieven --- lib/pdu.c | 1 + 1 file changed, 1 insertion(+) diff --git a/lib/pdu.c b/lib/pdu.c index 3c4bc3a..3866816 100644 --- a/lib/pdu.c +++ b/lib/pdu.c @@ -324,6 +324,7 @@ int iscsi_process_target_nop_in(struct iscsi_context *iscsi, ttt = scsi_get_uint32(&in->hdr[20]); iscsi_adjust_statsn(iscsi, in); + iscsi_adjust_maxexpcmdsn(iscsi, in); /* if the server does not want a response */ if (ttt == 0xffffffff) { From 47e2b8918e0f34127bce4d56f1d2b91f4effc894 Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Fri, 27 Mar 2015 22:09:44 +0100 Subject: [PATCH 11/17] socket: Data-Out PDUs may carry a CmdSN < ExpCmdSN Signed-off-by: Peter Lieven --- lib/socket.c | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/lib/socket.c b/lib/socket.c index 1ca2bfe..626fca6 100644 --- a/lib/socket.c +++ b/lib/socket.c @@ -650,9 +650,10 @@ iscsi_write_to_socket(struct iscsi_context *iscsi) return 0; } /* pop first element of the outqueue */ - if (iscsi_serial32_compare(iscsi->outqueue->cmdsn, iscsi->expcmdsn) < 0) { - iscsi_set_error(iscsi, "iscsi_write_to_scoket: outqueue[0]->cmdsn < expcmdsn (%08x < %08x)", - iscsi->outqueue->cmdsn, iscsi->expcmdsn); + if (iscsi_serial32_compare(iscsi->outqueue->cmdsn, iscsi->expcmdsn) < 0 && + (iscsi->outqueue->outdata.data[0] & 0x3f) != ISCSI_PDU_DATA_OUT) { + iscsi_set_error(iscsi, "iscsi_write_to_scoket: outqueue[0]->cmdsn < expcmdsn (%08x < %08x) opcode %02x", + iscsi->outqueue->cmdsn, iscsi->expcmdsn, iscsi->outqueue->outdata.data[0] & 0x3f); return -1; } iscsi->outqueue_current = iscsi->outqueue; From 37f908bb8a36a8db7e4746435246b0841a608a2c Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Mon, 30 Mar 2015 08:44:50 +0200 Subject: [PATCH 12/17] socket: set expstatsn when we put the PDU on the wire Signed-off-by: Peter Lieven --- lib/iscsi-command.c | 6 ------ lib/login.c | 3 --- lib/nop.c | 6 ------ lib/socket.c | 5 +++++ 4 files changed, 5 insertions(+), 15 deletions(-) diff --git a/lib/iscsi-command.c b/lib/iscsi-command.c index 7877b0d..ac6b683 100644 --- a/lib/iscsi-command.c +++ b/lib/iscsi-command.c @@ -115,9 +115,6 @@ iscsi_send_data_out(struct iscsi_context *iscsi, struct iscsi_pdu *cmd_pdu, /* ttt */ iscsi_pdu_set_ttt(pdu, ttt); - /* exp statsn */ - iscsi_pdu_set_expstatsn(pdu, iscsi->statsn+1); - /* data sn */ iscsi_pdu_set_datasn(pdu, cmd_pdu->datasn++); @@ -309,9 +306,6 @@ iscsi_scsi_command_async(struct iscsi_context *iscsi, int lun, pdu->cmdsn = iscsi->cmdsn; iscsi->cmdsn++; - /* exp statsn */ - iscsi_pdu_set_expstatsn(pdu, iscsi->statsn+1); - /* cdb */ iscsi_pdu_set_cdb(pdu, task); diff --git a/lib/login.c b/lib/login.c index 835675f..381f929 100644 --- a/lib/login.c +++ b/lib/login.c @@ -1269,9 +1269,6 @@ iscsi_logout_async(struct iscsi_context *iscsi, iscsi_command_cb cb, iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn); pdu->cmdsn = iscsi->cmdsn; - /* exp statsn */ - iscsi_pdu_set_expstatsn(pdu, iscsi->statsn+1); - pdu->callback = cb; pdu->private_data = private_data; diff --git a/lib/nop.c b/lib/nop.c index 4be9211..099e410 100644 --- a/lib/nop.c +++ b/lib/nop.c @@ -58,9 +58,6 @@ iscsi_nop_out_async(struct iscsi_context *iscsi, iscsi_command_cb cb, iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn); pdu->cmdsn = iscsi->cmdsn++; - /* exp statsn */ - iscsi_pdu_set_expstatsn(pdu, iscsi->statsn + 1); - pdu->callback = cb; pdu->private_data = private_data; @@ -117,9 +114,6 @@ iscsi_send_target_nop_out(struct iscsi_context *iscsi, uint32_t ttt) iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn); pdu->cmdsn = iscsi->cmdsn; - /* exp statsn */ - iscsi_pdu_set_expstatsn(pdu, iscsi->statsn+1); - if (iscsi_queue_pdu(iscsi, pdu) != 0) { iscsi_set_error(iscsi, "failed to queue iscsi nop-out pdu"); iscsi_free_pdu(iscsi, pdu); diff --git a/lib/socket.c b/lib/socket.c index 626fca6..803917e 100644 --- a/lib/socket.c +++ b/lib/socket.c @@ -649,6 +649,7 @@ iscsi_write_to_socket(struct iscsi_context *iscsi) iscsi->outqueue->cmdsn, iscsi->maxcmdsn); return 0; } + /* pop first element of the outqueue */ if (iscsi_serial32_compare(iscsi->outqueue->cmdsn, iscsi->expcmdsn) < 0 && (iscsi->outqueue->outdata.data[0] & 0x3f) != ISCSI_PDU_DATA_OUT) { @@ -657,6 +658,10 @@ iscsi_write_to_socket(struct iscsi_context *iscsi) return -1; } iscsi->outqueue_current = iscsi->outqueue; + + /* set exp statsn */ + iscsi_pdu_set_expstatsn(iscsi->outqueue_current, iscsi->statsn + 1); + ISCSI_LIST_REMOVE(&iscsi->outqueue, iscsi->outqueue_current); if (!(iscsi->outqueue_current->flags & ISCSI_PDU_DELETE_WHEN_SENT)) { /* we have to add the pdu to the waitqueue already here From 7e9776315563011a40f9c85ebed8b55fb29e0083 Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Mon, 30 Mar 2015 09:02:42 +0200 Subject: [PATCH 13/17] nop: add even more SN debugging Signed-off-by: Peter Lieven --- lib/nop.c | 12 ++++++++---- lib/pdu.c | 9 ++++++--- 2 files changed, 14 insertions(+), 7 deletions(-) diff --git a/lib/nop.c b/lib/nop.c index 099e410..3c00642 100644 --- a/lib/nop.c +++ b/lib/nop.c @@ -77,8 +77,8 @@ iscsi_nop_out_async(struct iscsi_context *iscsi, iscsi_command_cb cb, iscsi->nops_in_flight++; ISCSI_LOG(iscsi, (iscsi->nops_in_flight > 1) ? 1 : 6, - "NOP Out Send (nops_in_flight: %d, pdu->cmdsn %08x, pdu->itt %08x, maxcmdsn %08x, expcmdsn %08x)", - iscsi->nops_in_flight, pdu->cmdsn, pdu->itt, iscsi->maxcmdsn, iscsi->expcmdsn); + "NOP Out Send (nops_in_flight: %d, pdu->cmdsn %08x, pdu->itt %08x, pdu->ttt %08x, iscsi->maxcmdsn %08x, iscsi->expcmdsn %08x)", + iscsi->nops_in_flight, pdu->cmdsn, pdu->itt, 0xffffffff, iscsi->maxcmdsn, iscsi->expcmdsn); return 0; } @@ -120,6 +120,10 @@ iscsi_send_target_nop_out(struct iscsi_context *iscsi, uint32_t ttt) return -1; } + ISCSI_LOG(iscsi, (iscsi->nops_in_flight > 1) ? 1 : 6, + "NOP Out Send (nops_in_flight: %d, pdu->cmdsn %08x, pdu->itt %08x, pdu->ttt %08x, iscsi->maxcmdsn %08x, iscsi->expcmdsn %08x)", + iscsi->nops_in_flight, pdu->cmdsn, 0xffffffff, ttt, iscsi->maxcmdsn, iscsi->expcmdsn); + return 0; } @@ -132,8 +136,8 @@ iscsi_process_nop_out_reply(struct iscsi_context *iscsi, struct iscsi_pdu *pdu, iscsi_adjust_maxexpcmdsn(iscsi, in); ISCSI_LOG(iscsi, (iscsi->nops_in_flight > 1) ? 1 : 6, - "NOP Out Reply received (pdu->itt %08x, maxcmdsn %08x, expcmdsn %08x)", - pdu->itt, iscsi->maxcmdsn, iscsi->expcmdsn); + "NOP-In received (pdu->itt %08x, pdu->ttt %08x, iscsi->maxcmdsn %08x, iscsi->expcmdsn %08x, iscsi->statsn %08x)", + pdu->itt, 0xffffffff, iscsi->maxcmdsn, iscsi->expcmdsn, iscsi->statsn); iscsi->nops_in_flight = 0; diff --git a/lib/pdu.c b/lib/pdu.c index 3866816..d363cfa 100644 --- a/lib/pdu.c +++ b/lib/pdu.c @@ -319,13 +319,16 @@ static const char *iscsi_reject_reason_str(enum iscsi_reject_reason reason) int iscsi_process_target_nop_in(struct iscsi_context *iscsi, struct iscsi_in_pdu *in) { - uint32_t ttt; - - ttt = scsi_get_uint32(&in->hdr[20]); + uint32_t ttt = scsi_get_uint32(&in->hdr[20]); + uint32_t itt = scsi_get_uint32(&in->hdr[16]); iscsi_adjust_statsn(iscsi, in); iscsi_adjust_maxexpcmdsn(iscsi, in); + ISCSI_LOG(iscsi, (iscsi->nops_in_flight > 1) ? 1 : 6, + "NOP-In received (pdu->itt %08x, pdu->ttt %08x, iscsi->maxcmdsn %08x, iscsi->expcmdsn %08x, iscsi->statsn %08x)", + itt, ttt, iscsi->maxcmdsn, iscsi->expcmdsn, iscsi->statsn); + /* if the server does not want a response */ if (ttt == 0xffffffff) { return 0; From 74c2869b54100685d715b4e57e4fd2bf593b6266 Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Mon, 30 Mar 2015 09:03:18 +0200 Subject: [PATCH 14/17] nop: a NOP-Out Reply may also update the statsn Signed-off-by: Peter Lieven --- lib/nop.c | 1 + 1 file changed, 1 insertion(+) diff --git a/lib/nop.c b/lib/nop.c index 3c00642..701f31a 100644 --- a/lib/nop.c +++ b/lib/nop.c @@ -134,6 +134,7 @@ iscsi_process_nop_out_reply(struct iscsi_context *iscsi, struct iscsi_pdu *pdu, struct iscsi_data data; iscsi_adjust_maxexpcmdsn(iscsi, in); + iscsi_adjust_statsn(iscsi, in); ISCSI_LOG(iscsi, (iscsi->nops_in_flight > 1) ? 1 : 6, "NOP-In received (pdu->itt %08x, pdu->ttt %08x, iscsi->maxcmdsn %08x, iscsi->expcmdsn %08x, iscsi->statsn %08x)", From 79246def9d01eb9e0b2e172df8085dd051816e79 Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Mon, 30 Mar 2015 11:43:07 +0200 Subject: [PATCH 15/17] login: randomize cmdsn and itt Signed-off-by: Peter Lieven --- lib/login.c | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/lib/login.c b/lib/login.c index 381f929..10ea64f 100644 --- a/lib/login.c +++ b/lib/login.c @@ -790,6 +790,13 @@ iscsi_login_async(struct iscsi_context *iscsi, iscsi_command_cb cb, return -1; } + /* randomize cmdsn and itt */ + if (!iscsi->current_phase && !iscsi->secneg_phase) { + iscsi->itt = (u_int32_t) rand(); + iscsi->cmdsn = (u_int32_t) rand(); + iscsi->expcmdsn = iscsi->maxcmdsn = iscsi->cmdsn; + } + pdu = iscsi_allocate_pdu(iscsi, ISCSI_PDU_LOGIN_REQUEST, ISCSI_PDU_LOGIN_RESPONSE, @@ -804,6 +811,10 @@ iscsi_login_async(struct iscsi_context *iscsi, iscsi_command_cb cb, /* login request */ iscsi_pdu_set_immediate(pdu); + /* cmdsn is not increased if Immediate delivery*/ + iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn); + pdu->cmdsn = iscsi->cmdsn; + if (!iscsi->user[0]) { iscsi->current_phase = ISCSI_PDU_LOGIN_CSG_OPNEG; } From 395ca12746585bac00ed8037696dfc8b82fea314 Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Mon, 30 Mar 2015 11:50:04 +0200 Subject: [PATCH 16/17] login: implicitly set statsn RFC3720 10.13.4. states that the statsn should explicitly set with the first Login Repsonse. In theory the target could choose a StatSN that is not greater than iscsi->statsn (zero at start) in Serial32 arithmetic. Signed-off-by: Peter Lieven --- lib/login.c | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/lib/login.c b/lib/login.c index 10ea64f..0d56518 100644 --- a/lib/login.c +++ b/lib/login.c @@ -1045,7 +1045,13 @@ iscsi_process_login_reply(struct iscsi_context *iscsi, struct iscsi_pdu *pdu, status = scsi_get_uint16(&in->hdr[36]); - iscsi_adjust_statsn(iscsi, in); + // Status-Class is 0 + if (!(status >> 8)) { + if (!iscsi->current_phase && !iscsi->secneg_phase) { + iscsi->statsn = scsi_get_uint32(&in->hdr[24]); + } + iscsi_adjust_statsn(iscsi, in); + } iscsi_adjust_maxexpcmdsn(iscsi, in); /* Using bidirectional CHAP? Then we must see a chap_n and chap_r From 153e6ba07cabca4cea866588679ae9181a4a303a Mon Sep 17 00:00:00 2001 From: Peter Lieven Date: Mon, 30 Mar 2015 12:31:24 +0200 Subject: [PATCH 17/17] pdu: set pdu->cmdsn when the pdu structure is updated Signed-off-by: Peter Lieven --- lib/iscsi-command.c | 4 +--- lib/login.c | 2 -- lib/nop.c | 5 ++--- lib/pdu.c | 1 + lib/socket.c | 2 +- lib/task_mgmt.c | 1 - 6 files changed, 5 insertions(+), 10 deletions(-) diff --git a/lib/iscsi-command.c b/lib/iscsi-command.c index ac6b683..b7da624 100644 --- a/lib/iscsi-command.c +++ b/lib/iscsi-command.c @@ -302,9 +302,7 @@ iscsi_scsi_command_async(struct iscsi_context *iscsi, int lun, iscsi_pdu_set_expxferlen(pdu, task->expxferlen); /* cmdsn */ - iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn); - pdu->cmdsn = iscsi->cmdsn; - iscsi->cmdsn++; + iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn++); /* cdb */ iscsi_pdu_set_cdb(pdu, task); diff --git a/lib/login.c b/lib/login.c index 0d56518..f0e8be4 100644 --- a/lib/login.c +++ b/lib/login.c @@ -813,7 +813,6 @@ iscsi_login_async(struct iscsi_context *iscsi, iscsi_command_cb cb, /* cmdsn is not increased if Immediate delivery*/ iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn); - pdu->cmdsn = iscsi->cmdsn; if (!iscsi->user[0]) { iscsi->current_phase = ISCSI_PDU_LOGIN_CSG_OPNEG; @@ -1284,7 +1283,6 @@ iscsi_logout_async(struct iscsi_context *iscsi, iscsi_command_cb cb, /* cmdsn is not increased if Immediate delivery*/ iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn); - pdu->cmdsn = iscsi->cmdsn; pdu->callback = cb; pdu->private_data = private_data; diff --git a/lib/nop.c b/lib/nop.c index 701f31a..e010673 100644 --- a/lib/nop.c +++ b/lib/nop.c @@ -55,8 +55,8 @@ iscsi_nop_out_async(struct iscsi_context *iscsi, iscsi_command_cb cb, /* lun */ iscsi_pdu_set_lun(pdu, 0); - iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn); - pdu->cmdsn = iscsi->cmdsn++; + /* cmdsn */ + iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn++); pdu->callback = cb; pdu->private_data = private_data; @@ -112,7 +112,6 @@ iscsi_send_target_nop_out(struct iscsi_context *iscsi, uint32_t ttt) /* cmdsn is not increased if Immediate delivery*/ iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn); - pdu->cmdsn = iscsi->cmdsn; if (iscsi_queue_pdu(iscsi, pdu) != 0) { iscsi_set_error(iscsi, "failed to queue iscsi nop-out pdu"); diff --git a/lib/pdu.c b/lib/pdu.c index d363cfa..d6b09ca 100644 --- a/lib/pdu.c +++ b/lib/pdu.c @@ -625,6 +625,7 @@ void iscsi_pdu_set_cmdsn(struct iscsi_pdu *pdu, uint32_t cmdsn) { scsi_set_uint32(&pdu->outdata.data[24], cmdsn); + pdu->cmdsn = cmdsn; } void diff --git a/lib/socket.c b/lib/socket.c index 803917e..dd2e4bb 100644 --- a/lib/socket.c +++ b/lib/socket.c @@ -97,7 +97,7 @@ iscsi_add_to_outqueue(struct iscsi_context *iscsi, struct iscsi_pdu *pdu) */ if (pdu->outdata.data[0] & ISCSI_PDU_IMMEDIATE) { - pdu->cmdsn = current->cmdsn; + iscsi_pdu_set_cmdsn(pdu, current->cmdsn); } do { diff --git a/lib/task_mgmt.c b/lib/task_mgmt.c index 0847103..237ccad 100644 --- a/lib/task_mgmt.c +++ b/lib/task_mgmt.c @@ -73,7 +73,6 @@ iscsi_task_mgmt_async(struct iscsi_context *iscsi, /* cmdsn is not increased if Immediate delivery*/ iscsi_pdu_set_cmdsn(pdu, iscsi->cmdsn); - pdu->cmdsn = iscsi->cmdsn; /* rcmdsn */ iscsi_pdu_set_rcmdsn(pdu, rcmdsn);