labgrid-project / labgrid

Embedded systems control library for development, testing and installation
https://labgrid.readthedocs.io/
Other
327 stars 164 forks source link

No udisks2 device found for /dev/sdo1 #1357

Closed sjg20 closed 2 months ago

sjg20 commented 4 months ago

Following along with video-tutorial number 4, I am trying to use the USBStorageDriver.write_files() with an SDwire mux and get the above error, on this line:

    mount_path = self.proxy.mount(self.devpath)

It works OK the second time I try, perhaps because the block device has appeared by then.

For my home-grown (labman) lab I have code that retries for up to 5 seconds for the device to appear. Perhaps we need something like that?

sjg20 commented 4 months ago

I found a call to _wait_for_medium in write_image() so added that to write_files() too.

Now I get this error:

 LG_CROSSBAR=ws://kea:20408/ws labgrid-client -vv -c env_rpi_try.cfg -s uboot console
Selected role rpi3 and place rpi3 from configuration file
Transitioning into state uboot
INFO         StepLogger:  → USBSDWireDriver.sdmux_set(mode='host') 
INFO    SSHConnection(h:   Created new SSH connection to kea
INFO         StepLogger:   → ProcessWrapper.check_output(command=['ssh', '-x', '-o', 'LogLevel=ERROR', '-o', 'PasswordAuthentication=no', '-o', 'ControlMaster=no', '-o', 'ControlPath=/tmp/lg-con-rpj8axax/control-kea', 'kea', '--', 'sd-mux-ctrl', '--ts', '-e', 'sdwire-18']) 
INFO            Process:    [60142] command: ssh -x -o LogLevel=ERROR -o PasswordAuthentication=no -o ControlMaster=no -o ControlPath=/tmp/lg-con-rpj8axax/control-kea kea -- sd-mux-ctrl --ts -e sdwire-18
INFO         StepLogger:   ← ProcessWrapper.check_output() result=b'' [0.235s]
INFO         StepLogger:  ← USBSDWireDriver.sdmux_set() [0.330s]
here /tmp/b/rpi_3_32b/u-boot.bin
INFO         StepLogger:  → USBStorageDriver.write_files(sources=['/tmp/b/rpi_3_32b/u-boot.bin'] target=PurePosixPath('/rpi3-u-boot.bin') partition=1 target_is_directory=False) 
INFO         StepLogger:   → USBStorageDriver.get_size(partition=1) 
cat: /sys/class/block/sdo1/size: No such file or directory
INFO         StepLogger:   ⚠ USBStorageDriver.get_size() [0.015s] exception=Command '['ssh', '-x', '-o', 'LogLevel=ERROR', '-o', 'PasswordAuthentication=no', '-o', 'ControlMaster=no', '-o', 'ControlPath=/tmp/lg-con-rpj8axax/control-kea', 'kea', '--', 'cat', '/sys/class/block/sdo1/size']' returned non-zero exit status 1.
INFO         StepLogger:  ⚠ USBStorageDriver.write_files() [0.015s] exception=Command '['ssh', '-x', '-o', 'LogLevel=ERROR', '-o', 'PasswordAuthentication=no', '-o', 'ControlMaster=no', '-o', 'ControlPath=/tmp/lg-con-rpj8axax/control-kea', 'kea', '--', 'cat', '/sys/class/block/sdo1/size']' returned non-zero exit status 1.
Traceback (most recent call last):
  File "/home/sglass/.local/lib/python3.10/site-packages/labgrid/remote/client.py", line 1934, in main
    target = session._get_target(place)
  File "/home/sglass/.local/lib/python3.10/site-packages/labgrid/remote/client.py", line 679, in _get_target
    strategy.transition(self.args.state)
  File "/vid/software/devel/ubtest/lab/rpi3_strategy.py", line 63, in transition
    self.transition(Status.bootstrapped)
  File "/vid/software/devel/ubtest/lab/rpi3_strategy.py", line 60, in transition
    self.bootstrap()
  File "/vid/software/devel/ubtest/lab/rpi3_strategy.py", line 41, in bootstrap
    self.storage.write_files([image], pathlib.PurePath("/rpi3-u-boot.bin"),
  File "/home/sglass/.local/lib/python3.10/site-packages/labgrid/binding.py", line 102, in wrapper
    return func(self, *_args, **_kwargs)
  File "/home/sglass/.local/lib/python3.10/site-packages/labgrid/step.py", line 215, in wrapper
    _result = func(*_args, **_kwargs)
  File "/home/sglass/.local/lib/python3.10/site-packages/labgrid/driver/usbstoragedriver.py", line 80, in write_files
    self._wait_for_medium(partition)
  File "/home/sglass/.local/lib/python3.10/site-packages/labgrid/binding.py", line 102, in wrapper
    return func(self, *_args, **_kwargs)
  File "/home/sglass/.local/lib/python3.10/site-packages/labgrid/driver/usbstoragedriver.py", line 203, in _wait_for_medium
    if self.get_size(partition) > 0:
  File "/home/sglass/.local/lib/python3.10/site-packages/labgrid/binding.py", line 102, in wrapper
    return func(self, *_args, **_kwargs)
  File "/home/sglass/.local/lib/python3.10/site-packages/labgrid/step.py", line 215, in wrapper
    _result = func(*_args, **_kwargs)
  File "/home/sglass/.local/lib/python3.10/site-packages/labgrid/driver/usbstoragedriver.py", line 223, in get_size
    size = subprocess.check_output(self.storage.command_prefix + args)
  File "/usr/lib/python3.10/subprocess.py", line 421, in check_output
    return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
  File "/usr/lib/python3.10/subprocess.py", line 526, in run
    raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '['ssh', '-x', '-o', 'LogLevel=ERROR', '-o', 'PasswordAuthentication=no', '-o', 'ControlMaster=no', '-o', 'ControlPath=/tmp/lg-con-rpj8axax/control-kea', 'kea', '--', 'cat', '/sys/class/block/sdo1/size']' returned non-zero exit status 1.
INFO    SSHConnection(h:  Closing SSH connection to kea
sjg20 commented 4 months ago

I tried retrying when the partition device (/dev/sdo1) does not exist. Howver, I see see problems:

INFO         StepLogger:  → USBStorageDriver.write_files(sources=['/tmp/b/rpi_3_32b/u-boot.bin'] target=PurePosixPath('/rpi3-u-boot.bin') partition=1 target_is_directory=False) 
INFO         StepLogger:   → USBStorageDriver.get_size(partition=1) 
cat: /sys/class/block/sdo1/size: No such file or directory
INFO         StepLogger:   ← USBStorageDriver.get_size() result=0 [0.015s]
INFO         StepLogger:   → USBStorageDriver.get_size(partition=1) 
cat: /sys/class/block/sdo1/size: No such file or directory
INFO         StepLogger:   ← USBStorageDriver.get_size() result=0 [0.020s]
INFO         StepLogger:   → USBStorageDriver.get_size(partition=1) 
INFO         StepLogger:   ← USBStorageDriver.get_size() result=629145600 [0.018s]
INFO         StepLogger:  ⚠ USBStorageDriver.write_files() [1.080s] exception=ValueError('No udisks2 device found for /dev/sdo1')

So it seems that udisks2 takes extra time to discover the device, event when it is present in the filesystem