search

pyvisa / pyvisa-py

A pure python PyVISA backend
https://pyvisa-py.readthedocs.io
MIT License
287 stars 124 forks source link

RIGOL DM3068 TCP/IP ERROR IN LINUX #54

Closed zikako74 closed 9 years ago

zikako74 commented 9 years ago

Hello,

I'm going crazy in order to communicate with the DMM pyvisa-py on TCPIP:

2015-08-20 00:09:39,056 - pyvisa - DEBUG - Created library wrapper for unset 2015-08-20 00:09:39,056 - pyvisa - DEBUG - Created ResourceManager with session 2052846 2015-08-20 00:09:39,056 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - opening ... 2015-08-20 00:09:39,091 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - is open with session 7697116 2015-08-20 00:09:39,106 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - reading 20480 bytes (last status <StatusCode.success_max_count_read: 1073676294>)

2015-08-20 00:09:48,769 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - closing Exception NotImplementedError: NotImplementedError() in <bound method TCPIPInstrument.del of <'TCPIPInstrument'(u'TCPIP0::192.168.1.144::inst0::INSTR')>> ignored

the python script is this:

import visa visa.log_to_screen() rm = visa.ResourceManager("@py") inst = rm.open_resource("TCPIP0::192.168.1.144::INSTR") print(inst.query("*IDN?"))

I'm used Linux 64bit and WindowsXp with python 2.7 32bit, but the error is the same. I sniffed the network traffic and does not receive the correct response, the protocol VXI11 reports a timeout error. With original software and NI-VISA library work fine, not with PyVisa and the same NI-VISA.

This is the debug with last pyvisa-py and python3

2015-08-20 00:23:17,237 - pyvisa - DEBUG - SerialSession was correctly imported. 2015-08-20 00:23:17,254 - pyvisa - DEBUG - USBSession and USBRawSession were correctly imported. 2015-08-20 00:23:17,264 - pyvisa - DEBUG - TCPIPSession was not imported cannot import name 'TCPIPSession'. 2015-08-20 00:23:17,266 - pyvisa - DEBUG - GPIBSession was not imported No module named 'gpib'. 2015-08-20 00:23:17,267 - pyvisa - DEBUG - Created library wrapper for unset 2015-08-20 00:23:17,267 - pyvisa - DEBUG - Created ResourceManager with session 6265688 2015-08-20 00:23:17,267 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - opening ... 2015-08-20 00:23:17,267 - pyvisa - DEBUG - RawTCPClient: connecting to socket at (192.168.1.144, 111) 2015-08-20 00:23:17,273 - pyvisa - DEBUG - Make call <PortMapperVersion.get_port: 3>, (395183, 1, 6, 0), '<bound method PortMapperPacker.pack_mapping of <pyvisa-py.protocols.rpc.PortMapperPacker object at 0x7fd5132b1ba8>>', '<bound method PortMapperUnpacker.unpack_uint of <pyvisa-py.protocols.rpc.PortMapperUnpacker object at 0x7fd5162ad048>>' 2015-08-20 00:23:17,273 - pyvisa - DEBUG - Sending record through <socket.socket fd=12, family=AddressFamily.AF_INET, type=SocketType.SOCK_STREAM, proto=0, laddr=('192.168.1.103', 59810), raddr=('192.168.1.144', 111)>: b'\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x02\x00\x01\x86\xa0\x00\x00\x00\x02\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x06\x07\xaf\x00\x00\x00\x01\x00\x00\x00\x06\x00\x00\x00\x00' 2015-08-20 00:23:17,283 - pyvisa - DEBUG - Received record through <socket.socket fd=12, family=AddressFamily.AF_INET, type=SocketType.SOCK_STREAM, proto=0, laddr=('192.168.1.103', 59810), raddr=('192.168.1.144', 111)>: b'\x00\x00\x00\x01\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02f' 2015-08-20 00:23:17,283 - pyvisa - DEBUG - RawTCPClient: closing socket 2015-08-20 00:23:17,283 - pyvisa - DEBUG - RawTCPClient: connecting to socket at (192.168.1.144, 614) 2015-08-20 00:23:17,290 - pyvisa - DEBUG - Make call 10, (411798420, 0, 10000, 'inst0'), '<bound method Vxi11Packer.pack_create_link_parms of <pyvisa-py.protocols.vxi11.Vxi11Packer object at 0x7fd5132cdf98>>', '<bound method Vxi11Unpacker.unpack_create_link_resp of <pyvisa-py.protocols.vxi11.Vxi11Unpacker object at 0x7fd5132cdd68>>' 2015-08-20 00:23:17,290 - pyvisa - DEBUG - Sending record through <socket.socket fd=12, family=AddressFamily.AF_INET, type=SocketType.SOCK_STREAM, proto=0, laddr=('192.168.1.103', 48346), raddr=('192.168.1.144', 614)>: b"\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x02\x00\x06\x07\xaf\x00\x00\x00\x01\x00\x00\x00\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x18\x8b\x8b\x94\x00\x00\x00\x00\x00\x00'\x10\x00\x00\x00\x05inst0\x00\x00\x00" 2015-08-20 00:23:17,302 - pyvisa - DEBUG - Received record through <socket.socket fd=12, family=AddressFamily.AF_INET, type=SocketType.SOCK_STREAM, proto=0, laddr=('192.168.1.103', 48346), raddr=('192.168.1.144', 614)>: b'\x00\x00\x00\x01\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02f\x00\x00\x04\x00' 2015-08-20 00:23:17,303 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - is open with session 6559734 2015-08-20 00:23:17,303 - pyvisa - DEBUG - Make call 11, (0, 10000, 10000, 136, b'_IDN?\r\n'), '<bound method Vxi11Packer.pack_device_write_parms of <pyvisa-py.protocols.vxi11.Vxi11Packer object at 0x7fd5132cdf98>>', '<bound method Vxi11Unpacker.unpack_device_write_resp of <pyvisa-py.protocols.vxi11.Vxi11Unpacker object at 0x7fd5132cdd68>>' 2015-08-20 00:23:17,303 - pyvisa - DEBUG - Sending record through <socket.socket fd=12, family=AddressFamily.AF_INET, type=SocketType.SOCK_STREAM, proto=0, laddr=('192.168.1.103', 48346), raddr=('192.168.1.144', 614)>: b"\x00\x00\x00\x02\x00\x00\x00\x00\x00\x00\x00\x02\x00\x06\x07\xaf\x00\x00\x00\x01\x00\x00\x00\x0b\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'\x10\x00\x00'\x10\x00\x00\x00\x88\x00\x00\x00\x07_IDN?\r\n\x00" 2015-08-20 00:23:17,309 - pyvisa - DEBUG - Received record through <socket.socket fd=12, family=AddressFamily.AF_INET, type=SocketType.SOCK_STREAM, proto=0, laddr=('192.168.1.103', 48346), raddr=('192.168.1.144', 614)>: b'\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x0b\x00\x00\x00\x00' 2015-08-20 00:23:17,309 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - reading 20480 bytes (last status <StatusCode.success_max_count_read: 1073676294>) 2015-08-20 00:23:17,310 - pyvisa - DEBUG - Make call 12, (0, 1024, 10000, 10000, 0, 0), '<bound method Vxi11Packer.pack_device_read_parms of <pyvisa-py.protocols.vxi11.Vxi11Packer object at 0x7fd5132cdf98>>', '<bound method Vxi11Unpacker.unpack_device_read_resp of <pyvisa-py.protocols.vxi11.Vxi11Unpacker object at 0x7fd5132cdd68>>' 2015-08-20 00:23:17,310 - pyvisa - DEBUG - Sending record through <socket.socket fd=12, family=AddressFamily.AF_INET, type=SocketType.SOCK_STREAM, proto=0, laddr=('192.168.1.103', 48346), raddr=('192.168.1.144', 614)>: b"\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x02\x00\x06\x07\xaf\x00\x00\x00\x01\x00\x00\x00\x0c\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x04\x00\x00\x00'\x10\x00\x00'\x10\x00\x00\x00\x00\x00\x00\x00\x00" 2015-08-20 00:23:26,962 - pyvisa - DEBUG - Received record through <socket.socket fd=12, family=AddressFamily.AF_INET, type=SocketType.SOCK_STREAM, proto=0, laddr=('192.168.1.103', 48346), raddr=('192.168.1.144', 614)>: b'\x00\x00\x00\x03\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x0f\x00\x00\x00\x00\x00\x00\x00\x00'

2015-08-20 00:23:26,975 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - closing 2015-08-20 00:23:26,975 - pyvisa - DEBUG - Make call 23, 0, '<bound method Vxi11Packer.pack_device_link of <pyvisa-py.protocols.vxi11.Vxi11Packer object at 0x7fd5132cdf98>>', '<bound method Vxi11Unpacker.unpack_device_error of <pyvisa-py.protocols.vxi11.Vxi11Unpacker object at 0x7fd5132cdd68>>' 2015-08-20 00:23:26,975 - pyvisa - DEBUG - Sending record through <socket.socket fd=12, family=AddressFamily.AF_INET, type=SocketType.SOCK_STREAM, proto=0, laddr=('192.168.1.103', 48346), raddr=('192.168.1.144', 614)>: b'\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x00\x02\x00\x06\x07\xaf\x00\x00\x00\x01\x00\x00\x00\x17\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' 2015-08-20 00:23:26,983 - pyvisa - DEBUG - Received record through <socket.socket fd=12, family=AddressFamily.AF_INET, type=SocketType.SOCK_STREAM, proto=0, laddr=('192.168.1.103', 48346), raddr=('192.168.1.144', 614)>: b'\x00\x00\x00\x04\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' 2015-08-20 00:23:26,983 - pyvisa - DEBUG - RawTCPClient: closing socket 2015-08-20 00:23:26,983 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - is closed 2015-08-20 00:23:26,987 - pyvisa - DEBUG - Closing ResourceManager (session: 6265688)

Best regards

zikako74 commented 9 years ago

The version of software

PYTHON2.7

Machine Details: Platform ID: Linux-3.13.0-30-generic-x86_64-with-Ubuntu-14.04-trusty Processor: x86_64

Python: Implementation: CPython Executable: /usr/bin/python Version: 2.7.6 Compiler: GCC 4.8.2 Bits: 64bit Build: Jun 22 2015 17:58:13 (#default) Unicode: UCS4

PyVISA Version: 1.7

Backends: ni: Version: 1.7 (bundled with PyVISA)

1: /usr/lib/x86_64-linux-gnu/libvisa.so.0.0.0:

     found by: auto
     bitness: 64
     Could not get more info:
        VI_ERROR_NSUP_ATTR (-1073807331): The specified attribute is not defined or supported by the referenced object.

py: Version: 0.1 ASRL INSTR: Available via PySerial (N/A) TCPIP INSTR: Available USB INSTR: Please install PyUSB to use this resource type. No module named usb sim: Version: 0.2 Spec version: 1.1

PYTHON3 Python: Implementation: CPython Executable: /usr/bin/python3 Version: 3.4.0 Compiler: GCC 4.8.2 Bits: 64bit Build: Jun 19 2015 14:20:21 (#default) Unicode: UCS4

PyVISA Version: 1.7

Backends: ni: Version: 1.7 (bundled with PyVISA)

1: /usr/lib/x86_64-linux-gnu/libvisa.so.0.0.0:

     found by: auto
     bitness: 64
     Could not get more info:
        VI_ERROR_NSUP_ATTR (-1073807331): The specified attribute is not defined or supported by the referenced object.

sim: Version: 0.3.dev0 Spec version: 1.1 py: Version: 0.2.dev2 USB RAW: Available via PyUSB (1.0.0rc1). Backend: libusb1 TCPIP INSTR: Available TCPIP SOCKET: Available ASRL INSTR: Available via PySerial (2.7) USB INSTR: Available via PyUSB (1.0.0rc1). Backend: libusb1 GPIB INSTR: Please install linux-gpib to use this resource type. No module named 'gpib'

Receive this string with Rigol Software: Rigol Technologies,DM3068,DM3O155300840,01.01.00.01.08.00

hgrecco commented 9 years ago

Can you install pyvisa and pyvisa-py directly from github to check if this is the case with the latest version?

zikako74 commented 9 years ago

Machine Details: Platform ID: Linux-3.13.0-46-generic-i686-with-Ubuntu-14.04-trusty Processor: i686

Python: Implementation: CPython Executable: /usr/bin/python Version: 2.7.6 Compiler: GCC 4.8.2 Bits: 32bit Build: Jun 22 2015 18:00:18 (#default) Unicode: UCS4

PyVISA Version: 1.8.dev0

Backends: ni: Version: 1.8.dev0 (bundled with PyVISA)

1: /usr/local/lib/libvisa.so.0.0.0:

     found by: auto
     bitness: 32
     Could not get more info:
        VI_ERROR_NSUP_ATTR (-1073807331): The specified attribute is not defined or supported by the referenced object.

py: Version: 0.2.dev2 ASRL INSTR: Available via PySerial (2.7) TCPIP INSTR: Available USB RAW: Available via PyUSB (1.0.0b2). Backend: libusb1 USB INSTR: Available via PyUSB (1.0.0b2). Backend: libusb1 GPIB INSTR: Please install linux-gpib to use this resource type. No module named gpib TCPIP SOCKET: Available

This is debug on screen:

2015-08-20 18:51:42,065 - pyvisa - DEBUG - SerialSession was correctly imported. 2015-08-20 18:51:42,098 - pyvisa - DEBUG - USBSession and USBRawSession were correctly imported. 2015-08-20 18:51:42,115 - pyvisa - DEBUG - TCPIPSession was not imported cannot import name TCPIPSession. 2015-08-20 18:51:42,116 - pyvisa - DEBUG - GPIBSession was not imported No module named gpib. 2015-08-20 18:51:42,116 - pyvisa - DEBUG - Created library wrapper for unset 2015-08-20 18:51:42,117 - pyvisa - DEBUG - Created ResourceManager with session 7263952 2015-08-20 18:51:42,117 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - opening ... 2015-08-20 18:51:42,117 - pyvisa - DEBUG - RawTCPClient: connecting to socket at (192.168.1.144, 111) 2015-08-20 18:51:42,128 - pyvisa - DEBUG - Make call <PortMapperVersion.get_port: 3>, (395183, 1, 6, 0), '<bound method PortMapperPacker.pack_mapping of <pyvisa-py.protocols.rpc.PortMapperPacker instance at 0xb6db56ac>>', '<bound method PortMapperUnpacker.unpack_uint of <pyvisa-py.protocols.rpc.PortMapperUnpacker instance at 0xb642774c>>' Traceback (most recent call last): File "/usr/lib/python2.7/logging/init.py", line 851, in emit msg = self.format(record) File "/usr/lib/python2.7/logging/init.py", line 724, in format return fmt.format(record) File "/usr/lib/python2.7/logging/init.py", line 464, in format record.message = record.getMessage() File "/usr/lib/python2.7/logging/init.py", line 328, in getMessage msg = msg % self.args UnicodeDecodeError: 'ascii' codec can't decode byte 0x86 in position 14: ordinal not in range(128) Logged from file rpc.py, line 296 2015-08-20 18:51:42,135 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb641c614>: f 2015-08-20 18:51:42,135 - pyvisa - DEBUG - RawTCPClient: closing socket 2015-08-20 18:51:42,136 - pyvisa - DEBUG - RawTCPClient: connecting to socket at (192.168.1.144, 614) 2015-08-20 18:51:42,140 - pyvisa - DEBUG - Make call 10, (1677625204L, 0, 10000, u'inst0'), '<bound method Vxi11Packer.pack_create_link_parms of <pyvisa-py.protocols.vxi11.Vxi11Packer instance at 0xb6414dec>>', '<bound method Vxi11Unpacker.unpack_create_link_resp of <pyvisa-py.protocols.vxi11.Vxi11Unpacker instance at 0xb6414cac>>' Traceback (most recent call last): File "/usr/lib/python2.7/logging/init.py", line 851, in emit msg = self.format(record) File "/usr/lib/python2.7/logging/init.py", line 724, in format return fmt.format(record) File "/usr/lib/python2.7/logging/init.py", line 464, in format record.message = record.getMessage() File "/usr/lib/python2.7/logging/init.py", line 328, in getMessage msg = msg % self.args UnicodeDecodeError: 'ascii' codec can't decode byte 0xaf in position 15: ordinal not in range(128) Logged from file rpc.py, line 296 2015-08-20 18:51:42,152 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb643bf7c>: f 2015-08-20 18:51:42,152 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - is open with session 8148751 2015-08-20 18:51:42,152 - pyvisa - DEBUG - Make call 11, (0, 10000, 10000, 136, '*IDN?\r\n'), '<bound method Vxi11Packer.pack_device_write_parms of <pyvisa-py.protocols.vxi11.Vxi11Packer instance at 0xb6414dec>>', '<bound method Vxi11Unpacker.unpack_device_write_resp of <pyvisa-py.protocols.vxi11.Vxi11Unpacker instance at 0xb6414cac>>' Traceback (most recent call last): File "/usr/lib/python2.7/logging/init.py", line 851, in emit msg = self.format(record) File "/usr/lib/python2.7/logging/init.py", line 724, in format return fmt.format(record) File "/usr/lib/python2.7/logging/init.py", line 464, in format record.message = record.getMessage() File "/usr/lib/python2.7/logging/init.py", line 328, in getMessage msg = msg % self.args UnicodeDecodeError: 'ascii' codec can't decode byte 0xaf in position 15: ordinal not in range(128) Logged from file rpc.py, line 296 2015-08-20 18:51:42,159 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb643bf7c>: 

2015-08-20 18:51:42,159 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - reading 20480 bytes (last status <StatusCode.success_max_count_read: 1073676294>) 2015-08-20 18:51:42,161 - pyvisa - DEBUG - Make call 12, (0, 1024, 10000, 10000, 0, 0), '<bound method Vxi11Packer.pack_device_read_parms of <pyvisa-py.protocols.vxi11.Vxi11Packer instance at 0xb6414dec>>', '<bound method Vxi11Unpacker.unpack_device_read_resp of <pyvisa-py.protocols.vxi11.Vxi11Unpacker instance at 0xb6414cac>>' Traceback (most recent call last): File "/usr/lib/python2.7/logging/init.py", line 851, in emit msg = self.format(record) File "/usr/lib/python2.7/logging/init.py", line 724, in format return fmt.format(record) File "/usr/lib/python2.7/logging/init.py", line 464, in format record.message = record.getMessage() File "/usr/lib/python2.7/logging/init.py", line 328, in getMessage msg = msg % self.args UnicodeDecodeError: 'ascii' codec can't decode byte 0xaf in position 15: ordinal not in range(128) Logged from file rpc.py, line 296 2015-08-20 18:51:51,812 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb643bf7c>: 

2015-08-20 18:51:51,822 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - closing 2015-08-20 18:51:51,823 - pyvisa - DEBUG - Make call 23, 0, '<bound method Vxi11Packer.pack_device_link of <pyvisa-py.protocols.vxi11.Vxi11Packer instance at 0xb6414dec>>', '<bound method Vxi11Unpacker.unpack_device_error of <pyvisa-py.protocols.vxi11.Vxi11Unpacker instance at 0xb6414cac>>' Traceback (most recent call last): File "/usr/lib/python2.7/logging/init.py", line 851, in emit msg = self.format(record) File "/usr/lib/python2.7/logging/init.py", line 724, in format return fmt.format(record) File "/usr/lib/python2.7/logging/init.py", line 464, in format record.message = record.getMessage() File "/usr/lib/python2.7/logging/init.py", line 328, in getMessage msg = msg % self.args UnicodeDecodeError: 'ascii' codec can't decode byte 0xaf in position 15: ordinal not in range(128) Logged from file rpc.py, line 296 2015-08-20 18:51:51,829 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb643bf7c>:  2015-08-20 18:51:51,830 - pyvisa - DEBUG - RawTCPClient: closing socket 2015-08-20 18:51:51,830 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - is closed

zikako74 commented 9 years ago

In windows machine with python 2.7.10 32bit, the PYVISA-PY from github is compiled and installed but not available, in test python -m visa info

hgrecco commented 9 years ago

I was able to reproduce and fix it, at least in my machine. Please try it and let me know,

zikako74 commented 9 years ago

Machine Details: Platform ID: Linux-3.13.0-46-generic-i686-with-Ubuntu-14.04-trusty Processor: i686

Python: Implementation: CPython Executable: /usr/bin/python Version: 2.7.6 Compiler: GCC 4.8.2 Bits: 32bit Build: Jun 22 2015 18:00:18 (#default) Unicode: UCS4

PyVISA Version: 1.8

Backends: ni: Version: 1.8 (bundled with PyVISA)

1: /usr/local/lib/libvisa.so.0.0.0:

     found by: auto
     bitness: 32
     Could not get more info:
        VI_ERROR_NSUP_ATTR (-1073807331): The specified attribute is not defined or supported by the referenced object.

py: Version: 0.3.dev0 ASRL INSTR: Available via PySerial (2.7) TCPIP INSTR: Available USB RAW: Available via PyUSB (1.0.0b2). Backend: libusb1 USB INSTR: Available via PyUSB (1.0.0b2). Backend: libusb1 GPIB INSTR: Please install linux-gpib to use this resource type. No module named gpib TCPIP SOCKET: Available

2015-08-25 22:51:22,811 - pyvisa - DEBUG - SerialSession was correctly imported. 2015-08-25 22:51:22,841 - pyvisa - DEBUG - USBSession and USBRawSession were correctly imported. 2015-08-25 22:51:22,857 - pyvisa - DEBUG - TCPIPSession was not imported cannot import name TCPIPSession. 2015-08-25 22:51:22,858 - pyvisa - DEBUG - GPIBSession was not imported No module named gpib. 2015-08-25 22:51:22,858 - pyvisa - DEBUG - Created library wrapper for unset 2015-08-25 22:51:22,858 - pyvisa - DEBUG - Created ResourceManager with session 2415762 2015-08-25 22:51:22,859 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - opening ... 2015-08-25 22:51:22,859 - pyvisa - DEBUG - RawTCPClient: connecting to socket at (192.168.1.144, 111) 2015-08-25 22:51:22,869 - pyvisa - DEBUG - Make call <PortMapperVersion.get_port: 3>, (395183, 1, 6, 0), <bound method PortMapperPacker.pack_mapping of <pyvisa-py.protocols.rpc.PortMapperPacker instance at 0xb635d54c>>, <bound method PortMapperUnpacker.unpack_uint of <pyvisa-py.protocols.rpc.PortMapperUnpacker instance at 0xb63665ec>> Traceback (most recent call last): File "/usr/lib/python2.7/logging/init.py", line 851, in emit msg = self.format(record) File "/usr/lib/python2.7/logging/init.py", line 724, in format return fmt.format(record) File "/usr/lib/python2.7/logging/init.py", line 464, in format record.message = record.getMessage() File "/usr/lib/python2.7/logging/init.py", line 328, in getMessage msg = msg % self.args UnicodeDecodeError: 'ascii' codec can't decode byte 0x86 in position 14: ordinal not in range(128) Logged from file rpc.py, line 296 2015-08-25 22:51:22,876 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb635a64c>: '\x00\x00\x00\x01\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02f' 2015-08-25 22:51:22,877 - pyvisa - DEBUG - RawTCPClient: closing socket 2015-08-25 22:51:22,877 - pyvisa - DEBUG - RawTCPClient: connecting to socket at (192.168.1.144, 614) 2015-08-25 22:51:22,882 - pyvisa - DEBUG - Make call 10, (1391771490L, 0, 10000, u'inst0'), <bound method Vxi11Packer.pack_create_link_parms of <pyvisa-py.protocols.vxi11.Vxi11Packer instance at 0xb6352c8c>>, <bound method Vxi11Unpacker.unpack_create_link_resp of <pyvisa-py.protocols.vxi11.Vxi11Unpacker instance at 0xb6352b4c>> Traceback (most recent call last): File "/usr/lib/python2.7/logging/init.py", line 851, in emit msg = self.format(record) File "/usr/lib/python2.7/logging/init.py", line 724, in format return fmt.format(record) File "/usr/lib/python2.7/logging/init.py", line 464, in format record.message = record.getMessage() File "/usr/lib/python2.7/logging/init.py", line 328, in getMessage msg = msg % self.args UnicodeDecodeError: 'ascii' codec can't decode byte 0xaf in position 15: ordinal not in range(128) Logged from file rpc.py, line 296 2015-08-25 22:51:22,893 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb6378fb4>: '\x00\x00\x00\x01\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02f\x00\x00\x04\x00' 2015-08-25 22:51:22,894 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - is open with session 6606305 2015-08-25 22:51:22,894 - pyvisa - DEBUG - Make call 11, (0, 10000, 10000, 136, '*IDN?\r\n'), <bound method Vxi11Packer.pack_device_write_parms of <pyvisa-py.protocols.vxi11.Vxi11Packer instance at 0xb6352c8c>>, <bound method Vxi11Unpacker.unpack_device_write_resp of <pyvisa-py.protocols.vxi11.Vxi11Unpacker instance at 0xb6352b4c>> Traceback (most recent call last): File "/usr/lib/python2.7/logging/init.py", line 851, in emit msg = self.format(record) File "/usr/lib/python2.7/logging/init.py", line 724, in format return fmt.format(record) File "/usr/lib/python2.7/logging/init.py", line 464, in format record.message = record.getMessage() File "/usr/lib/python2.7/logging/init.py", line 328, in getMessage msg = msg % self.args UnicodeDecodeError: 'ascii' codec can't decode byte 0xaf in position 15: ordinal not in range(128) Logged from file rpc.py, line 296 2015-08-25 22:51:22,899 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb6378fb4>: '\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x0b\x00\x00\x00\x00' 2015-08-25 22:51:22,900 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - reading 20480 bytes (last status <StatusCode.success_max_count_read: 1073676294>) 2015-08-25 22:51:22,900 - pyvisa - DEBUG - Make call 12, (0, 1024, 10000, 10000, 0, 0), <bound method Vxi11Packer.pack_device_read_parms of <pyvisa-py.protocols.vxi11.Vxi11Packer instance at 0xb6352c8c>>, <bound method Vxi11Unpacker.unpack_device_read_resp of <pyvisa-py.protocols.vxi11.Vxi11Unpacker instance at 0xb6352b4c>> Traceback (most recent call last): File "/usr/lib/python2.7/logging/init.py", line 851, in emit msg = self.format(record) File "/usr/lib/python2.7/logging/init.py", line 724, in format return fmt.format(record) File "/usr/lib/python2.7/logging/init.py", line 464, in format record.message = record.getMessage() File "/usr/lib/python2.7/logging/init.py", line 328, in getMessage msg = msg % self.args UnicodeDecodeError: 'ascii' codec can't decode byte 0xaf in position 15: ordinal not in range(128) Logged from file rpc.py, line 296 2015-08-25 22:51:32,551 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb6378fb4>: '\x00\x00\x00\x03\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x0f\x00\x00\x00\x00\x00\x00\x00\x00'

2015-08-25 22:51:32,561 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - closing 2015-08-25 22:51:32,562 - pyvisa - DEBUG - Make call 23, 0, <bound method Vxi11Packer.pack_device_link of <pyvisa-py.protocols.vxi11.Vxi11Packer instance at 0xb6352c8c>>, <bound method Vxi11Unpacker.unpack_device_error of <pyvisa-py.protocols.vxi11.Vxi11Unpacker instance at 0xb6352b4c>> Traceback (most recent call last): File "/usr/lib/python2.7/logging/init.py", line 851, in emit msg = self.format(record) File "/usr/lib/python2.7/logging/init.py", line 724, in format return fmt.format(record) File "/usr/lib/python2.7/logging/init.py", line 464, in format record.message = record.getMessage() File "/usr/lib/python2.7/logging/init.py", line 328, in getMessage msg = msg % self.args UnicodeDecodeError: 'ascii' codec can't decode byte 0xaf in position 15: ordinal not in range(128) Logged from file rpc.py, line 296 2015-08-25 22:51:32,568 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb6378fb4>: '\x00\x00\x00\x04\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' 2015-08-25 22:51:32,568 - pyvisa - DEBUG - RawTCPClient: closing socket 2015-08-25 22:51:32,568 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - is closed

hgrecco commented 9 years ago

In pyvisa-py/protocols/rpc.py, can you change 

logger.debug('Sending record through %s: %s', sock, record)

to 

logger.debug('Sending record through %s', sock)

(we loose info but should work all the time)

zikako74 commented 9 years ago

2015-08-25 23:12:07,973 - pyvisa - DEBUG - SerialSession was correctly imported. 2015-08-25 23:12:08,022 - pyvisa - DEBUG - USBSession and USBRawSession were correctly imported. 2015-08-25 23:12:08,039 - pyvisa - DEBUG - TCPIPSession was not imported cannot import name TCPIPSession. 2015-08-25 23:12:08,040 - pyvisa - DEBUG - GPIBSession was not imported No module named gpib. 2015-08-25 23:12:08,040 - pyvisa - DEBUG - Created library wrapper for unset 2015-08-25 23:12:08,041 - pyvisa - DEBUG - Created ResourceManager with session 4699394 2015-08-25 23:12:08,041 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - opening ... 2015-08-25 23:12:08,041 - pyvisa - DEBUG - RawTCPClient: connecting to socket at (192.168.1.144, 111) 2015-08-25 23:12:08,056 - pyvisa - DEBUG - Make call <PortMapperVersion.get_port: 3>, (395183, 1, 6, 0), <bound method PortMapperPacker.pack_mapping of <pyvisa-py.protocols.rpc.PortMapperPacker instance at 0xb6d9584c>>, <bound method PortMapperUnpacker.unpack_uint of <pyvisa-py.protocols.rpc.PortMapperUnpacker instance at 0xb64068ec>> 2015-08-25 23:12:08,057 - pyvisa - DEBUG - Sending record through <socket._socketobject object at 0xb63fc764> 2015-08-25 23:12:08,061 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb63fc764>: '\x00\x00\x00\x01\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02f' 2015-08-25 23:12:08,061 - pyvisa - DEBUG - RawTCPClient: closing socket 2015-08-25 23:12:08,062 - pyvisa - DEBUG - RawTCPClient: connecting to socket at (192.168.1.144, 614) 2015-08-25 23:12:08,066 - pyvisa - DEBUG - Make call 10, (1713653267L, 0, 10000, u'inst0'), <bound method Vxi11Packer.pack_create_link_parms of <pyvisa-py.protocols.vxi11.Vxi11Packer instance at 0xb6d9510c>>, <bound method Vxi11Unpacker.unpack_create_link_resp of <pyvisa-py.protocols.vxi11.Vxi11Unpacker instance at 0xb6d9504c>> 2015-08-25 23:12:08,067 - pyvisa - DEBUG - Sending record through <socket._socketobject object at 0xb64058ec> 2015-08-25 23:12:08,078 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb64058ec>: '\x00\x00\x00\x01\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02f\x00\x00\x04\x00' 2015-08-25 23:12:08,078 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - is open with session 7856346 2015-08-25 23:12:08,078 - pyvisa - DEBUG - Make call 11, (0, 10000, 10000, 136, '*IDN?\r\n'), <bound method Vxi11Packer.pack_device_write_parms of <pyvisa-py.protocols.vxi11.Vxi11Packer instance at 0xb6d9510c>>, <bound method Vxi11Unpacker.unpack_device_write_resp of <pyvisa-py.protocols.vxi11.Vxi11Unpacker instance at 0xb6d9504c>> 2015-08-25 23:12:08,079 - pyvisa - DEBUG - Sending record through <socket._socketobject object at 0xb64058ec> 2015-08-25 23:12:08,084 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb64058ec>: '\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x0b\x00\x00\x00\x00' 2015-08-25 23:12:08,084 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - reading 20480 bytes (last status <StatusCode.success_max_count_read: 1073676294>) 2015-08-25 23:12:08,084 - pyvisa - DEBUG - Make call 12, (0, 1024, 10000, 10000, 0, 0), <bound method Vxi11Packer.pack_device_read_parms of <pyvisa-py.protocols.vxi11.Vxi11Packer instance at 0xb6d9510c>>, <bound method Vxi11Unpacker.unpack_device_read_resp of <pyvisa-py.protocols.vxi11.Vxi11Unpacker instance at 0xb6d9504c>> 2015-08-25 23:12:08,084 - pyvisa - DEBUG - Sending record through <socket._socketobject object at 0xb64058ec> 2015-08-25 23:12:17,736 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb64058ec>: '\x00\x00\x00\x03\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x0f\x00\x00\x00\x00\x00\x00\x00\x00'

2015-08-25 23:12:17,746 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - closing 2015-08-25 23:12:17,746 - pyvisa - DEBUG - Make call 23, 0, <bound method Vxi11Packer.pack_device_link of <pyvisa-py.protocols.vxi11.Vxi11Packer instance at 0xb6d9510c>>, <bound method Vxi11Unpacker.unpack_device_error of <pyvisa-py.protocols.vxi11.Vxi11Unpacker instance at 0xb6d9504c>> 2015-08-25 23:12:17,747 - pyvisa - DEBUG - Sending record through <socket._socketobject object at 0xb64058ec> 2015-08-25 23:12:17,751 - pyvisa - DEBUG - Received record through <socket._socketobject object at 0xb64058ec>: '\x00\x00\x00\x04\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' 2015-08-25 23:12:17,752 - pyvisa - DEBUG - RawTCPClient: closing socket 2015-08-25 23:12:17,752 - pyvisa - DEBUG - TCPIP0::192.168.1.144::INSTR - is closed

zikako74 commented 9 years ago

Is slow and no response on screen

hgrecco commented 9 years ago

That might be a timeout or something. But it is not stoping which is a good thing. Try to disable logging to see if is still slow.

zikako74 commented 9 years ago

Is a timeout, i'm sniffing a network and report this: No. Time Source Destination Protocol Length Info 10 3.024248000 192.168.1.110 192.168.1.144 TCP 74 38861 > sunrpc [SYN] Seq=0 Win=29200 Len=0 MSS=1460 SACK_PERM=1 TSval=803139 TSecr=0 WS=1024

Frame 10: 74 bytes on wire (592 bits), 74 bytes captured (592 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 38861 (38861), Dst Port: sunrpc (111), Seq: 0, Len: 0

No. Time Source Destination Protocol Length Info 12 4.021794000 192.168.1.110 192.168.1.144 TCP 74 [TCP Retransmission] 38861 > sunrpc [SYN] Seq=0 Win=29200 Len=0 MSS=1460 SACK_PERM=1 TSval=803389 TSecr=0 WS=1024

Frame 12: 74 bytes on wire (592 bits), 74 bytes captured (592 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 38861 (38861), Dst Port: sunrpc (111), Seq: 0, Len: 0

No. Time Source Destination Protocol Length Info 15 4.025614000 192.168.1.144 192.168.1.110 TCP 60 sunrpc > 38861 [SYN, ACK] Seq=0 Ack=1 Win=8192 Len=0 MSS=1460

Frame 15: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0 Ethernet II, Src: 00:00:00_00:00:00 (00:00:00:00:00:00), Dst: Foxconn_e3:09:29 (00:15:58:e3:09:29) Internet Protocol Version 4, Src: 192.168.1.144 (192.168.1.144), Dst: 192.168.1.110 (192.168.1.110) Transmission Control Protocol, Src Port: sunrpc (111), Dst Port: 38861 (38861), Seq: 0, Ack: 1, Len: 0

No. Time Source Destination Protocol Length Info 16 4.025654000 192.168.1.110 192.168.1.144 TCP 54 38861 > sunrpc [ACK] Seq=1 Ack=1 Win=29200 Len=0

Frame 16: 54 bytes on wire (432 bits), 54 bytes captured (432 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 38861 (38861), Dst Port: sunrpc (111), Seq: 1, Ack: 1, Len: 0

No. Time Source Destination Protocol Length Info 17 4.026027000 192.168.1.110 192.168.1.144 Portmap 114 V2 GETPORT Call (Reply In 18) VXI-11 Core(395183) V:1 TCP

Frame 17: 114 bytes on wire (912 bits), 114 bytes captured (912 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 38861 (38861), Dst Port: sunrpc (111), Seq: 1, Ack: 1, Len: 60 Remote Procedure Call, Type:Call XID:0x00000001 Portmap GETPORT Call VXI-11 Core(395183) Version:1 TCP

No. Time Source Destination Protocol Length Info 18 4.032870000 192.168.1.144 192.168.1.110 Portmap 86 V2 GETPORT Reply (Call In 17) Port:614

Frame 18: 86 bytes on wire (688 bits), 86 bytes captured (688 bits) on interface 0 Ethernet II, Src: RigolTec_44:03:d9 (00:19:af:44:03:d9), Dst: Foxconn_e3:09:29 (00:15:58:e3:09:29) Internet Protocol Version 4, Src: 192.168.1.144 (192.168.1.144), Dst: 192.168.1.110 (192.168.1.110) Transmission Control Protocol, Src Port: sunrpc (111), Dst Port: 38861 (38861), Seq: 1, Ack: 61, Len: 32 Remote Procedure Call, Type:Reply XID:0x00000001 Portmap GETPORT Reply Port:614 Port:614

No. Time Source Destination Protocol Length Info 19 4.032903000 192.168.1.110 192.168.1.144 TCP 54 38861 > sunrpc [ACK] Seq=61 Ack=33 Win=29200 Len=0

Frame 19: 54 bytes on wire (432 bits), 54 bytes captured (432 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 38861 (38861), Dst Port: sunrpc (111), Seq: 61, Ack: 33, Len: 0

No. Time Source Destination Protocol Length Info 20 4.033185000 192.168.1.110 192.168.1.144 TCP 54 38861 > sunrpc [FIN, ACK] Seq=61 Ack=33 Win=29200 Len=0

Frame 20: 54 bytes on wire (432 bits), 54 bytes captured (432 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 38861 (38861), Dst Port: sunrpc (111), Seq: 61, Ack: 33, Len: 0

No. Time Source Destination Protocol Length Info 21 4.033361000 192.168.1.110 192.168.1.144 TCP 74 39762 > sshell [SYN] Seq=0 Win=29200 Len=0 MSS=1460 SACK_PERM=1 TSval=803391 TSecr=0 WS=1024

Frame 21: 74 bytes on wire (592 bits), 74 bytes captured (592 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 39762 (39762), Dst Port: sshell (614), Seq: 0, Len: 0

No. Time Source Destination Protocol Length Info 22 4.036706000 192.168.1.144 192.168.1.110 TCP 60 sunrpc > 38861 [ACK] Seq=33 Ack=62 Win=8191 Len=0

Frame 22: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0 Ethernet II, Src: RigolTec_44:03:d9 (00:19:af:44:03:d9), Dst: Foxconn_e3:09:29 (00:15:58:e3:09:29) Internet Protocol Version 4, Src: 192.168.1.144 (192.168.1.144), Dst: 192.168.1.110 (192.168.1.110) Transmission Control Protocol, Src Port: sunrpc (111), Dst Port: 38861 (38861), Seq: 33, Ack: 62, Len: 0

No. Time Source Destination Protocol Length Info 23 4.037944000 192.168.1.144 192.168.1.110 TCP 60 sshell > 39762 [SYN, ACK] Seq=0 Ack=1 Win=8192 Len=0 MSS=1460

Frame 23: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0 Ethernet II, Src: RigolTec_44:03:d9 (00:19:af:44:03:d9), Dst: Foxconn_e3:09:29 (00:15:58:e3:09:29) Internet Protocol Version 4, Src: 192.168.1.144 (192.168.1.144), Dst: 192.168.1.110 (192.168.1.110) Transmission Control Protocol, Src Port: sshell (614), Dst Port: 39762 (39762), Seq: 0, Ack: 1, Len: 0

No. Time Source Destination Protocol Length Info 24 4.037963000 192.168.1.110 192.168.1.144 TCP 54 39762 > sshell [ACK] Seq=1 Ack=1 Win=29200 Len=0

Frame 24: 54 bytes on wire (432 bits), 54 bytes captured (432 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 39762 (39762), Dst Port: sshell (614), Seq: 1, Ack: 1, Len: 0

No. Time Source Destination Protocol Length Info 25 4.038192000 192.168.1.110 192.168.1.144 VXI-11 Core 122 V1 CREATE_LINK Call (Reply In 28) inst0

Frame 25: 122 bytes on wire (976 bits), 122 bytes captured (976 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 39762 (39762), Dst Port: sshell (614), Seq: 1, Ack: 1, Len: 68 Remote Procedure Call, Type:Call XID:0x00000001 VXI-11 Core Protocol (Create_LinkParms) inst0

No. Time Source Destination Protocol Length Info 26 4.043453000 192.168.1.144 192.168.1.110 TCP 60 sunrpc > 38861 [FIN, ACK] Seq=33 Ack=62 Win=8191 Len=0

Frame 26: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0 Ethernet II, Src: RigolTec_44:03:d9 (00:19:af:44:03:d9), Dst: Foxconn_e3:09:29 (00:15:58:e3:09:29) Internet Protocol Version 4, Src: 192.168.1.144 (192.168.1.144), Dst: 192.168.1.110 (192.168.1.110) Transmission Control Protocol, Src Port: sunrpc (111), Dst Port: 38861 (38861), Seq: 33, Ack: 62, Len: 0

No. Time Source Destination Protocol Length Info 27 4.043471000 192.168.1.110 192.168.1.144 TCP 54 38861 > sunrpc [ACK] Seq=62 Ack=34 Win=29200 Len=0

Frame 27: 54 bytes on wire (432 bits), 54 bytes captured (432 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 38861 (38861), Dst Port: sunrpc (111), Seq: 62, Ack: 34, Len: 0

No. Time Source Destination Protocol Length Info 28 4.048872000 192.168.1.144 192.168.1.110 VXI-11 Core 98 V1 CREATE_LINK Reply (Call In 25) No Error LID=0

Frame 28: 98 bytes on wire (784 bits), 98 bytes captured (784 bits) on interface 0 Ethernet II, Src: RigolTec_44:03:d9 (00:19:af:44:03:d9), Dst: Foxconn_e3:09:29 (00:15:58:e3:09:29) Internet Protocol Version 4, Src: 192.168.1.144 (192.168.1.144), Dst: 192.168.1.110 (192.168.1.110) Transmission Control Protocol, Src Port: sshell (614), Dst Port: 39762 (39762), Seq: 1, Ack: 69, Len: 44 Remote Procedure Call, Type:Reply XID:0x00000001 VXI-11 Core Protocol (Create_LinkResp) No Error LID=0

No. Time Source Destination Protocol Length Info 29 4.048896000 192.168.1.110 192.168.1.144 TCP 54 39762 > sshell [ACK] Seq=69 Ack=45 Win=29200 Len=0

Frame 29: 54 bytes on wire (432 bits), 54 bytes captured (432 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 39762 (39762), Dst Port: sshell (614), Seq: 69, Ack: 45, Len: 0

No. Time Source Destination Protocol Length Info 30 4.049384000 192.168.1.110 192.168.1.144 VXI-11 Core 126 V1 DEVICE_WRITE Call (Reply In 31) LID=0

Frame 30: 126 bytes on wire (1008 bits), 126 bytes captured (1008 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 39762 (39762), Dst Port: sshell (614), Seq: 69, Ack: 45, Len: 72 Remote Procedure Call, Type:Call XID:0x00000002 VXI-11 Core Protocol (Device_WriteParms) LID=0

No. Time Source Destination Protocol Length Info 31 4.054604000 192.168.1.144 192.168.1.110 VXI-11 Core 90 V1 DEVICE_WRITE Reply (Call In 30) Device Locked

Frame 31: 90 bytes on wire (720 bits), 90 bytes captured (720 bits) on interface 0 Ethernet II, Src: RigolTec_44:03:d9 (00:19:af:44:03:d9), Dst: Foxconn_e3:09:29 (00:15:58:e3:09:29) Internet Protocol Version 4, Src: 192.168.1.144 (192.168.1.144), Dst: 192.168.1.110 (192.168.1.110) Transmission Control Protocol, Src Port: sshell (614), Dst Port: 39762 (39762), Seq: 45, Ack: 141, Len: 36 Remote Procedure Call, Type:Reply XID:0x00000002 VXI-11 Core Protocol (Device_WriteResp) Device Locked

No. Time Source Destination Protocol Length Info 32 4.055020000 192.168.1.110 192.168.1.144 VXI-11 Core 122 V1 DEVICE_READ Call (Reply In 42) LID=0

Frame 32: 122 bytes on wire (976 bits), 122 bytes captured (976 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 39762 (39762), Dst Port: sshell (614), Seq: 141, Ack: 81, Len: 68 Remote Procedure Call, Type:Call XID:0x00000003 VXI-11 Core Protocol (Device_ReadParms) LID=0

No. Time Source Destination Protocol Length Info 33 4.148469000 192.168.1.144 192.168.1.110 TCP 60 sshell > 39762 [ACK] Seq=81 Ack=209 Win=8192 Len=0

Frame 33: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0 Ethernet II, Src: RigolTec_44:03:d9 (00:19:af:44:03:d9), Dst: Foxconn_e3:09:29 (00:15:58:e3:09:29) Internet Protocol Version 4, Src: 192.168.1.144 (192.168.1.144), Dst: 192.168.1.110 (192.168.1.110) Transmission Control Protocol, Src Port: sshell (614), Dst Port: 39762 (39762), Seq: 81, Ack: 209, Len: 0

No. Time Source Destination Protocol Length Info 42 13.707061000 192.168.1.144 192.168.1.110 VXI-11 Core 94 V1 DEVICE_READ Reply (Call In 32) I/O Timeout

Frame 42: 94 bytes on wire (752 bits), 94 bytes captured (752 bits) on interface 0 Ethernet II, Src: RigolTec_44:03:d9 (00:19:af:44:03:d9), Dst: Foxconn_e3:09:29 (00:15:58:e3:09:29) Internet Protocol Version 4, Src: 192.168.1.144 (192.168.1.144), Dst: 192.168.1.110 (192.168.1.110) Transmission Control Protocol, Src Port: sshell (614), Dst Port: 39762 (39762), Seq: 81, Ack: 209, Len: 40 Remote Procedure Call, Type:Reply XID:0x00000003 VXI-11 Core Protocol (Device_ReadResp) I/O Timeout

No. Time Source Destination Protocol Length Info 43 13.717141000 192.168.1.110 192.168.1.144 VXI-11 Core 102 V1 DESTROY_LINK Call (Reply In 44) LID=0

Frame 43: 102 bytes on wire (816 bits), 102 bytes captured (816 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 39762 (39762), Dst Port: sshell (614), Seq: 209, Ack: 121, Len: 48 Remote Procedure Call, Type:Call XID:0x00000004 VXI-11 Core Protocol (Device_Link) LID=0

No. Time Source Destination Protocol Length Info 44 13.721302000 192.168.1.144 192.168.1.110 VXI-11 Core 86 V1 DESTROY_LINK Reply (Call In 43) No Error

Frame 44: 86 bytes on wire (688 bits), 86 bytes captured (688 bits) on interface 0 Ethernet II, Src: RigolTec_44:03:d9 (00:19:af:44:03:d9), Dst: Foxconn_e3:09:29 (00:15:58:e3:09:29) Internet Protocol Version 4, Src: 192.168.1.144 (192.168.1.144), Dst: 192.168.1.110 (192.168.1.110) Transmission Control Protocol, Src Port: sshell (614), Dst Port: 39762 (39762), Seq: 121, Ack: 257, Len: 32 Remote Procedure Call, Type:Reply XID:0x00000004 VXI-11 Core Protocol (Device_Error) No Error

No. Time Source Destination Protocol Length Info 45 13.721535000 192.168.1.110 192.168.1.144 TCP 54 39762 > sshell [FIN, ACK] Seq=257 Ack=153 Win=29200 Len=0

Frame 45: 54 bytes on wire (432 bits), 54 bytes captured (432 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 39762 (39762), Dst Port: sshell (614), Seq: 257, Ack: 153, Len: 0

No. Time Source Destination Protocol Length Info 46 13.724832000 192.168.1.144 192.168.1.110 TCP 60 sshell > 39762 [ACK] Seq=153 Ack=258 Win=8191 Len=0

Frame 46: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0 Ethernet II, Src: RigolTec_44:03:d9 (00:19:af:44:03:d9), Dst: Foxconn_e3:09:29 (00:15:58:e3:09:29) Internet Protocol Version 4, Src: 192.168.1.144 (192.168.1.144), Dst: 192.168.1.110 (192.168.1.110) Transmission Control Protocol, Src Port: sshell (614), Dst Port: 39762 (39762), Seq: 153, Ack: 258, Len: 0

No. Time Source Destination Protocol Length Info 47 13.727164000 192.168.1.144 192.168.1.110 TCP 60 sshell > 39762 [FIN, ACK] Seq=153 Ack=258 Win=8191 Len=0

Frame 47: 60 bytes on wire (480 bits), 60 bytes captured (480 bits) on interface 0 Ethernet II, Src: RigolTec_44:03:d9 (00:19:af:44:03:d9), Dst: Foxconn_e3:09:29 (00:15:58:e3:09:29) Internet Protocol Version 4, Src: 192.168.1.144 (192.168.1.144), Dst: 192.168.1.110 (192.168.1.110) Transmission Control Protocol, Src Port: sshell (614), Dst Port: 39762 (39762), Seq: 153, Ack: 258, Len: 0

No. Time Source Destination Protocol Length Info 48 13.727202000 192.168.1.110 192.168.1.144 TCP 54 39762 > sshell [ACK] Seq=258 Ack=154 Win=29200 Len=0

Frame 48: 54 bytes on wire (432 bits), 54 bytes captured (432 bits) on interface 0 Ethernet II, Src: Foxconn_e3:09:29 (00:15:58:e3:09:29), Dst: RigolTec_44:03:d9 (00:19:af:44:03:d9) Internet Protocol Version 4, Src: 192.168.1.110 (192.168.1.110), Dst: 192.168.1.144 (192.168.1.144) Transmission Control Protocol, Src Port: 39762 (39762), Dst Port: sshell (614), Seq: 258, Ack: 154, Len: 0

zikako74 commented 9 years ago

Read Frame 30 - 42

hgrecco commented 9 years ago

Does it work ok with NI-VISA? It would be very nice to have a diff between the sniffed packaged with @ni and @py

zikako74 commented 9 years ago

I have sniffed packet for @ni, @pi and ni-visa with rigol tool. The difference is in I/O Timeout and LOCK Timeout.

with @ni or @py

VXI-11 Core Protocol (Device_WriteParms) LID=0 [Program Version: 1] [V1 Procedure: DEVICE_WRITE (11)] Link ID: 0 I/O Timeout: 2000 Lock Timeout: 0 Flags: 0x00000008 (END) .... .... .... .... .... .... .... ...0 = Wait Until Locked: False .... .... .... .... .... .... .... 1... = Set EOI: True .... .... .... .... .... .... 0... .... = Termination Character Set: False Data: length: 6 contents: fill bytes: opaque data

0000 00 19 af 44 03 d9 b8 76 3f 1a 5b e4 08 00 45 00 ...D...v?.[...E. 0010 00 70 1e 35 40 00 80 06 58 08 c0 a8 01 6a c0 a8 .p.5@...X....j.. 0020 01 90 05 43 02 66 f3 b2 6b dd 00 00 1d 58 50 18 ...C.f..k....XP. 0030 fa c4 32 c9 00 00 80 00 00 44 00 00 3b 93 00 00 ..2......D..;... 0040 00 00 00 00 00 02 00 06 07 af 00 00 00 01 00 00 ................ 0050 00 0b 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ 0060 00 00 00 00 00 00 00 00 07 d0 00 00 00 00 00 00 ................ 0070 00 08 00 00 00 06 2a 49 44 4e 3f 0a 00 00 ......*IDN?...

with Rigol tools and ni-visa (the same used for @ni and pyvisa)

VXI-11 Core Protocol (Device_WriteParms) LID=0 [Program Version: 1] [V1 Procedure: DEVICE_WRITE (11)] Link ID: 0 I/O Timeout: 2000 Lock Timeout: 0 Flags: 0x00000008 (END) .... .... .... .... .... .... .... ...0 = Wait Until Locked: False .... .... .... .... .... .... .... 1... = Set EOI: True .... .... .... .... .... .... 0... .... = Termination Character Set: False Data: length: 7 contents: fill bytes: opaque data

0000 00 19 af 44 03 d9 b8 76 3f 1a 5b e4 08 00 45 00 ...D...v?.[...E. 0010 00 70 1f d5 40 00 80 06 56 68 c0 a8 01 6a c0 a8 .p..@...Vh...j.. 0020 01 90 05 5b 02 66 a2 d7 ef 6b 00 00 30 f6 50 18 ...[.f...k..0.P. 0030 fa c4 0d 2d 00 00 80 00 00 44 00 00 10 c2 00 00 ...-.....D...... 0040 00 00 00 00 00 02 00 06 07 af 00 00 00 01 00 00 ................ 0050 00 0b 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ 0060 00 00 00 00 00 00 00 00 07 d0 00 00 00 00 00 00 ................ 0070 00 08 00 00 00 07 2a 49 44 4e 3f 0d 0a 00 ......*IDN?...

Where is Timeout in VXI protocol ?

zikako74 commented 9 years ago

In the @py the Termination charapter set is TRUE, but the response is the same. if you want I can send you the logs of packet. Send your email !

hgrecco commented 9 years ago

Awesome. Thanks for all the info. I would say that you first try to change the termination character. The current implementation does not allow you to change the default timeout of the sockets.

hgrecco commented 9 years ago

my e-mail if in the AUTHORS file

zikako74 commented 9 years ago

email sent ... i have used the last pyvisa 1.9 and pyvisa-py 0.3 on WindowsXP 32 bit and ni-visa dll and with the "manual" modify to rpc.py. The RPC protocol RPC seems to work...

zikako74 commented 9 years ago

Machine Details: Platform ID: Linux-3.4.6-2.10-default-i686-with-SuSE-12.2-i586 Processor: i686

Python: Implementation: CPython Executable: /usr/bin/python Version: 2.7.3 Compiler: GCC Bits: 32bit Build: Apr 14 2012 08:58:41 (#default) Unicode: UCS4

PyVISA Version: 1.8

Backends: ni: Version: 1.8 (bundled with PyVISA)

1: /usr/local/vxipnp/linux/bin/libvisa.so.7:

     found by: auto
     bitness: 32
     Vendor: National Instruments
     Impl. Version: 5243904
     Spec. Version: 5243136

py: Version: 0.3.dev0 ASRL INSTR: Available via PySerial (2.7) TCPIP INSTR: Available USB RAW: Please install PyUSB to use this resource type. No module named usb USB INSTR: Please install PyUSB to use this resource type. No module named usb GPIB INSTR: Please install linux-gpib to use this resource type. No module named gpib TCPIP SOCKET: Available

squalo@linux-2ccd:~> python rigol.py 2015-08-27 22:52:41,955 - pyvisa - DEBUG - No user defined library files 2015-08-27 22:52:42,005 - pyvisa - DEBUG - Automatically found library files: ['/usr/local/vxipnp/linux/bin/libvisa.so.7'] 2015-08-27 22:52:42,006 - pyvisa - DEBUG - Library signatures: 90 ok, 0 failed 2015-08-27 22:52:42,007 - pyvisa - DEBUG - Created library wrapper for /usr/local/vxipnp/linux/bin/libvisa.so.7 2015-08-27 22:52:42,011 - pyvisa - DEBUG - viOpenDefaultRM('<ViObject object at 0x8787e3c>',) -> 0 2015-08-27 22:52:42,011 - pyvisa - DEBUG - Created ResourceManager with session 142720448 2015-08-27 22:52:42,012 - pyvisa - DEBUG - viParseRsrcEx(142720448L, 'TCPIP::192.168.1.144::INSTR', 'c_ushort(6)', 'c_ushort(0)', <ctypes.c_char_Array_256 object at 0x8854a4c>, <ctypes.c_char_Array_256 object at 0x8854bfc>, <ctypes.c_char_Array_256 object at 0x8854dac>) -> 0 2015-08-27 22:52:42,012 - pyvisa - DEBUG - TCPIP::192.168.1.144::INSTR - opening ... 2015-08-27 22:52:42,061 - pyvisa - DEBUG - viOpen(142720448L, 'TCPIP::192.168.1.144::INSTR', <AccessModes.no_lock: 0>, 0, '<ViObject object at 0x8787e3c>') -> 0 2015-08-27 22:52:42,061 - pyvisa - DEBUG - TCPIP::192.168.1.144::INSTR - is open with session 143911456 2015-08-27 22:52:42,118 - pyvisa - DEBUG - viWrite(143911456L, '_IDN?\r\n', 7, 'c_ulong(7L)') -> 0 2015-08-27 22:52:42,119 - pyvisa - DEBUG - TCPIP::192.168.1.144::INSTR - reading 20480 bytes (last status <StatusCode.success_max_count_read: 1073676294>) 2015-08-27 22:52:43,983 - pyvisa - DEBUG - viRead(143911456L, <ctypes.c_char_Array_20480 object at 0x8787e3c>, 20480, 'c_ulong(0L)') -> -1073807339 2015-08-27 22:52:43,984 - pyvisa - DEBUG - TCPIP::192.168.1.144::INSTR - exception while reading: VI_ERROR_TMO (-1073807339): Timeout expired before operation completed. Traceback (most recent call last): File "rigol.py", line 5, in print(inst.query("_IDN?")) File "/usr/local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 407, in query return self.read() File "/usr/local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 332, in read message = self.read_raw().decode(enco) File "/usr/local/lib/python2.7/site-packages/pyvisa/resources/messagebased.py", line 306, in read_raw chunk, status = self.visalib.read(self.session, size) File "/usr/local/lib/python2.7/site-packages/pyvisa/ctwrapper/functions.py", line 1582, in read ret = library.viRead(session, buffer, count, byref(return_count)) File "/usr/local/lib/python2.7/site-packages/pyvisa/ctwrapper/highlevel.py", line 188, in _return_handler raise errors.VisaIOError(ret_value) pyvisa.errors.VisaIOError: VI_ERROR_TMO (-1073807339): Timeout expired before operation completed. 2015-08-27 22:52:43,996 - pyvisa - DEBUG - TCPIP::192.168.1.144::INSTR - closing 2015-08-27 22:52:43,998 - pyvisa - DEBUG - viDisableEvent(143911456L, 1073709055, 65535) -> 1073676291 2015-08-27 22:52:43,998 - pyvisa - DEBUG - viDiscardEvents(143911456L, 1073709055, 65535) -> 1073676292 2015-08-27 22:52:44,035 - pyvisa - DEBUG - viClose(143911456L,) -> 0 2015-08-27 22:52:44,036 - pyvisa - DEBUG - TCPIP::192.168.1.144::INSTR - is closed

zikako74 commented 9 years ago

This is a solution ? http://optics.eee.nottingham.ac.uk/vxi11/

Rigol DM3068 multimeters In vxi11_user.cc you need to change the write_parms.lock_timeout value to 0, rather than VXI11_DEFAULT_TIMEOUT, in the vxi11_send() function (currently line 466 in version 1.10). If you don't do this, the DM3068 returns 'Device Locked'. Thanks to Ian West for reporting this gotcha.