[ENBD] 2.4.32

[Peter T. Breuer]

"Also sprach Tad Kollar:"
> Okay, not a problem, I moved the declaration to the beginning of
> do_srv_write and reran the test using XFS and doing a cp -a of
> /usr/src/linux-2.6.1. Syslog attached as syslog6.gz.

Beautiful. If that is the case, the proof is definitive:

 Feb  5 08:05:23 gmass4 enbd-server: enbd-server  9761: <#1316>
 do_srv_write req 
 seqno 1 from 0x7e00 len 512 with 0 emitted,
 got 512 from net making 512 tot/512 rem 

It was actually dealing with a request of length 512B.  Your kernel
seems to emit them, at least from the xfs file system.  It is possible,
since request counts are in sectors, but "block devices" are supposed to
work in blocks, and the blocksize of the enbd device under your xfs file
system must have been at least 1024 (in fact I see it was 4096 from the
startup messages), so "Nobody Ought To Dave Dang Gone Done That" (TM).

I'm not sure if that is a kernel bug. Should one report it or allow it?
The gentlemanly thing is to take care of it oneself in an application.

In this case, the code has seen that it has no hope of getting a full
block from the request, and has given up and passed on what it had.



> took awhile to get back, yesterday and today I'm juggling a lot
> of different stuff.

That's OK. Very interesting log. Further down there is this amazing
sequence:

  Feb  5 08:07:16 gmass4 enbd-server: enbd-server  9761: <#1292>
  do_srv_write  PTB
  we expect more, go round and read again 
  Feb  5 08:07:16 gmass4 enbd-server: enbd-server  9761: <#1294>
  do_srv_write  TJK
   Req seqno 156699, got 2896 from net making 2896/131072 total buffered 


Wow!  This request appears to have been for 131072 = 128 * 1024 bytes
and we found 2896 of then in the pipe.  That is 2*1448, or two ethernet
tcp packet payloads (I believe).

I see nothing indicating the write, but I assume that it went on to get
another 1448 bytes in another read, and then wrote 4096 bytes back out.
Somehow it avoiding making noise in its subsequent read/write cycles
for at least a while. 

The interest is in the fact that the socket contained TWO tcp packet
payloads. Either we are slow at reading it or two are sent at once.
My reading of the log is that the socket is often fuller than 1448
(indeed very often fuller than 4096) and the incoming requests are
often also large.

What is also striking is that some of these writes are also
sector-aligned, not block aligned.


  Feb  5 08:07:31 gmass4 enbd-server: enbd-server  9761: <#1324>
  do_srv_write write to nonblock offset 0x13153f7200 (81960858112) seqno 156703 len 11048 
  Feb  5 08:07:31 gmass4 enbd-server: enbd-server  9761: <#1324> do_srv_write write to nonblock offset 0x13153f9200 (81960866304) seqno 156703 len 0 


(I suspect that printout statement is still erronious - "len 0" indeed!)


  Feb  5 08:07:31 gmass4 enbd-server: enbd-server  9761: <#1324> do_srv_write write to nonblock offset 0x13153fc200 (81960878592) seqno 156704 len 28424 

It wuld be useful to have the more elaborate reporting from the "TJK
Req seqno ..." message there. I'm satisfied that there really are
requests of size 512. What I'm not clear about is 

  a) if there are requests for other odd multiples of 512
  b) if there are requests that are aligned on odd multiples of 512

Could you put right at the front of the routine something like the test
for alignment that occurs later on just before the write?


   if (request->from % self->blksize != 0) {
           PERR ("request for nonblock offset %#Lx (%Ld) seqno %d len %d\n",
              request->from, request->from, request->seqno, request->len);
   }
   if (request->len % self->blksize != 0) {
           PERR ("request for nonblock length %#Lx (%Ld) seqno %d len %d\n",
              request->from, request->from, request->seqno, request->len);
   }




Peter