search

labgrid-project / labgrid

embedded systems control library for development, testing and installation
https://labgrid.readthedocs.io/
Other
313 stars 162 forks source link

Dealing with a transient serial port #1387

Open sjg20 opened 2 months ago

sjg20 commented 2 months ago

I have a zynq_zybo board which has a built-in UART, connected to my lab server via a micro-USB cable. The UART appears when the board powers on and goes away when not.

At present I am seeing this output from labgrid-client:

LG_CROSSBAR=ws://kea:20408/ws labgrid-client  -c /vid/software/devel/ubtest/lab/env_rpi_try.cfg -V do-bootstrap 1 -V do-build 1 -V do-send 0 -p zynq_zybo -s start -a console
Building U-Boot in sourcedir for xilinx_zynq_virt
Writing U-Boot using method zynq
cat: /sys/class/block/sdv1/size: No such file or directory
cat: /sys/class/block/sdv1/size: No such file or directory
cat: /sys/class/block/sdv1/size: No such file or directory
console
Traceback (most recent call last):
  File "/vid/software/devel/ubtest/labgrid/labgrid/remote/client.py", line 1969, in main
    target = session._get_target(place)
  File "/vid/software/devel/ubtest/labgrid/labgrid/remote/client.py", line 681, in _get_target
    strategy.transition(self.args.state)
  File "/vid/software/devel/ubtest/labgrid/labgrid/strategy/ubootstrategy.py", line 91, in transition
    self.target.activate(self.console)  # for zynq_zybo
  File "/vid/software/devel/ubtest/labgrid/labgrid/target.py", line 469, in activate
    self.await_resources(resources)
  File "/vid/software/devel/ubtest/labgrid/labgrid/target.py", line 101, in await_resources
    raise NoResourceFoundError(
labgrid.exceptions.NoResourceFoundError: Not all resources are available: {NetworkSerialPort(target=Target(name='zynq_zybo', env=Environment(config_file='/vid/software/devel/ubtest/lab/env_rpi_try.cfg'), var_dict=None), name='USBSerialPort', state=<BindingState.bound: 1>, avail=False, host='kea', port=None, speed=115200, protocol='rfc2217')}

The word 'console' is printed just before the console is activated (self.target.activate(self.console))

I was expecting that this sort of thing would be handled automatically. Is there a way to make this work?

BTW the labgrid-suggest output is this:

=== added device ===
  USBSerialPort for /devices/pci0000:00/0000:00:1b.0/0000:02:00.0/0000:03:00.2/usb1/1-5/1-5.2/1-5.2.1/1-5.2.1:1.0/ttyUSB7/tty/ttyUSB7
  === device properties ===
  device node: /dev/ttyUSB7
  udev tags: , systemd
  vendor: Digilent
  vendor (DB): Future Technology Devices International, Ltd
  model: Digilent_Adept_USB_Device
  model (DB): FT2232C/D/H Dual UART/FIFO IC
  revision: 0700
  === suggested matches ===
  USBSerialPort:
    match:
      ID_PATH: pci-0000:03:00.2-usb-0:5.2.1:1.0
  ---
  USBSerialPort:
    match:
      ID_SERIAL_SHORT: '210279653540'
      ID_USB_INTERFACE_NUM: '00'
  ---

=== added device ===
  USBSerialPort for /devices/pci0000:00/0000:00:1b.0/0000:02:00.0/0000:03:00.2/usb1/1-5/1-5.2/1-5.2.1/1-5.2.1:1.1/ttyUSB20/tty/ttyUSB20
  === device properties ===
  device node: /dev/ttyUSB20
  udev tags: , systemd
  vendor: Digilent
  vendor (DB): Future Technology Devices International, Ltd
  model: Digilent_Adept_USB_Device
  model (DB): FT2232C/D/H Dual UART/FIFO IC
  revision: 0700
  === suggested matches ===
  USBSerialPort:
    match:
      ID_PATH: pci-0000:03:00.2-usb-0:5.2.1:1.1
  ---
  USBSerialPort:
    match:
      ID_SERIAL_SHORT: '210279653540'
      ID_USB_INTERFACE_NUM: '01'
  ---

so I am using this in my export file:

zynq_zybo:
  location: 'lab'
  USBSerialPort:
    ## ttyusb_port5
    ## hub c1
    match:
      ##'@ID_PATH': 'pci-0000:03:00.2-usb-0:5.2.1:1.1'
      ID_SERIAL_SHORT: 210279653540
      ID_USB_INTERFACE_NUM: 01

  USBSDWireDevice:
    ## sdwire3
    ## hub
    match:
      'ID_SERIAL_SHORT': '202001064001'

  NetworkPowerPort:
    ## dli_main_port1
    model: digitalloggers_http
    host: http://admin:1234@192.168.4.19
    index: 5

  HIDRelay:
    ## usbrelay 0 6
    ##serial: 6QMBS
    index: 6
    usbrelay: True
    match:
      '@ID_PATH': 'pci-0000:00:14.0-usb-0:10.1.2'

although I have tried various things for USBSerialPort

Emantor commented 2 months ago

Your strategy probably does not wait for the resources to become available with await_resources, I added documentation for this in #1388.

sjg20 commented 2 months ago

Thanks, I tried that but I still get an error, this time in the call to 

                self.target.await_resources([self.console.port], 10.0)

:
labgrid-client: error: Not all resources are available: {NetworkSerialPort(target=Target(name='zynq_zybo', env=Environment(config_file='/vid/software/devel/ubtest/lab/env_rpi_try.cfg'), var_dict=None), name='USBSerialPort', state=<BindingState.bound: 1>, avail=False, host='kea', port=None, speed=115200, protocol='rfc2217')}

I see that labgrid-suggest shows the port coming up:

=== added device ===
  USBSerialPort for /devices/pci0000:00/0000:00:1b.0/0000:02:00.0/0000:03:00.2/usb1/1-5/1-5.2/1-5.2.1/1-5.2.1:1.0/ttyUSB7/tty/ttyUSB7
  === device properties ===
  device node: /dev/ttyUSB7
  udev tags: , systemd
  vendor: Digilent
  vendor (DB): Future Technology Devices International, Ltd
  model: Digilent_Adept_USB_Device
  model (DB): FT2232C/D/H Dual UART/FIFO IC
  revision: 0700
  === suggested matches ===
  USBSerialPort:
    match:
      ID_PATH: pci-0000:03:00.2-usb-0:5.2.1:1.0
  ---
  USBSerialPort:
    match:
      ID_SERIAL_SHORT: '210279653540'
      ID_USB_INTERFACE_NUM: '00'
  ---

=== added device ===
  USBSerialPort for /devices/pci0000:00/0000:00:1b.0/0000:02:00.0/0000:03:00.2/usb1/1-5/1-5.2/1-5.2.1/1-5.2.1:1.1/ttyUSB20/tty/ttyUSB20
  === device properties ===
  device node: /dev/ttyUSB20
  udev tags: , systemd
  vendor: Digilent
  vendor (DB): Future Technology Devices International, Ltd
  model: Digilent_Adept_USB_Device
  model (DB): FT2232C/D/H Dual UART/FIFO IC
  revision: 0700
  === suggested matches ===
  USBSerialPort:
    match:
      ID_PATH: pci-0000:03:00.2-usb-0:5.2.1:1.1
  ---
  USBSerialPort:
    match:
      ID_SERIAL_SHORT: '210279653540'
      ID_USB_INTERFACE_NUM: '01'
  ---

What triggers the 'avail' to change to True on the client?

sjg20 commented 2 months ago

Strangely, when I do this:

LG_CROSSBAR=ws://kea:20408/ws labgrid-client  -c /vid/software/devel/ubtest/lab/env_rpi_try.cfg -p zynq_zybo resources

I can see the device appear and disappear from the list when the device is on/off. But it seems to be 'stuck' in 'avail == False' in the strategy.

sjg20 commented 2 months ago

Hmm I see that NetworkSerialPort() defines poll() to do nothing. Why is that?

When I remove that, I see a bit more progress. The device does become available and it gets further:

failed to connect: Connection refused

Here is the debug log:

...
INFO         StepLogger:   ← NetworkPowerDriver.on() [0.101s]
INFO         StepLogger:  ← NetworkPowerDriver.cycle() [2.194s]
console NetworkSerialPort(target=Target(name='zynq_zybo', env=Environment(config_file='/vid/software/devel/ubtest/lab/env_rpi_try.cfg'), var_dict=None), name='USBSerialPort', state=<BindingState.bound: 1>, avail=False, host='kea', port=None, speed=115200, protocol='rfc2217')
DEBUG   RemotePlaceMana:  changed attributes for NetworkSerialPort(target=Target(name='zynq_zybo', env=Environment(config_file='/vid/software/devel/ubtest/lab/env_rpi_try.cfg'), var_dict=None), name='USBSerialPort', state=<BindingState.bound: 1>, avail=True, host='kea', port=39809, speed=115200, protocol='rfc2217'):
DEBUG   RemotePlaceMana:    port: None -> 39809
DEBUG   RemotePlaceMana:    avail: False -> True
console NetworkSerialPort(target=Target(name='zynq_zybo', env=Environment(config_file='/vid/software/devel/ubtest/lab/env_rpi_try.cfg'), var_dict=None), name='USBSerialPort', state=<BindingState.bound: 1>, avail=True, host='kea', port=39809, speed=115200, protocol='rfc2217')
INFO         StepLogger:  → NetworkPowerDriver.reset() 
INFO         StepLogger:   → NetworkPowerDriver.cycle() 
INFO         StepLogger:    → NetworkPowerDriver.off() 
DEBUG   urllib3.connect:     Starting new HTTP connection (1): 192.168.4.19:80
DEBUG   urllib3.connect:     http://192.168.4.19:80 "GET /outlet?5=OFF HTTP/1.1" 200 None
INFO         StepLogger:    ← NetworkPowerDriver.off() [0.112s]
INFO         StepLogger:    → NetworkPowerDriver.on() 
DEBUG   urllib3.connect:     Starting new HTTP connection (1): 192.168.4.19:80
DEBUG   urllib3.connect:     http://192.168.4.19:80 "GET /outlet?5=ON HTTP/1.1" 200 None
INFO         StepLogger:    ← NetworkPowerDriver.on() [0.112s]
INFO         StepLogger:   ← NetworkPowerDriver.cycle() [2.227s]
INFO         StepLogger:  ← NetworkPowerDriver.reset() [2.227s]
INFO               root:  connecting to NetworkSerialPort(target=Target(name='zynq_zybo', env=Environment(config_file='/vid/software/devel/ubtest/lab/env_rpi_try.cfg'), var_dict=None), name='USBSerialPort', state=<BindingState.active: 2>, avail=True, host='kea', port=39809, speed=115200, protocol='rfc2217') calling microcom -s 115200 -t kea:39809
failed to connect: Connection refused
connection lost
Traceback (most recent call last):
  File "/vid/software/devel/ubtest/labgrid/labgrid/remote/client.py", line 1973, in main
    session.loop.run_until_complete(coro)
  File "/usr/lib/python3.10/asyncio/base_events.py", line 649, in run_until_complete
    return future.result()
  File "/vid/software/devel/ubtest/labgrid/labgrid/remote/client.py", line 874, in console
    raise exc
labgrid.remote.client.InteractiveCommandError: microcom error
INFO    SSHConnection(h:  Closing SSH connection to kea
DEBUG   SSHConnection(h:  Stopping keepalive for kea
DEBUG   SSHConnection(h:  Running control command: ssh -x -o LogLevel=ERROR -o PasswordAuthentication=no -o ControlMaster=no -o ControlPath=/tmp/lg-con-dn6j5myf/control-kea -O cancel kea
DEBUG   SSHConnection(h:  Running control command: ssh -x -o LogLevel=ERROR -o PasswordAuthentication=no -o ControlMaster=no -o ControlPath=/tmp/lg-con-dn6j5myf/control-kea -O exit kea

On kea (exporter)I see:

2024-05-03T08:45:15 started ser2net for /dev/ttyUSB7 on port 39809
ser2net[151475]: dev read error for device on port con01: Remote end closed connection
2024-05-03T08:45:19 stopped ser2net for /dev/ttyUSB7 on port 39809
2024-05-03T08:45:22 started ser2net for /dev/ttyUSB7 on port 60409