Re: SCSI problems with SANE 1.0.5, Linux 2.4.x and double buffering

From: abel deuring (a.deuring@satzbau-gmbh.de)
Date: Sat Jul 07 2001 - 10:31:58 PDT

  • Next message: Henning Meier-Geinitz: "Re: SCSI problems with SANE 1.0.5, Linux 2.4.x and double buffering"

    Henning Meier-Geinitz wrote:
    >
    > Hi,
    >
    > I got several reports of SCSI problems with Mustek scanners in the
    > last days. I don't think that these are mustek-bugs. The bug reporters
    > provided the following common facts:
    >
    > * Linux 2.4.x
    > * a SCSI controller that has a queue depth of 1 (e.g. Adaptec 1520)
    > * SuSe 7.x (may be coincidence)
    >
    > They tried to scan an image but they only get the first stripe of
    > aprox. 64k that is repeated until the page is completely scanned. The
    > scanner stops after this first stripe. Sometimes the system freezes
    > completely, sometimes there is only an error message and sometimes no
    > error is output at all.
    >
    > I tried to reproduce this bug but couldn't until I did the following:
    > rename /usr/include/scsi/sg.h to something else. After recompile
    > sanei_scsi.c seems to use the kernel headers from /usr/src/linux
    > (which are the right ones for my current kernel 2.4.5). I'm using
    > Debian 2.2.
     
    So the error does not occur, if /usr/include/scsi/sg.h exists? (for
    more, see below)

                                                                                 
    [...]
    > [mustek] SANE mustek backend version 1.0 build 107 from sane-backends-1.0.5
    > [...]
    > [sanei_scsi] sanei_scsi_open: sanei_scsi_max_request_size=131072 bytes
    > [sanei_scsi] sanei_scsi_open: SG driver version: 30117
    > [sanei_scsi] sanei_scsi_open_extended: using 8192 bytes as SCSI buffer
    > [sanei_scsi] trying to enable low level command queueing
    > [sanei_scsi] sanei_scsi_open: Host adapter queue depth: 1
    > [sanei_scsi] sanei_scsi_open: SG driver can change buffer size at run time
    > [sanei_scsi] sanei_scsi_open: using new SG header structure
    > --- The last line isn't printed if I use /usr/include/scsi/sg.h
     
    This means that /usr/include/scsi/sg.h does not define SG_IO and other
    stuff necessary for SG driver 3.x. In this case, sanei_scsi.c is
    compiled only for SG 2.x. Since the newer SG drivers support the old
    interface too, everything should work -- but the new interface is much
    more "clean": It does not need to guess the size of a SCSI command
    block; sanei_scsi_req_enter does not need to copy command block and
    write data into a new buffer which starts with the old SG header.
    Douglas Gilbert can certainly name a few other advances :)
     
    So, if the error does occur, if /usr/include/scsi/sg.h exists, this
    might point to a problem in the parts of the SG driver for the new
    header structure ... or we have indeed a nasty bug in the queue
    management of sanei_scsi.c . I'll try to reproduce the problems
    tomorrow.
     
    > [...]
    > [mustek] attach: sending INQUIRY
    > [sanei_scsi] scsi_req_enter: entered 0x80f6d88
    > [sanei_scsi] sanei_scsi.issue: 0x80f6d88
    > dev_max(currently)=7 max_active_device=1 (origin 1)
    > scsi_dma_free_sectors=48 sg_pool_secs_aval=320 def_reserved_size=32768
    > >>> device=sg0 scsi0 chan=0 id=6 lun=0 em=0 sg_tablesize=255 excl=1
    > FD(1): timeout=600000ms bufflen=8192 (res)sgat=0 low_dma=0
    > cmd_q=1 f_packid=0 k_orphan=0 closed=0
    > rb>> rcv: id=0 blen=96 dur=10ms sgat=0 op=0x12
    > --- Where does this come from? I can't find it in sanei_scsci.c.
     
    That's in function issue:
     
      IF_DBG(if (DBG_LEVEL >= 255) system("cat /proc/scsi/sg/debug 1>&2");)
     
    It was suggested by Douglas. The idea is to have debug information from
    Sane and from the SG driver in one place.

    > [...]
    > [mustek] sane_start
    > [...]
    > [mustek] reader_process: buffer 1: entering read request for 64470 bytes (buffer 1)
    > [...]
    > [mustek] reader_process: buffer 1: entered (line 35 of 995, buffer 1)
    > [mustek] reader_process: buffer 2: entering read request for 64470 bytes (buffer 2)
    > [...]
    > [sanei_scsi] scsi_req_enter: entered 0x81d4150
    > [sanei_scsi] sanei_scsi.issue: 0x81d4150
    > [sanei_scsi] scsi_req_enter: queue_used: 1, queue_max: 1
    > [mustek] reader_process: buffer 2: entered (line 70 of 995, buffer 2)
    > [mustek] reader_process: buffer 1: waiting for request to be ready
    > [sanei_scsi] sanei_scsi_req_wait: waiting for 0x81b2d58
    > [sanei_scsi] sanei_scsi.issue: 0x81b2d58
    > dev_max(currently)=7 max_active_device=1 (origin 1)
    > scsi_dma_free_sectors=48 sg_pool_secs_aval=320 def_reserved_size=32768
    > >>> device=sg0 scsi0 chan=0 id=6 lun=0 em=0 sg_tablesize=255 excl=1
    > FD(1): timeout=600000ms bufflen=131072 (res)sgat=4 low_dma=0
    > cmd_q=1 f_packid=0 k_orphan=0 closed=0
    > rb>> rcv: id=14 blen=64470 dur=2690ms sgat=2 op=0x08
    > [sanei_scsi] sanei_scsi.issue: 0x81d4150
    > dev_max(currently)=7 max_active_device=1 (origin 1)
    > scsi_dma_free_sectors=48 sg_pool_secs_aval=320 def_reserved_size=32768
    > >>> device=sg0 scsi0 chan=0 id=6 lun=0 em=0 sg_tablesize=255 excl=1
    > FD(1): timeout=600000ms bufflen=131072 (res)sgat=4 low_dma=0
    > cmd_q=1 f_packid=0 k_orphan=0 closed=0
    > rb>> rcv: id=15 blen=64470 dur=0ms sgat=2 op=0x83
    > [sanei_scsi] sanei_scsi_req_wait: read 64 bytes
    > --- Why is this only 64 bytes (that's printed for every req_wait even
    > if the buffer is much bigger)?
     
    The "meaning" of the value returned by a read from an SG device changed
    with SG version 3.x. For SG version 1.x and 2.x, all information to be
    sent to/read from the device (SCSI command, read/write data, sense
    buffer, and a handful of status fields) is stuffed into one buffer.
    Accordingly read/write for an SG device return the size of this buffer.
    The SG drivers 3.x use a new header structure, which contains pointers
    to separate buffers for SCSI command, read/write data and sense buffer.
    Hence, read/write calls look like:
     
            Sg_io_hdr cmd;
            /* setup the data for cmd */
            write(fd, &cmd, sizeof(Sg_io_hdr));
            read(fd, &cmd, sizeof(Sg_io_hdr));
     
    regardless of the size of the read/write buffer, the calls return simply
    sizeof(Sg_io_hdr) (unless an error occurs).

    > [mustek]
    reader_process: buffer 1 is ready, wanted 64470, got 64470 bytes
    > [mustek] reader_process: buffer 1: sending 64470 bytes to output_data
    > [...]
    > [mustek] reader_process: buffer 1: entering read request for 64470 bytes (buffer 3)
    > [...]
    >
    > This goes on until the full page is scanned. No error occurs but the
    > resulting image conatines the first buffer over and over again.
    >
    > >From a bug-reporter I got a debug log that's a bit different:
    >
    > [...]
    > [sanei_scsi] sanei_scsi.issue: 0x80bcef0
    > dev_max(currently)=9 max_active_device=3 (origin 1)
    > scsi_dma_free_sectors=144 sg_pool_secs_aval=320 def_reserved_size=32768
    > >>> device=sg0 scsi0 chan=0 id=6 lun=0 em=0 sg_tablesize=255 excl=1
    > FD(1): timeout=600000ms bufflen=131072 (res)sgat=4 low_dma=0
    > cmd_q=1 f_packid=0 k_orphan=0 closed=0
    > rb>> act: id=12 blen=44208 t_o/elap=600000/40ms sgat=2 op=0x53
    > [sanei_scsi] sanei_scsi_req_wait: read 64 bytes
    > [sanei_scsi] sanei_scsi_req_wait: SCSI command complained: Success
    > [sanei_scsi] sense buffer: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
    > [sanei_scsi] target status: 00 host status: 0007 driver status: 0000
    > [mustek] sense_handler: got sense code 00 for fd 7 (arg = null)
    > [...]
    > [mustek] reader_process: buffer 1: waiting for request to be ready
    > [sanei_scsi] sanei_scsi_req_wait: waiting for 0x80bcef0
    > [sanei_scsi] sanei_scsi.issue: 0x80bcef0
    > dev_max(currently)=9 max_active_device=3 (origin 1)
    > scsi_dma_free_sectors=144 sg_pool_secs_aval=320 def_reserved_size=32768
    > >>> device=sg0 scsi0 chan=0 id=6 lun=0 em=0 sg_tablesize=255 excl=1
    > FD(1): timeout=600000ms bufflen=131072 (res)sgat=4 low_dma=0
    > cmd_q=1 f_packid=0 k_orphan=0 closed=0
    > rb>> rcv: id=12 blen=44208 dur=260ms sgat=2 op=0x53
    > [sanei_scsi] sanei_scsi.issue: 0x80e3710
    > dev_max(currently)=9 max_active_device=3 (origin 1)
    > scsi_dma_free_sectors=144 sg_pool_secs_aval=320 def_reserved_size=32768
    > >>> device=sg0 scsi0 chan=0 id=6 lun=0 em=0 sg_tablesize=255 excl=1
    > FD(1): timeout=600000ms bufflen=131072 (res)sgat=4 low_dma=0
    > cmd_q=1 f_packid=0 k_orphan=0 closed=0
    > rb>> act: id=13 blen=44208 t_o/elap=600000/30ms sgat=2 op=0x53
    > [sanei_scsi] sanei_scsi_req_wait: read 64 bytes
    > [sanei_scsi] sanei_scsi_req_wait: SCSI command complained: Success
    > [sanei_scsi] sense buffer: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
    > [sanei_scsi] target status: 00 host status: 0001 driver status: 0000
    > [mustek] reader_process: failed to read data, status: Device busy, buffer: 1
    > [...]
    >
    > --- What's this funny error message?
     
    No idea...
     
    Abel

    --
    Source code, list archive, and docs: http://www.mostang.com/sane/
    To unsubscribe: echo unsubscribe sane-devel | mail majordomo@mostang.com
    



    This archive was generated by hypermail 2b29 : Sat Jul 07 2001 - 09:14:00 PDT