Missed commands

[lstebel]

While launching the powerup script, three consecutive commands were missed.
Why?
Can this be fixed/checked somehow?
Which commands can be affected by this kind of error?

The malfunction was evident from the behavior of the system and was confirmed by the content of percival-trace.log... see the following:

INFO - Percival execution trace logging

POWERUP STARTED

INFO - PUT Command [cmd_download_channel_cfg] executed, parameters: {}
INFO - {'Username': 'percival', 'Source_ID': 'hl_download_channel_settings.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:54:49.775159'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'enable_global_monitoring'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:10.732483'}
INFO - PUT Command [cmd_load_config] executed, parameters: {'config_type': 'clock_settings', 'config': '{ too long to display }'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_configure_clock_settings.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:10.999264'}
INFO - PUT Command [cmd_load_config] executed, parameters: {'config_type': 'chip_readout_settings', 'config': '{ too long to display }'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_configure_chip_readout_settings.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:11.745649'}
INFO - PUT Command [cmd_load_config] executed, parameters: {'config_type': 'system_settings', 'config': '{ too long to display }'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_configure_system_settings.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:13.543193'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'disable_LVDS_IOs'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:14.777982'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'stop_acquisition'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:15.584020'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'exit_acquisition_armed_status'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:16.289530'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'fast_disable_control_standby'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:17.048807'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'disable_startup_mode'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:17.857280'}
INFO - PUT Command [cmd_initialise_channels] executed, parameters: {}
INFO - {'Username': 'percival', 'Source_ID': 'hl_initialise_channels.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:18.610447'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'fast_sensor_powerdown'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:20.384363'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'disable_safety_actions'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:21.149367'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'enable_device_level_safety_controls'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:21.925404'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'enable_system_level_safety_controls'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:22.751225'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': '{ too long to display }'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:23.488075'}
INFO - PUT Command [cmd_load_config] executed, parameters: {'config_type': 'control_groups', 'config': '{ too long to display }'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_configure_control_groups.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:24.388193'}
INFO - PUT Command [cmd_load_config] executed, parameters: {'config_type': 'monitor_groups', 'config': '{ too long to display }'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_configure_monitor_groups.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:25.355537'}
INFO - PUT Command [cmd_load_config] executed, parameters: {'config_type': 'setpoints', 'config': '{ too long to display }'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_configure_setpoints.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:25.707623'}
INFO - PUT Command [cmd_scan_setpoints] executed, parameters: {'dwell': '2000', 'setpoints': "['00_0_0V0A', '01_0_VDD_ON']", 'steps': '4'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_scan_setpoints.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:26.469205'}
INFO - PUT Command [cmd_scan_setpoints] executed, parameters: {'dwell': '2000', 'setpoints': "['01_0_VDD_ON', '02_0_LVDS_ON']", 'steps': '4'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_scan_setpoints.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:55:48.409979'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'enable_LVDS_IOs'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:56:07.305967'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'assert_sensor_Master_Reset'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:56:08.064862'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'deassert_sensor_Master_Reset'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_system_command.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:56:08.819264'}
INFO - PUT Command [cmd_scan_setpoints] executed, parameters: {'dwell': '2000', 'setpoints': '{ too long to display }', 'steps': '4'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_scan_setpoints.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:56:09.549426'}
INFO - PUT Command [cmd_scan_setpoints] executed, parameters: {'dwell': '2000', 'setpoints': '{ too long to display }', 'steps': '4'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_scan_setpoints.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:56:30.493902'}
INFO - PUT Command [cmd_scan_setpoints] executed, parameters: {'dwell': '2000', 'setpoints': '{ too long to display }', 'steps': '4'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_scan_setpoints.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:56:48.443059'}
INFO - PUT Command [cmd_scan_setpoints] executed, parameters: {'dwell': '2000', 'setpoints': '{ too long to display }', 'steps': '4'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_scan_setpoints.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:57:05.890085'}
INFO - PUT Command [cmd_scan_setpoints] executed, parameters: {'dwell': '2000', 'setpoints': '{ too long to display }', 'steps': '4'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_scan_setpoints.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:57:22.862467'}
INFO - PUT Command [cmd_scan_setpoints] executed, parameters: {'dwell': '2000', 'setpoints': '{ too long to display }', 'steps': '4'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_scan_setpoints.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:57:48.853954'}
INFO - PUT Command [cmd_load_config] executed, parameters: {'config_type': 'clock_settings', 'config': '{ too long to display }'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_configure_clock_settings.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:58:06.361968'}
INFO - PUT Command [cmd_load_config] executed, parameters: {'config_type': 'chip_readout_settings', 'config': '{ too long to display }'}
INFO - {'Username': 'percival', 'Source_ID': 'hl_configure_chip_readout_settings.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 11:58:07.119614'}

POWERUP ENDED BUT NOT COMPLETED
missing commands:
percival-hl-configure-system-settings -i ./ELETTRA/W3C8/config/03_System_Settings/SystemSettings_N06_pixel_Test_FEL_MODE.ini
percival-hl-apply-sensor-roi
percival-hl-system-command -c enter_acquisition_armed_status

Conversely, command
echo - Enter armed status
was regularly executed.

Then, I did the following:

INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'enter_acquisition_armed_status'}
INFO - {'Username': 'unknown', 'Source_ID': 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/49.0.2623.108 Chrome/49.0.2623.108 Safari/537.36', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 12:01:25.502391'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'start_acquisition'}
INFO - {'Username': 'unknown', 'Source_ID': 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/49.0.2623.108 Chrome/49.0.2623.108 Safari/537.36', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 12:04:23.007620'}

And I noticed that ROI had not been properly initialized. Consequently, I did the following:

INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'stop_acquisition'}
INFO - {'Username': 'unknown', 'Source_ID': 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/49.0.2623.108 Chrome/49.0.2623.108 Safari/537.36', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 12:05:23.381899'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'exit_acquisition_armed_status'}
INFO - {'Username': 'unknown', 'Source_ID': 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/49.0.2623.108 Chrome/49.0.2623.108 Safari/537.36', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 12:05:28.702994'}
INFO - PUT Command [cmd_apply_roi] executed, parameters: {}
INFO - {'Username': 'percival', 'Source_ID': 'hl_apply_sensor_roi.py', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 12:06:54.673241'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'enter_acquisition_armed_status'}
INFO - {'Username': 'unknown', 'Source_ID': 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/49.0.2623.108 Chrome/49.0.2623.108 Safari/537.36', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 12:07:35.311264'}
INFO - PUT Command [cmd_system_command] executed, parameters: {'name': 'start_acquisition'}
INFO - {'Username': 'unknown', 'Source_ID': 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/49.0.2623.108 Chrome/49.0.2623.108 Safari/537.36', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 12:07:49.533128'}

And I discovered that system setting hadn’t been loaded. So I did:

INFO - PUT Command [cmd_load_config] executed, parameters: {'config_type': 'system_settings', 'config': '{ too long to display }'}
INFO - {'Username': 'unknown', 'Source_ID': 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/49.0.2623.108 Chrome/49.0.2623.108 Safari/537.36', 'Source_Address': '127.0.0.1', 'Created': '2018-03-22 12:09:34.316424'}

**NOTE: in general, this shouldn’t be done while system is armed (by the way)

Then the system started to operate properly.**

[ajgdls]

@lstebel can you confirm the script did not receive a reply? Or was the command rejected (for example if the system thinks another command was still active)?

I have just had a quick look at the user_scripts and I notice that these are just shell scripts, you are not checking any return status from executed commands etc. I think you should be trying to monitor return status from commands and then you can print errors and abort if necessary.

[lstebel]

can you confirm the script did not receive a reply? Or was the command rejected (for example if the system thinks another command was still active)?

I have no idea of what happened. The only info available comes from the log.

I have just had a quick look at the user_scripts and I notice that these are just shell scripts, you are not checking any return status from executed commands etc. I think you should be trying to monitor return status from commands and then you can print errors and abort if necessary.

Remember you are not talking to a Python programmer of software engineer ;-)

[ajgdls]

OK I understand your point about not being a programmer :)
In general terms then, if you are running lots of commands one after the other then what happens if any of them fail for some reason. Currently you are setup to just keep running the next one and next one. Now, if the software application has legitimately failed that command for some reason (too much traffic or something else) then the fault is not with the software application as it has correctly rejected the commands.

We need to understand why those commands did not make it through, is this repeatable or did it just happen one single time?

[ajgdls]

Further testing and monitoring of this is required before any action can be taken.