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.

Sign up for GitHub

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

Jump to bottom

Dealing with a transient serial port #1387

Open
sjg20 opened this issue May 2, 2024 · 7 comments
Open

Dealing with a transient serial port #1387

sjg20 opened this issue May 2, 2024 · 7 comments

Comments

@sjg20
Copy link
Contributor

sjg20 commented May 2, 2024

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:[email protected]
    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
Copy link
Member

Emantor commented May 3, 2024

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

@sjg20
Copy link
Contributor Author

sjg20 commented May 3, 2024

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
Copy link
Contributor Author

sjg20 commented May 3, 2024

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
Copy link
Contributor Author

sjg20 commented May 3, 2024

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

@Emantor
Copy link
Member

Emantor commented Sep 9, 2024

On which ser2net version did you observe this on? We have seen quite some issues in newer versions.

@sjg20
Copy link
Contributor Author

sjg20 commented Sep 12, 2024

Oh dear. It is this:

ii ser2net 4.3.4-2 amd64 Serial port to network proxy

@Emantor
Copy link
Member

Emantor commented Sep 12, 2024 •
edited
Loading

AFAIR this mostly affects versions 4.6.1 and 4.6.2.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@Emantor @sjg20