testsuite: Validating header writes leads to unexpected FPRead failures

[rdmark]

While refactoring the afpcli API functions, I found a handful of functions that were hard coded to always return 0. This revealed a bug where AFPWriteHeader returns DSI errors during two stress tests in FPRead:

FPRead:test309: FPRead, FPWrite deadlock
FPRead:test327: FPRead, FPWrite deadlock

############## entering test309 ##############
[FPCreateFile] Create File SOFT Vol 256 did : 0x2 <t309 FPRead,FPWrite deadlock>
[FPCreateFile] Create File SOFT Vol 256 did : 0x2 <t309 second file>
[FPopenLogin] Login Version: "AFP3.4" uam: "Cleartxt Passwrd" user: "atalk1"
[FPOpenVolFull] Open Vol test1 bitmap 21
[FPOpenFork] Open Fork data Vol 256 did : 0x2 <t309 FPRead,FPWrite deadlock> access 3
fork refnum ID 1
[FPOpenFork] Open Fork data Vol 256 did : 0x2 <t309 second file> access 3
fork refnum ID 2
[FPSetForkParam] Set Fork param fork 1 bitmap 0x200 size 1310720
[FPReadHeader] send read header fork 1  offset 0 size 1024
[FPReadHeader] send read header fork 1  offset 1024 size 1024
[FPReadHeader] send read header fork 1  offset 2048 size 1024
[FPReadFooter] get read reply fork 1  offset 0 size 1024
[FPReadHeader] send read header fork 1  offset 3072 size 1024
[FPReadHeader] send read header fork 1  offset 4096 size 1024
[FPReadHeader] send read header fork 1  offset 5120 size 1024
[FPReadHeader] send read header fork 1  offset 6144 size 1024
[FPReadHeader] send read header fork 1  offset 7168 size 1024
[FPReadHeader] send read header fork 1  offset 8192 size 1024
[FPWriteHeader] send write header fork 2  offset 0 size 1024 from 0x0
header.dsi_code       12	
[../test/testsuite/FPRead.c:464] FPWriteHeader(dsi2, fork1, offset, size, Data, 0)
	FAILED
[FPWriteHeader] send write header fork 2  offset 1024 size 1024 from 0x0
header.dsi_code       12	
[../test/testsuite/FPRead.c:466] FPWriteHeader(dsi2, fork1, offset, size, Data, 0)
	FAILED
[FPWriteHeader] send write header fork 2  offset 2048 size 1024 from 0x0
header.dsi_code       12	
[../test/testsuite/FPRead.c:468] FPWriteHeader(dsi2, fork1, offset, size, Data, 0)
	FAILED
[FPWriteHeader] send write header fork 2  offset 3072 size 1024 from 0x0
header.dsi_code       12	
[../test/testsuite/FPRead.c:470] FPWriteHeader(dsi2, fork1, offset, size, Data, 0)
	FAILED
[FPReadFooter] get read reply fork 1  offset 1024 size 1024
[FPReadFooter] get read reply fork 1  offset 2048 size 1024
[FPReadFooter] get read reply fork 1  offset 3072 size 1024
[FPReadFooter] get read reply fork 1  offset 4096 size 1024
[FPReadFooter] get read reply fork 1  offset 5120 size 1024
[FPReadFooter] get read reply fork 1  offset 6144 size 1024
[FPReadFooter] get read reply fork 1  offset 7168 size 1024
[FPReadFooter] get read reply fork 1  offset 8192 size 1024
[FPWriteFooter] get write footer fork 2  offset 0 size 1024 from 0x0
[FPWriteFooter] get write footer fork 2  offset 1024 size 1024 from 0x0
[FPWriteFooter] get write footer fork 2  offset 2048 size 1024 from 0x0
[FPWriteFooter] get write footer fork 2  offset 3072 size 1024 from 0x0
[FPCloseFork] Close Fork 2
[FPCloseFork] Close Fork 1
[FPDelete] FPDelete conn 0x55ba2c35f390 Vol 256 did : 0x2 <t309 second file>
[FPDelete] FPDelete conn 0x55ba2c35f390 Vol 256 did : 0x2 <t309 FPRead,FPWrite deadlock>
FPRead:test309: FPRead, FPWrite deadlock - FAILED

[rdmark]

This function is used in exactly one other place in the codebase, namely in the AFP speedtest. The same DSI code 12 is encountered here too.

[FPWriteFooter] get write footer fork 1  offset 52428800 size 1048576 from 0x0
[FPWriteHeader] send write header fork 1  offset 53477376 size 1048576 from 0x0
header.dsi_code       12	

[rdmark]

Interestingly, the read/write header/footer protocol functions are not part of the AFP spec (as of 3.3). Seems to be interacting with the DSI header directly.

[rdmark]

Ok, the problem is obviously that the offset value of 12 is assigned to dsi_code inside AFPWriteHeader. I can't see how this would be correct, not least because it's not a valid AFP status code.

	dsi->datalen = ofs;		/* 12*/
	dsi->header.dsi_len = htonl(dsi->datalen +size);
	dsi->header.dsi_code = htonl(ofs);

Edit: Actually, this trick is used in multiple places across the testsuite. We also assign hard coded invalid AFP status codes in a few places. It's not clear if these are deliberate and testing something in particular.

[rdmark]

I have postponed the dsi_code cleanup. It triggered cascading failures in the lantest module.

[NJRoadfan]

DSIWrite() is only used by two AFP functions, the error field in the packet header is shared with the offset field (the definition switches if the packet is a response or a request). All FPWrite() requests should have the DSI header offset set to 12. This was the problem with ASC 3.7.4 with zero byte writes. It was setting the header offset to 0, when it should have been 12. For the record, per Apple's docs, the offset value on DSIWrite() requests commands should NEVER be zero.

This is the relevant text from Apple:

Error Code/Enclosed Data Offset: This field in the DSI header can take up a different role based on the command type and the message kind (either request or reply). In case of reply messages, this field will always carry an error code. On the other hand, in the request messages, except for the DSIWrite request, the server will ignore this field. However, in request messages, except for the DSIWrite request, clients should set this field to zero for future compatibility. The DSIWrite request will have an enclosed data offset in this field of DSI header. The enclosed data offset field, for DSIWrite requests, is the number of bytes in the data that represent AFP command information. This is used by the server to collect the AFP command part of the packet before accepting the data corresponding with that command. For example, when an FPWrite command is issued to write the data on the server, the enclosed data offset will be equal to 12.

[rdmark]

Discarding this. This code can probably be refactored to have a more consistent logical separation between return codes and DSI offsets, but I won't mess with it now.