Re: SRP timeout

On Tue, Jun 22, 2010 at 11:25 AM, Matthew Lowe <[email protected]> wrote:
> SRP 0x1d9d4 TX request tag 00000000000000000000001b SRP 0x1d9d4 socket closed: Connection timed out (0x4c206035)

11:31 < stefanha> gpxebot: error 0x4c206035
11:31 < gpxebot> pxenv_status=PXENV_STATUS_TFTP_READ_TIMEOUT uniq=0
errfile=ERRFILE_ib_mi
                 posix_errno=ETIMEDOUT

gpxe/src/net/infiniband/ib_mi.c:
static void ib_mi_timer_expired ( struct retry_timer *timer, int expired ) {

gPXE is giving up.

> The Linux box is a little more helpful. As we can see below, the connection is established just fine, but eventually times out on this end too.
[..]
> [24923.754700] [19451]: scst: scst_register_target:469:Target ib_srpt_target_4 (rel ID 5) for template ib_srpt registered successfully
> [24955.191467] ib_srpt: Received SRP_LOGIN_REQ with i_port_id 0x0:0x2c9020021b829, t_port_id 0x2c9020021b8d0:0x2c9020021b8d0 and it_iu_len 80 on port 1 (guid=0xfe80000000000000:0x2c9020021b8d1)

The target receives the login request and sets up the new session...

> [24955.192272] [1207]: scst: scst_init_session:6166:Using security group "Default" for initiator "0x00000000000000000002c9020021b829"
> [24955.192282] [1207]: scst_alloc_add_tgt_dev:2976:Device vdisk0 on SCST lun=0
> [24955.192290] [1207]: scst_alloc_set_UA:6004:Adding new UA to tgt_dev ffff8800d77928a0
> [24955.192537] [19457]: scst: scst_cmd_thread:4171:Processing thread vdisk00_0 (PID 19457) started
> [24955.192546] [19457]: scst_cmd_thread:4192:Alloced new IO context ffff88004b1bfbd0 (p_cmd_threads ffff8800d7792990)
> [24955.192573] [19458]: scst: scst_cmd_thread:4171:Processing thread vdisk00_1 (PID 19458) started
> [24955.192576] [19458]: scst_cmd_thread:4211:Linked IO context ffff88004b1bfbd0 (p_cmd_threads ffff8800d7792990)
> [24955.192588] [19459]: scst: scst_cmd_thread:4171:Processing thread vdisk00_2 (PID 19459) started
> [24955.192591] [19459]: scst_cmd_thread:4211:Linked IO context ffff88004b1bfbd0 (p_cmd_threads ffff8800d7792990)
> [24955.192599] [19460]: scst: scst_cmd_thread:4171:Processing thread vdisk00_3 (PID 19460) started
> [24955.192601] [19460]: scst_cmd_thread:4211:Linked IO context ffff88004b1bfbd0 (p_cmd_threads ffff8800d7792990)
> [24955.192612] [19461]: scst: scst_cmd_thread:4171:Processing thread vdisk00_4 (PID 19461) started
> [24955.192615] [19461]: scst_cmd_thread:4211:Linked IO context ffff88004b1bfbd0 (p_cmd_threads ffff8800d7792990)
> [24955.192622] [19462]: scst: scst_cmd_thread:4171:Processing thread vdisk00_5 (PID 19462) started
> [24955.192625] [19462]: scst_cmd_thread:4211:Linked IO context ffff88004b1bfbd0 (p_cmd_threads ffff8800d7792990)
> [24955.192637] [19463]: scst: scst_cmd_thread:4171:Processing thread vdisk00_6 (PID 19463) started
> [24955.192641] [19463]: scst_cmd_thread:4211:Linked IO context ffff88004b1bfbd0 (p_cmd_threads ffff8800d7792990)
> [24955.192659] [19464]: scst: scst_cmd_thread:4171:Processing thread vdisk00_7 (PID 19464) started
> [24955.192663] [19464]: scst_cmd_thread:4211:Linked IO context ffff88004b1bfbd0 (p_cmd_threads ffff8800d7792990)
> [24967.090591] ib_srpt: Received SRP_LOGIN_REQ with i_port_id 0x0:0x2c9020021b829, t_port_id 0x2c9020021b8d0:0x2c9020021b8d0 and it_iu_len 80 on port 1 (guid=0xfe80000000000000:0x2c9020021b8d1)

gPXE doesn't notice that the session has been started.  It retransmits
the login request.

Building with DEBUG=ib_mi:3 would show the management interface debug
messages from gPXE.  I wonder if whether gPXE sees the reply but
discards it or doesn't see the reply at all.

Stefan

------------------------------------------------------------------------------
ThinkGeek and WIRED's GeekDad team up for the Ultimate 
GeekDad Father's Day Giveaway. ONE MASSIVE PRIZE to the 
lucky parental unit.  See the prize list and enter to win: 
http://p.sf.net/sfu/thinkgeek-promo