Bug 873800

Created attachment 639503 [details]
20121106 virtual client log for qemu-kvm el6_3.5.hdg2

Hi Hans,

I've installed the new qemu-kvm packages and retried flashing the magelan 8200 scanner, failed at 3%.

Log file attached.

Kind regards,
Thorsten

I'm afraid the new log file does not give me any additional hints. I think the best way forward is to arrange ne getting physical access to one of the trouble some devices.

Created attachment 646282 [details]
20121115 Comparison success/fail of configuration flashing (DSO+Log)

Hi Hans,

same file I send earlier today via mail.

Kind regards,
Thorsten

(In reply to comment #4)
> Created attachment 646282 [details]
> 20121115 Comparison success/fail of configuration flashing (DSO+Log)

Hmm, ok 2 things:

1) It seems to be using rts/cts flowcontrol, but, but the serial port pass-through of
qemu will not pass this through, where as the  pl2303 does support hardware
flowcontrol at the hardware level, and usb pass-through will pass this through,
so this does not seem to be a flow control issue.

2) Matching up this info with the "20121106 virtual client log for qemu-kvm el6_3.5.hdg2"
info, I think I know what is going on. Looking in the qemu log with usb debug output
you attached, it seems that for some reason the windows driver for the pl2303, is
only sending 1 byte per usb-packet.  Which makes things very slow, at which point
the barcode scanner times out, and sends a status byte with an error code
(and asserts cts, but that is a side effect of the timeout I believe, as we're going
way slower then the working setup).

So 2 questions:
1) Can you do an install of Fedora-17 on some hardware, then enable the virt-preview
repository: http://fedoraproject.org/wiki/Virtualization_Preview_Repository
And try again, both with the aten and the ftdi convertor.

2) The logs of the qemu build with usb debuginfo from comment #2 are of a
flash attempt with the aten convertor, can you please make similar logs
while using the ftdi convertor ?

Hi Hans,

I've tested a lot of combinations lately the ones included in the PDF are only FTDI ones. I felt it might be easier to compare things if the hardware is the same.

Details
========
The 20121115_Result.PDF (attachment 646282 [details]) from comment #2 contains these setups:
  page 1:
    Digital Storage Osci native Windows 7 
     FTDI chipset <====  Sorry, I did not mention this !
    DSO KVM Win 7 
     FTDI chipset, spice USB redirection <=== did not mention
  page 2:
    DSO native Windows 7
      FTDI chipset <===
    DSO KVM Windows 7
      FTDI chipset, spice USB redirection <===
  page 3,4:
    Serial communication log
      First line says "native Windows" <=== that's wrong
      Third line says "KVM Win7"  <=== that's right
      FTDI chipset <===
      Linux device /dev/ttyUSB0 "hard linked" / redirected directly as virtual qemu serial device "COM2" using virt-manager machine virtual hardware details.
  page 5,6
    Serial communication log
      KVM Win7 
      FTDI via SPICE USB redirection <====

Bottom line
============
  * only using the FTDI device "Lenovo Brainboxes VX001" here 
  * using FTDI device with different setup combinations,

Kind regards,
Thorsten

Hi Hans,

FEDORA 17 test done. I tried all combinations I could think of using my three NetMos9922, FTDI and PL2303 serial adapters.

Installation
=============
 1. F17 standard
 2. installed qemu-kvm + virt-manager + ... 
 3. copied virtual machine's raw drive image
 4. dumped config, copied xml to F17 system and did minor changes to get it running on F17
 5. included virtualization preview repo & updated
 6. applied updates / win drivers in virtual machine


Tests & Results
================
#1 NetMos9922 - PASSED
Hardware:      SYBA SD-EXP15005 express card
Redirection:   defined /dev/ttyS1 as virtual serial device
Communication: PASSED - device information read (firmware, S/N, ...)
Flash config:  PASSED - configuration successfully flashed with 115200N8

#2a FDTI via /dev/ttyUSB0 - PASSED
Hardware:      Lenovo Brainboxes VX001
Redirection:   defined /dev/ttyUSB0 as virtual serial device
Communication: PASSED - device information read (firmware, S/N, ...)
Flash config:  PASSED - configuration successfully flashed with 115200N8

#2b FDTI with SPICE - FAILED (but device was detected)
Hardware:      Lenovo Brainboxes VX001
Redirection:   used spice USB device redirection in virt-viewer
Communication: PASSED - device information read (firmware, S/N, ...)
Flash config:  FAILED - could not get pass 3% regardless of baud rate 
                        (tried 9600 8N1 and 115200 8N1)

#3a PL2303 via /dev/ttyUSB0 - FAILED
Hardware:      ATEN UC232A
Redirection:   defined /dev/ttyUSB0 as virtual serial device
Communication: FAILED - device was not detected, no information read
                        The Magelan 8200 scanner detected CTS signal change.
Flash config:  %      - no device, could not test

#3b PL2303 via SPICE - FAILED
Hardware:      ATEN UC232A
Redirection:   used spice USB device redirection in virt-viewer
Communication: FAILED - device was not detected, no information read
                        The Magelan 8200 scanner detected CTS signal change.
Flash config:  %      - no device, could not test


General remark: 
FYI: first I did the same tests on the fresh installed F17 without the virtualization preview repo included and got the same results. Did the test again after reading your post.

Kind regards,
Thorsten

Hi,

(In reply to comment #6)
> I've tested a lot of combinations lately the ones included in the PDF are
> only FTDI ones. I felt it might be easier to compare things if the hardware
> is the same.

Ok, thanks for clarifying

(In reply to comment #7)
> Hi Hans,
> 
> FEDORA 17 test done. I tried all combinations I could think of using my
> three NetMos9922, FTDI and PL2303 serial adapters.
> 
> Installation
> =============
>  1. F17 standard
>  2. installed qemu-kvm + virt-manager + ... 
>  3. copied virtual machine's raw drive image
>  4. dumped config, copied xml to F17 system and did minor changes to get it
> running on F17
>  5. included virtualization preview repo & updated
>  6. applied updates / win drivers in virtual machine
> 
> 
> Tests & Results
> ================
> #1 NetMos9922 - PASSED
> Hardware:      SYBA SD-EXP15005 express card
> Redirection:   defined /dev/ttyS1 as virtual serial device
> Communication: PASSED - device information read (firmware, S/N, ...)
> Flash config:  PASSED - configuration successfully flashed with 115200N8
> 
> #2a FDTI via /dev/ttyUSB0 - PASSED
> Hardware:      Lenovo Brainboxes VX001
> Redirection:   defined /dev/ttyUSB0 as virtual serial device
> Communication: PASSED - device information read (firmware, S/N, ...)
> Flash config:  PASSED - configuration successfully flashed with 115200N8
> 
> #2b FDTI with SPICE - FAILED (but device was detected)
> Hardware:      Lenovo Brainboxes VX001
> Redirection:   used spice USB device redirection in virt-viewer
> Communication: PASSED - device information read (firmware, S/N, ...)
> Flash config:  FAILED - could not get pass 3% regardless of baud rate 
>                         (tried 9600 8N1 and 115200 8N1)
> 
> #3a PL2303 via /dev/ttyUSB0 - FAILED
> Hardware:      ATEN UC232A
> Redirection:   defined /dev/ttyUSB0 as virtual serial device
> Communication: FAILED - device was not detected, no information read
>                         The Magelan 8200 scanner detected CTS signal change.
> Flash config:  %      - no device, could not test
> 
> #3b PL2303 via SPICE - FAILED
> Hardware:      ATEN UC232A
> Redirection:   used spice USB device redirection in virt-viewer
> Communication: FAILED - device was not detected, no information read
>                         The Magelan 8200 scanner detected CTS signal change.
> Flash config:  %      - no device, could not test

Ok,

So given the above test results + the qemu logs, etc. I think we can come to the following conclusions:

1) Using the ATEN UC232A serial does not seem to work at all (iirc not even when running windows natively, correct?)

2) Using serial-port pass-through works as long as we've a working serial-port adapter in the first place

3) Using the FTDI works in serial-port pass-through mode but not in usb pass-through mode.


3 Can be explained by the following:

Given the qemu logs I suspected already that the windows FTDI driver uses only one bulk transfer and reuses that all the time rather then queuing up multiple transfers, and the test with Fedora-17 which supports bulk out pipelining confirm this.

So what is happening is;
1) The magelan firmware flashing tool is written sub-optimal and is passing data a byte at a time to the Windows serial layer
2) This causes the FTDI windows driver to send single byte bulk transfers, which means a lot of overhead per byte!
3) Since the FTDI driver uses only a single bulk URB / transfer, it will send 1 byte, wait for it to get the urb back (so for the transfer to be completed) and then reuse it, putting a lot of time between each byte, given the regular pattern in the messages in qemu.log:

qemu-kvm: bulk data out: 00

qemu-kvm: usb-redir: bulk-in status 0 ep 02 len 1 id 594

qemu-kvm: usb-redir: interrupt-token-in ep 81, no intp

qemu-kvm: usb-redir: interrupt-token-in ep 81, no intp

qemu-kvm: usb-redir: interrupt-token-in ep 81, no intp

qemu-kvm: usb-redir: bulk-out ep 02 len 1 id 595

qemu-kvm: bulk data out: 60

qemu-kvm: usb-redir: bulk-in status 0 ep 02 len 1 id 595

qemu-kvm: usb-redir: interrupt-token-in ep 81, no intp

qemu-kvm: usb-redir: interrupt-token-in ep 81, no intp

qemu-kvm: usb-redir: interrupt-token-in ep 81, no intp

qemu-kvm: usb-redir: bulk-out ep 02 len 1 id 596

qemu-kvm: bulk data out: 89

...

I would say at least 3 ms between each byte! As the interrupt ep gets polled 1000/sec. One weird thing
is that the completion, signaled by the "usb-redir: bulk-in" messages in the log happens "immediately" after the submission "usb-redir: bulk-out" messages, yet then it takes Windows 2-3 ms to resubmit the next transfer with the next byte

The slowness of windows to re-submit the transfer makes me think that we may have an uhci controller emulation bug biting us here, the only one I can think of which is fixed upstream but not in F-17 / virt-preview is this one: http://www.kraxel.org/cgit/qemu/commit/?h=usb.67&id=883bca776daa43111e9c39008f0038f7c62ae723

4) This slowness of the data transfer when using usb pass-through causes the scanner to time out.


The only problem with my slowness theory is that it does not explain why things fail at 9600 bps too. Thorsten, can you try flashing with a working setup (ie the FTDI adapter using serial pass-through, at 9600 bps ?  Maybe 9600 bps is broken in general, because the scanner timeout is too short ?

Hi Hans,

thank you for ideas, builds, discussions and explanations. I really enjoyed working with you and the Red Hat team.

Due to a new, internal political decision in 2013 this serial behaviour has become less important and I'm able to close this ticket accepting as-is.

Thank you,
Thorsten

Hi,

updating ticket because this bug has been set to "Need Info" today:

This issue/bug has lower priority compared with KVM and Wifi issues at the moment. Cannot spend much time on this one at the moment.

If you have a question, please feel free to ask.

Kind regards,
Thorsten