Pete Wyckoff wrote: > erezz at voltaire.com wrote on Sun, 12 Aug 2007 17:03 +0300: > >> I ran the following command: >> >> sgp_dd bs=512 of=/dev/null if=/dev/sg3 bpt=256 thr=8 time=1 count=8000 >> >> and got the following error: >> > > I'm on travel this week, but want to fix this! Everything works > here unfortunately. WC status 10 == IBV_WC_REM_ACCESS_ERR, which > means that the other side was somehow unhappy. Maybe wrong rkey. > We've never seen that error, even in testing, so I will probably ask > you for more debugging information on both sides. > > If you are motivated, you might check the key and VA that appears > in the initiator request and make sure the target tries to use those > same values when it does RDMA. > Pete, I went over the iSER target code, and something looks strange (unless I'm missing something here): iscsi_iser_read calls iser_parse_hdr, which reads the iSER header and saves the remote va & stag on the conn_info object. Later, iser_rdma_read/write is called (from another context?), and uses the remote va & stag. The problem that I see is: what happens if another cmd is received before RDMA read/write is performed for the 1st cmd? I can see that on the log file: The last 3 cmds that were received have stags 6004a, 6004b & 6004c respectively. [iSER]:iSCSI control type PDU. [iSER]:rem_write_stag 6004a rem_write_va 69cea000. [iSER]:iscsi_iser_read ret 48. tgtd: iscsi_scsi_cmd_rx_start(1462) 1 2a 0 8192 131072 1 42 [iSER]:meml 0x634d88 buf 0x2aaaaad30010. tgtd: iscsi_scsi_cmd_rx_start(1489) 0 122880 0 8192 [iSER]:in iscsi_iser_read buf 0x2aaaaad302b0 nbytes 8192. [iSER]:iscsi_iser_read ret 8192. tgtd: iscsi_task_queue(1403) 42 42 1 tgtd: iser_event_modify(1435) ep 0 events 5 tgtd: iser_event_modify(1442) ep 0 was already on the list. Track? [iSER]:handle_wc() Done processing recv 0x642228, reposted it. [iSER]:handle_wc() Incoming Cmd - COMPLETE (8268 bytes). [iSER]:in iscsi_iser_read buf 0x636eb0 nbytes 48. [iSER]:iSCSI control type PDU. [iSER]:rem_write_stag 6004b rem_write_va 6a74a000. [iSER]:iscsi_iser_read ret 48. tgtd: iscsi_scsi_cmd_rx_start(1462) 1 2a 0 8192 131072 1 43 [iSER]:meml 0x634da0 buf 0x2aaaaadb1010. tgtd: iscsi_scsi_cmd_rx_start(1489) 0 122880 0 8192 [iSER]:in iscsi_iser_read buf 0x2aaaaadb12b0 nbytes 8192. [iSER]:iscsi_iser_read ret 8192. tgtd: iscsi_task_queue(1403) 43 43 1 tgtd: iser_event_modify(1435) ep 0 events 5 tgtd: iser_event_modify(1442) ep 0 was already on the list. Track? [iSER]:handle_wc() Done processing recv 0x6432f8, reposted it. [iSER]:handle_wc() Incoming Cmd - COMPLETE (8268 bytes). [iSER]:in iscsi_iser_read buf 0x636eb0 nbytes 48. [iSER]:iSCSI control type PDU. [iSER]:rem_write_stag 6004c rem_write_va 6a18a000. [iSER]:iscsi_iser_read ret 48. Later, RDMA read is performed for the cmds. For all cmds, the stag is 6004c - just like the last stag that was received: [iSER]:in iser_rdma_read. [iSER]:in iser_post_rdma_wr size 122880 rem_va 6a18a000 rem_stag 6004c wr_id = 0x63f010 (itt = 0x3d) . [iSER]:iser_post_rdma_wr() Exit rdma = 0x63f010. tgtd: iser_progress(1382) trying tx on fd 0 conn 0x636d90 tgtd: iscsi_task_tx_start(1750) found a task 3e 131072 8192 122880 [iSER]:in iser_rdma_read. [iSER]:in iser_post_rdma_wr size 122880 rem_va 6a1a8000 rem_stag 6004c wr_id = 0x63f090 (itt = 0x3e) . [iSER]:iser_post_rdma_wr() Exit rdma = 0x63f090. tgtd: iser_progress(1382) trying tx on fd 0 conn 0x636d90 tgtd: iscsi_task_tx_start(1750) found a task 3f 131072 8192 122880 [iSER]:in iser_rdma_read. [iSER]:in iser_post_rdma_wr size 122880 rem_va 6a1c6000 rem_stag 6004c wr_id = 0x63f110 (itt = 0x3f) Erez |