Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Raspberry Pi 4 VL805 bulk transfer problem #458

Closed
charkster opened this issue Sep 4, 2019 · 23 comments
Closed

Raspberry Pi 4 VL805 bulk transfer problem #458

charkster opened this issue Sep 4, 2019 · 23 comments

Comments

@charkster
Copy link

charkster commented Sep 4, 2019

I am having a problem with query_binary_values() and read_raw() when downloading waveform or csv data from my Rigol DS1054Z. These commands run just fine on my RPi3, RPi2 and PC, but with the latest RPi4 (and the VL805) I am seeing errors.

Here is what I see from query_binary_values():

  File "test_print_screen.py", line 6, in <module>
    scope.write_screen_capture()
  File "/home/pi/python_code/rigol/rigol_ds1054z.py", line 120, in write_screen_capture
    raw_data_list = self.oscilloscope.query_binary_values(':DISP:DATA? ON,OFF,PNG')
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 703, in query_binary_values
    data_points, chunk_size)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 481, in read_binary_values
    block = self._read_raw(chunk_size)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 387, in _read_raw
    chunk, status = self.visalib.read(self.session, size)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/highlevel.py", line 345, in read
    ret = self.sessions[session].read(count)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/usb.py", line 111, in read
    usb.USBError)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/sessions.py", line 477, in _read
    current = reader()
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/usb.py", line 105, in <lambda>
    return self._read(lambda: self.interface.read(count),
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/protocols/usbtmc.py", line 338, in read
    response = BulkInMessage.from_bytes(resp)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/protocols/usbtmc.py", line 108, in from_bytes
    assert msgid == MsgID.dev_dep_msg_in
AssertionError

Here is what I see from read_raw():

Traceback (most recent call last):
  File "test_print_screen.py", line 6, in <module>
    scope.write_screen_capture()
  File "/home/pi/python_code/rigol/rigol_ds1054z.py", line 124, in write_screen_capture
    raw_data = self.oscilloscope.read_raw()[11:] # strip off first 11 bytes
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 364, in read_raw
    return bytes(self._read_raw(size))
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 387, in _read_raw
    chunk, status = self.visalib.read(self.session, size)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/highlevel.py", line 345, in read
    ret = self.sessions[session].read(count)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/usb.py", line 111, in read
    usb.USBError)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/sessions.py", line 477, in _read
    current = reader()
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/usb.py", line 105, in <lambda>
    return self._read(lambda: self.interface.read(count),
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/protocols/usbtmc.py", line 338, in read
    response = BulkInMessage.from_bytes(resp)
  File "/home/pi/.local/lib/python2.7/site-packages/pyvisa-py/protocols/usbtmc.py", line 108, in from_bytes
    assert msgid == MsgID.dev_dep_msg_in
AssertionError

If I wait one second after sending my write(':DISP:DATA? ON,OFF,PNG') command, I don't get any errors, but I only download 41bytes of data (when expecting 30KB).

Is this an issue with the VL805?
I suspect this is not a pyvisa issue, but a problem with bulk transfers with the VL805.

@MatthieuDartiailh
Copy link
Member

You can try running using pyvisa-py master. Rigol instruments are known to implement the USBTMC protocol in a nor fully rigorous manner and the master can circumvent that. Let me know if you get it to work.

@charkster
Copy link
Author

charkster commented Sep 4, 2019 via email

@MatthieuDartiailh
Copy link
Member

Could you post the traceback you get on your raspberry 3 ?

@charkster
Copy link
Author

charkster commented Sep 5, 2019 via email

@charkster
Copy link
Author

charkster commented Sep 5, 2019 via email

@MatthieuDartiailh
Copy link
Member

Could you also post the traceback you get on pyvisa-py master ? I would prefer to avoid breaking your code with the new release.

@charkster
Copy link
Author

charkster commented Sep 6, 2019 via email

@bjaraujo
Copy link

bjaraujo commented Sep 7, 2019

@charkster

Using the master branch, does it help if you change chunk_size like so?

inst.query_binary_values(':DISP:DATA? ON,OFF,PNG', chunk_size=2000*1024)

If not, maybe play around with the chunk size value (try chunk_size > or = total data size).

@MatthieuDartiailh
Copy link
Member

Can you try pyvisa/pyvisa-py#207 ? It should the attribute issue on the USB backend.

@charkster
Copy link
Author

Hi Matthieu,
I installed #207 and on my RPi3 and it works just fine (like it did before), but on my RPi4 I am seeing a different error now. I also turned-on the pyusb logfile and see that the RPi4 is not detaching the kernel driver. I have tried to detach it using usb.core, but have been unsuccessful (I can detach the usb port on my Ubuntu x86 PC with the same code).
It's odd that simple SCPI commands work fine, but any time I am downloading killobytes of PNG data or binary oscilloscope settings I get the unexpected MsgID.

Specifying the chunk_size also did not help (Thx bjaraujo).

2019-09-11 21:00:10,494 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - reading 20480 bytes (last status <StatusCode.success_max_count_read: 1073676294>)
/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/protocols/usbtmc.py:119: UserWarning: Unexpected MsgID format. Consider updating the device's firmware. See pyvisa/pyvisa-py#20
warnings.warn('Unexpected MsgID format. Consider updating the device's firmware. See pyvisa/pyvisa-py#20')
Traceback (most recent call last):
File "test_print_screen.py", line 15, in
scope.print_info()
File "/home/pi/python_code/rigol/rigol_ds1054z.py", line 22, in print_info
fullreading = self.oscilloscope.read_raw()
File "/home/pi/.local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 377, in read_raw
return bytes(self._read_raw(size))
File "/home/pi/.local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 400, in _read_raw
chunk, status = self.visalib.read(self.session, size)
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/highlevel.py", line 329, in read
ret = self.sessions[session].read(count)
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/usb.py", line 128, in read
USBTimeoutException)
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/sessions.py", line 478, in _read
current = reader()
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/usb.py", line 108, in _usb_reader
return self.interface.read(count)
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/protocols/usbtmc.py", line 419, in read
response = BulkInMessage.from_bytes(resp)
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/protocols/usbtmc.py", line 120, in from_bytes
return BulkInMessage.from_quirky(data)
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/protocols/usbtmc.py", line 135, in from_quirky
if ';' in str(data):
UnicodeDecodeError: 'ascii' codec can't decode byte 0xda in position 3: ordinal not in range(128)
2019-09-11 21:00:10,562 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - closing
2019-09-11 21:00:10,565 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - is closed

@MatthieuDartiailh
Copy link
Member

Thanks for testing. I still have no idea why the Raspberry 4 show the issue but we are doing something incorrect for quirky devices (ie which uses the wrong MsgId) in trying to convert the data to string. I pushed a temporary fix to pyvisa/pyvisa-py#207 but it would need some refinement (testing just for ; in any place looks dangerous to me). If you can test again it would be great. I will try to come with better fix in the meantime.

@charkster
Copy link
Author

Your latest change fixed the errors but the payload was only 104 bytes (I was expecting 30k bytes). It looks like valid data is being removed. Certainly it is an improvement.

@MatthieuDartiailh
Copy link
Member

Please note that read_raw will read till it encounters a termination character. Typically in binary block those can happen anywhere. I would recommend using read_binary_values and using the appropriate header format.

@charkster
Copy link
Author

Hi Matthieu,
I switched to read_binary_values, but I don't know how to use "the appropriate header format".

I updated my script to be:

		self.oscilloscope.write(':DISP:DATA? ON,OFF,PNG')
		raw_data_list = self.oscilloscope.read_binary_values()

But I get this error:

2019-09-12 19:05:37,488 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - reading 20480 bytes (last status <StatusCode.success_max_count_read: 1073676294>)
/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/protocols/usbtmc.py:119: UserWarning: Unexpected MsgID format. Consider updating the device's firmware. See pyvisa/pyvisa-py#20
warnings.warn('Unexpected MsgID format. Consider updating the device's firmware. See pyvisa/pyvisa-py#20')
Scope information: RIGOL TECHNOLOGIES,DS1104Z,DS1ZA192107675,00.04.04.SP4
2019-09-12 19:05:39,499 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - reading 20480 bytes (last status <StatusCode.success_max_count_read: 1073676294>)
2019-09-12 19:05:40,292 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - reading 20480 bytes (last status None)
2019-09-12 19:05:40,293 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - reading 20480 bytes (last status <StatusCode.success: 0>)
2019-09-12 19:05:40,295 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - reading 20480 bytes (last status <StatusCode.success: 0>)
2019-09-12 19:05:40,297 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - reading 20480 bytes (last status <StatusCode.success: 0>)
2019-09-12 19:05:40,298 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - reading 20480 bytes (last status <StatusCode.success: 0>)
2019-09-12 19:05:40,299 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - reading 20480 bytes (last status <StatusCode.success: 0>)
Traceback (most recent call last):
File "test_print_screen_disable_kernel_driver.py", line 17, in
scope.write_screen_capture()
File "/home/pi/python_code/rigol/rigol_ds1054z.py", line 125, in write_screen_capture
raw_data_list = self.oscilloscope.read_binary_values()
File "/home/pi/.local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 520, in read_binary_values
chunk_size=chunk_size))
File "/home/pi/.local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 356, in read_bytes
chunk, status = self.visalib.read(self.session, size)
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/highlevel.py", line 329, in read
ret = self.sessions[session].read(count)
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/usb.py", line 128, in read
USBTimeoutException)
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/sessions.py", line 478, in _read
current = reader()
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/usb.py", line 108, in _usb_reader
return self.interface.read(count)
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/protocols/usbtmc.py", line 421, in read
response = BulkInMessage.from_bytes(resp)
File "/usr/local/lib/python2.7/dist-packages/PyVISA_py-0.4.0.dev0-py2.7.egg/pyvisa-py/protocols/usbtmc.py", line 117, in from_bytes
msgid, btag, btaginverse = struct.unpack_from('BBBx', data)
struct.error: unpack_from requires a buffer of at least 4 bytes
2019-09-12 19:05:40,348 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - closing
2019-09-12 19:05:40,349 - pyvisa - DEBUG - USB0::6833::1230::DS1ZA192107675::0::INSTR - is closed

@bjaraujo
Copy link

bjaraujo commented Sep 13, 2019

It would be interesting to print those first 104 bytes to see the header.
What is the inst.timeout value?
Does this issue also happen using NI backend on a windows machine?

@MatthieuDartiailh
Copy link
Member

You can have a look at https://pyvisa.readthedocs.io/en/latest/introduction/rvalues.html but it looks lile there is still something wrong in the usb backend.

@charkster
Copy link
Author

charkster commented Sep 14, 2019

@bjaraujo You are right about the 104 bytes being the header (PNG header) here they are:
<89>PNG
^Z
^@^@^@^MIHDR^@^@^C ^@^@^A^H^B^@^@^@e<9E>^@^@^@^LtEXtAuthor^@rigol爌^@^@^@^QtEXtSource^@DSZ series?Z^]<97>^@^@^@)tEXtDescription

Here is the first 1000 bytes of a successful transfer:
<89>PNG
^Z
^@^@^@^MIHDR^@^@^C ^@^@^A^H^B^@^@^@e<9E>^@^@^@^LtEXtAuthor^@rigol爌^@^@^@^QtEXtSource^@DSZ series?Z^]<97>^@^@^@)tEXtDescription^@DSZ_Printing equipment output5^@^@^@^\tEXtCopyright^@rigol TECHNOLOGIES^Ta^@^@<86><9F>IDATx^A-ؑ훠@
<81>^F^E^Z^\Р@<83>^B^F^E^L
48A^C<83>^B^C^NhP<C0>^@<83>^K^L^F^T^X0<E0><82>^A^O^X^L^X0<A0><81><81><C1>^C^F^F^M.00^X<F0><C0><80>^K^F^p<C1><C0>^B^M<DE>RF<E6><CA> <C8><FD>!<85><B6>>2SZ<FA><C9><EA>P숽c<FF><B5>u<B4><AC><93><95><E7><F0>~g<DB>A<9B>^H<88><80>^H<88><80>^H<88><80>^H<88><80>^H<88><80>^H<88> <80>^H<88><80>^H<88><80>^H<88><80>^H<88><80>^H<88><80>^H<88><80>^H<88><80>^H<88><80>^H<88><80>^H<88><80>^H<88><80>^H<88><C0>^L^D<BE>>^\<DE> ^_^N<DF>^]^NϷ<DB>1:j@%<DA>D@^DD@^DD@^DD<E0><B1> <BC>:^\<BE>=J<AB>;<99>^Fd^V<EA>AU<DA>D@^DD@^DD@^DD<E0>Q |}TW^P4<FF>z8<FC><F7><E1><F0><CB> <E1><F0><E5>^V;<C6><C5><E8><A8>^A<95>|<A7><F7>X<8F><BA><9A>T<B7>^H<88><80>^H<88><80>^H<88><C0><91><C0><FB><E3><F1><FF>9^\<FE>z8<FC><D3><E1> <F0>^O<87><C3>oo<B1>c\<8C><8E>^ZP <B6><F7><C7><E3><E1><F0><C3>o~<F8>=<B6>^?<DC><CA><FE><FB><DF>cF<A7><B9>=<C8>^?<B6>v 6<B3><96>4<91> <B1>^D<C6><DC>}Z<F6><8F><FD>Sw̵<C6>Ob]<EE>9/<F7>H<F8>^O<F2>$l+^S<AF><8B><B0><FD><E5>p<F8><C7><C3><E1>ӭwԀJ<B0>}<D7>^]~<F8><E1><87>O<BF><FD> <F4><FC><FC><FC><FE>כ<F8><82><B2>_<BF><C7>\0#̫<9B><DE>y<FB><F2><CB>^W<EE><E6>KN<E1>L<8=g<9F><FE>K^O#<E9>I"y:^X<80>ȭ]<82>M<AC>#M<A2><85>@<E5> <EE><E3><ED><E0>^M-<FB>^V<C2><F7><93>3<E6>Z<EB><A7><DC><CC><D7>m$|^?<DF>m<D1>~>N<EA><8F>ǷV?^^^N<B7><DD><F1><F2>^L<95>{^N/?|̗

aF<98>W7<96>^H^]^?jvѓ8HtcΣ]jq^S/<97>~+K .<83>&.
򽧙^G5..-^D?^\z?^^^?K^@M9^<F6>o^G
^A]!^Qa7_%ӷO<87>^?
ޥ؎߽^B<90>Xݞ<8F>-<8E>Uv^_;^]>
G<F8>wz
^W߻0#̋5*{.z^Rg^^!<A0><D5>v:<99><9E>71^FF<C3>%<F0>^W+WW<F0><F8>^@<D9>"<B0>&<81><E4><EE><F3>K<DD><DB>^S<97><BD> <CD><C8>w({}^B<C1>k<8D><U+0082><97><FB><ED>۷<AF>_<BF>^^?"<8F>2"<E0>^@<91>-<FE>^P|J<99>~<E3>^O<FF>x!^@<91>T^Lf^D^D<D9>^?<FD><A9>^\c<89>PH<F9>^F<85>T<EC>^V<CE><FF><F3><97>N<9C>q+^V^@)Vݞ<8F>-<FF><8A>Uv^_;*<C1><F6><DC>^]>~<FC>8<EA><87><EF><D3>7O]<DA>}o<98>^Q<E6><C5>^Z<A9>o<BC><E2> <F1><AD><B0><D9>D<DB><<F9><D1>^B|<Sx&MvjDZ<97> ^<90>S7^RX "<9D>L}e<8F>^Y="w<93>^FBZc<91>˭^K^Z$^@ew0(<9B>^?8<90>5^ Ҷ^Gؾ^U=
^U

@MatthieuDartiailh
Copy link
Member

If you know beforehand how many bytes to expect and do not need to convert them the more straightforward way is actually read_bytes (I not realized you were reading a PNG, often binary transfer is used to transfer actual data and the header let you know what to expect, it does not appear to be so here). I need to find the time to dive into the USBTMC specification to figure out if we are doing something improperly here.

@charkster
Copy link
Author

charkster commented Sep 18, 2019

I installed wireshark and have the log files for the good and bad transfers. I can see the data differences from the start of the communication between the host and the oscilloscope. It looks like it could be in pyusb or libusb. Are there any pyusb connection options that could be tried to help this?

@bjaraujo
Copy link

bjaraujo commented Sep 18, 2019

I also thought this binary data had a header describing first the amount of bytes transferred but this data has no header, only the raw PNG data. In this case, I guess you have to be careful with the termination character as it will stop when it finds it. It may work or not depending on if it finds it or not. You could try setting inst.read_termination = None and then reading until it has no more bytes to read.

@MatthieuDartiailh
Copy link
Member

Could you share those wireshark results ?

@charkster
Copy link
Author

charkster commented Sep 19, 2019

I also thought this binary data had a header describing first the amount of bytes transferred but this data has no header, only the raw PNG data. In this case, I guess you have to be careful with the termination character as it will stop when it finds it. It may work or not depending on if it finds it or not. You could try setting inst.read_termination = None and then reading until it has no more bytes to read.

I strip the first 11 bytes when I do a raw_read (as seen above in my "write_screen_capture" function)... the amount of bytes is probably listed in there. I have been relying on pyvisa's raw_read to skip the termination characters and just pass on the entire data that the scope sends. It has been working just fine using my Raspberry Pi 3.

Here are the wireshark files.
I use this display filter for the good RPi3:
usb.bus_id==001 and usb.device_address==007
I use this display filter for the bad RPi4:
usb.bus_id==001 and usb.device_address==003
I use this display filter for the good Windows 10 (NI backend)
usb.bus_id==002 and usb.device_address==002

wireshark_print_screen_bad_rpi4.pcapng.gz
wireshark_print_screen_good.pcapng.gz
wireshark_print_screen_good_win10_bus2_device2.pcapng.gz

I have noticed that there is a "SET ADDRESS Request" in the good logfile. I don't know if that is related to when pyusb does a detach_kernel_driver command.

Thanks for your help.

@charkster
Copy link
Author

I am thinking that this is a pyvisa-py issue as I have no problems running on WIndows 10 using the NI backend.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants