search

PlanktoScope / PlanktoScope

Open and Affordable Quantitative Imaging Platform
https://www.planktoscope.org
Creative Commons Attribution Share Alike 4.0 International
62 stars 23 forks source link

backend/controller: Occasional camera timeout errors at the start of image acquisition #206

Closed ethanjli closed 6 months ago

ethanjli commented 1 year ago

Describe the bug Sometimes, when we start image acquisition, the first frame fails with a camera timeout error. Usually this is resolved by restarting Python, or else by rebooting the PlanktoScope.

This problem has been observed by Ethan on the Sikuliaq ToTS cruise, as well as in ten-earth rack bringup, and was also reported by Fabien (in a call) and reported by Satoshi in v2023.9.0-beta.0's testing period: "Acquisition does not start until the hardware controller is restarted. It always happens just after turning on the machine (and just after rebooting the device)" (with the attached log and the following screenshot): image

A similar problem was encountered by Ana Fernandez Carrera, where raspimjpeg seemed to stop responding to anything sent to it (both trying to start image acquisition, and adjusting camera parameters): log1_20230918.log

I have not yet found any existing GitHub Issues items reporting this behavior as something to fix.

To Reproduce I have not yet figured out how to reliably reproduce this issue.

Expected behavior Ideally, camera timeout errors should never occur if the hardware configuration has not changed.

Additional context This problem has occurred in the v2.3 software on both the v2.1 hardware and the v2.5 hardware (in Ethan's experience), and maybe also in the v2023.9.0-beta.0 software (based on Fabien Lombard's test report). Fabien has provided some logs (attached) when the timeout error occurs, e.g. in the 2023-09-02_08-20-58_015861.log file. fabien-logs-hardware-controller.zip

ethanjli commented 1 year ago

Here's the associated log which Satoshi uploaded, exhibiting a timeout with raspimjpeg:

2023-09-02 07:27:29.105 | INFO     | __main__:<module>:38 - Starting the PlanktoScope python script!
2023-09-02 07:27:29.107 | INFO     | __main__:<module>:50 - Welcome!
2023-09-02 07:27:29.108 | INFO     | __main__:<module>:51 - Initialising signals handling and sanitizing the directories (step 1/5)
2023-09-02 07:27:29.115 | INFO     | __main__:<module>:77 - This PlanktoScope unique ID is 10000000b23d5dc2
2023-09-02 07:27:29.118 | INFO     | __main__:<module>:78 - This PlanktoScope unique name is Babasau Gaulitoa
2023-09-02 07:27:29.123 | INFO     | __main__:<module>:87 - Starting the stepper control process (step 2/5)
2023-09-02 07:27:29.125 | INFO     | planktoscope.stepper:__init__:138 - Initialising the stepper process
2023-09-02 07:27:29.127 | DEBUG    | planktoscope.stepper:__init__:149 - Hardware configuration loaded is {'stepper_reverse': False, 'microsteps': 256, 'focus_steps_per_mm': 40, 'pump_steps_per_ml': 2045, 'focus_max_speed': 5, 'pump_max_speed': 50, 'stepper_type': 'pscope_hat', 'red_gain': 1.9, 'blue_gain': 1.7, 'analog_gain': 1, 'digital_gain': 1, 'acq_fnumber_objective': 16, 'process_pixel_fixed': 0.75}
2023-09-02 07:27:29.142 | DEBUG    | planktoscope.stepper:acceleration:108 - Setting stepper acceleration to 1000
2023-09-02 07:27:29.144 | DEBUG    | planktoscope.stepper:deceleration:122 - Setting stepper deceleration to 1000
2023-09-02 07:27:29.145 | DEBUG    | planktoscope.stepper:speed:94 - Setting stepper speed to 51200
2023-09-02 07:27:29.146 | DEBUG    | planktoscope.stepper:acceleration:108 - Setting stepper acceleration to 2000
2023-09-02 07:27:29.149 | DEBUG    | planktoscope.stepper:deceleration:122 - Setting stepper deceleration to 2000
2023-09-02 07:27:29.151 | DEBUG    | planktoscope.stepper:speed:94 - Setting stepper speed to 436266.6666666667
2023-09-02 07:27:29.153 | INFO     | planktoscope.stepper:__init__:191 - Stepper initialisation is over
2023-09-02 07:27:29.188 | INFO     | planktoscope.stepper:run:411 - The stepper control process has been started in process 2996
2023-09-02 07:27:29.185 | INFO     | __main__:<module>:92 - Starting the imager control process (step 3/5)
2023-09-02 07:27:29.191 | INFO     | planktoscope.imager:__init__:66 - planktoscope.imager is initialising
2023-09-02 07:27:29.190 | INFO     | planktoscope.mqtt:connect:87 - trying to connect to 127.0.0.1:1883
2023-09-02 07:27:29.193 | DEBUG    | planktoscope.imager:__init__:72 - Hardware configuration loaded is {'stepper_reverse': False, 'microsteps': 256, 'focus_steps_per_mm': 40, 'pump_steps_per_ml': 2045, 'focus_max_speed': 5, 'pump_max_speed': 50, 'stepper_type': 'pscope_hat', 'red_gain': 1.9, 'blue_gain': 1.7, 'analog_gain': 1, 'digital_gain': 1, 'acq_fnumber_objective': 16, 'process_pixel_fixed': 0.75}
2023-09-02 07:27:29.195 | DEBUG    | planktoscope.imager.raspimjpeg:__init__:32 - The status file does not exists, creating now
2023-09-02 07:27:29.197 | DEBUG    | planktoscope.imager.raspimjpeg:__init__:43 - The pipe does not exists, creating now
2023-09-02 07:27:29.203 | SUCCESS  | planktoscope.mqtt:on_connect:113 - actuator_client connected to 127.0.0.1:1883! - 0: Connection successful
2023-09-02 07:27:29.204 | SUCCESS  | planktoscope.stepper:run:428 - Stepper is READY!
2023-09-02 07:27:29.209 | DEBUG    | planktoscope.imager.raspimjpeg:start:52 - Starting up raspimjpeg
2023-09-02 07:27:29.226 | DEBUG    | planktoscope.imager.raspimjpeg:__parse_output_for:122 - Parsing the output for Camera Name for 5s
2023-09-02 07:27:29.250 | SUCCESS  | planktoscope.mqtt:on_subscribe:124 - actuator_client subscribed to actuator/#! - mid:3 qos:(0,)
2023-09-02 07:27:29.329 | DEBUG    | planktoscope.imager.raspimjpeg:__parse_output_for:122 - Parsing the output for Camera Max Width: for 5s
2023-09-02 07:27:29.330 | DEBUG    | planktoscope.imager.raspimjpeg:__parse_output_for:122 - Parsing the output for Camera Max Height for 5s
2023-09-02 07:27:29.332 | DEBUG    | planktoscope.imager.raspimjpeg:__wait_for_output:151 - Waiting for Starting command loop for 5s
2023-09-02 07:27:30.441 | INFO     | planktoscope.imager:__init__:145 - Initialising the camera with the default settings
2023-09-02 07:27:30.442 | DEBUG    | planktoscope.imager.raspimjpeg:resolution:257 - Setting the resolution to (4056, 3040)
2023-09-02 07:27:30.444 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [px 1640 1232 15 15 4056 3040 01] to raspimjpeg
2023-09-02 07:27:30.546 | DEBUG    | planktoscope.imager.raspimjpeg:iso:288 - Setting the iso number to 100
2023-09-02 07:27:30.547 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [is 100] to raspimjpeg
2023-09-02 07:27:30.549 | DEBUG    | planktoscope.imager.raspimjpeg:__wait_for_output:151 - Waiting for Change: iso for 5s
2023-09-02 07:27:31.554 | DEBUG    | planktoscope.imager.raspimjpeg:shutter_speed:309 - Setting the shutter speed to 1
2023-09-02 07:27:31.556 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [ss 1] to raspimjpeg
2023-09-02 07:27:31.558 | DEBUG    | planktoscope.imager.raspimjpeg:__wait_for_output:151 - Waiting for Change: shutter_speed for 5s
2023-09-02 07:27:31.760 | DEBUG    | planktoscope.imager.raspimjpeg:exposure_mode:332 - Setting the exposure mode to auto
2023-09-02 07:27:31.761 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [em auto] to raspimjpeg
2023-09-02 07:27:31.864 | DEBUG    | planktoscope.imager.raspimjpeg:white_balance:368 - Setting the white balance mode to off
2023-09-02 07:27:31.867 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [wb off] to raspimjpeg
2023-09-02 07:27:31.969 | DEBUG    | planktoscope.imager.raspimjpeg:white_balance_gain:403 - Setting the white balance mode to (190, 170)
2023-09-02 07:27:31.970 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [ag 190 170] to raspimjpeg
2023-09-02 07:27:32.072 | DEBUG    | planktoscope.imager.raspimjpeg:image_gain:430 - Setting the analog gain to (100, 100)
2023-09-02 07:27:32.074 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [ig 100 100] to raspimjpeg
2023-09-02 07:27:32.078 | SUCCESS  | planktoscope.imager:__init__:208 - planktoscope.imager is initialised and ready to go!
2023-09-02 07:27:32.086 | INFO     | __main__:<module>:102 - Starting the light control process (step 4/5)
2023-09-02 07:27:32.092 | INFO     | planktoscope.light:__init__:234 - planktoscope.light is initialising
2023-09-02 07:27:32.091 | INFO     | planktoscope.imager:run:701 - The imager control thread has been started in process 3026
2023-09-02 07:27:32.094 | DEBUG    | planktoscope.light:output_to_led1:81 - Switching output to LED 1
2023-09-02 07:27:32.095 | DEBUG    | planktoscope.light:force_reset:109 - Resetting the LED chip
2023-09-02 07:27:32.096 | INFO     | planktoscope.mqtt:connect:87 - trying to connect to 127.0.0.1:1883
2023-09-02 07:27:32.101 | DEBUG    | planktoscope.light:__init__:78 - LED module id is 1
2023-09-02 07:27:32.102 | DEBUG    | planktoscope.light:set_torch_current:140 - Setting torch current to 20mA, or integer 6 in the register
2023-09-02 07:27:32.104 | DEBUG    | planktoscope.light:output_to_led1:81 - Switching output to LED 1
2023-09-02 07:27:32.106 | DEBUG    | planktoscope.light:activate_torch_ramp:97 - Activating the torch ramp
2023-09-02 07:27:32.113 | DEBUG    | planktoscope.light:activate_torch:157 - Activate torch
2023-09-02 07:27:32.128 | SUCCESS  | planktoscope.mqtt:on_connect:113 - imager_client connected to 127.0.0.1:1883! - 0: Connection successful
2023-09-02 07:27:32.131 | INFO     | planktoscope.imager:run:724 - Starting the streaming server thread
2023-09-02 07:27:32.137 | SUCCESS  | planktoscope.imager:run:740 - Camera is READY!
2023-09-02 07:27:32.176 | SUCCESS  | planktoscope.mqtt:on_subscribe:124 - imager_client subscribed to imager/#! - mid:3 qos:(0,)
2023-09-02 07:27:32.621 | DEBUG    | planktoscope.light:output_to_led2:85 - Switching output to LED 2
2023-09-02 07:27:33.124 | DEBUG    | planktoscope.light:deactivate_torch:162 - Deactivate torch
2023-09-02 07:27:33.126 | DEBUG    | planktoscope.light:output_to_led1:81 - Switching output to LED 1
2023-09-02 07:27:33.132 | SUCCESS  | planktoscope.light:__init__:256 - planktoscope.light is initialised and ready to go!
2023-09-02 07:27:33.136 | INFO     | __main__:<module>:111 - Starting the display control (step 5/5)
2023-09-02 07:27:33.143 | INFO     | planktoscope.light:run:371 - The light control thread has been started in process 3029
2023-09-02 07:27:33.151 | INFO     | planktoscope.mqtt:connect:87 - trying to connect to 127.0.0.1:1883
2023-09-02 07:27:33.163 | ERROR    | planktoscope.display:__init__:33 - Could not detect the display
2023-09-02 07:27:33.165 | ERROR    | planktoscope.display:__init__:34 - Exception was [Errno 121] Remote I/O error
2023-09-02 07:27:33.177 | SUCCESS  | __main__:<module>:114 - Looks like everything is set up and running, have fun!
2023-09-02 07:27:33.174 | SUCCESS  | planktoscope.mqtt:on_connect:113 - light_client connected to 127.0.0.1:1883! - 0: Connection successful
2023-09-02 07:27:33.183 | SUCCESS  | planktoscope.light:run:383 - Light module is READY!
2023-09-02 07:27:33.236 | SUCCESS  | planktoscope.mqtt:on_subscribe:124 - light_client subscribed to light! - mid:2 qos:(0,)
2023-09-02 07:27:37.620 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: imager/image 0 b'{"action":"settings","settings":{"shutter_speed":125}}'
2023-09-02 07:27:37.622 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'settings', 'settings': {'shutter_speed': 125}}
2023-09-02 07:27:37.623 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'imager/image', 'payload': {'action': 'settings', 'settings': {'shutter_speed': 125}}}
2023-09-02 07:27:37.625 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:27:37.628 | DEBUG    | planktoscope.imager:treat_message:459 - {'action': 'settings', 'settings': {'shutter_speed': 125}}
2023-09-02 07:27:37.630 | DEBUG    | planktoscope.imager:treat_message:461 - settings
2023-09-02 07:27:37.631 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:27:37.633 | INFO     | planktoscope.imager:__message_settings:289 - Updating the camera settings now with the received data
2023-09-02 07:27:37.637 | DEBUG    | planktoscope.imager:__message_settings:330 - Updating the camera shutter speed to 125
2023-09-02 07:27:37.648 | DEBUG    | planktoscope.imager.raspimjpeg:shutter_speed:309 - Setting the shutter speed to 125
2023-09-02 07:27:37.650 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [ss 125] to raspimjpeg
2023-09-02 07:27:37.653 | DEBUG    | planktoscope.imager.raspimjpeg:__wait_for_output:151 - Waiting for Change: shutter_speed for 5s
2023-09-02 07:27:37.708 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: imager/image 0 b'{"action":"settings","settings":{"white_balance_gain":{"red":190}}}'
2023-09-02 07:27:37.710 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'settings', 'settings': {'white_balance_gain': {'red': 190}}}
2023-09-02 07:27:37.712 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'imager/image', 'payload': {'action': 'settings', 'settings': {'white_balance_gain': {'red': 190}}}}
2023-09-02 07:27:37.714 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: imager/image 0 b'{"action":"settings","settings":{"white_balance_gain":{"blue":170}}}'
2023-09-02 07:27:37.716 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'settings', 'settings': {'white_balance_gain': {'blue': 170}}}
2023-09-02 07:27:37.717 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'imager/image', 'payload': {'action': 'settings', 'settings': {'white_balance_gain': {'blue': 170}}}}
2023-09-02 07:27:42.678 | ERROR    | planktoscope.imager.raspimjpeg:__wait_for_output:165 - A timeout has occured waiting for a RaspiMJPEG answer
2023-09-02 07:27:42.681 | ERROR    | planktoscope.imager:__message_settings:336 - A timeout has occured when setting the shutter speed, trying again
2023-09-02 07:27:42.684 | DEBUG    | planktoscope.imager.raspimjpeg:shutter_speed:309 - Setting the shutter speed to 125
2023-09-02 07:27:42.685 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [ss 125] to raspimjpeg
2023-09-02 07:27:42.686 | DEBUG    | planktoscope.imager.raspimjpeg:__wait_for_output:151 - Waiting for Change: shutter_speed for 5s
2023-09-02 07:27:47.708 | ERROR    | planktoscope.imager.raspimjpeg:__wait_for_output:165 - A timeout has occured waiting for a RaspiMJPEG answer
2023-09-02 07:27:47.711 | ERROR    | planktoscope.imager:run:745 - An error has been caught in function 'run', process 'imager' (3026), thread 'MainThread' (4150363712):
Traceback (most recent call last):

  File "/home/pi/device-backend/control/pscopehat/planktoscope/imager/__init__.py", line 334, in __message_settings
    self.__camera.shutter_speed = self.__shutter_speed
    │                             └ <ImagerProcess name='imager' parent=2865 started>
    └ <ImagerProcess name='imager' parent=2865 started>

  File "/home/pi/device-backend/control/pscopehat/planktoscope/imager/raspimjpeg.py", line 313, in shutter_speed
    self.__wait_for_output("Change: shutter_speed")
    └ <planktoscope.imager.raspimjpeg.raspimjpeg object at 0xf609fe68>

  File "/home/pi/device-backend/control/pscopehat/planktoscope/imager/raspimjpeg.py", line 166, in __wait_for_output
    raise TimeoutError

TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):

  File "/home/pi/device-backend/control/pscopehat/main.py", line 99, in <module>
    imager_thread.start()
    │             └ <function BaseProcess.start at 0xf7040658>
    └ <ImagerProcess name='imager' parent=2865 started>

  File "/usr/lib/python3.9/multiprocessing/process.py", line 121, in start
    self._popen = self._Popen(self)
    │    │        │    │      └ <ImagerProcess name='imager' parent=2865 started>
    │    │        │    └ <staticmethod object at 0xf7039940>
    │    │        └ <ImagerProcess name='imager' parent=2865 started>
    │    └ None
    └ <ImagerProcess name='imager' parent=2865 started>
  File "/usr/lib/python3.9/multiprocessing/context.py", line 224, in _Popen
    return _default_context.get_context().Process._Popen(process_obj)
           │                │                            └ <ImagerProcess name='imager' parent=2865 started>
           │                └ <function DefaultContext.get_context at 0xf6fa71d8>
           └ <multiprocessing.context.DefaultContext object at 0xf6fa40e8>
  File "/usr/lib/python3.9/multiprocessing/context.py", line 277, in _Popen
    return Popen(process_obj)
           │     └ <ImagerProcess name='imager' parent=2865 started>
           └ <class 'multiprocessing.popen_fork.Popen'>
  File "/usr/lib/python3.9/multiprocessing/popen_fork.py", line 19, in __init__
    self._launch(process_obj)
    │    │       └ <ImagerProcess name='imager' parent=2865 started>
    │    └ <function Popen._launch at 0xf60b31d8>
    └ <multiprocessing.popen_fork.Popen object at 0xf609fe38>
  File "/usr/lib/python3.9/multiprocessing/popen_fork.py", line 71, in _launch
    code = process_obj._bootstrap(parent_sentinel=child_r)
           │           │                          └ 14
           │           └ <function BaseProcess._bootstrap at 0xf7040ad8>
           └ <ImagerProcess name='imager' parent=2865 started>
  File "/usr/lib/python3.9/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
    │    └ <function ImagerProcess.run at 0xf6706100>
    └ <ImagerProcess name='imager' parent=2865 started>

> File "/home/pi/device-backend/control/pscopehat/planktoscope/imager/__init__.py", line 745, in run
    self.treat_message()
    │    └ <function ImagerProcess.treat_message at 0xf66fcc40>
    └ <ImagerProcess name='imager' parent=2865 started>

  File "/home/pi/device-backend/control/pscopehat/planktoscope/imager/__init__.py", line 496, in treat_message
    self.__message_settings(last_message)
    │                       └ {'action': 'settings', 'settings': {'shutter_speed': 125}}
    └ <ImagerProcess name='imager' parent=2865 started>

  File "/home/pi/device-backend/control/pscopehat/planktoscope/imager/__init__.py", line 339, in __message_settings
    self.__camera.shutter_speed = self.__shutter_speed
    │                             └ <ImagerProcess name='imager' parent=2865 started>
    └ <ImagerProcess name='imager' parent=2865 started>

  File "/home/pi/device-backend/control/pscopehat/planktoscope/imager/raspimjpeg.py", line 313, in shutter_speed
    self.__wait_for_output("Change: shutter_speed")
    └ <planktoscope.imager.raspimjpeg.raspimjpeg object at 0xf609fe68>

  File "/home/pi/device-backend/control/pscopehat/planktoscope/imager/raspimjpeg.py", line 166, in __wait_for_output
    raise TimeoutError

TimeoutError
2023-09-02 07:27:47.751 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:27:47.753 | DEBUG    | planktoscope.imager:treat_message:459 - {'action': 'settings', 'settings': {'white_balance_gain': {'blue': 170}}}
2023-09-02 07:27:47.755 | DEBUG    | planktoscope.imager:treat_message:461 - settings
2023-09-02 07:27:47.757 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:27:47.758 | INFO     | planktoscope.imager:__message_settings:289 - Updating the camera settings now with the received data
2023-09-02 07:27:47.759 | DEBUG    | planktoscope.imager:__message_settings:359 - Updating the camera white balance blue gain to {'blue': 170}
2023-09-02 07:27:47.760 | DEBUG    | planktoscope.imager:__message_settings:368 - Updating the camera white balance gain to (190, 170)
2023-09-02 07:27:47.762 | DEBUG    | planktoscope.imager.raspimjpeg:white_balance_gain:403 - Setting the white balance mode to (190, 170)
2023-09-02 07:27:47.763 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [ag 190 170] to raspimjpeg
2023-09-02 07:27:47.765 | INFO     | planktoscope.imager:__message_settings:447 - Camera settings have been updated
2023-09-02 07:28:45.578 | INFO     | planktoscope.mqtt:on_message:132 - light_client: light 0 b'{"action":"on"}'
2023-09-02 07:28:45.580 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'on'}
2023-09-02 07:28:45.581 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'light', 'payload': {'action': 'on'}}
2023-09-02 07:28:45.673 | INFO     | planktoscope.light:treat_message:280 - We received a new message
2023-09-02 07:28:45.675 | DEBUG    | planktoscope.light:treat_message:282 - {'action': 'on'}
2023-09-02 07:28:45.676 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:28:45.677 | INFO     | planktoscope.light:treat_message:297 - Turning the light on.
2023-09-02 07:28:45.678 | DEBUG    | planktoscope.light:led_on:269 - Turning led 1 on
2023-09-02 07:28:45.679 | DEBUG    | planktoscope.light:output_to_led1:81 - Switching output to LED 1
2023-09-02 07:28:45.680 | DEBUG    | planktoscope.light:activate_torch:157 - Activate torch
2023-09-02 07:33:29.789 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: imager/image 0 b'{"action":"update_config","config":{"description":{"sample_project":"Project\'s name","sample_id":"Sample ID","sample_uuid":"Sample UUID (Autogenerated)","sample_ship":"Ship\'s name","sample_operator":"Operator\'s name","sample_sampling_gear":"Sampling gear used","sample_concentrated_sample_volume":"Volume of concentrated sample, in mL","sample_total_volume":"Total volume filtered by the net used, in L","sample_dilution_factor":"Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2","sample_speed_through_water":"Speed of the boat through water when sampling, in kts","acq_id":"Acquisition ID","acq_uuid":"Acquisition UUID (Autogenerated)","acq_instrument":"Instrument type","acq_instrument_id":"Instrument ID","acq_celltype":"Flow cell dimension thickness, in \xc2\xb5m","acq_minimum_mesh":"Minimum filtration mesh size, in \xc2\xb5m","acq_maximum_mesh":"Maximum filtration mesh size, in \xc2\xb5m","acq_min_esd":"","acq_max_esd":"","acq_volume":"Pumped volume, in mL","acq_imaged_volume":"Total imaged volume, in mL","acq_magnification":"Optical magnification","acq_fnumber_objective":"Focal length of the objective, in mm","acq_camera_name":"Name of the camera used","acq_nb_frame":"Number of picture taken","acq_local_datetime":"Instrument local datetime","acq_camera_resolution":"Resolution of the images","acq_camera_iso":"ISO Number of the images","acq_camera_shutter_speed":"Shutter speed of the images, in \xc2\xb5s","acq_software":"Software version number","object_date":"Sample collection date (or beginning if using a net)","object_time":"Sample collection time (or beginning if using a net)","object_lat":"Sample collection latitude (or beginning if using a net)","object_lon":"Sample collection longitude (or beginning if using a net)","object_depth_min":"Sample collection minimal depth, in m","object_depth_max":"Sample collection maximum depth, in m","process_pixel":"Pixel imaging resolution, in \xc2\xb5m/pixel","process_datetime":"Segmentation timestamp","process_id":"Segmentation ID","process_uuid":"Segmentation UUID (Autogenerated)","process_source":"Code source link of the executed code","process_commit":"Version reference of the executed code","sample_gear_net_opening":"Sample mouth opening dimension, in mm","object_date_end":"Sample end collection date when using a net","object_time_end":"Sample end collection time when using a net","object_lat_end":"Sample end collection latitude when using a net","object_lon_end":"Sample end collection longitude when using a net"},"sample_project":"Project\'s name","sample_id":"Project\'s name_1","sample_ship":"Vessel name","sample_operator":"Operator\'s name","sample_sampling_gear":"single_location","sample_concentrated_sample_volume":30,"acq_id":"Project\'s name_1_7","acq_instrument":"PlanktoScope v2.5","acq_instrument_id":"smooth-wave-21342\\n","acq_celltype":200,"acq_minimum_mesh":30,"acq_maximum_mesh":200,"acq_volume":"0.10","acq_magnification":"ERROR","acq_fnumber_objective":16,"acq_nb_frame":10,"acq_software":"PlanktoScope v2023.9.0-beta.0","object_date":"20230914","object_time":"0435","object_lat":"32.8126","object_lon":"129.7726","object_depth_min":0,"object_depth_max":0,"process_pixel":0.75,"process_source":"https://www.github.com/PlanktonPlanet/PlanktoScope"}}'
2023-09-02 07:33:29.792 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'update_config', 'config': {'description': {'sample_project': "Project's name", 'sample_id': 'Sample ID', 'sample_uuid': 'Sample UUID (Autogenerated)', 'sample_ship': "Ship's name", 'sample_operator': "Operator's name", 'sample_sampling_gear': 'Sampling gear used', 'sample_concentrated_sample_volume': 'Volume of concentrated sample, in mL', 'sample_total_volume': 'Total volume filtered by the net used, in L', 'sample_dilution_factor': 'Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2', 'sample_speed_through_water': 'Speed of the boat through water when sampling, in kts', 'acq_id': 'Acquisition ID', 'acq_uuid': 'Acquisition UUID (Autogenerated)', 'acq_instrument': 'Instrument type', 'acq_instrument_id': 'Instrument ID', 'acq_celltype': 'Flow cell dimension thickness, in µm', 'acq_minimum_mesh': 'Minimum filtration mesh size, in µm', 'acq_maximum_mesh': 'Maximum filtration mesh size, in µm', 'acq_min_esd': '', 'acq_max_esd': '', 'acq_volume': 'Pumped volume, in mL', 'acq_imaged_volume': 'Total imaged volume, in mL', 'acq_magnification': 'Optical magnification', 'acq_fnumber_objective': 'Focal length of the objective, in mm', 'acq_camera_name': 'Name of the camera used', 'acq_nb_frame': 'Number of picture taken', 'acq_local_datetime': 'Instrument local datetime', 'acq_camera_resolution': 'Resolution of the images', 'acq_camera_iso': 'ISO Number of the images', 'acq_camera_shutter_speed': 'Shutter speed of the images, in µs', 'acq_software': 'Software version number', 'object_date': 'Sample collection date (or beginning if using a net)', 'object_time': 'Sample collection time (or beginning if using a net)', 'object_lat': 'Sample collection latitude (or beginning if using a net)', 'object_lon': 'Sample collection longitude (or beginning if using a net)', 'object_depth_min': 'Sample collection minimal depth, in m', 'object_depth_max': 'Sample collection maximum depth, in m', 'process_pixel': 'Pixel imaging resolution, in µm/pixel', 'process_datetime': 'Segmentation timestamp', 'process_id': 'Segmentation ID', 'process_uuid': 'Segmentation UUID (Autogenerated)', 'process_source': 'Code source link of the executed code', 'process_commit': 'Version reference of the executed code', 'sample_gear_net_opening': 'Sample mouth opening dimension, in mm', 'object_date_end': 'Sample end collection date when using a net', 'object_time_end': 'Sample end collection time when using a net', 'object_lat_end': 'Sample end collection latitude when using a net', 'object_lon_end': 'Sample end collection longitude when using a net'}, 'sample_project': "Project's name", 'sample_id': "Project's name_1", 'sample_ship': 'Vessel name', 'sample_operator': "Operator's name", 'sample_sampling_gear': 'single_location', 'sample_concentrated_sample_volume': 30, 'acq_id': "Project's name_1_7", 'acq_instrument': 'PlanktoScope v2.5', 'acq_instrument_id': 'smooth-wave-21342\n', 'acq_celltype': 200, 'acq_minimum_mesh': 30, 'acq_maximum_mesh': 200, 'acq_volume': '0.10', 'acq_magnification': 'ERROR', 'acq_fnumber_objective': 16, 'acq_nb_frame': 10, 'acq_software': 'PlanktoScope v2023.9.0-beta.0', 'object_date': '20230914', 'object_time': '0435', 'object_lat': '32.8126', 'object_lon': '129.7726', 'object_depth_min': 0, 'object_depth_max': 0, 'process_pixel': 0.75, 'process_source': 'https://www.github.com/PlanktonPlanet/PlanktoScope'}}
2023-09-02 07:33:29.796 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'imager/image', 'payload': {'action': 'update_config', 'config': {'description': {'sample_project': "Project's name", 'sample_id': 'Sample ID', 'sample_uuid': 'Sample UUID (Autogenerated)', 'sample_ship': "Ship's name", 'sample_operator': "Operator's name", 'sample_sampling_gear': 'Sampling gear used', 'sample_concentrated_sample_volume': 'Volume of concentrated sample, in mL', 'sample_total_volume': 'Total volume filtered by the net used, in L', 'sample_dilution_factor': 'Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2', 'sample_speed_through_water': 'Speed of the boat through water when sampling, in kts', 'acq_id': 'Acquisition ID', 'acq_uuid': 'Acquisition UUID (Autogenerated)', 'acq_instrument': 'Instrument type', 'acq_instrument_id': 'Instrument ID', 'acq_celltype': 'Flow cell dimension thickness, in µm', 'acq_minimum_mesh': 'Minimum filtration mesh size, in µm', 'acq_maximum_mesh': 'Maximum filtration mesh size, in µm', 'acq_min_esd': '', 'acq_max_esd': '', 'acq_volume': 'Pumped volume, in mL', 'acq_imaged_volume': 'Total imaged volume, in mL', 'acq_magnification': 'Optical magnification', 'acq_fnumber_objective': 'Focal length of the objective, in mm', 'acq_camera_name': 'Name of the camera used', 'acq_nb_frame': 'Number of picture taken', 'acq_local_datetime': 'Instrument local datetime', 'acq_camera_resolution': 'Resolution of the images', 'acq_camera_iso': 'ISO Number of the images', 'acq_camera_shutter_speed': 'Shutter speed of the images, in µs', 'acq_software': 'Software version number', 'object_date': 'Sample collection date (or beginning if using a net)', 'object_time': 'Sample collection time (or beginning if using a net)', 'object_lat': 'Sample collection latitude (or beginning if using a net)', 'object_lon': 'Sample collection longitude (or beginning if using a net)', 'object_depth_min': 'Sample collection minimal depth, in m', 'object_depth_max': 'Sample collection maximum depth, in m', 'process_pixel': 'Pixel imaging resolution, in µm/pixel', 'process_datetime': 'Segmentation timestamp', 'process_id': 'Segmentation ID', 'process_uuid': 'Segmentation UUID (Autogenerated)', 'process_source': 'Code source link of the executed code', 'process_commit': 'Version reference of the executed code', 'sample_gear_net_opening': 'Sample mouth opening dimension, in mm', 'object_date_end': 'Sample end collection date when using a net', 'object_time_end': 'Sample end collection time when using a net', 'object_lat_end': 'Sample end collection latitude when using a net', 'object_lon_end': 'Sample end collection longitude when using a net'}, 'sample_project': "Project's name", 'sample_id': "Project's name_1", 'sample_ship': 'Vessel name', 'sample_operator': "Operator's name", 'sample_sampling_gear': 'single_location', 'sample_concentrated_sample_volume': 30, 'acq_id': "Project's name_1_7", 'acq_instrument': 'PlanktoScope v2.5', 'acq_instrument_id': 'smooth-wave-21342\n', 'acq_celltype': 200, 'acq_minimum_mesh': 30, 'acq_maximum_mesh': 200, 'acq_volume': '0.10', 'acq_magnification': 'ERROR', 'acq_fnumber_objective': 16, 'acq_nb_frame': 10, 'acq_software': 'PlanktoScope v2023.9.0-beta.0', 'object_date': '20230914', 'object_time': '0435', 'object_lat': '32.8126', 'object_lon': '129.7726', 'object_depth_min': 0, 'object_depth_max': 0, 'process_pixel': 0.75, 'process_source': 'https://www.github.com/PlanktonPlanet/PlanktoScope'}}}
2023-09-02 07:33:29.798 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:33:29.799 | DEBUG    | planktoscope.imager:treat_message:459 - {'action': 'update_config', 'config': {'description': {'sample_project': "Project's name", 'sample_id': 'Sample ID', 'sample_uuid': 'Sample UUID (Autogenerated)', 'sample_ship': "Ship's name", 'sample_operator': "Operator's name", 'sample_sampling_gear': 'Sampling gear used', 'sample_concentrated_sample_volume': 'Volume of concentrated sample, in mL', 'sample_total_volume': 'Total volume filtered by the net used, in L', 'sample_dilution_factor': 'Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2', 'sample_speed_through_water': 'Speed of the boat through water when sampling, in kts', 'acq_id': 'Acquisition ID', 'acq_uuid': 'Acquisition UUID (Autogenerated)', 'acq_instrument': 'Instrument type', 'acq_instrument_id': 'Instrument ID', 'acq_celltype': 'Flow cell dimension thickness, in µm', 'acq_minimum_mesh': 'Minimum filtration mesh size, in µm', 'acq_maximum_mesh': 'Maximum filtration mesh size, in µm', 'acq_min_esd': '', 'acq_max_esd': '', 'acq_volume': 'Pumped volume, in mL', 'acq_imaged_volume': 'Total imaged volume, in mL', 'acq_magnification': 'Optical magnification', 'acq_fnumber_objective': 'Focal length of the objective, in mm', 'acq_camera_name': 'Name of the camera used', 'acq_nb_frame': 'Number of picture taken', 'acq_local_datetime': 'Instrument local datetime', 'acq_camera_resolution': 'Resolution of the images', 'acq_camera_iso': 'ISO Number of the images', 'acq_camera_shutter_speed': 'Shutter speed of the images, in µs', 'acq_software': 'Software version number', 'object_date': 'Sample collection date (or beginning if using a net)', 'object_time': 'Sample collection time (or beginning if using a net)', 'object_lat': 'Sample collection latitude (or beginning if using a net)', 'object_lon': 'Sample collection longitude (or beginning if using a net)', 'object_depth_min': 'Sample collection minimal depth, in m', 'object_depth_max': 'Sample collection maximum depth, in m', 'process_pixel': 'Pixel imaging resolution, in µm/pixel', 'process_datetime': 'Segmentation timestamp', 'process_id': 'Segmentation ID', 'process_uuid': 'Segmentation UUID (Autogenerated)', 'process_source': 'Code source link of the executed code', 'process_commit': 'Version reference of the executed code', 'sample_gear_net_opening': 'Sample mouth opening dimension, in mm', 'object_date_end': 'Sample end collection date when using a net', 'object_time_end': 'Sample end collection time when using a net', 'object_lat_end': 'Sample end collection latitude when using a net', 'object_lon_end': 'Sample end collection longitude when using a net'}, 'sample_project': "Project's name", 'sample_id': "Project's name_1", 'sample_ship': 'Vessel name', 'sample_operator': "Operator's name", 'sample_sampling_gear': 'single_location', 'sample_concentrated_sample_volume': 30, 'acq_id': "Project's name_1_7", 'acq_instrument': 'PlanktoScope v2.5', 'acq_instrument_id': 'smooth-wave-21342\n', 'acq_celltype': 200, 'acq_minimum_mesh': 30, 'acq_maximum_mesh': 200, 'acq_volume': '0.10', 'acq_magnification': 'ERROR', 'acq_fnumber_objective': 16, 'acq_nb_frame': 10, 'acq_software': 'PlanktoScope v2023.9.0-beta.0', 'object_date': '20230914', 'object_time': '0435', 'object_lat': '32.8126', 'object_lon': '129.7726', 'object_depth_min': 0, 'object_depth_max': 0, 'process_pixel': 0.75, 'process_source': 'https://www.github.com/PlanktonPlanet/PlanktoScope'}}
2023-09-02 07:33:29.800 | DEBUG    | planktoscope.imager:treat_message:461 - update_config
2023-09-02 07:33:29.801 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:33:29.802 | INFO     | planktoscope.imager:__message_update:264 - Updating the configuration now with the received data
2023-09-02 07:33:29.804 | INFO     | planktoscope.imager:__message_update:272 - Configuration has been updated
2023-09-02 07:33:30.788 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: imager/image 0 b'{"action":"image","sleep":0.5,"pump_direction":"FORWARD","volume":0.01,"nb_frame":10}'
2023-09-02 07:33:30.789 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'image', 'sleep': 0.5, 'pump_direction': 'FORWARD', 'volume': 0.01, 'nb_frame': 10}
2023-09-02 07:33:30.790 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'imager/image', 'payload': {'action': 'image', 'sleep': 0.5, 'pump_direction': 'FORWARD', 'volume': 0.01, 'nb_frame': 10}}
2023-09-02 07:33:30.792 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:33:30.794 | DEBUG    | planktoscope.imager:treat_message:459 - {'action': 'image', 'sleep': 0.5, 'pump_direction': 'FORWARD', 'volume': 0.01, 'nb_frame': 10}
2023-09-02 07:33:30.796 | DEBUG    | planktoscope.imager:treat_message:461 - image
2023-09-02 07:33:30.797 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:33:30.798 | INFO     | planktoscope.imager.state_machine:switch:27 - Current:stop => switched to new state imaging
2023-09-02 07:33:30.802 | SUCCESS  | planktoscope.mqtt:on_subscribe:124 - imager_client subscribed to imager/#! - mid:8 qos:(0,)
2023-09-02 07:33:30.809 | INFO     | planktoscope.imager:__state_imaging:553 - Setting up the directory structure for storing the pictures
2023-09-02 07:33:30.816 | INFO     | planktoscope.imager:__state_imaging:577 - Exporting the metadata to a metadata.json
2023-09-02 07:33:30.820 | DEBUG    | planktoscope.imager:__state_imaging:581 - Metadata dumped in <_io.TextIOWrapper name="/home/pi/data/img/20230914/Project's_name_1/Project's_name_1_7/metadata.json" mode='w' encoding='UTF-8'> are {'description': {'sample_project': "Project's name", 'sample_id': 'Sample ID', 'sample_uuid': 'Sample UUID (Autogenerated)', 'sample_ship': "Ship's name", 'sample_operator': "Operator's name", 'sample_sampling_gear': 'Sampling gear used', 'sample_concentrated_sample_volume': 'Volume of concentrated sample, in mL', 'sample_total_volume': 'Total volume filtered by the net used, in L', 'sample_dilution_factor': 'Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2', 'sample_speed_through_water': 'Speed of the boat through water when sampling, in kts', 'acq_id': 'Acquisition ID', 'acq_uuid': 'Acquisition UUID (Autogenerated)', 'acq_instrument': 'Instrument type', 'acq_instrument_id': 'Instrument ID', 'acq_celltype': 'Flow cell dimension thickness, in µm', 'acq_minimum_mesh': 'Minimum filtration mesh size, in µm', 'acq_maximum_mesh': 'Maximum filtration mesh size, in µm', 'acq_min_esd': '', 'acq_max_esd': '', 'acq_volume': 'Pumped volume, in mL', 'acq_imaged_volume': 'Total imaged volume, in mL', 'acq_magnification': 'Optical magnification', 'acq_fnumber_objective': 'Focal length of the objective, in mm', 'acq_camera_name': 'Name of the camera used', 'acq_nb_frame': 'Number of picture taken', 'acq_local_datetime': 'Instrument local datetime', 'acq_camera_resolution': 'Resolution of the images', 'acq_camera_iso': 'ISO Number of the images', 'acq_camera_shutter_speed': 'Shutter speed of the images, in µs', 'acq_software': 'Software version number', 'object_date': 'Sample collection date (or beginning if using a net)', 'object_time': 'Sample collection time (or beginning if using a net)', 'object_lat': 'Sample collection latitude (or beginning if using a net)', 'object_lon': 'Sample collection longitude (or beginning if using a net)', 'object_depth_min': 'Sample collection minimal depth, in m', 'object_depth_max': 'Sample collection maximum depth, in m', 'process_pixel': 'Pixel imaging resolution, in µm/pixel', 'process_datetime': 'Segmentation timestamp', 'process_id': 'Segmentation ID', 'process_uuid': 'Segmentation UUID (Autogenerated)', 'process_source': 'Code source link of the executed code', 'process_commit': 'Version reference of the executed code', 'sample_gear_net_opening': 'Sample mouth opening dimension, in mm', 'object_date_end': 'Sample end collection date when using a net', 'object_time_end': 'Sample end collection time when using a net', 'object_lat_end': 'Sample end collection latitude when using a net', 'object_lon_end': 'Sample end collection longitude when using a net'}, 'sample_project': "Project's name", 'sample_id': "Project's name_1", 'sample_ship': 'Vessel name', 'sample_operator': "Operator's name", 'sample_sampling_gear': 'single_location', 'sample_concentrated_sample_volume': 30, 'acq_id': "Project's name_1_7", 'acq_instrument': 'PlanktoScope v2.5', 'acq_instrument_id': 'smooth-wave-21342\n', 'acq_celltype': 200, 'acq_minimum_mesh': 30, 'acq_maximum_mesh': 200, 'acq_volume': '0.10', 'acq_magnification': 'ERROR', 'acq_fnumber_objective': 16, 'acq_nb_frame': 10, 'acq_software': 'PlanktoScope v2023.9.0-beta.0', 'object_date': '20230914', 'object_time': '0435', 'object_lat': '32.8126', 'object_lon': '129.7726', 'object_depth_min': 0, 'object_depth_max': 0, 'process_pixel': 0.75, 'process_source': 'https://www.github.com/PlanktonPlanet/PlanktoScope', 'acq_local_datetime': '2023-09-02T07:33:30', 'acq_camera_resolution': '4056x3040', 'acq_camera_iso': 100, 'acq_camera_shutter_speed': 125, 'acq_uuid': '03b8712f-4963-11ee-a315-0000b23d5dc2', 'sample_uuid': '03b8ab48-4963-11ee-b6de-0000b23d5dc2'}
2023-09-02 07:33:30.821 | DEBUG    | planktoscope.integrity:create_integrity_file:86 - Create the integrity file in the folder /home/pi/data/img/20230914/Project's_name_1/Project's_name_1_7
2023-09-02 07:33:30.823 | DEBUG    | planktoscope.integrity:get_filename_checksum:56 - Calculating the integrity of /home/pi/data/img/20230914/Project's_name_1/Project's_name_1_7/metadata.json's content and its filename
2023-09-02 07:33:30.825 | INFO     | planktoscope.imager.state_machine:switch:27 - Current:imaging => switched to new state waiting
2023-09-02 07:33:30.825 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action": "move", "direction": "FORWARD", "volume": 0.01, "flowrate": 2}'
2023-09-02 07:33:30.826 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'move', 'direction': 'FORWARD', 'volume': 0.01, 'flowrate': 2}
2023-09-02 07:33:30.827 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'move', 'direction': 'FORWARD', 'volume': 0.01, 'flowrate': 2}}
2023-09-02 07:33:30.833 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 07:33:30.834 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'move', 'direction': 'FORWARD', 'volume': 0.01, 'flowrate': 2}
2023-09-02 07:33:30.835 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 07:33:30.836 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:33:30.838 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 07:33:30.839 | DEBUG    | planktoscope.stepper:__message_pump:208 - We have received a move pump command
2023-09-02 07:33:30.839 | INFO     | planktoscope.stepper:__message_pump:237 - The pump is started.
2023-09-02 07:33:30.840 | INFO     | planktoscope.stepper:pump:371 - The pump will move FORWARD for 0.01mL at 2.0mL/min
2023-09-02 07:33:30.841 | DEBUG    | planktoscope.stepper:pump:381 - The number of microsteps that will be applied is 5235.0
2023-09-02 07:33:30.842 | DEBUG    | planktoscope.stepper:pump:388 - There will be a speed of 17450.666666666668 steps per second
2023-09-02 07:33:30.844 | DEBUG    | planktoscope.stepper:speed:94 - Setting stepper speed to 17450
2023-09-02 07:33:30.847 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: status/pump 0 b'{"status":"Started", "duration":0.2999885391198044}'
2023-09-02 07:33:30.849 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'status': 'Started', 'duration': 0.2999885391198044}
2023-09-02 07:33:30.855 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'status/pump', 'payload': {'status': 'Started', 'duration': 0.2999885391198044}}
2023-09-02 07:33:30.860 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:33:30.864 | DEBUG    | planktoscope.imager:treat_message:463 - Status message payload is {'status': 'Started', 'duration': 0.2999885391198044}
2023-09-02 07:33:30.866 | INFO     | planktoscope.imager:treat_message:471 - The pump is not done yet {'status': 'Started', 'duration': 0.2999885391198044}
2023-09-02 07:33:30.867 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:33:31.351 | SUCCESS  | planktoscope.stepper:run:433 - The pump movement is over!
2023-09-02 07:33:31.354 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: status/pump 0 b'{"status":"Done"}'
2023-09-02 07:33:31.355 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'status': 'Done'}
2023-09-02 07:33:31.356 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'status/pump', 'payload': {'status': 'Done'}}
2023-09-02 07:33:31.359 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:33:31.360 | DEBUG    | planktoscope.imager:treat_message:463 - Status message payload is {'status': 'Done'}
2023-09-02 07:33:31.363 | INFO     | planktoscope.imager.state_machine:switch:27 - Current:waiting => switched to new state capture
2023-09-02 07:33:31.365 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:33:31.367 | INFO     | planktoscope.imager:__state_capture:610 - Capturing image 1/10 to /home/pi/data/img/20230914/Project's_name_1/Project's_name_1_7/07_33_31_367555.jpg
2023-09-02 07:33:31.870 | DEBUG    | planktoscope.imager.raspimjpeg:capture:490 - Capturing an image to 
2023-09-02 07:33:31.872 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [im] to raspimjpeg
2023-09-02 07:33:31.974 | DEBUG    | planktoscope.imager.raspimjpeg:__wait_for_output:151 - Waiting for Capturing image for 2.5s
2023-09-02 07:33:34.489 | ERROR    | planktoscope.imager.raspimjpeg:__wait_for_output:165 - A timeout has occured waiting for a RaspiMJPEG answer
2023-09-02 07:33:34.490 | ERROR    | planktoscope.imager:__capture_error:663 - An error occurred during the capture: timeout during capture
2023-09-02 07:33:35.494 | INFO     | planktoscope.imager:__state_capture:610 - Capturing image 1/10 to /home/pi/data/img/20230914/Project's_name_1/Project's_name_1_7/07_33_35_494299.jpg
2023-09-02 07:33:35.995 | DEBUG    | planktoscope.imager.raspimjpeg:capture:490 - Capturing an image to 
2023-09-02 07:33:36.000 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [im] to raspimjpeg
2023-09-02 07:33:36.104 | DEBUG    | planktoscope.imager.raspimjpeg:__wait_for_output:151 - Waiting for Capturing image for 2.5s
2023-09-02 07:33:36.629 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: imager/image 0 b'{"action":"stop"}'
2023-09-02 07:33:36.630 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'stop'}
2023-09-02 07:33:36.632 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'imager/image', 'payload': {'action': 'stop'}}
2023-09-02 07:33:38.614 | ERROR    | planktoscope.imager.raspimjpeg:__wait_for_output:165 - A timeout has occured waiting for a RaspiMJPEG answer
2023-09-02 07:33:38.616 | ERROR    | planktoscope.imager:__capture_error:663 - An error occurred during the capture: timeout during capture
2023-09-02 07:33:38.617 | ERROR    | planktoscope.imager:__capture_error:665 - This is a repeating problem, stopping the capture now
2023-09-02 07:33:38.619 | INFO     | planktoscope.imager.state_machine:switch:27 - Current:capture => switched to new state stop
2023-09-02 07:33:39.626 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:33:39.632 | DEBUG    | planktoscope.imager:treat_message:459 - {'action': 'stop'}
2023-09-02 07:33:39.634 | DEBUG    | planktoscope.imager:treat_message:461 - stop
2023-09-02 07:33:39.635 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:33:39.637 | INFO     | planktoscope.imager:__message_stop:246 - The imaging has been interrupted.
2023-09-02 07:33:39.638 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action": "stop"}'
2023-09-02 07:33:39.639 | ERROR    | planktoscope.imager.state_machine:switch:30 - Current:stop => switching to stop not possible.
2023-09-02 07:33:39.638 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'stop'}
2023-09-02 07:33:39.643 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'stop'}}
2023-09-02 07:33:39.649 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 07:33:39.651 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'stop'}
2023-09-02 07:33:39.653 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 07:33:39.669 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:33:39.677 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 07:33:39.685 | DEBUG    | planktoscope.stepper:__message_pump:196 - We have received a stop pump command
2023-09-02 07:33:39.689 | INFO     | planktoscope.stepper:__message_pump:200 - The pump has been interrupted
2023-09-02 07:50:49.277 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: imager/image 0 b'{"action":"update_config","config":{"description":{"sample_project":"Project\'s name","sample_id":"Sample ID","sample_uuid":"Sample UUID (Autogenerated)","sample_ship":"Ship\'s name","sample_operator":"Operator\'s name","sample_sampling_gear":"Sampling gear used","sample_concentrated_sample_volume":"Volume of concentrated sample, in mL","sample_total_volume":"Total volume filtered by the net used, in L","sample_dilution_factor":"Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2","sample_speed_through_water":"Speed of the boat through water when sampling, in kts","acq_id":"Acquisition ID","acq_uuid":"Acquisition UUID (Autogenerated)","acq_instrument":"Instrument type","acq_instrument_id":"Instrument ID","acq_celltype":"Flow cell dimension thickness, in \xc2\xb5m","acq_minimum_mesh":"Minimum filtration mesh size, in \xc2\xb5m","acq_maximum_mesh":"Maximum filtration mesh size, in \xc2\xb5m","acq_min_esd":"","acq_max_esd":"","acq_volume":"Pumped volume, in mL","acq_imaged_volume":"Total imaged volume, in mL","acq_magnification":"Optical magnification","acq_fnumber_objective":"Focal length of the objective, in mm","acq_camera_name":"Name of the camera used","acq_nb_frame":"Number of picture taken","acq_local_datetime":"Instrument local datetime","acq_camera_resolution":"Resolution of the images","acq_camera_iso":"ISO Number of the images","acq_camera_shutter_speed":"Shutter speed of the images, in \xc2\xb5s","acq_software":"Software version number","object_date":"Sample collection date (or beginning if using a net)","object_time":"Sample collection time (or beginning if using a net)","object_lat":"Sample collection latitude (or beginning if using a net)","object_lon":"Sample collection longitude (or beginning if using a net)","object_depth_min":"Sample collection minimal depth, in m","object_depth_max":"Sample collection maximum depth, in m","process_pixel":"Pixel imaging resolution, in \xc2\xb5m/pixel","process_datetime":"Segmentation timestamp","process_id":"Segmentation ID","process_uuid":"Segmentation UUID (Autogenerated)","process_source":"Code source link of the executed code","process_commit":"Version reference of the executed code","sample_gear_net_opening":"Sample mouth opening dimension, in mm","object_date_end":"Sample end collection date when using a net","object_time_end":"Sample end collection time when using a net","object_lat_end":"Sample end collection latitude when using a net","object_lon_end":"Sample end collection longitude when using a net"},"sample_project":"Project\'s name","sample_id":"Project\'s name_1","sample_ship":"Vessel name","sample_operator":"Operator\'s name","sample_sampling_gear":"single_location","sample_concentrated_sample_volume":30,"acq_id":"Project\'s name_1_7","acq_instrument":"PlanktoScope v2.5","acq_instrument_id":"smooth-wave-21342\\n","acq_celltype":200,"acq_minimum_mesh":30,"acq_maximum_mesh":200,"acq_volume":"0.10","acq_magnification":"ERROR","acq_fnumber_objective":16,"acq_nb_frame":10,"acq_software":"PlanktoScope v2023.9.0-beta.0","object_date":"20230914","object_time":"0435","object_lat":"32.8126","object_lon":"129.7726","object_depth_min":0,"object_depth_max":0,"process_pixel":0.75,"process_source":"https://www.github.com/PlanktonPlanet/PlanktoScope"}}'
2023-09-02 07:50:49.280 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'update_config', 'config': {'description': {'sample_project': "Project's name", 'sample_id': 'Sample ID', 'sample_uuid': 'Sample UUID (Autogenerated)', 'sample_ship': "Ship's name", 'sample_operator': "Operator's name", 'sample_sampling_gear': 'Sampling gear used', 'sample_concentrated_sample_volume': 'Volume of concentrated sample, in mL', 'sample_total_volume': 'Total volume filtered by the net used, in L', 'sample_dilution_factor': 'Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2', 'sample_speed_through_water': 'Speed of the boat through water when sampling, in kts', 'acq_id': 'Acquisition ID', 'acq_uuid': 'Acquisition UUID (Autogenerated)', 'acq_instrument': 'Instrument type', 'acq_instrument_id': 'Instrument ID', 'acq_celltype': 'Flow cell dimension thickness, in µm', 'acq_minimum_mesh': 'Minimum filtration mesh size, in µm', 'acq_maximum_mesh': 'Maximum filtration mesh size, in µm', 'acq_min_esd': '', 'acq_max_esd': '', 'acq_volume': 'Pumped volume, in mL', 'acq_imaged_volume': 'Total imaged volume, in mL', 'acq_magnification': 'Optical magnification', 'acq_fnumber_objective': 'Focal length of the objective, in mm', 'acq_camera_name': 'Name of the camera used', 'acq_nb_frame': 'Number of picture taken', 'acq_local_datetime': 'Instrument local datetime', 'acq_camera_resolution': 'Resolution of the images', 'acq_camera_iso': 'ISO Number of the images', 'acq_camera_shutter_speed': 'Shutter speed of the images, in µs', 'acq_software': 'Software version number', 'object_date': 'Sample collection date (or beginning if using a net)', 'object_time': 'Sample collection time (or beginning if using a net)', 'object_lat': 'Sample collection latitude (or beginning if using a net)', 'object_lon': 'Sample collection longitude (or beginning if using a net)', 'object_depth_min': 'Sample collection minimal depth, in m', 'object_depth_max': 'Sample collection maximum depth, in m', 'process_pixel': 'Pixel imaging resolution, in µm/pixel', 'process_datetime': 'Segmentation timestamp', 'process_id': 'Segmentation ID', 'process_uuid': 'Segmentation UUID (Autogenerated)', 'process_source': 'Code source link of the executed code', 'process_commit': 'Version reference of the executed code', 'sample_gear_net_opening': 'Sample mouth opening dimension, in mm', 'object_date_end': 'Sample end collection date when using a net', 'object_time_end': 'Sample end collection time when using a net', 'object_lat_end': 'Sample end collection latitude when using a net', 'object_lon_end': 'Sample end collection longitude when using a net'}, 'sample_project': "Project's name", 'sample_id': "Project's name_1", 'sample_ship': 'Vessel name', 'sample_operator': "Operator's name", 'sample_sampling_gear': 'single_location', 'sample_concentrated_sample_volume': 30, 'acq_id': "Project's name_1_7", 'acq_instrument': 'PlanktoScope v2.5', 'acq_instrument_id': 'smooth-wave-21342\n', 'acq_celltype': 200, 'acq_minimum_mesh': 30, 'acq_maximum_mesh': 200, 'acq_volume': '0.10', 'acq_magnification': 'ERROR', 'acq_fnumber_objective': 16, 'acq_nb_frame': 10, 'acq_software': 'PlanktoScope v2023.9.0-beta.0', 'object_date': '20230914', 'object_time': '0435', 'object_lat': '32.8126', 'object_lon': '129.7726', 'object_depth_min': 0, 'object_depth_max': 0, 'process_pixel': 0.75, 'process_source': 'https://www.github.com/PlanktonPlanet/PlanktoScope'}}
2023-09-02 07:50:49.282 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'imager/image', 'payload': {'action': 'update_config', 'config': {'description': {'sample_project': "Project's name", 'sample_id': 'Sample ID', 'sample_uuid': 'Sample UUID (Autogenerated)', 'sample_ship': "Ship's name", 'sample_operator': "Operator's name", 'sample_sampling_gear': 'Sampling gear used', 'sample_concentrated_sample_volume': 'Volume of concentrated sample, in mL', 'sample_total_volume': 'Total volume filtered by the net used, in L', 'sample_dilution_factor': 'Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2', 'sample_speed_through_water': 'Speed of the boat through water when sampling, in kts', 'acq_id': 'Acquisition ID', 'acq_uuid': 'Acquisition UUID (Autogenerated)', 'acq_instrument': 'Instrument type', 'acq_instrument_id': 'Instrument ID', 'acq_celltype': 'Flow cell dimension thickness, in µm', 'acq_minimum_mesh': 'Minimum filtration mesh size, in µm', 'acq_maximum_mesh': 'Maximum filtration mesh size, in µm', 'acq_min_esd': '', 'acq_max_esd': '', 'acq_volume': 'Pumped volume, in mL', 'acq_imaged_volume': 'Total imaged volume, in mL', 'acq_magnification': 'Optical magnification', 'acq_fnumber_objective': 'Focal length of the objective, in mm', 'acq_camera_name': 'Name of the camera used', 'acq_nb_frame': 'Number of picture taken', 'acq_local_datetime': 'Instrument local datetime', 'acq_camera_resolution': 'Resolution of the images', 'acq_camera_iso': 'ISO Number of the images', 'acq_camera_shutter_speed': 'Shutter speed of the images, in µs', 'acq_software': 'Software version number', 'object_date': 'Sample collection date (or beginning if using a net)', 'object_time': 'Sample collection time (or beginning if using a net)', 'object_lat': 'Sample collection latitude (or beginning if using a net)', 'object_lon': 'Sample collection longitude (or beginning if using a net)', 'object_depth_min': 'Sample collection minimal depth, in m', 'object_depth_max': 'Sample collection maximum depth, in m', 'process_pixel': 'Pixel imaging resolution, in µm/pixel', 'process_datetime': 'Segmentation timestamp', 'process_id': 'Segmentation ID', 'process_uuid': 'Segmentation UUID (Autogenerated)', 'process_source': 'Code source link of the executed code', 'process_commit': 'Version reference of the executed code', 'sample_gear_net_opening': 'Sample mouth opening dimension, in mm', 'object_date_end': 'Sample end collection date when using a net', 'object_time_end': 'Sample end collection time when using a net', 'object_lat_end': 'Sample end collection latitude when using a net', 'object_lon_end': 'Sample end collection longitude when using a net'}, 'sample_project': "Project's name", 'sample_id': "Project's name_1", 'sample_ship': 'Vessel name', 'sample_operator': "Operator's name", 'sample_sampling_gear': 'single_location', 'sample_concentrated_sample_volume': 30, 'acq_id': "Project's name_1_7", 'acq_instrument': 'PlanktoScope v2.5', 'acq_instrument_id': 'smooth-wave-21342\n', 'acq_celltype': 200, 'acq_minimum_mesh': 30, 'acq_maximum_mesh': 200, 'acq_volume': '0.10', 'acq_magnification': 'ERROR', 'acq_fnumber_objective': 16, 'acq_nb_frame': 10, 'acq_software': 'PlanktoScope v2023.9.0-beta.0', 'object_date': '20230914', 'object_time': '0435', 'object_lat': '32.8126', 'object_lon': '129.7726', 'object_depth_min': 0, 'object_depth_max': 0, 'process_pixel': 0.75, 'process_source': 'https://www.github.com/PlanktonPlanet/PlanktoScope'}}}
2023-09-02 07:50:49.285 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:50:49.286 | DEBUG    | planktoscope.imager:treat_message:459 - {'action': 'update_config', 'config': {'description': {'sample_project': "Project's name", 'sample_id': 'Sample ID', 'sample_uuid': 'Sample UUID (Autogenerated)', 'sample_ship': "Ship's name", 'sample_operator': "Operator's name", 'sample_sampling_gear': 'Sampling gear used', 'sample_concentrated_sample_volume': 'Volume of concentrated sample, in mL', 'sample_total_volume': 'Total volume filtered by the net used, in L', 'sample_dilution_factor': 'Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2', 'sample_speed_through_water': 'Speed of the boat through water when sampling, in kts', 'acq_id': 'Acquisition ID', 'acq_uuid': 'Acquisition UUID (Autogenerated)', 'acq_instrument': 'Instrument type', 'acq_instrument_id': 'Instrument ID', 'acq_celltype': 'Flow cell dimension thickness, in µm', 'acq_minimum_mesh': 'Minimum filtration mesh size, in µm', 'acq_maximum_mesh': 'Maximum filtration mesh size, in µm', 'acq_min_esd': '', 'acq_max_esd': '', 'acq_volume': 'Pumped volume, in mL', 'acq_imaged_volume': 'Total imaged volume, in mL', 'acq_magnification': 'Optical magnification', 'acq_fnumber_objective': 'Focal length of the objective, in mm', 'acq_camera_name': 'Name of the camera used', 'acq_nb_frame': 'Number of picture taken', 'acq_local_datetime': 'Instrument local datetime', 'acq_camera_resolution': 'Resolution of the images', 'acq_camera_iso': 'ISO Number of the images', 'acq_camera_shutter_speed': 'Shutter speed of the images, in µs', 'acq_software': 'Software version number', 'object_date': 'Sample collection date (or beginning if using a net)', 'object_time': 'Sample collection time (or beginning if using a net)', 'object_lat': 'Sample collection latitude (or beginning if using a net)', 'object_lon': 'Sample collection longitude (or beginning if using a net)', 'object_depth_min': 'Sample collection minimal depth, in m', 'object_depth_max': 'Sample collection maximum depth, in m', 'process_pixel': 'Pixel imaging resolution, in µm/pixel', 'process_datetime': 'Segmentation timestamp', 'process_id': 'Segmentation ID', 'process_uuid': 'Segmentation UUID (Autogenerated)', 'process_source': 'Code source link of the executed code', 'process_commit': 'Version reference of the executed code', 'sample_gear_net_opening': 'Sample mouth opening dimension, in mm', 'object_date_end': 'Sample end collection date when using a net', 'object_time_end': 'Sample end collection time when using a net', 'object_lat_end': 'Sample end collection latitude when using a net', 'object_lon_end': 'Sample end collection longitude when using a net'}, 'sample_project': "Project's name", 'sample_id': "Project's name_1", 'sample_ship': 'Vessel name', 'sample_operator': "Operator's name", 'sample_sampling_gear': 'single_location', 'sample_concentrated_sample_volume': 30, 'acq_id': "Project's name_1_7", 'acq_instrument': 'PlanktoScope v2.5', 'acq_instrument_id': 'smooth-wave-21342\n', 'acq_celltype': 200, 'acq_minimum_mesh': 30, 'acq_maximum_mesh': 200, 'acq_volume': '0.10', 'acq_magnification': 'ERROR', 'acq_fnumber_objective': 16, 'acq_nb_frame': 10, 'acq_software': 'PlanktoScope v2023.9.0-beta.0', 'object_date': '20230914', 'object_time': '0435', 'object_lat': '32.8126', 'object_lon': '129.7726', 'object_depth_min': 0, 'object_depth_max': 0, 'process_pixel': 0.75, 'process_source': 'https://www.github.com/PlanktonPlanet/PlanktoScope'}}
2023-09-02 07:50:49.288 | DEBUG    | planktoscope.imager:treat_message:461 - update_config
2023-09-02 07:50:49.289 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:50:49.290 | INFO     | planktoscope.imager:__message_update:264 - Updating the configuration now with the received data
2023-09-02 07:50:49.292 | INFO     | planktoscope.imager:__message_update:272 - Configuration has been updated
2023-09-02 07:50:50.276 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: imager/image 0 b'{"action":"image","sleep":0.5,"pump_direction":"FORWARD","volume":0.01,"nb_frame":10}'
2023-09-02 07:50:50.278 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'image', 'sleep': 0.5, 'pump_direction': 'FORWARD', 'volume': 0.01, 'nb_frame': 10}
2023-09-02 07:50:50.279 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'imager/image', 'payload': {'action': 'image', 'sleep': 0.5, 'pump_direction': 'FORWARD', 'volume': 0.01, 'nb_frame': 10}}
2023-09-02 07:50:50.280 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:50:50.282 | DEBUG    | planktoscope.imager:treat_message:459 - {'action': 'image', 'sleep': 0.5, 'pump_direction': 'FORWARD', 'volume': 0.01, 'nb_frame': 10}
2023-09-02 07:50:50.283 | DEBUG    | planktoscope.imager:treat_message:461 - image
2023-09-02 07:50:50.285 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:50:50.287 | INFO     | planktoscope.imager.state_machine:switch:27 - Current:stop => switched to new state imaging
2023-09-02 07:50:50.291 | SUCCESS  | planktoscope.mqtt:on_subscribe:124 - imager_client subscribed to imager/#! - mid:18 qos:(0,)
2023-09-02 07:50:50.292 | INFO     | planktoscope.imager:__state_imaging:553 - Setting up the directory structure for storing the pictures
2023-09-02 07:50:50.298 | ERROR    | planktoscope.imager:__state_imaging:563 - The export path at /home/pi/data/img/20230914/Project's_name_1/Project's_name_1_7 already exists
2023-09-02 07:50:50.304 | INFO     | planktoscope.imager.state_machine:switch:27 - Current:imaging => switched to new state stop
2023-09-02 07:50:55.187 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: imager/image 0 b'{"action":"stop"}'
2023-09-02 07:50:55.191 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'stop'}
2023-09-02 07:50:55.193 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'imager/image', 'payload': {'action': 'stop'}}
2023-09-02 07:50:55.195 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:50:55.197 | DEBUG    | planktoscope.imager:treat_message:459 - {'action': 'stop'}
2023-09-02 07:50:55.199 | DEBUG    | planktoscope.imager:treat_message:461 - stop
2023-09-02 07:50:55.201 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:50:55.205 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action": "stop"}'
2023-09-02 07:50:55.204 | INFO     | planktoscope.imager:__message_stop:246 - The imaging has been interrupted.
2023-09-02 07:50:55.206 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'stop'}
2023-09-02 07:50:55.207 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'stop'}}
2023-09-02 07:50:55.208 | ERROR    | planktoscope.imager.state_machine:switch:30 - Current:stop => switching to stop not possible.
2023-09-02 07:50:55.213 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 07:50:55.217 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'stop'}
2023-09-02 07:50:55.219 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 07:50:55.222 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:50:55.224 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 07:50:55.225 | DEBUG    | planktoscope.stepper:__message_pump:196 - We have received a stop pump command
2023-09-02 07:50:55.227 | INFO     | planktoscope.stepper:__message_pump:200 - The pump has been interrupted
2023-09-02 07:50:58.880 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: imager/image 0 b'{"action":"update_config","config":{"description":{"sample_project":"Project\'s name","sample_id":"Sample ID","sample_uuid":"Sample UUID (Autogenerated)","sample_ship":"Ship\'s name","sample_operator":"Operator\'s name","sample_sampling_gear":"Sampling gear used","sample_concentrated_sample_volume":"Volume of concentrated sample, in mL","sample_total_volume":"Total volume filtered by the net used, in L","sample_dilution_factor":"Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2","sample_speed_through_water":"Speed of the boat through water when sampling, in kts","acq_id":"Acquisition ID","acq_uuid":"Acquisition UUID (Autogenerated)","acq_instrument":"Instrument type","acq_instrument_id":"Instrument ID","acq_celltype":"Flow cell dimension thickness, in \xc2\xb5m","acq_minimum_mesh":"Minimum filtration mesh size, in \xc2\xb5m","acq_maximum_mesh":"Maximum filtration mesh size, in \xc2\xb5m","acq_min_esd":"","acq_max_esd":"","acq_volume":"Pumped volume, in mL","acq_imaged_volume":"Total imaged volume, in mL","acq_magnification":"Optical magnification","acq_fnumber_objective":"Focal length of the objective, in mm","acq_camera_name":"Name of the camera used","acq_nb_frame":"Number of picture taken","acq_local_datetime":"Instrument local datetime","acq_camera_resolution":"Resolution of the images","acq_camera_iso":"ISO Number of the images","acq_camera_shutter_speed":"Shutter speed of the images, in \xc2\xb5s","acq_software":"Software version number","object_date":"Sample collection date (or beginning if using a net)","object_time":"Sample collection time (or beginning if using a net)","object_lat":"Sample collection latitude (or beginning if using a net)","object_lon":"Sample collection longitude (or beginning if using a net)","object_depth_min":"Sample collection minimal depth, in m","object_depth_max":"Sample collection maximum depth, in m","process_pixel":"Pixel imaging resolution, in \xc2\xb5m/pixel","process_datetime":"Segmentation timestamp","process_id":"Segmentation ID","process_uuid":"Segmentation UUID (Autogenerated)","process_source":"Code source link of the executed code","process_commit":"Version reference of the executed code","sample_gear_net_opening":"Sample mouth opening dimension, in mm","object_date_end":"Sample end collection date when using a net","object_time_end":"Sample end collection time when using a net","object_lat_end":"Sample end collection latitude when using a net","object_lon_end":"Sample end collection longitude when using a net"},"sample_project":"Project\'s name","sample_id":"Project\'s name_1","sample_ship":"Vessel name","sample_operator":"Operator\'s name","sample_sampling_gear":"single_location","sample_concentrated_sample_volume":30,"acq_id":"Project\'s name_1_8","acq_instrument":"PlanktoScope v2.5","acq_instrument_id":"smooth-wave-21342\\n","acq_celltype":200,"acq_minimum_mesh":30,"acq_maximum_mesh":200,"acq_volume":"0.10","acq_magnification":"ERROR","acq_fnumber_objective":16,"acq_nb_frame":10,"acq_software":"PlanktoScope v2023.9.0-beta.0","object_date":"20230914","object_time":"0435","object_lat":"32.8126","object_lon":"129.7726","object_depth_min":0,"object_depth_max":0,"process_pixel":0.75,"process_source":"https://www.github.com/PlanktonPlanet/PlanktoScope"}}'
2023-09-02 07:50:58.882 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'update_config', 'config': {'description': {'sample_project': "Project's name", 'sample_id': 'Sample ID', 'sample_uuid': 'Sample UUID (Autogenerated)', 'sample_ship': "Ship's name", 'sample_operator': "Operator's name", 'sample_sampling_gear': 'Sampling gear used', 'sample_concentrated_sample_volume': 'Volume of concentrated sample, in mL', 'sample_total_volume': 'Total volume filtered by the net used, in L', 'sample_dilution_factor': 'Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2', 'sample_speed_through_water': 'Speed of the boat through water when sampling, in kts', 'acq_id': 'Acquisition ID', 'acq_uuid': 'Acquisition UUID (Autogenerated)', 'acq_instrument': 'Instrument type', 'acq_instrument_id': 'Instrument ID', 'acq_celltype': 'Flow cell dimension thickness, in µm', 'acq_minimum_mesh': 'Minimum filtration mesh size, in µm', 'acq_maximum_mesh': 'Maximum filtration mesh size, in µm', 'acq_min_esd': '', 'acq_max_esd': '', 'acq_volume': 'Pumped volume, in mL', 'acq_imaged_volume': 'Total imaged volume, in mL', 'acq_magnification': 'Optical magnification', 'acq_fnumber_objective': 'Focal length of the objective, in mm', 'acq_camera_name': 'Name of the camera used', 'acq_nb_frame': 'Number of picture taken', 'acq_local_datetime': 'Instrument local datetime', 'acq_camera_resolution': 'Resolution of the images', 'acq_camera_iso': 'ISO Number of the images', 'acq_camera_shutter_speed': 'Shutter speed of the images, in µs', 'acq_software': 'Software version number', 'object_date': 'Sample collection date (or beginning if using a net)', 'object_time': 'Sample collection time (or beginning if using a net)', 'object_lat': 'Sample collection latitude (or beginning if using a net)', 'object_lon': 'Sample collection longitude (or beginning if using a net)', 'object_depth_min': 'Sample collection minimal depth, in m', 'object_depth_max': 'Sample collection maximum depth, in m', 'process_pixel': 'Pixel imaging resolution, in µm/pixel', 'process_datetime': 'Segmentation timestamp', 'process_id': 'Segmentation ID', 'process_uuid': 'Segmentation UUID (Autogenerated)', 'process_source': 'Code source link of the executed code', 'process_commit': 'Version reference of the executed code', 'sample_gear_net_opening': 'Sample mouth opening dimension, in mm', 'object_date_end': 'Sample end collection date when using a net', 'object_time_end': 'Sample end collection time when using a net', 'object_lat_end': 'Sample end collection latitude when using a net', 'object_lon_end': 'Sample end collection longitude when using a net'}, 'sample_project': "Project's name", 'sample_id': "Project's name_1", 'sample_ship': 'Vessel name', 'sample_operator': "Operator's name", 'sample_sampling_gear': 'single_location', 'sample_concentrated_sample_volume': 30, 'acq_id': "Project's name_1_8", 'acq_instrument': 'PlanktoScope v2.5', 'acq_instrument_id': 'smooth-wave-21342\n', 'acq_celltype': 200, 'acq_minimum_mesh': 30, 'acq_maximum_mesh': 200, 'acq_volume': '0.10', 'acq_magnification': 'ERROR', 'acq_fnumber_objective': 16, 'acq_nb_frame': 10, 'acq_software': 'PlanktoScope v2023.9.0-beta.0', 'object_date': '20230914', 'object_time': '0435', 'object_lat': '32.8126', 'object_lon': '129.7726', 'object_depth_min': 0, 'object_depth_max': 0, 'process_pixel': 0.75, 'process_source': 'https://www.github.com/PlanktonPlanet/PlanktoScope'}}
2023-09-02 07:50:58.885 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'imager/image', 'payload': {'action': 'update_config', 'config': {'description': {'sample_project': "Project's name", 'sample_id': 'Sample ID', 'sample_uuid': 'Sample UUID (Autogenerated)', 'sample_ship': "Ship's name", 'sample_operator': "Operator's name", 'sample_sampling_gear': 'Sampling gear used', 'sample_concentrated_sample_volume': 'Volume of concentrated sample, in mL', 'sample_total_volume': 'Total volume filtered by the net used, in L', 'sample_dilution_factor': 'Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2', 'sample_speed_through_water': 'Speed of the boat through water when sampling, in kts', 'acq_id': 'Acquisition ID', 'acq_uuid': 'Acquisition UUID (Autogenerated)', 'acq_instrument': 'Instrument type', 'acq_instrument_id': 'Instrument ID', 'acq_celltype': 'Flow cell dimension thickness, in µm', 'acq_minimum_mesh': 'Minimum filtration mesh size, in µm', 'acq_maximum_mesh': 'Maximum filtration mesh size, in µm', 'acq_min_esd': '', 'acq_max_esd': '', 'acq_volume': 'Pumped volume, in mL', 'acq_imaged_volume': 'Total imaged volume, in mL', 'acq_magnification': 'Optical magnification', 'acq_fnumber_objective': 'Focal length of the objective, in mm', 'acq_camera_name': 'Name of the camera used', 'acq_nb_frame': 'Number of picture taken', 'acq_local_datetime': 'Instrument local datetime', 'acq_camera_resolution': 'Resolution of the images', 'acq_camera_iso': 'ISO Number of the images', 'acq_camera_shutter_speed': 'Shutter speed of the images, in µs', 'acq_software': 'Software version number', 'object_date': 'Sample collection date (or beginning if using a net)', 'object_time': 'Sample collection time (or beginning if using a net)', 'object_lat': 'Sample collection latitude (or beginning if using a net)', 'object_lon': 'Sample collection longitude (or beginning if using a net)', 'object_depth_min': 'Sample collection minimal depth, in m', 'object_depth_max': 'Sample collection maximum depth, in m', 'process_pixel': 'Pixel imaging resolution, in µm/pixel', 'process_datetime': 'Segmentation timestamp', 'process_id': 'Segmentation ID', 'process_uuid': 'Segmentation UUID (Autogenerated)', 'process_source': 'Code source link of the executed code', 'process_commit': 'Version reference of the executed code', 'sample_gear_net_opening': 'Sample mouth opening dimension, in mm', 'object_date_end': 'Sample end collection date when using a net', 'object_time_end': 'Sample end collection time when using a net', 'object_lat_end': 'Sample end collection latitude when using a net', 'object_lon_end': 'Sample end collection longitude when using a net'}, 'sample_project': "Project's name", 'sample_id': "Project's name_1", 'sample_ship': 'Vessel name', 'sample_operator': "Operator's name", 'sample_sampling_gear': 'single_location', 'sample_concentrated_sample_volume': 30, 'acq_id': "Project's name_1_8", 'acq_instrument': 'PlanktoScope v2.5', 'acq_instrument_id': 'smooth-wave-21342\n', 'acq_celltype': 200, 'acq_minimum_mesh': 30, 'acq_maximum_mesh': 200, 'acq_volume': '0.10', 'acq_magnification': 'ERROR', 'acq_fnumber_objective': 16, 'acq_nb_frame': 10, 'acq_software': 'PlanktoScope v2023.9.0-beta.0', 'object_date': '20230914', 'object_time': '0435', 'object_lat': '32.8126', 'object_lon': '129.7726', 'object_depth_min': 0, 'object_depth_max': 0, 'process_pixel': 0.75, 'process_source': 'https://www.github.com/PlanktonPlanet/PlanktoScope'}}}
2023-09-02 07:50:58.889 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:50:58.892 | DEBUG    | planktoscope.imager:treat_message:459 - {'action': 'update_config', 'config': {'description': {'sample_project': "Project's name", 'sample_id': 'Sample ID', 'sample_uuid': 'Sample UUID (Autogenerated)', 'sample_ship': "Ship's name", 'sample_operator': "Operator's name", 'sample_sampling_gear': 'Sampling gear used', 'sample_concentrated_sample_volume': 'Volume of concentrated sample, in mL', 'sample_total_volume': 'Total volume filtered by the net used, in L', 'sample_dilution_factor': 'Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2', 'sample_speed_through_water': 'Speed of the boat through water when sampling, in kts', 'acq_id': 'Acquisition ID', 'acq_uuid': 'Acquisition UUID (Autogenerated)', 'acq_instrument': 'Instrument type', 'acq_instrument_id': 'Instrument ID', 'acq_celltype': 'Flow cell dimension thickness, in µm', 'acq_minimum_mesh': 'Minimum filtration mesh size, in µm', 'acq_maximum_mesh': 'Maximum filtration mesh size, in µm', 'acq_min_esd': '', 'acq_max_esd': '', 'acq_volume': 'Pumped volume, in mL', 'acq_imaged_volume': 'Total imaged volume, in mL', 'acq_magnification': 'Optical magnification', 'acq_fnumber_objective': 'Focal length of the objective, in mm', 'acq_camera_name': 'Name of the camera used', 'acq_nb_frame': 'Number of picture taken', 'acq_local_datetime': 'Instrument local datetime', 'acq_camera_resolution': 'Resolution of the images', 'acq_camera_iso': 'ISO Number of the images', 'acq_camera_shutter_speed': 'Shutter speed of the images, in µs', 'acq_software': 'Software version number', 'object_date': 'Sample collection date (or beginning if using a net)', 'object_time': 'Sample collection time (or beginning if using a net)', 'object_lat': 'Sample collection latitude (or beginning if using a net)', 'object_lon': 'Sample collection longitude (or beginning if using a net)', 'object_depth_min': 'Sample collection minimal depth, in m', 'object_depth_max': 'Sample collection maximum depth, in m', 'process_pixel': 'Pixel imaging resolution, in µm/pixel', 'process_datetime': 'Segmentation timestamp', 'process_id': 'Segmentation ID', 'process_uuid': 'Segmentation UUID (Autogenerated)', 'process_source': 'Code source link of the executed code', 'process_commit': 'Version reference of the executed code', 'sample_gear_net_opening': 'Sample mouth opening dimension, in mm', 'object_date_end': 'Sample end collection date when using a net', 'object_time_end': 'Sample end collection time when using a net', 'object_lat_end': 'Sample end collection latitude when using a net', 'object_lon_end': 'Sample end collection longitude when using a net'}, 'sample_project': "Project's name", 'sample_id': "Project's name_1", 'sample_ship': 'Vessel name', 'sample_operator': "Operator's name", 'sample_sampling_gear': 'single_location', 'sample_concentrated_sample_volume': 30, 'acq_id': "Project's name_1_8", 'acq_instrument': 'PlanktoScope v2.5', 'acq_instrument_id': 'smooth-wave-21342\n', 'acq_celltype': 200, 'acq_minimum_mesh': 30, 'acq_maximum_mesh': 200, 'acq_volume': '0.10', 'acq_magnification': 'ERROR', 'acq_fnumber_objective': 16, 'acq_nb_frame': 10, 'acq_software': 'PlanktoScope v2023.9.0-beta.0', 'object_date': '20230914', 'object_time': '0435', 'object_lat': '32.8126', 'object_lon': '129.7726', 'object_depth_min': 0, 'object_depth_max': 0, 'process_pixel': 0.75, 'process_source': 'https://www.github.com/PlanktonPlanet/PlanktoScope'}}
2023-09-02 07:50:58.895 | DEBUG    | planktoscope.imager:treat_message:461 - update_config
2023-09-02 07:50:58.896 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:50:58.899 | INFO     | planktoscope.imager:__message_update:264 - Updating the configuration now with the received data
2023-09-02 07:50:58.901 | INFO     | planktoscope.imager:__message_update:272 - Configuration has been updated
2023-09-02 07:50:59.879 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: imager/image 0 b'{"action":"image","sleep":0.5,"pump_direction":"FORWARD","volume":0.01,"nb_frame":10}'
2023-09-02 07:50:59.880 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'image', 'sleep': 0.5, 'pump_direction': 'FORWARD', 'volume': 0.01, 'nb_frame': 10}
2023-09-02 07:50:59.881 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'imager/image', 'payload': {'action': 'image', 'sleep': 0.5, 'pump_direction': 'FORWARD', 'volume': 0.01, 'nb_frame': 10}}
2023-09-02 07:50:59.882 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:50:59.883 | DEBUG    | planktoscope.imager:treat_message:459 - {'action': 'image', 'sleep': 0.5, 'pump_direction': 'FORWARD', 'volume': 0.01, 'nb_frame': 10}
2023-09-02 07:50:59.884 | DEBUG    | planktoscope.imager:treat_message:461 - image
2023-09-02 07:50:59.888 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:50:59.891 | INFO     | planktoscope.imager.state_machine:switch:27 - Current:stop => switched to new state imaging
2023-09-02 07:50:59.895 | INFO     | planktoscope.imager:__state_imaging:553 - Setting up the directory structure for storing the pictures
2023-09-02 07:50:59.897 | SUCCESS  | planktoscope.mqtt:on_subscribe:124 - imager_client subscribed to imager/#! - mid:25 qos:(0,)
2023-09-02 07:50:59.900 | INFO     | planktoscope.imager:__state_imaging:577 - Exporting the metadata to a metadata.json
2023-09-02 07:50:59.903 | DEBUG    | planktoscope.imager:__state_imaging:581 - Metadata dumped in <_io.TextIOWrapper name="/home/pi/data/img/20230914/Project's_name_1/Project's_name_1_8/metadata.json" mode='w' encoding='UTF-8'> are {'description': {'sample_project': "Project's name", 'sample_id': 'Sample ID', 'sample_uuid': 'Sample UUID (Autogenerated)', 'sample_ship': "Ship's name", 'sample_operator': "Operator's name", 'sample_sampling_gear': 'Sampling gear used', 'sample_concentrated_sample_volume': 'Volume of concentrated sample, in mL', 'sample_total_volume': 'Total volume filtered by the net used, in L', 'sample_dilution_factor': 'Dilution factor of the sample, 0.5 if diluted by 2, 2 if concentrated by 2', 'sample_speed_through_water': 'Speed of the boat through water when sampling, in kts', 'acq_id': 'Acquisition ID', 'acq_uuid': 'Acquisition UUID (Autogenerated)', 'acq_instrument': 'Instrument type', 'acq_instrument_id': 'Instrument ID', 'acq_celltype': 'Flow cell dimension thickness, in µm', 'acq_minimum_mesh': 'Minimum filtration mesh size, in µm', 'acq_maximum_mesh': 'Maximum filtration mesh size, in µm', 'acq_min_esd': '', 'acq_max_esd': '', 'acq_volume': 'Pumped volume, in mL', 'acq_imaged_volume': 'Total imaged volume, in mL', 'acq_magnification': 'Optical magnification', 'acq_fnumber_objective': 'Focal length of the objective, in mm', 'acq_camera_name': 'Name of the camera used', 'acq_nb_frame': 'Number of picture taken', 'acq_local_datetime': 'Instrument local datetime', 'acq_camera_resolution': 'Resolution of the images', 'acq_camera_iso': 'ISO Number of the images', 'acq_camera_shutter_speed': 'Shutter speed of the images, in µs', 'acq_software': 'Software version number', 'object_date': 'Sample collection date (or beginning if using a net)', 'object_time': 'Sample collection time (or beginning if using a net)', 'object_lat': 'Sample collection latitude (or beginning if using a net)', 'object_lon': 'Sample collection longitude (or beginning if using a net)', 'object_depth_min': 'Sample collection minimal depth, in m', 'object_depth_max': 'Sample collection maximum depth, in m', 'process_pixel': 'Pixel imaging resolution, in µm/pixel', 'process_datetime': 'Segmentation timestamp', 'process_id': 'Segmentation ID', 'process_uuid': 'Segmentation UUID (Autogenerated)', 'process_source': 'Code source link of the executed code', 'process_commit': 'Version reference of the executed code', 'sample_gear_net_opening': 'Sample mouth opening dimension, in mm', 'object_date_end': 'Sample end collection date when using a net', 'object_time_end': 'Sample end collection time when using a net', 'object_lat_end': 'Sample end collection latitude when using a net', 'object_lon_end': 'Sample end collection longitude when using a net'}, 'sample_project': "Project's name", 'sample_id': "Project's name_1", 'sample_ship': 'Vessel name', 'sample_operator': "Operator's name", 'sample_sampling_gear': 'single_location', 'sample_concentrated_sample_volume': 30, 'acq_id': "Project's name_1_8", 'acq_instrument': 'PlanktoScope v2.5', 'acq_instrument_id': 'smooth-wave-21342\n', 'acq_celltype': 200, 'acq_minimum_mesh': 30, 'acq_maximum_mesh': 200, 'acq_volume': '0.10', 'acq_magnification': 'ERROR', 'acq_fnumber_objective': 16, 'acq_nb_frame': 10, 'acq_software': 'PlanktoScope v2023.9.0-beta.0', 'object_date': '20230914', 'object_time': '0435', 'object_lat': '32.8126', 'object_lon': '129.7726', 'object_depth_min': 0, 'object_depth_max': 0, 'process_pixel': 0.75, 'process_source': 'https://www.github.com/PlanktonPlanet/PlanktoScope', 'acq_local_datetime': '2023-09-02T07:50:59', 'acq_camera_resolution': '4056x3040', 'acq_camera_iso': 100, 'acq_camera_shutter_speed': 125, 'acq_uuid': '75068399-4965-11ee-8730-0000b23d5dc2', 'sample_uuid': '7506954c-4965-11ee-8782-0000b23d5dc2'}
2023-09-02 07:50:59.905 | DEBUG    | planktoscope.integrity:create_integrity_file:86 - Create the integrity file in the folder /home/pi/data/img/20230914/Project's_name_1/Project's_name_1_8
2023-09-02 07:50:59.907 | DEBUG    | planktoscope.integrity:get_filename_checksum:56 - Calculating the integrity of /home/pi/data/img/20230914/Project's_name_1/Project's_name_1_8/metadata.json's content and its filename
2023-09-02 07:50:59.911 | INFO     | planktoscope.imager.state_machine:switch:27 - Current:imaging => switched to new state waiting
2023-09-02 07:50:59.911 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action": "move", "direction": "FORWARD", "volume": 0.01, "flowrate": 2}'
2023-09-02 07:50:59.913 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'move', 'direction': 'FORWARD', 'volume': 0.01, 'flowrate': 2}
2023-09-02 07:50:59.914 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'move', 'direction': 'FORWARD', 'volume': 0.01, 'flowrate': 2}}
2023-09-02 07:50:59.919 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 07:50:59.920 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'move', 'direction': 'FORWARD', 'volume': 0.01, 'flowrate': 2}
2023-09-02 07:50:59.921 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 07:50:59.923 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:50:59.924 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 07:50:59.925 | DEBUG    | planktoscope.stepper:__message_pump:208 - We have received a move pump command
2023-09-02 07:50:59.927 | INFO     | planktoscope.stepper:__message_pump:237 - The pump is started.
2023-09-02 07:50:59.927 | INFO     | planktoscope.stepper:pump:371 - The pump will move FORWARD for 0.01mL at 2.0mL/min
2023-09-02 07:50:59.929 | DEBUG    | planktoscope.stepper:pump:381 - The number of microsteps that will be applied is 5235.0
2023-09-02 07:50:59.930 | DEBUG    | planktoscope.stepper:pump:388 - There will be a speed of 17450.666666666668 steps per second
2023-09-02 07:50:59.934 | DEBUG    | planktoscope.stepper:speed:94 - Setting stepper speed to 17450
2023-09-02 07:50:59.938 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: status/pump 0 b'{"status":"Started", "duration":0.2999885391198044}'
2023-09-02 07:50:59.939 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'status': 'Started', 'duration': 0.2999885391198044}
2023-09-02 07:50:59.941 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'status/pump', 'payload': {'status': 'Started', 'duration': 0.2999885391198044}}
2023-09-02 07:50:59.943 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:50:59.944 | DEBUG    | planktoscope.imager:treat_message:463 - Status message payload is {'status': 'Started', 'duration': 0.2999885391198044}
2023-09-02 07:50:59.945 | INFO     | planktoscope.imager:treat_message:471 - The pump is not done yet {'status': 'Started', 'duration': 0.2999885391198044}
2023-09-02 07:50:59.947 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:51:00.447 | SUCCESS  | planktoscope.stepper:run:433 - The pump movement is over!
2023-09-02 07:51:00.455 | INFO     | planktoscope.mqtt:on_message:132 - imager_client: status/pump 0 b'{"status":"Done"}'
2023-09-02 07:51:00.457 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'status': 'Done'}
2023-09-02 07:51:00.460 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'status/pump', 'payload': {'status': 'Done'}}
2023-09-02 07:51:00.466 | INFO     | planktoscope.imager:treat_message:456 - We received a new message
2023-09-02 07:51:00.467 | DEBUG    | planktoscope.imager:treat_message:463 - Status message payload is {'status': 'Done'}
2023-09-02 07:51:00.468 | INFO     | planktoscope.imager.state_machine:switch:27 - Current:waiting => switched to new state capture
2023-09-02 07:51:00.469 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 07:51:00.470 | INFO     | planktoscope.imager:__state_capture:610 - Capturing image 1/10 to /home/pi/data/img/20230914/Project's_name_1/Project's_name_1_8/07_51_00_470889.jpg
2023-09-02 07:51:00.972 | DEBUG    | planktoscope.imager.raspimjpeg:capture:490 - Capturing an image to 
2023-09-02 07:51:00.973 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [im] to raspimjpeg
2023-09-02 07:51:01.076 | DEBUG    | planktoscope.imager.raspimjpeg:__wait_for_output:151 - Waiting for Capturing image for 2.5s
2023-09-02 07:51:03.596 | ERROR    | planktoscope.imager.raspimjpeg:__wait_for_output:165 - A timeout has occured waiting for a RaspiMJPEG answer
2023-09-02 07:51:03.597 | ERROR    | planktoscope.imager:__capture_error:663 - An error occurred during the capture: timeout during capture
2023-09-02 07:51:04.600 | INFO     | planktoscope.imager:__state_capture:610 - Capturing image 1/10 to /home/pi/data/img/20230914/Project's_name_1/Project's_name_1_8/07_51_04_600519.jpg
2023-09-02 07:51:05.103 | DEBUG    | planktoscope.imager.raspimjpeg:capture:490 - Capturing an image to 
2023-09-02 07:51:05.104 | DEBUG    | planktoscope.imager.raspimjpeg:__send_command:220 - Sending the command [im] to raspimjpeg
2023-09-02 07:51:05.205 | DEBUG    | planktoscope.imager.raspimjpeg:__wait_for_output:151 - Waiting for Capturing image for 2.5s
2023-09-02 07:51:07.719 | ERROR    | planktoscope.imager.raspimjpeg:__wait_for_output:165 - A timeout has occured waiting for a RaspiMJPEG answer
2023-09-02 07:51:07.721 | ERROR    | planktoscope.imager:__capture_error:663 - An error occurred during the capture: timeout during capture
2023-09-02 07:51:07.722 | ERROR    | planktoscope.imager:__capture_error:665 - This is a repeating problem, stopping the capture now
2023-09-02 07:51:07.727 | INFO     | planktoscope.imager.state_machine:switch:27 - Current:capture => switched to new state stop
2023-09-02 08:06:41.034 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"move","direction":"FORWARD","volume":2,"flowrate":2}'
2023-09-02 08:06:41.035 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:06:41.036 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}}
2023-09-02 08:06:41.038 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:06:41.038 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:06:41.039 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:06:41.040 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:06:41.041 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:06:41.042 | DEBUG    | planktoscope.stepper:__message_pump:208 - We have received a move pump command
2023-09-02 08:06:41.043 | INFO     | planktoscope.stepper:__message_pump:237 - The pump is started.
2023-09-02 08:06:41.044 | INFO     | planktoscope.stepper:pump:371 - The pump will move FORWARD for 2.0mL at 2.0mL/min
2023-09-02 08:06:41.048 | DEBUG    | planktoscope.stepper:pump:381 - The number of microsteps that will be applied is 1047040.0
2023-09-02 08:06:41.053 | DEBUG    | planktoscope.stepper:pump:388 - There will be a speed of 17450.666666666668 steps per second
2023-09-02 08:06:41.054 | DEBUG    | planktoscope.stepper:speed:94 - Setting stepper speed to 17450
2023-09-02 08:06:43.246 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"stop"}'
2023-09-02 08:06:43.249 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'stop'}
2023-09-02 08:06:43.250 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'stop'}}
2023-09-02 08:06:43.252 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:06:43.254 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'stop'}
2023-09-02 08:06:43.256 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:06:43.258 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:06:43.262 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:06:43.264 | DEBUG    | planktoscope.stepper:__message_pump:196 - We have received a stop pump command
2023-09-02 08:06:43.361 | INFO     | planktoscope.stepper:__message_pump:200 - The pump has been interrupted
2023-09-02 08:06:43.365 | SUCCESS  | planktoscope.stepper:run:433 - The pump movement is over!
2023-09-02 08:07:04.424 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"move","direction":"FORWARD","volume":2,"flowrate":2}'
2023-09-02 08:07:04.426 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:04.430 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}}
2023-09-02 08:07:04.432 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:04.434 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:04.440 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:04.444 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:04.447 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:04.449 | DEBUG    | planktoscope.stepper:__message_pump:208 - We have received a move pump command
2023-09-02 08:07:04.451 | INFO     | planktoscope.stepper:__message_pump:237 - The pump is started.
2023-09-02 08:07:04.453 | INFO     | planktoscope.stepper:pump:371 - The pump will move FORWARD for 2.0mL at 2.0mL/min
2023-09-02 08:07:04.455 | DEBUG    | planktoscope.stepper:pump:381 - The number of microsteps that will be applied is 1047040.0
2023-09-02 08:07:04.456 | DEBUG    | planktoscope.stepper:pump:388 - There will be a speed of 17450.666666666668 steps per second
2023-09-02 08:07:04.458 | DEBUG    | planktoscope.stepper:speed:94 - Setting stepper speed to 17450
2023-09-02 08:07:09.683 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"stop"}'
2023-09-02 08:07:09.685 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'stop'}
2023-09-02 08:07:09.687 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'stop'}}
2023-09-02 08:07:09.689 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:09.690 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'stop'}
2023-09-02 08:07:09.693 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:09.697 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:09.700 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:09.703 | DEBUG    | planktoscope.stepper:__message_pump:196 - We have received a stop pump command
2023-09-02 08:07:09.802 | INFO     | planktoscope.stepper:__message_pump:200 - The pump has been interrupted
2023-09-02 08:07:09.804 | SUCCESS  | planktoscope.stepper:run:433 - The pump movement is over!
2023-09-02 08:07:10.893 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"move","direction":"FORWARD","volume":2,"flowrate":2}'
2023-09-02 08:07:10.896 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:10.898 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}}
2023-09-02 08:07:10.903 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:10.904 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:10.905 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:10.907 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:10.908 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:10.912 | DEBUG    | planktoscope.stepper:__message_pump:208 - We have received a move pump command
2023-09-02 08:07:10.914 | INFO     | planktoscope.stepper:__message_pump:237 - The pump is started.
2023-09-02 08:07:10.915 | INFO     | planktoscope.stepper:pump:371 - The pump will move FORWARD for 2.0mL at 2.0mL/min
2023-09-02 08:07:10.917 | DEBUG    | planktoscope.stepper:pump:381 - The number of microsteps that will be applied is 1047040.0
2023-09-02 08:07:10.919 | DEBUG    | planktoscope.stepper:pump:388 - There will be a speed of 17450.666666666668 steps per second
2023-09-02 08:07:10.920 | DEBUG    | planktoscope.stepper:speed:94 - Setting stepper speed to 17450
2023-09-02 08:07:14.827 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"stop"}'
2023-09-02 08:07:14.829 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'stop'}
2023-09-02 08:07:14.831 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'stop'}}
2023-09-02 08:07:14.834 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:14.838 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'stop'}
2023-09-02 08:07:14.841 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:14.844 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:14.851 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:14.858 | DEBUG    | planktoscope.stepper:__message_pump:196 - We have received a stop pump command
2023-09-02 08:07:14.955 | INFO     | planktoscope.stepper:__message_pump:200 - The pump has been interrupted
2023-09-02 08:07:14.959 | SUCCESS  | planktoscope.stepper:run:433 - The pump movement is over!
2023-09-02 08:07:21.294 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"move","direction":"FORWARD","volume":2,"flowrate":2}'
2023-09-02 08:07:21.296 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:21.298 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}}
2023-09-02 08:07:21.307 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:21.308 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:21.310 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:21.311 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:21.312 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:21.313 | DEBUG    | planktoscope.stepper:__message_pump:208 - We have received a move pump command
2023-09-02 08:07:21.315 | INFO     | planktoscope.stepper:__message_pump:237 - The pump is started.
2023-09-02 08:07:21.320 | INFO     | planktoscope.stepper:pump:371 - The pump will move FORWARD for 2.0mL at 2.0mL/min
2023-09-02 08:07:21.323 | DEBUG    | planktoscope.stepper:pump:381 - The number of microsteps that will be applied is 1047040.0
2023-09-02 08:07:21.324 | DEBUG    | planktoscope.stepper:pump:388 - There will be a speed of 17450.666666666668 steps per second
2023-09-02 08:07:21.326 | DEBUG    | planktoscope.stepper:speed:94 - Setting stepper speed to 17450
2023-09-02 08:07:36.315 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"stop"}'
2023-09-02 08:07:36.317 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'stop'}
2023-09-02 08:07:36.320 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'stop'}}
2023-09-02 08:07:36.333 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:36.334 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'stop'}
2023-09-02 08:07:36.335 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:36.336 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:36.337 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:36.338 | DEBUG    | planktoscope.stepper:__message_pump:196 - We have received a stop pump command
2023-09-02 08:07:36.435 | INFO     | planktoscope.stepper:__message_pump:200 - The pump has been interrupted
2023-09-02 08:07:36.441 | SUCCESS  | planktoscope.stepper:run:433 - The pump movement is over!
2023-09-02 08:07:43.196 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"move","direction":"FORWARD","volume":2,"flowrate":2}'
2023-09-02 08:07:43.202 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:43.204 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}}
2023-09-02 08:07:43.209 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:43.210 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:43.211 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:43.212 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:43.213 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:43.213 | DEBUG    | planktoscope.stepper:__message_pump:208 - We have received a move pump command
2023-09-02 08:07:43.214 | INFO     | planktoscope.stepper:__message_pump:237 - The pump is started.
2023-09-02 08:07:43.215 | INFO     | planktoscope.stepper:pump:371 - The pump will move FORWARD for 2.0mL at 2.0mL/min
2023-09-02 08:07:43.216 | DEBUG    | planktoscope.stepper:pump:381 - The number of microsteps that will be applied is 1047040.0
2023-09-02 08:07:43.217 | DEBUG    | planktoscope.stepper:pump:388 - There will be a speed of 17450.666666666668 steps per second
2023-09-02 08:07:43.218 | DEBUG    | planktoscope.stepper:speed:94 - Setting stepper speed to 17450
2023-09-02 08:07:44.256 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"stop"}'
2023-09-02 08:07:44.257 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'stop'}
2023-09-02 08:07:44.258 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'stop'}}
2023-09-02 08:07:44.265 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:44.266 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'stop'}
2023-09-02 08:07:44.271 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:44.275 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:44.277 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:44.278 | DEBUG    | planktoscope.stepper:__message_pump:196 - We have received a stop pump command
2023-09-02 08:07:44.382 | INFO     | planktoscope.stepper:__message_pump:200 - The pump has been interrupted
2023-09-02 08:07:44.384 | SUCCESS  | planktoscope.stepper:run:433 - The pump movement is over!
2023-09-02 08:07:45.291 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"move","direction":"BACKWARD","volume":2,"flowrate":2}'
2023-09-02 08:07:45.292 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'move', 'direction': 'BACKWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:45.293 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'move', 'direction': 'BACKWARD', 'volume': 2, 'flowrate': 2}}
2023-09-02 08:07:45.296 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:45.296 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'move', 'direction': 'BACKWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:45.298 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:45.304 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:45.307 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:45.309 | DEBUG    | planktoscope.stepper:__message_pump:208 - We have received a move pump command
2023-09-02 08:07:45.311 | INFO     | planktoscope.stepper:__message_pump:237 - The pump is started.
2023-09-02 08:07:45.312 | INFO     | planktoscope.stepper:pump:371 - The pump will move BACKWARD for 2.0mL at 2.0mL/min
2023-09-02 08:07:45.314 | DEBUG    | planktoscope.stepper:pump:381 - The number of microsteps that will be applied is 1047040.0
2023-09-02 08:07:45.316 | DEBUG    | planktoscope.stepper:pump:388 - There will be a speed of 17450.666666666668 steps per second
2023-09-02 08:07:45.317 | DEBUG    | planktoscope.stepper:speed:94 - Setting stepper speed to 17450
2023-09-02 08:07:45.941 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"stop"}'
2023-09-02 08:07:45.942 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'stop'}
2023-09-02 08:07:45.944 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'stop'}}
2023-09-02 08:07:45.952 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:45.953 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'stop'}
2023-09-02 08:07:45.954 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:45.956 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:45.957 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:45.959 | DEBUG    | planktoscope.stepper:__message_pump:196 - We have received a stop pump command
2023-09-02 08:07:46.063 | INFO     | planktoscope.stepper:__message_pump:200 - The pump has been interrupted
2023-09-02 08:07:46.070 | SUCCESS  | planktoscope.stepper:run:433 - The pump movement is over!
2023-09-02 08:07:47.325 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"move","direction":"FORWARD","volume":2,"flowrate":2}'
2023-09-02 08:07:47.326 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:47.327 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}}
2023-09-02 08:07:47.333 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:47.334 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:47.337 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:47.339 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:47.342 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:47.345 | DEBUG    | planktoscope.stepper:__message_pump:208 - We have received a move pump command
2023-09-02 08:07:47.347 | INFO     | planktoscope.stepper:__message_pump:237 - The pump is started.
2023-09-02 08:07:47.348 | INFO     | planktoscope.stepper:pump:371 - The pump will move FORWARD for 2.0mL at 2.0mL/min
2023-09-02 08:07:47.351 | DEBUG    | planktoscope.stepper:pump:381 - The number of microsteps that will be applied is 1047040.0
2023-09-02 08:07:47.352 | DEBUG    | planktoscope.stepper:pump:388 - There will be a speed of 17450.666666666668 steps per second
2023-09-02 08:07:47.357 | DEBUG    | planktoscope.stepper:speed:94 - Setting stepper speed to 17450
2023-09-02 08:07:47.690 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"stop"}'
2023-09-02 08:07:47.693 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'stop'}
2023-09-02 08:07:47.695 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'stop'}}
2023-09-02 08:07:47.697 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:47.699 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'stop'}
2023-09-02 08:07:47.701 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:47.703 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:47.705 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:47.706 | DEBUG    | planktoscope.stepper:__message_pump:196 - We have received a stop pump command
2023-09-02 08:07:47.805 | INFO     | planktoscope.stepper:__message_pump:200 - The pump has been interrupted
2023-09-02 08:07:47.807 | SUCCESS  | planktoscope.stepper:run:433 - The pump movement is over!
2023-09-02 08:07:50.208 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"move","direction":"FORWARD","volume":2,"flowrate":2}'
2023-09-02 08:07:50.209 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:50.211 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}}
2023-09-02 08:07:50.222 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:50.223 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'move', 'direction': 'FORWARD', 'volume': 2, 'flowrate': 2}
2023-09-02 08:07:50.224 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:50.225 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:50.226 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:50.230 | DEBUG    | planktoscope.stepper:__message_pump:208 - We have received a move pump command
2023-09-02 08:07:50.234 | INFO     | planktoscope.stepper:__message_pump:237 - The pump is started.
2023-09-02 08:07:50.236 | INFO     | planktoscope.stepper:pump:371 - The pump will move FORWARD for 2.0mL at 2.0mL/min
2023-09-02 08:07:50.237 | DEBUG    | planktoscope.stepper:pump:381 - The number of microsteps that will be applied is 1047040.0
2023-09-02 08:07:50.239 | DEBUG    | planktoscope.stepper:pump:388 - There will be a speed of 17450.666666666668 steps per second
2023-09-02 08:07:50.240 | DEBUG    | planktoscope.stepper:speed:94 - Setting stepper speed to 17450
2023-09-02 08:07:51.125 | INFO     | planktoscope.mqtt:on_message:132 - actuator_client: actuator/pump 0 b'{"action":"stop"}'
2023-09-02 08:07:51.126 | DEBUG    | planktoscope.mqtt:on_message:135 - args are {'action': 'stop'}
2023-09-02 08:07:51.128 | DEBUG    | planktoscope.mqtt:on_message:137 - msg is {'topic': 'actuator/pump', 'payload': {'action': 'stop'}}
2023-09-02 08:07:51.141 | INFO     | planktoscope.stepper:treat_command:285 - We received a new message
2023-09-02 08:07:51.143 | DEBUG    | planktoscope.stepper:treat_command:287 - {'action': 'stop'}
2023-09-02 08:07:51.144 | DEBUG    | planktoscope.stepper:treat_command:289 - pump
2023-09-02 08:07:51.145 | DEBUG    | planktoscope.mqtt:read_message:155 - clearing the __new_message flag
2023-09-02 08:07:51.146 | DEBUG    | planktoscope.stepper:__message_pump:194 - We have received a pumping command
2023-09-02 08:07:51.147 | DEBUG    | planktoscope.stepper:__message_pump:196 - We have received a stop pump command
2023-09-02 08:07:51.251 | INFO     | planktoscope.stepper:__message_pump:200 - The pump has been interrupted
2023-09-02 08:07:51.255 | SUCCESS  | planktoscope.stepper:run:433 - The pump movement is over!
2023-09-02 08:09:21.074 | INFO     | planktoscope.imager.streamer:do_GET:52 - Removed streaming client ('172.18.0.2', 44606)
2023-09-02 08:25:07.262 | INFO     | planktoscope.imager.streamer:do_GET:52 - Removed streaming client ('172.18.0.2', 35476)
ethanjli commented 10 months ago

This problem has also been encountered at least a two times by Savannah Mapes on the #3-start-testing channel of the PlanktoScope Slack. The first time, rebooting was an adequate workaround; the most recent time, rebooting did not make the error go away.

ethanjli commented 10 months ago

@fabienlombard added a comment in the 2023-11-02 meeting notes that he considers this a blocker for the release. Given the number of other people who've encountered this problem, I agree. We will need to delay the v2023.9.0 release until we figure out what's going on and how to fix it.

ethanjli commented 8 months ago

Because of the following reasons, I think it is better to release v2023.9.0 before we figure out how to solve this problem:

Thus, I will be removing this issue from the v2023.9.0 milestone.

ethanjli commented 8 months ago

We've seen several reports of this bug affecting users; it appears to occur non-deterministically but in some cases it can be very widespread (e.g. as in this report by @fabienlombard). The only time I was able to reproduce this bug in the past month, it was after leaving a Raspberry Pi on overnight. Usually my testing of the image acquisition feature happens relatively soon after booting up the Raspberry Pi, so my current hypothesis is that raspimjpeg might be failing with some probability/rate per unit time - so leaving it on for longer increases the change that it may fail. We could test this hypothesis by varying how long we keep the Raspberry Pi on after boot before starting image acquisition and then measuring the error rate. However, that still wouldn't really tell us how to fix the problem.

When the failure did occur for me, I tried killing a child process of the raspimjpeg process; raspimjpeg then restarted the child processes and lost the previous camera settings (e.g. exposure changed), but then it started responding again. So restarting raspimjpeg after each image acquisition is a potential workaround, but it's not easy because we'd need to also send all camera settings to it again.

The proper solution will be to replace raspimjpeg with picamera2 (#79).

ethanjli commented 7 months ago

In testing, @tpollina managed to reproduce this bug. I then tried to kill one of raspimjpeg's child processes, which caused raspimjpeg to restart itself, and afterwards raspimjpeg restored its ability to respond to camera control commands from the Python backend. This reproduces the behavior I observed in my previous comment, which strongly suggests that the source of the problem is in raspimjpeg itself.