[sane-devel] Canon PIXMA MX870

[Louis Lagendijk]

On Sun, 2011-01-16 at 02:04 -0800, Kenton Varda wrote:
I leave your first question for Nicolas to answer. I don't understand
the backend well enough to dig into this part. sorry for the late reply,
I have been out of the country for a few days and busy with work...

> Unfortunately, there is another, less-deterministic problem.  It seems
> that the scanner very frequently refuses sane's TCP connections:
> 
> 
> [pixma] Reader task terminated
> Scanned page 1. (scanner status = 5)
> Scanning page 2
> [pixma] Reader task id=14568 (forked)
> [pixma] Reader task started
> [pixma] sanei_bjnp_activate (0)
> [pixma] udp_command: Sending UDP command to 10.0.1.22:8612
> [pixma] bjnp_open_tcp: Can not connect to scanner: Connection refused
> [pixma] sanei_bjnp_deactivate (0)
> [pixma] udp_command: Sending UDP command to 10.0.1.22:8612
> [pixma] [pixma] Reader task terminated: EINVAL
> read_image():reader task closed the pipe:0 bytes received, 10718400
> bytes expected
> scanimage: sane_read: Invalid argument
> Scanned page 2. (scanner status = 4)
> [pixma] pixma_close(): Canon PIXMA MX870
> [pixma] sanei_bjnp_close(0):
> 
> 
> It's hard to pin down a pattern describing when this happens, but:
> 
> 
> - It never happens if the scanner was just powered on (and had time to
> boot).  Or in other words, power cycling the scanner fixes problems,
> suggesting that the scanner is getting into a bad state.
> 
I have seen cases before where we got stuck opening a TCP connection
where the scanner got confused. Your guess is most likely correct.
> 
> - It always happens when the ADF runs out of paper.  sane appears to
> form a new connection for each page.  After the last page, sane tries
> to connect again even though there are no more pages, and this
> connection always fails AFAICT.  This causes scanimage to exit with an
> error code even though technically it completed its task successfully.
> 
> 
> - After having completed a batch, the scanner is sometimes (but not
> always) left in a state where all further connections are refused
> until the device is power-cycled.  Sometimes the device will recover
> from this state magically without a power cycle, if I retry a few
> times.  Sometimes running Scangear MP can revive the device from this
> state, but not always.
> 
> 
> - I changed the TCP connection code to retry once, and the result is
> even odder:  The retry sometimes succeeds, but then the scanner
> apparently does not reply to any requests on the new connection.
> 
I has a look at the bjnp code again, but can not check details as some
of the information is missing. Can you please get me a log file with
log-level 14 or (maybe even better) a wireshark trace? I am especially
interested to see what the "unknown1" value of the last UDP command is
before we try to open the TCP connection. I have never seen it set, but
that may be due to the fact that I don't have an ADF....It may be that
your scanner uses that unknown stuff to signal that is is not ready to
read more data. It may also be that we need to teach the higher level of
the backend when no more pages will be available. Does a USB connection
behave any better?
> 
> I tried comparing network dumps between SANE and Scangear MP, but they
> were completely different.  Scangear MP appears to make only one TCP
> connection for the whole batch, rather than one per page.
> 
That is due to the fact that the backend closes the bjnp connection
(like if does for the USB-connection).
> 
> Any ideas?
Please provide some detailed traces so we can see what is happening

best regards, Louis