2025-04-07T18:08:41.889Z,1744049321.889 [Supervisor](DEBUG): Initializing supervisor.
2025-04-07T18:08:41.893Z,1744049321.893 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-04-07T18:08:41.894Z,1744049321.894 [SyncHandler](INFO): Protected caller Thread ID is 2020
2025-04-07T18:08:41.894Z,1744049321.894 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-04-07T18:08:41.895Z,1744049321.895 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-04-07T18:08:41.895Z,1744049321.895 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2021
2025-04-07T18:08:41.899Z,1744049321.899 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-04-07T18:08:41.920Z,1744049321.920 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-04-07T18:08:41.921Z,1744049321.921 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-04-07T18:08:41.921Z,1744049321.921 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 2022
2025-04-07T18:08:41.926Z,1744049321.926 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-04-07T18:08:41.926Z,1744049321.926 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-04-07T18:08:41.927Z,1744049321.927 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2023
2025-04-07T18:08:41.929Z,1744049321.929 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-04-07T18:08:41.930Z,1744049321.930 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-04-07T18:08:41.930Z,1744049321.930 [logger ThreadHandler](INFO): Protected caller Thread ID is 2024
2025-04-07T18:08:41.934Z,1744049321.934 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-04-07T18:08:41.935Z,1744049321.935 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-04-07T18:08:41.936Z,1744049321.936 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-04-07T18:08:42.165Z,1744049322.165 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-04-07T18:08:42.165Z,1744049322.165 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-04-07T18:08:42.285Z,1744049322.285 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-04-07T18:08:42.285Z,1744049322.285 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-04-07T18:08:42.393Z,1744049322.393 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-04-07T18:08:42.394Z,1744049322.394 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-04-07T18:08:42.907Z,1744049322.907 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-04-07T18:08:42.908Z,1744049322.908 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-04-07T18:08:43.280Z,1744049323.280 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-04-07T18:08:43.280Z,1744049323.280 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-04-07T18:08:43.649Z,1744049323.649 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-04-07T18:08:43.649Z,1744049323.649 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-04-07T18:08:43.856Z,1744049323.856 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-04-07T18:08:43.856Z,1744049323.856 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-04-07T18:08:43.947Z,1744049323.947 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-04-07T18:08:44.040Z,1744049324.040 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-04-07T18:08:44.479Z,1744049324.479 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-04-07T18:08:44.479Z,1744049324.479 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-04-07T18:08:44.790Z,1744049324.790 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-04-07T18:08:44.791Z,1744049324.791 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-04-07T18:08:45.383Z,1744049325.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-04-07T18:08:45.384Z,1744049325.384 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-04-07T18:08:45.873Z,1744049325.874 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-04-07T18:08:45.874Z,1744049325.874 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-04-07T18:08:46.225Z,1744049326.225 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-04-07T18:08:46.225Z,1744049326.225 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-04-07T18:08:46.379Z,1744049326.379 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-04-07T18:08:46.379Z,1744049326.379 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-04-07T18:08:47.288Z,1744049327.288 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-04-07T18:08:47.290Z,1744049327.290 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2025-04-07T18:08:47.291Z,1744049327.291 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2025-04-07T18:08:47.388Z,1744049327.388 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2025-04-07T18:08:47.533Z,1744049327.533 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2025-04-07T18:08:47.817Z,1744049327.817 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-04-07T18:08:47.818Z,1744049327.818 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2025-04-07T18:08:47.955Z,1744049327.955 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2025-04-07T18:08:48.065Z,1744049328.065 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2025-04-07T18:08:48.171Z,1744049328.171 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2025-04-07T18:08:48.292Z,1744049328.292 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2025-04-07T18:08:48.388Z,1744049328.388 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2025-04-07T18:08:48.486Z,1744049328.486 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2025-04-07T18:08:48.589Z,1744049328.589 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2025-04-07T18:08:48.773Z,1744049328.773 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-04-07T18:08:48.784Z,1744049328.784 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-04-07T18:08:48.837Z,1744049328.837 [DepthRateCalculator] Loaded
2025-04-07T18:08:48.838Z,1744049328.838 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-04-07T18:08:48.843Z,1744049328.843 [PitchRateCalculator] Loaded
2025-04-07T18:08:48.843Z,1744049328.843 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-04-07T18:08:48.854Z,1744049328.854 [SpeedCalculator] Loaded
2025-04-07T18:08:48.855Z,1744049328.855 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-04-07T18:08:48.860Z,1744049328.860 [YawRateCalculator] Loaded
2025-04-07T18:08:48.860Z,1744049328.860 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-04-07T18:08:48.882Z,1744049328.882 [ElevatorOffsetCalculator] Loaded
2025-04-07T18:08:48.882Z,1744049328.882 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-04-07T18:08:48.883Z,1744049328.883 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-04-07T18:08:48.883Z,1744049328.883 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-04-07T18:08:48.912Z,1744049328.912 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-04-07T18:08:48.913Z,1744049328.913 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-04-07T18:08:48.924Z,1744049328.924 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-04-07T18:08:48.924Z,1744049328.924 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-04-07T18:08:49.455Z,1744049329.455 [AHRS_M2] Loaded
2025-04-07T18:08:49.455Z,1744049329.455 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-04-07T18:08:49.493Z,1744049329.493 [BackseatComponent] Loaded
2025-04-07T18:08:49.494Z,1744049329.494 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-04-07T18:08:49.495Z,1744049329.495 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408754E0
2025-04-07T18:08:49.495Z,1744049329.495 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 2106
2025-04-07T18:08:49.498Z,1744049329.498 [LcmUniversalReporter] Loaded
2025-04-07T18:08:49.498Z,1744049329.498 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-04-07T18:08:50.293Z,1744049330.293 [BPC1] Loaded
2025-04-07T18:08:50.293Z,1744049330.293 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-04-07T18:08:50.389Z,1744049330.389 [DAT] Loaded
2025-04-07T18:08:50.390Z,1744049330.390 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-04-07T18:08:50.391Z,1744049330.391 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408A54E0
2025-04-07T18:08:50.391Z,1744049330.391 [DAT ThreadHandler](INFO): Protected caller Thread ID is 2107
2025-04-07T18:08:50.466Z,1744049330.466 [DataOverHttps] Loaded
2025-04-07T18:08:50.466Z,1744049330.466 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-04-07T18:08:50.467Z,1744049330.467 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408D54E0
2025-04-07T18:08:50.467Z,1744049330.467 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2108
2025-04-07T18:08:50.490Z,1744049330.490 [Depth_Keller] Loaded
2025-04-07T18:08:50.490Z,1744049330.490 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-04-07T18:08:50.495Z,1744049330.495 [DropWeight] Loaded
2025-04-07T18:08:50.496Z,1744049330.496 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-04-07T18:08:50.517Z,1744049330.517 [MultiRay](INFO): Found secondary power supply at: /dev/loadC7
2025-04-07T18:08:50.517Z,1744049330.517 [MultiRay] Loaded
2025-04-07T18:08:50.517Z,1744049330.517 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread.
2025-04-07T18:08:50.581Z,1744049330.581 [NAL9602] Loaded
2025-04-07T18:08:50.582Z,1744049330.582 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-04-07T18:08:50.611Z,1744049330.611 [Onboard] Loaded
2025-04-07T18:08:50.611Z,1744049330.611 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-04-07T18:08:50.612Z,1744049330.612 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409054E0
2025-04-07T18:08:50.613Z,1744049330.613 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2109
2025-04-07T18:08:50.619Z,1744049330.619 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3
2025-04-07T18:08:50.632Z,1744049330.632 [PowerOnly] Loaded
2025-04-07T18:08:50.632Z,1744049330.632 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2025-04-07T18:08:50.646Z,1744049330.646 [Power24vConverter] Loaded
2025-04-07T18:08:50.646Z,1744049330.646 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-04-07T18:08:50.663Z,1744049330.663 [Radio_Surface] Loaded
2025-04-07T18:08:50.664Z,1744049330.664 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-04-07T18:08:50.665Z,1744049330.665 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409354E0
2025-04-07T18:08:50.665Z,1744049330.665 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2110
2025-04-07T18:08:50.666Z,1744049330.666 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-04-07T18:08:50.667Z,1744049330.667 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-04-07T18:08:51.151Z,1744049331.151 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-04-07T18:08:51.151Z,1744049331.151 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-04-07T18:08:51.184Z,1744049331.184 [NavChart] Loaded
2025-04-07T18:08:51.184Z,1744049331.184 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-04-07T18:08:51.244Z,1744049331.244 [UniversalFixResidualReporter] Loaded
2025-04-07T18:08:51.245Z,1744049331.245 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-04-07T18:08:51.245Z,1744049331.245 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-04-07T18:08:51.246Z,1744049331.246 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-04-07T18:08:51.577Z,1744049331.577 [SBIT](DEBUG): Construct Startup Built In Test.
2025-04-07T18:08:51.592Z,1744049331.592 [SBIT] Loaded
2025-04-07T18:08:51.592Z,1744049331.592 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-04-07T18:08:51.595Z,1744049331.595 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-04-07T18:08:51.608Z,1744049331.608 [IBIT] Loaded
2025-04-07T18:08:51.608Z,1744049331.608 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-04-07T18:08:51.614Z,1744049331.614 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-04-07T18:08:51.694Z,1744049331.694 [CBIT] Loaded
2025-04-07T18:08:51.694Z,1744049331.694 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-04-07T18:08:51.726Z,1744049331.726 [GFScanner] Loaded
2025-04-07T18:08:51.726Z,1744049331.726 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-04-07T18:08:51.726Z,1744049331.726 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-04-07T18:08:51.727Z,1744049331.727 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-04-07T18:08:51.897Z,1744049331.897 [CTD_Seabird] Loaded
2025-04-07T18:08:51.897Z,1744049331.897 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-04-07T18:08:51.898Z,1744049331.898 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A474E0
2025-04-07T18:08:51.899Z,1744049331.899 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2111
2025-04-07T18:08:51.922Z,1744049331.922 [PAR_Licor] Loaded
2025-04-07T18:08:51.922Z,1744049331.922 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-04-07T18:08:51.968Z,1744049331.968 [WetLabsBB2FL] Loaded
2025-04-07T18:08:51.968Z,1744049331.968 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-04-07T18:08:51.969Z,1744049331.969 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A774E0
2025-04-07T18:08:51.970Z,1744049331.970 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2112
2025-04-07T18:08:51.971Z,1744049331.971 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-04-07T18:08:51.971Z,1744049331.971 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-04-07T18:08:52.112Z,1744049332.112 [BuoyancyServo] Loaded
2025-04-07T18:08:52.112Z,1744049332.112 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-04-07T18:08:52.136Z,1744049332.136 [ElevatorServo] Loaded
2025-04-07T18:08:52.136Z,1744049332.136 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-04-07T18:08:52.160Z,1744049332.160 [MassServo] Loaded
2025-04-07T18:08:52.160Z,1744049332.160 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-04-07T18:08:52.183Z,1744049332.183 [RudderServo] Loaded
2025-04-07T18:08:52.183Z,1744049332.183 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-04-07T18:08:52.201Z,1744049332.201 [ThrusterHE] Loaded
2025-04-07T18:08:52.201Z,1744049332.201 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-04-07T18:08:52.202Z,1744049332.202 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-04-07T18:08:52.202Z,1744049332.202 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-04-07T18:08:52.258Z,1744049332.258 [VerticalControl](DEBUG): Construct VerticalControl.
2025-04-07T18:08:52.311Z,1744049332.311 [VerticalControl] Loaded
2025-04-07T18:08:52.311Z,1744049332.311 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-04-07T18:08:52.314Z,1744049332.314 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-04-07T18:08:52.358Z,1744049332.358 [HorizontalControl] Loaded
2025-04-07T18:08:52.359Z,1744049332.359 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-04-07T18:08:52.361Z,1744049332.361 [SpeedControl](DEBUG): Construct SpeedControl.
2025-04-07T18:08:52.363Z,1744049332.363 [SpeedControl] Loaded
2025-04-07T18:08:52.363Z,1744049332.363 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-04-07T18:08:52.366Z,1744049332.366 [LoopControl](DEBUG): Construct LoopControl.
2025-04-07T18:08:52.367Z,1744049332.367 [LoopControl] Loaded
2025-04-07T18:08:52.367Z,1744049332.367 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-04-07T18:08:52.367Z,1744049332.367 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-04-07T18:08:52.368Z,1744049332.368 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-04-07T18:08:52.504Z,1744049332.504 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-04-07T18:08:52.505Z,1744049332.505 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-04-07T18:08:52.686Z,1744049332.686 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-04-07T18:08:52.686Z,1744049332.686 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-04-07T18:08:53.046Z,1744049333.046 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-04-07T18:08:53.047Z,1744049333.047 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-04-07T18:08:53.107Z,1744049333.107 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-04-07T18:08:53.113Z,1744049333.113 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-04-07T18:08:53.116Z,1744049333.116 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-04-07T18:08:53.128Z,1744049333.128 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-04-07T18:08:53.129Z,1744049333.129 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C654E0
2025-04-07T18:08:53.129Z,1744049333.129 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2113
2025-04-07T18:08:53.134Z,1744049333.134 [Supervisor](INFO): Main Thread ID is 830
2025-04-07T18:08:53.134Z,1744049333.134 [Supervisor](DEBUG): Running supervisor.
2025-04-07T18:08:53.134Z,1744049333.134 [CommandExec ThreadHandler](INFO): Handler Thread ID is 2114
2025-04-07T18:08:53.135Z,1744049333.135 [CommandExec](INFO): Initializing the command executive.
2025-04-07T18:08:53.136Z,1744049333.136 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2115
2025-04-07T18:08:53.139Z,1744049333.139 [controlThread ThreadHandler](INFO): Handler Thread ID is 2116
2025-04-07T18:08:53.139Z,1744049333.139 [controlThread](DEBUG): Initializing ControlThread
2025-04-07T18:08:53.140Z,1744049333.140 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-04-07T18:08:53.140Z,1744049333.140 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-04-07T18:08:53.140Z,1744049333.140 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-04-07T18:08:53.141Z,1744049333.141 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-04-07T18:08:53.141Z,1744049333.141 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-04-07T18:08:53.146Z,1744049333.146 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-04-07T18:08:53.146Z,1744049333.146 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-04-07T18:08:53.146Z,1744049333.146 [SBIT](INFO): Initialize SBIT Component.
2025-04-07T18:08:53.147Z,1744049333.147 [SBIT](IMPORTANT): git: 2025-04-02-2-g1635786d1
2025-04-07T18:08:53.147Z,1744049333.147 [SBIT](INFO): git hash: 1635786d188a1b3aba7073e6184020eb8609012e
2025-04-07T18:08:53.147Z,1744049333.147 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-04-07T18:08:53.148Z,1744049333.148 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2025-04-07T18:08:53.150Z,1744049333.150 [SBIT](INFO): Beginning SBIT in 61.000000 seconds.
2025-04-07T18:08:53.150Z,1744049333.150 [IBIT](INFO): Initialize IBIT Component.
2025-04-07T18:08:53.151Z,1744049333.151 [CBIT](DEBUG): Initialize CBIT Component.
2025-04-07T18:08:53.152Z,1744049333.152 [logger ThreadHandler](INFO): Handler Thread ID is 2117
2025-04-07T18:08:53.165Z,1744049333.165 [CBIT](DEBUG): Initialized mux pins.
2025-04-07T18:08:53.165Z,1744049333.165 [CBIT](DEBUG): Initializing the watchdog timer.
2025-04-07T18:08:53.177Z,1744049333.177 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 2118
2025-04-07T18:08:53.189Z,1744049333.189 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-04-07T18:08:53.189Z,1744049333.189 [CBIT](DEBUG): Initializing heartbeat.
2025-04-07T18:08:53.190Z,1744049333.190 [DAT ThreadHandler](INFO): Handler Thread ID is 2119
2025-04-07T18:08:53.191Z,1744049333.191 [DAT](INFO): Powering up
2025-04-07T18:08:53.191Z,1744049333.191 [DAT](DEBUG): Initializing DAT.
2025-04-07T18:08:53.194Z,1744049333.194 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2121
2025-04-07T18:08:53.196Z,1744049333.196 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-04-07T18:08:53.217Z,1744049333.217 [Onboard ThreadHandler](INFO): Handler Thread ID is 2122
2025-04-07T18:08:53.235Z,1744049333.235 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2123
2025-04-07T18:08:53.255Z,1744049333.255 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2124
2025-04-07T18:08:53.255Z,1744049333.255 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-04-07T18:08:53.261Z,1744049333.261 [CBIT](DEBUG): Deactivating emergency mode.
2025-04-07T18:08:53.263Z,1744049333.263 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2126
2025-04-07T18:08:53.265Z,1744049333.265 [WetLabsBB2FL](INFO): Powering up
2025-04-07T18:08:53.267Z,1744049333.267 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2128
2025-04-07T18:08:53.269Z,1744049333.269 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-04-07T18:08:53.269Z,1744049333.269 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-04-07T18:08:53.269Z,1744049333.269 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-04-07T18:08:53.270Z,1744049333.270 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-04-07T18:08:53.270Z,1744049333.270 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-04-07T18:08:53.270Z,1744049333.270 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-04-07T18:08:53.270Z,1744049333.270 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-04-07T18:08:53.270Z,1744049333.270 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-04-07T18:08:53.301Z,1744049333.301 [CBIT](DEBUG): Backplane powered.
2025-04-07T18:08:53.301Z,1744049333.301 [GFScanner](DEBUG): Initializing GFScanner
2025-04-07T18:08:53.301Z,1744049333.301 [GFScanner](DEBUG): Deactivating GF circuits.
2025-04-07T18:08:53.310Z,1744049333.310 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-04-07T18:08:53.312Z,1744049333.312 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-04-07T18:08:53.313Z,1744049333.313 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-04-07T18:08:53.314Z,1744049333.314 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-04-07T18:08:53.314Z,1744049333.314 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-04-07T18:08:53.315Z,1744049333.315 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-04-07T18:08:53.315Z,1744049333.315 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-04-07T18:08:53.316Z,1744049333.316 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-04-07T18:08:53.371Z,1744049333.371 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-04-07T18:08:53.376Z,1744049333.376 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-04-07T18:08:53.400Z,1744049333.400 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Startup {
behavior Guidance:GoToSurface {
run in progression
}
aggregate StartupSatComms {
run in sequence
readDatum {
timeout duration=P1M
Universal:latitude_fix
}
readDatum {
timeout duration=P1M
Universal:platform_communications
}
}
}
2025-04-07T18:08:53.401Z,1744049333.401 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-04-07T18:08:53.401Z,1744049333.401 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-04-07T18:08:53.402Z,1744049333.402 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-04-07T18:08:53.607Z,1744049333.607 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
0
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2025-04-07T18:08:53.625Z,1744049333.625 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-04-07T18:08:53.627Z,1744049333.627 [Default:A.Wait](DEBUG): Construct Wait.
2025-04-07T18:08:53.629Z,1744049333.629 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-04-07T18:08:53.641Z,1744049333.641 [Radio_Surface](INFO): Powering up
2025-04-07T18:08:53.666Z,1744049333.666 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-04-07T18:08:53.668Z,1744049333.668 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-04-07T18:08:53.674Z,1744049333.674 [Default:E.Execute](DEBUG): Construct Execute.
2025-04-07T18:08:53.689Z,1744049333.689 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Default {
arguments {
ElapsedSinceDefaultStarted = 0 minute
}
behavior Guidance:Wait {
"""
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
"""
run in sequence
set duration = 13 second
}
behavior Guidance:GoToSurface {
run in progression
}
aggregate CheckIn {
run in sequence repeat=288
readDatum id="Read_GPS" {
timeout duration=P5M
Universal:time_fix
}
readDatum id="Read_Iridium" {
timeout duration=P4H {
behavior Guidance:Execute {
run in sequence
set command = "Burn on"
}
syslog critical "Dropped weight due to communications timeout."
}
Universal:platform_communications
}
behavior Guidance:Wait {
run in sequence
set duration = 5 minute
}
assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started )
syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute
}
syslog important "Restarting logs and Default mission."
behavior Guidance:Execute {
run in sequence
set command = "restart logs"
}
}
2025-04-07T18:08:53.695Z,1744049333.695 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,PowerOnly,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-04-07T18:08:53.703Z,1744049333.703 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-04-07T18:08:53.758Z,1744049333.758 [Depth_Keller](INFO): Initializing.
2025-04-07T18:08:53.759Z,1744049333.759 [MultiRay](INFO): Powering up MultiRay Lights
2025-04-07T18:08:53.759Z,1744049333.759 [MultiRay](INFO): Powering up secondary power supply.
2025-04-07T18:08:53.794Z,1744049333.794 [Power24vConverter](INFO): Powering up.
2025-04-07T18:08:53.802Z,1744049333.802 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-04-07T18:08:53.820Z,1744049333.820 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-04-07T18:08:53.821Z,1744049333.821 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-04-07T18:08:53.822Z,1744049333.822 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-04-07T18:08:53.829Z,1744049333.829 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-04-07T18:08:53.830Z,1744049333.830 [MassServo](DEBUG): Initializing EZServoServo.
2025-04-07T18:08:53.841Z,1744049333.841 [MassServo](DEBUG): Initializing MassServo.
2025-04-07T18:08:53.842Z,1744049333.842 [RudderServo](DEBUG): Initializing EZServoServo.
2025-04-07T18:08:53.849Z,1744049333.849 [RudderServo](DEBUG): Initializing RudderServo.
2025-04-07T18:08:53.850Z,1744049333.850 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-04-07T18:08:53.857Z,1744049333.857 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-04-07T18:08:54.914Z,1744049334.914 [MultiRay](INFO): Powering down
2025-04-07T18:08:55.033Z,1744049335.033 [MultiRay](INFO): Powering down LCB2
2025-04-07T18:08:55.877Z,1744049335.877 [WetLabsBB2FL](INFO): Powering down
2025-04-07T18:09:00.285Z,1744049340.285 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2025-04-07T18:09:04.782Z,1744049344.782 [DAT](INFO): DAT read:
2025-04-07T18:09:04.784Z,1744049344.784 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-04-07T18:09:06.294Z,1744049346.294 [DAT](INFO): DAT read: MF Frequency Band
2025-04-07T18:09:06.295Z,1744049346.295 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-04-07T18:09:06.296Z,1744049346.296 [DAT](INFO): DAT read: Apr 7 2025 18:09:01
2025-04-07T18:09:07.302Z,1744049347.302 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-04-07T18:09:07.303Z,1744049347.303 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2025-04-07T18:09:07.304Z,1744049347.304 [DAT](INFO): commRate: 800
2025-04-07T18:09:09.370Z,1744049349.370 [DAT](INFO): entering command mode
2025-04-07T18:09:09.569Z,1744049349.569 [DAT](INFO): DAT read:
2025-04-07T18:09:09.570Z,1744049349.570 [DAT](INFO): DAT read: user:1>
2025-04-07T18:09:09.570Z,1744049349.570 [DAT](INFO): setting verbose to 3
2025-04-07T18:09:09.822Z,1744049349.822 [DAT](INFO): DAT read: user:1>
2025-04-07T18:09:09.823Z,1744049349.823 [DAT](INFO): DAT read: Verbose | 3
2025-04-07T18:09:09.823Z,1744049349.823 [DAT](INFO): set verbose to 3
2025-04-07T18:09:09.823Z,1744049349.823 [DAT](INFO): setting DatVerbose to 27440
2025-04-07T18:09:10.074Z,1744049350.074 [DAT](INFO): DAT read: user:2>
2025-04-07T18:09:10.075Z,1744049350.075 [DAT](INFO): DAT read: DatVerbose | 27440
2025-04-07T18:09:10.075Z,1744049350.075 [DAT](INFO): set DatVerbose to 27440
2025-04-07T18:09:10.075Z,1744049350.075 [DAT](INFO): setting transmit power to 8
2025-04-07T18:09:10.326Z,1744049350.326 [DAT](INFO): DAT read: user:3>
2025-04-07T18:09:10.327Z,1744049350.327 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-04-07T18:09:10.327Z,1744049350.327 [DAT](INFO): set transmit power to 8
2025-04-07T18:09:10.327Z,1744049350.327 [DAT](INFO): setting local address to 9
2025-04-07T18:09:10.578Z,1744049350.578 [DAT](INFO): DAT read: user:4>
2025-04-07T18:09:10.579Z,1744049350.579 [DAT](INFO): DAT read: LocalAddr | 9
2025-04-07T18:09:10.579Z,1744049350.579 [DAT](INFO): set local address to 9
2025-04-07T18:09:10.580Z,1744049350.580 [DAT](INFO): Setting time to: 18:9:10 And date to:4/7/2025
2025-04-07T18:09:10.830Z,1744049350.830 [DAT](INFO): DAT read: user:5>
2025-04-07T18:09:10.831Z,1744049350.831 [DAT](INFO): DAT read: Mon Apr 7, 2025 18:09:10
2025-04-07T18:09:10.831Z,1744049350.831 [DAT](INFO): Local DAT time set to Mon Apr 7, 2025 18:09:10
2025-04-07T18:09:20.919Z,1744049360.919 [NAL9602](INFO): Powering up NAL9602
2025-04-07T18:09:31.834Z,1744049371.834 [NAL9602](INFO): NAL9602 initialized
2025-04-07T18:09:54.896Z,1744049394.896 [SBIT](IMPORTANT): Beginning Startup BIT
2025-04-07T18:09:54.901Z,1744049394.901 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-07T18:09:59.498Z,1744049399.498 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006884
CHAN A1 (24V): 0.001231
CHAN A2 (12V): -0.005376
CHAN A3 (5V): -0.002490
CHAN B0 (3.3V): -0.001557
CHAN B1 (3.15aV): -0.001244
CHAN B2 (3.15bV): -0.000961
CHAN B3 (GND): -0.000233
OPEN: 0.005153
Full Scale: +/- 1 mA
2025-04-07T18:10:48.256Z,1744049448.256 [SBIT](IMPORTANT): SBIT PASSED
2025-04-07T18:10:48.256Z,1744049448.256 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-04-07T18:10:48.257Z,1744049448.257 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter;
2025-04-07T18:10:48.257Z,1744049448.257 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter;
2025-04-07T18:10:48.257Z,1744049448.257 [SBIT](IMPORTANT): GFScanner.loadAtStartup=1 bool;
2025-04-07T18:10:48.257Z,1744049448.257 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool;
2025-04-07T18:10:48.258Z,1744049448.258 [SBIT](IMPORTANT): MultiRay.brightnessWhite=100 none;
2025-04-07T18:10:48.258Z,1744049448.258 [SBIT](IMPORTANT): MultiRay.loadAtStartup=1 bool;
2025-04-07T18:10:48.258Z,1744049448.258 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=1 bool;
2025-04-07T18:10:48.258Z,1744049448.258 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=0 bool;
2025-04-07T18:10:48.258Z,1744049448.258 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=241.314617 cubic_centimeter;
2025-04-07T18:10:48.258Z,1744049448.258 [SBIT](IMPORTANT): VerticalControl.massDefault=10.352381 millimeter;
2025-04-07T18:10:48.258Z,1744049448.258 [SBIT](IMPORTANT): Waterlinked.loadAtStartup=0 bool;
2025-04-07T18:10:48.646Z,1744049448.646 [MissionManager](IMPORTANT): Started mission Startup
2025-04-07T18:10:48.646Z,1744049448.646 [Startup] Running Loop=1
2025-04-07T18:10:48.646Z,1744049448.646 [Startup](DEBUG): Aggregate::initialize Startup
2025-04-07T18:10:48.646Z,1744049448.646 [Startup:A.GoToSurface] Running Loop=1
2025-04-07T18:10:48.646Z,1744049448.646 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T18:10:48.647Z,1744049448.647 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T18:10:48.647Z,1744049448.647 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T18:10:48.648Z,1744049448.648 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T18:10:48.648Z,1744049448.648 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T18:10:48.648Z,1744049448.648 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T18:10:48.649Z,1744049448.649 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T18:10:48.651Z,1744049448.651 [Startup:StartupSatComms] Running Loop=1
2025-04-07T18:10:48.652Z,1744049448.652 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-04-07T18:10:48.652Z,1744049448.652 [Startup:StartupSatComms:A] Running Loop=1
2025-04-07T18:10:49.036Z,1744049449.036 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-04-07T18:11:48.851Z,1744049508.851 [Startup:StartupSatComms:A](INFO): Timed out from 2025-04-07T18:10:48.7Z
2025-04-07T18:11:48.851Z,1744049508.851 [Startup:StartupSatComms:A] Stopped
2025-04-07T18:11:48.851Z,1744049508.851 [Startup:StartupSatComms:B] Running Loop=1
2025-04-07T18:11:49.231Z,1744049509.231 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-04-07T18:11:53.266Z,1744049513.266 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-04-07T18:11:53.266Z,1744049513.266 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T18:11:53.277Z,1744049513.277 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T18:11:53.691Z,1744049513.691 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T18:11:53.691Z,1744049513.691 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-04-07T18:12:17.692Z,1744049537.692 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005000
2025-04-07T18:12:17.883Z,1744049537.883 [CommandExec](IMPORTANT): got command show stack
2025-04-07T18:12:17.883Z,1744049537.883 [CommandExec](IMPORTANT): Behavior Stack:
2025-04-07T18:12:17.883Z,1744049537.883 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2025-04-07T18:12:17.883Z,1744049537.883 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B
2025-04-07T18:12:25.645Z,1744049545.645 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250407T175457/Courier0004.lzma
2025-04-07T18:12:26.647Z,1744049546.647 [DataOverHttps](INFO): Moved sent file to Logs/20250407T175457/Courier0004.lzma.bak
2025-04-07T18:12:26.647Z,1744049546.647 [DataOverHttps](INFO): SBD MOMSN=24562411
2025-04-07T18:12:34.837Z,1744049554.837 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1744049546 second
2025-04-07T18:12:42.661Z,1744049562.661 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250407T175457/Courier0007.lzma
2025-04-07T18:12:43.663Z,1744049563.663 [DataOverHttps](INFO): Moved sent file to Logs/20250407T175457/Courier0007.lzma.bak
2025-04-07T18:12:43.663Z,1744049563.663 [DataOverHttps](INFO): SBD MOMSN=24562413
2025-04-07T18:12:49.040Z,1744049569.040 [Startup:StartupSatComms:B](INFO): Timed out from 2025-04-07T18:11:48.9Z
2025-04-07T18:12:49.040Z,1744049569.040 [Startup:StartupSatComms:B] Stopped
2025-04-07T18:12:49.040Z,1744049569.040 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-04-07T18:12:49.040Z,1744049569.040 [Startup:StartupSatComms] Stopped
2025-04-07T18:12:49.040Z,1744049569.040 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-04-07T18:12:49.045Z,1744049569.045 [Startup](INFO): Completed Startup
2025-04-07T18:12:49.045Z,1744049569.045 [MissionManager](INFO): Startup is completed.
2025-04-07T18:12:49.046Z,1744049569.046 [MissionManager](INFO): Uninitializing Mission Startup
2025-04-07T18:12:49.046Z,1744049569.046 [Startup] Stopped
2025-04-07T18:12:49.046Z,1744049569.046 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-04-07T18:12:49.046Z,1744049569.046 [Startup:A.GoToSurface] Stopped
2025-04-07T18:12:49.046Z,1744049569.046 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T18:12:49.451Z,1744049569.451 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T18:12:49.451Z,1744049569.451 [Default] Running Loop=1
2025-04-07T18:12:49.451Z,1744049569.451 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T18:12:49.452Z,1744049569.452 [Default:B.GoToSurface] Running Loop=1
2025-04-07T18:12:49.452Z,1744049569.452 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T18:12:49.452Z,1744049569.452 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T18:12:49.452Z,1744049569.452 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T18:12:49.452Z,1744049569.452 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T18:12:49.457Z,1744049569.457 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T18:12:49.457Z,1744049569.457 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T18:12:49.458Z,1744049569.458 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T18:12:49.458Z,1744049569.458 [Default:A.Wait] Running Loop=1
2025-04-07T18:12:49.458Z,1744049569.458 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:12:52.110Z,1744049572.110 [DataOverHttps](IMPORTANT): SBD MTMSN=20250407T181251
2025-04-07T18:12:59.606Z,1744049579.606 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250407T175457/Courier0010.lzma
2025-04-07T18:12:59.609Z,1744049579.609 [DataOverHttps](INFO): Received command: run Engineering/lab_test_optim.tl
2025-04-07T18:12:59.700Z,1744049579.700 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:12:59.700Z,1744049579.700 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:12:59.700Z,1744049579.700 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:12:59.714Z,1744049579.714 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:13:00.016Z,1744049580.016 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
15
1
30
2
100
100
Waiting
for backseat to start up...
Trying to run Optim and Multiray forreal
1
Setting multiray red brightness to
2
Setting muliray white brightness to
Recording for
2025-04-07T18:13:00.027Z,1744049580.027 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-04-07T18:13:00.030Z,1744049580.030 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-04-07T18:13:00.033Z,1744049580.033 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-04-07T18:13:00.036Z,1744049580.036 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-04-07T18:13:00.039Z,1744049580.039 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-04-07T18:13:00.042Z,1744049580.042 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-04-07T18:13:00.045Z,1744049580.045 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-04-07T18:13:00.048Z,1744049580.048 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-04-07T18:13:00.048Z,1744049580.048 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-04-07T18:13:00.048Z,1744049580.048 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-04-07T18:13:00.050Z,1744049580.050 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-04-07T18:13:00.068Z,1744049580.068 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-04-07T18:13:00.097Z,1744049580.097 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-04-07T18:13:00.112Z,1744049580.112 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-04-07T18:13:00.152Z,1744049580.152 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-04-07T18:13:00.203Z,1744049580.203 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-04-07T18:13:00.204Z,1744049580.204 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-04-07T18:13:00.230Z,1744049580.230 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission lab_test_optim {
arguments {
MissionTimeout = 15 minute
"""
Backseat will stay on for this duration, independent of Optim state
"""
RecordTime = 1 minute
"""
How long to record after startup sequence (hopefully) turns on Optim camera
"""
BackseatWait = 30 second
"""
How long to wait for the backseat to power up before attempting to power the Optim
"""
LightMode = 2 count
"""
Mode for Multiray lights. 0 is off, 1 is red, 2 is white
"""
BrightnessWhite = 100 none_int
"""
White Multiray LED brightness, 0-100
"""
BrightnessRed = 100 none_int
"""
Red Multiray LED brightness, 0-100
"""
}
output {
RecordingEnabled = false
LightsEnabled = false
}
timeout duration=MissionTimeout
insert Insert/BackseatDriver.tl
assign in parallel BackseatDriver:EnableBackseat = true
readData strategy="MinError" {
while ( RecordingEnabled )
Sensor:PowerOnly.sampleLoad1
}
readData strategy="MinError" {
while ( LightsEnabled )
Sensor:MultiRay.lightModeLog
}
aggregate Startup {
run in sequence
syslog important "Waiting " + BackseatWait~s + " for backseat to start up..."
behavior Guidance:Wait {
run in sequence
set duration = BackseatWait
}
}
aggregate Run {
run in sequence
syslog important "Trying to run Optim and Multiray forreal"
assign in sequence RecordingEnabled = true
assign in sequence LightsEnabled = true
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode
aggregate setRed {
run in sequence
break if ( LightMode != 1 count )
assign in sequence Sensor:MultiRay.brightnessRed = BrightnessRed
syslog info "Setting multiray red brightness to" + BrightnessRed~count
}
aggregate setWhite {
run in sequence
break if ( LightMode != 2 count )
assign in sequence Sensor:MultiRay.brightnessWhite = BrightnessWhite
syslog info "Setting muliray white brightness to" + BrightnessWhite~count
}
syslog important "Recording for " + RecordTime~min
behavior Guidance:Wait {
run in sequence
set duration = RecordTime
}
}
behavior Guidance:Wait {
run in sequence
set duration = MissionTimeout
}
}
2025-04-07T18:13:00.282Z,1744049580.282 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:13:00.354Z,1744049580.354 [Default] Stopped
2025-04-07T18:13:00.354Z,1744049580.354 [Default](DEBUG): Aggregate::uninitialize Default
2025-04-07T18:13:00.355Z,1744049580.355 [Default:A.Wait] Stopped
2025-04-07T18:13:00.355Z,1744049580.355 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:13:00.355Z,1744049580.355 [Default:B.GoToSurface] Stopped
2025-04-07T18:13:00.355Z,1744049580.355 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T18:13:00.355Z,1744049580.355 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-04-07T18:13:00.355Z,1744049580.355 [lab_test_optim] Running Loop=1
2025-04-07T18:13:00.355Z,1744049580.355 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-04-07T18:13:00.355Z,1744049580.355 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T18:13:00.355Z,1744049580.355 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-04-07T18:13:00.356Z,1744049580.356 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-04-07T18:13:00.356Z,1744049580.356 [lab_test_optim:B] Running Loop=1
2025-04-07T18:13:00.356Z,1744049580.356 [lab_test_optim:C] Running Loop=1
2025-04-07T18:13:00.356Z,1744049580.356 [lab_test_optim:D] Running Loop=1
2025-04-07T18:13:00.356Z,1744049580.356 [lab_test_optim:Startup] Running Loop=1
2025-04-07T18:13:00.356Z,1744049580.356 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-04-07T18:13:00.356Z,1744049580.356 [lab_test_optim:Startup:A] Running Loop=1
2025-04-07T18:13:00.361Z,1744049580.361 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up...
2025-04-07T18:13:00.361Z,1744049580.361 [lab_test_optim:Startup:A] Stopped
2025-04-07T18:13:00.361Z,1744049580.361 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-04-07T18:13:00.361Z,1744049580.361 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:13:00.361Z,1744049580.361 [lab_test_optim:D] Stopped
2025-04-07T18:13:00.362Z,1744049580.362 [lab_test_optim:C] Stopped
2025-04-07T18:13:00.362Z,1744049580.362 [lab_test_optim:B] Running Loop=1
2025-04-07T18:13:00.362Z,1744049580.362 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T18:13:00.362Z,1744049580.362 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-04-07T18:13:00.463Z,1744049580.463 [DataOverHttps](INFO): Moved sent file to Logs/20250407T175457/Courier0010.lzma.bak
2025-04-07T18:13:00.463Z,1744049580.463 [DataOverHttps](INFO): SBD MOMSN=24562416
2025-04-07T18:13:00.517Z,1744049580.517 [BackseatComponent](INFO): Powering up
2025-04-07T18:13:00.518Z,1744049580.518 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-04-07T18:13:31.071Z,1744049611.071 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting.
2025-04-07T18:13:31.072Z,1744049611.072 [lab_test_optim:Startup:B.Wait] Stopped
2025-04-07T18:13:31.072Z,1744049611.072 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:13:31.072Z,1744049611.072 [lab_test_optim:Startup](INFO): Completed lab_test_optim:Startup
2025-04-07T18:13:31.072Z,1744049611.072 [lab_test_optim:Startup] Stopped
2025-04-07T18:13:31.072Z,1744049611.072 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-04-07T18:13:31.072Z,1744049611.072 [lab_test_optim:Run] Running Loop=1
2025-04-07T18:13:31.072Z,1744049611.072 [lab_test_optim:Run](DEBUG): Aggregate::initialize lab_test_optim:Run
2025-04-07T18:13:31.072Z,1744049611.072 [lab_test_optim:Run:A] Running Loop=1
2025-04-07T18:13:31.470Z,1744049611.470 [lab_test_optim:Run:A](IMPORTANT): Trying to run Optim and Multiray forreal
2025-04-07T18:13:31.471Z,1744049611.471 [lab_test_optim:Run:A] Stopped
2025-04-07T18:13:31.471Z,1744049611.471 [lab_test_optim:Run:B] Running Loop=1
2025-04-07T18:13:31.867Z,1744049611.867 [lab_test_optim:Run:B] Stopped
2025-04-07T18:13:31.867Z,1744049611.867 [lab_test_optim:Run:C] Running Loop=1
2025-04-07T18:13:32.281Z,1744049612.281 [lab_test_optim:Run:C] Stopped
2025-04-07T18:13:32.282Z,1744049612.282 [lab_test_optim:Run:D] Running Loop=1
2025-04-07T18:13:32.282Z,1744049612.282 [lab_test_optim:C] Running Loop=1
2025-04-07T18:13:32.282Z,1744049612.282 [lab_test_optim:C] Running Loop=1
2025-04-07T18:13:32.282Z,1744049612.282 [lab_test_optim:C](DEBUG): Initialize ReadDataComponent to sense PowerOnly.sampleLoad1
2025-04-07T18:13:32.643Z,1744049612.643 [PowerOnly](INFO): Powering up loadControl
2025-04-07T18:13:32.703Z,1744049612.703 [lab_test_optim:Run:D] Stopped
2025-04-07T18:13:32.703Z,1744049612.703 [lab_test_optim:Run:setRed] Running Loop=1
2025-04-07T18:13:32.703Z,1744049612.703 [lab_test_optim:Run:setRed](DEBUG): Aggregate::initialize lab_test_optim:Run:setRed
2025-04-07T18:13:32.703Z,1744049612.703 [lab_test_optim:Run:setRed:A] Running Loop=1
2025-04-07T18:13:32.704Z,1744049612.704 [lab_test_optim:D] Running Loop=1
2025-04-07T18:13:32.704Z,1744049612.704 [lab_test_optim:D] Running Loop=1
2025-04-07T18:13:32.704Z,1744049612.704 [lab_test_optim:D](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-04-07T18:13:33.086Z,1744049613.086 [lab_test_optim:Run:setRed] Stopped
2025-04-07T18:13:33.086Z,1744049613.086 [lab_test_optim:Run:setRed](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setRed
2025-04-07T18:13:33.086Z,1744049613.086 [lab_test_optim:Run:setRed:A] Stopped
2025-04-07T18:13:33.086Z,1744049613.086 [lab_test_optim:Run:setWhite] Running Loop=1
2025-04-07T18:13:33.086Z,1744049613.086 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::initialize lab_test_optim:Run:setWhite
2025-04-07T18:13:33.087Z,1744049613.087 [lab_test_optim:Run:setWhite:A] Running Loop=1
2025-04-07T18:13:33.547Z,1744049613.547 [lab_test_optim:Run:setWhite:A] Stopped
2025-04-07T18:13:33.547Z,1744049613.547 [lab_test_optim:Run:setWhite:B] Running Loop=1
2025-04-07T18:13:33.938Z,1744049613.938 [lab_test_optim:Run:setWhite:B](INFO): Setting muliray white brightness to 100.000000 count
2025-04-07T18:13:33.938Z,1744049613.938 [lab_test_optim:Run:setWhite:B] Stopped
2025-04-07T18:13:33.939Z,1744049613.939 [lab_test_optim:Run:setWhite](INFO): Completed lab_test_optim:Run:setWhite
2025-04-07T18:13:33.939Z,1744049613.939 [lab_test_optim:Run:setWhite] Stopped
2025-04-07T18:13:33.939Z,1744049613.939 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setWhite
2025-04-07T18:13:33.939Z,1744049613.939 [lab_test_optim:Run:G] Running Loop=1
2025-04-07T18:13:34.478Z,1744049614.478 [lab_test_optim:Run:G](IMPORTANT): Recording for 1.000000 min
2025-04-07T18:13:34.478Z,1744049614.478 [lab_test_optim:Run:G] Stopped
2025-04-07T18:13:34.478Z,1744049614.478 [lab_test_optim:Run:H.Wait] Running Loop=1
2025-04-07T18:13:34.479Z,1744049614.479 [lab_test_optim:Run:H.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:13:35.103Z,1744049615.103 [MultiRay](IMPORTANT): MultiRay white lights ON
2025-04-07T18:13:41.886Z,1744049621.886 [CommandExec](IMPORTANT): got command stop
2025-04-07T18:13:41.886Z,1744049621.886 [CommandExec](IMPORTANT): Scheduling is paused
2025-04-07T18:13:41.886Z,1744049621.886 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-04-07T18:13:42.005Z,1744049622.005 [MissionManager](INFO): MissionManager is completed.
2025-04-07T18:13:42.005Z,1744049622.005 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-04-07T18:13:42.005Z,1744049622.005 [lab_test_optim] Stopped
2025-04-07T18:13:42.006Z,1744049622.006 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-04-07T18:13:42.006Z,1744049622.006 [lab_test_optim:BackseatDriver] Stopped
2025-04-07T18:13:42.006Z,1744049622.006 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-04-07T18:13:42.006Z,1744049622.006 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-04-07T18:13:42.006Z,1744049622.006 [lab_test_optim:B] Stopped
2025-04-07T18:13:42.006Z,1744049622.006 [lab_test_optim:C] Stopped
2025-04-07T18:13:42.006Z,1744049622.006 [lab_test_optim:D] Stopped
2025-04-07T18:13:42.006Z,1744049622.006 [lab_test_optim:Run] Stopped
2025-04-07T18:13:42.006Z,1744049622.006 [lab_test_optim:Run](DEBUG): Aggregate::uninitialize lab_test_optim:Run
2025-04-07T18:13:42.006Z,1744049622.006 [lab_test_optim:Run:H.Wait] Stopped
2025-04-07T18:13:42.006Z,1744049622.006 [lab_test_optim:Run:H.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:13:42.367Z,1744049622.367 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T18:13:42.367Z,1744049622.367 [Default] Running Loop=1
2025-04-07T18:13:42.367Z,1744049622.367 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T18:13:42.368Z,1744049622.368 [Default:B.GoToSurface] Running Loop=1
2025-04-07T18:13:42.368Z,1744049622.368 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T18:13:42.368Z,1744049622.368 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T18:13:42.368Z,1744049622.368 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T18:13:42.368Z,1744049622.368 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T18:13:42.369Z,1744049622.369 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T18:13:42.369Z,1744049622.369 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T18:13:42.370Z,1744049622.370 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T18:13:42.370Z,1744049622.370 [Default:A.Wait] Running Loop=1
2025-04-07T18:13:42.370Z,1744049622.370 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:13:42.743Z,1744049622.743 [MultiRay](INFO): Powering down
2025-04-07T18:13:42.862Z,1744049622.862 [MultiRay](INFO): Powering down LCB2
2025-04-07T18:13:43.914Z,1744049623.914 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-04-07T18:13:43.914Z,1744049623.914 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-04-07T18:13:55.684Z,1744049635.684 [Default:A.Wait](INFO): Done Waiting.
2025-04-07T18:13:55.684Z,1744049635.684 [Default:A.Wait] Stopped
2025-04-07T18:13:55.684Z,1744049635.684 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:13:56.097Z,1744049636.097 [Default:CheckIn] Running Loop=1
2025-04-07T18:13:56.098Z,1744049636.098 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:13:56.098Z,1744049636.098 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:13:56.491Z,1744049636.491 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-04-07T18:14:02.069Z,1744049642.069 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-04-07T18:14:02.070Z,1744049642.070 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-04-07T18:14:02.070Z,1744049642.070 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-04-07T18:14:11.770Z,1744049651.770 [DataOverHttps](IMPORTANT): SBD MTMSN=20250407T181410
2025-04-07T18:14:19.179Z,1744049659.179 [DataOverHttps](INFO): Received command: run Engineering/lab_test_optim.tl
2025-04-07T18:14:19.308Z,1744049659.308 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:14:19.308Z,1744049659.308 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:14:19.309Z,1744049659.309 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:14:19.310Z,1744049659.310 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:14:19.827Z,1744049659.827 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
15
1
30
2
100
100
Waiting
for backseat to start up...
Trying to run Optim and Multiray forreal
1
Setting multiray red brightness to
2
Setting muliray white brightness to
Recording for
2025-04-07T18:14:19.833Z,1744049659.833 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-04-07T18:14:19.835Z,1744049659.835 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-04-07T18:14:19.864Z,1744049659.864 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-04-07T18:14:19.867Z,1744049659.867 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-04-07T18:14:19.869Z,1744049659.869 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-04-07T18:14:19.871Z,1744049659.871 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-04-07T18:14:19.873Z,1744049659.873 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-04-07T18:14:19.875Z,1744049659.875 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-04-07T18:14:19.876Z,1744049659.876 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-04-07T18:14:19.876Z,1744049659.876 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-04-07T18:14:19.877Z,1744049659.877 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-04-07T18:14:19.985Z,1744049659.985 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-04-07T18:14:19.988Z,1744049659.988 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-04-07T18:14:20.003Z,1744049660.003 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-04-07T18:14:20.040Z,1744049660.040 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-04-07T18:14:20.076Z,1744049660.076 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-04-07T18:14:20.082Z,1744049660.082 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-04-07T18:14:20.092Z,1744049660.092 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission lab_test_optim {
arguments {
MissionTimeout = 15 minute
"""
Backseat will stay on for this duration, independent of Optim state
"""
RecordTime = 1 minute
"""
How long to record after startup sequence (hopefully) turns on Optim camera
"""
BackseatWait = 30 second
"""
How long to wait for the backseat to power up before attempting to power the Optim
"""
LightMode = 2 count
"""
Mode for Multiray lights. 0 is off, 1 is red, 2 is white
"""
BrightnessWhite = 100 none_int
"""
White Multiray LED brightness, 0-100
"""
BrightnessRed = 100 none_int
"""
Red Multiray LED brightness, 0-100
"""
}
output {
RecordingEnabled = false
LightsEnabled = false
}
timeout duration=MissionTimeout
insert Insert/BackseatDriver.tl
assign in parallel BackseatDriver:EnableBackseat = true
readData strategy="MinError" {
while ( RecordingEnabled )
Sensor:PowerOnly.sampleLoad1
}
readData strategy="MinError" {
while ( LightsEnabled )
Sensor:MultiRay.lightModeLog
}
aggregate Startup {
run in sequence
syslog important "Waiting " + BackseatWait~s + " for backseat to start up..."
behavior Guidance:Wait {
run in sequence
set duration = BackseatWait
}
}
aggregate Run {
run in sequence
syslog important "Trying to run Optim and Multiray forreal"
assign in sequence RecordingEnabled = true
assign in sequence LightsEnabled = true
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode
aggregate setRed {
run in sequence
break if ( LightMode != 1 count )
assign in sequence Sensor:MultiRay.brightnessRed = BrightnessRed
syslog info "Setting multiray red brightness to" + BrightnessRed~count
}
aggregate setWhite {
run in sequence
break if ( LightMode != 2 count )
assign in sequence Sensor:MultiRay.brightnessWhite = BrightnessWhite
syslog info "Setting muliray white brightness to" + BrightnessWhite~count
}
syslog important "Recording for " + RecordTime~min
behavior Guidance:Wait {
run in sequence
set duration = RecordTime
}
}
behavior Guidance:Wait {
run in sequence
set duration = MissionTimeout
}
}
2025-04-07T18:14:20.098Z,1744049660.098 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:14:20.345Z,1744049660.345 [Default] Stopped
2025-04-07T18:14:20.345Z,1744049660.345 [Default](DEBUG): Aggregate::uninitialize Default
2025-04-07T18:14:20.345Z,1744049660.345 [Default:B.GoToSurface] Stopped
2025-04-07T18:14:20.345Z,1744049660.345 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T18:14:20.345Z,1744049660.345 [Default:CheckIn] Stopped
2025-04-07T18:14:20.345Z,1744049660.345 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:14:20.345Z,1744049660.345 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:14:20.345Z,1744049660.345 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-04-07T18:14:20.346Z,1744049660.346 [lab_test_optim] Running Loop=1
2025-04-07T18:14:20.346Z,1744049660.346 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-04-07T18:14:20.346Z,1744049660.346 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T18:14:20.346Z,1744049660.346 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-04-07T18:14:20.346Z,1744049660.346 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-04-07T18:14:20.346Z,1744049660.346 [lab_test_optim:B] Running Loop=1
2025-04-07T18:14:20.346Z,1744049660.346 [lab_test_optim:C] Running Loop=1
2025-04-07T18:14:20.347Z,1744049660.347 [lab_test_optim:D] Running Loop=1
2025-04-07T18:14:20.347Z,1744049660.347 [lab_test_optim:Startup] Running Loop=1
2025-04-07T18:14:20.347Z,1744049660.347 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-04-07T18:14:20.347Z,1744049660.347 [lab_test_optim:Startup:A] Running Loop=1
2025-04-07T18:14:20.348Z,1744049660.348 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up...
2025-04-07T18:14:20.348Z,1744049660.348 [lab_test_optim:Startup:A] Stopped
2025-04-07T18:14:20.348Z,1744049660.348 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-04-07T18:14:20.348Z,1744049660.348 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:14:20.348Z,1744049660.348 [lab_test_optim:D] Stopped
2025-04-07T18:14:20.348Z,1744049660.348 [lab_test_optim:C] Stopped
2025-04-07T18:14:20.348Z,1744049660.348 [lab_test_optim:B] Running Loop=1
2025-04-07T18:14:20.349Z,1744049660.349 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T18:14:20.349Z,1744049660.349 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-04-07T18:14:20.518Z,1744049660.518 [BackseatComponent](INFO): Powering up
2025-04-07T18:14:20.520Z,1744049660.520 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-04-07T18:14:34.470Z,1744049674.470 [CommandExec](IMPORTANT): got command strobe off
2025-04-07T18:14:34.471Z,1744049674.471 [CommandExec](IMPORTANT): Deactivating strobe
2025-04-07T18:14:34.867Z,1744049674.867 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-04-07T18:14:51.061Z,1744049691.061 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting.
2025-04-07T18:14:51.061Z,1744049691.061 [lab_test_optim:Startup:B.Wait] Stopped
2025-04-07T18:14:51.061Z,1744049691.061 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:14:51.061Z,1744049691.061 [lab_test_optim:Startup](INFO): Completed lab_test_optim:Startup
2025-04-07T18:14:51.062Z,1744049691.062 [lab_test_optim:Startup] Stopped
2025-04-07T18:14:51.062Z,1744049691.062 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-04-07T18:14:51.062Z,1744049691.062 [lab_test_optim:Run] Running Loop=1
2025-04-07T18:14:51.062Z,1744049691.062 [lab_test_optim:Run](DEBUG): Aggregate::initialize lab_test_optim:Run
2025-04-07T18:14:51.062Z,1744049691.062 [lab_test_optim:Run:A] Running Loop=1
2025-04-07T18:14:51.446Z,1744049691.446 [lab_test_optim:Run:A](IMPORTANT): Trying to run Optim and Multiray forreal
2025-04-07T18:14:51.446Z,1744049691.446 [lab_test_optim:Run:A] Stopped
2025-04-07T18:14:51.446Z,1744049691.446 [lab_test_optim:Run:B] Running Loop=1
2025-04-07T18:14:51.852Z,1744049691.852 [lab_test_optim:Run:B] Stopped
2025-04-07T18:14:51.852Z,1744049691.852 [lab_test_optim:Run:C] Running Loop=1
2025-04-07T18:14:52.262Z,1744049692.262 [lab_test_optim:Run:C] Stopped
2025-04-07T18:14:52.262Z,1744049692.262 [lab_test_optim:Run:D] Running Loop=1
2025-04-07T18:14:52.262Z,1744049692.262 [lab_test_optim:C] Running Loop=1
2025-04-07T18:14:52.263Z,1744049692.263 [lab_test_optim:C] Running Loop=1
2025-04-07T18:14:52.263Z,1744049692.263 [lab_test_optim:C](DEBUG): Initialize ReadDataComponent to sense PowerOnly.sampleLoad1
2025-04-07T18:14:52.668Z,1744049692.668 [lab_test_optim:Run:D] Stopped
2025-04-07T18:14:52.668Z,1744049692.668 [lab_test_optim:Run:setRed] Running Loop=1
2025-04-07T18:14:52.668Z,1744049692.668 [lab_test_optim:Run:setRed](DEBUG): Aggregate::initialize lab_test_optim:Run:setRed
2025-04-07T18:14:52.669Z,1744049692.669 [lab_test_optim:Run:setRed:A] Running Loop=1
2025-04-07T18:14:52.669Z,1744049692.669 [lab_test_optim:D] Running Loop=1
2025-04-07T18:14:52.673Z,1744049692.673 [lab_test_optim:D] Running Loop=1
2025-04-07T18:14:52.673Z,1744049692.673 [lab_test_optim:D](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-04-07T18:14:53.084Z,1744049693.084 [lab_test_optim:Run:setRed] Stopped
2025-04-07T18:14:53.085Z,1744049693.085 [lab_test_optim:Run:setRed](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setRed
2025-04-07T18:14:53.089Z,1744049693.089 [lab_test_optim:Run:setRed:A] Stopped
2025-04-07T18:14:53.089Z,1744049693.089 [lab_test_optim:Run:setWhite] Running Loop=1
2025-04-07T18:14:53.089Z,1744049693.089 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::initialize lab_test_optim:Run:setWhite
2025-04-07T18:14:53.089Z,1744049693.089 [lab_test_optim:Run:setWhite:A] Running Loop=1
2025-04-07T18:14:53.532Z,1744049693.532 [lab_test_optim:Run:setWhite:A] Stopped
2025-04-07T18:14:53.532Z,1744049693.532 [lab_test_optim:Run:setWhite:B] Running Loop=1
2025-04-07T18:14:53.904Z,1744049693.904 [lab_test_optim:Run:setWhite:B](INFO): Setting muliray white brightness to 100.000000 count
2025-04-07T18:14:53.904Z,1744049693.904 [lab_test_optim:Run:setWhite:B] Stopped
2025-04-07T18:14:53.904Z,1744049693.904 [lab_test_optim:Run:setWhite](INFO): Completed lab_test_optim:Run:setWhite
2025-04-07T18:14:53.904Z,1744049693.904 [lab_test_optim:Run:setWhite] Stopped
2025-04-07T18:14:53.904Z,1744049693.904 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setWhite
2025-04-07T18:14:53.904Z,1744049693.904 [lab_test_optim:Run:G] Running Loop=1
2025-04-07T18:14:54.385Z,1744049694.385 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-04-07T18:14:54.386Z,1744049694.386 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T18:14:54.388Z,1744049694.388 [lab_test_optim:Run:G](IMPORTANT): Recording for 1.000000 min
2025-04-07T18:14:54.388Z,1744049694.388 [lab_test_optim:Run:G] Stopped
2025-04-07T18:14:54.388Z,1744049694.388 [lab_test_optim:Run:H.Wait] Running Loop=1
2025-04-07T18:14:54.388Z,1744049694.388 [lab_test_optim:Run:H.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:14:54.401Z,1744049694.401 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T18:14:54.751Z,1744049694.751 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T18:14:54.752Z,1744049694.752 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-04-07T18:14:55.086Z,1744049695.086 [MultiRay](IMPORTANT): MultiRay white lights ON
2025-04-07T18:15:00.742Z,1744049700.742 [CommandExec](IMPORTANT): got command stop
2025-04-07T18:15:00.742Z,1744049700.742 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-04-07T18:15:01.133Z,1744049701.133 [MissionManager](INFO): MissionManager is completed.
2025-04-07T18:15:01.133Z,1744049701.133 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-04-07T18:15:01.133Z,1744049701.133 [lab_test_optim] Stopped
2025-04-07T18:15:01.133Z,1744049701.133 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-04-07T18:15:01.133Z,1744049701.133 [lab_test_optim:BackseatDriver] Stopped
2025-04-07T18:15:01.134Z,1744049701.134 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-04-07T18:15:01.134Z,1744049701.134 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-04-07T18:15:01.134Z,1744049701.134 [lab_test_optim:B] Stopped
2025-04-07T18:15:01.134Z,1744049701.134 [lab_test_optim:C] Stopped
2025-04-07T18:15:01.134Z,1744049701.134 [lab_test_optim:D] Stopped
2025-04-07T18:15:01.134Z,1744049701.134 [lab_test_optim:Run] Stopped
2025-04-07T18:15:01.134Z,1744049701.134 [lab_test_optim:Run](DEBUG): Aggregate::uninitialize lab_test_optim:Run
2025-04-07T18:15:01.134Z,1744049701.134 [lab_test_optim:Run:H.Wait] Stopped
2025-04-07T18:15:01.134Z,1744049701.134 [lab_test_optim:Run:H.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:15:01.536Z,1744049701.536 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T18:15:01.537Z,1744049701.537 [Default] Running Loop=1
2025-04-07T18:15:01.537Z,1744049701.537 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T18:15:01.537Z,1744049701.537 [Default:B.GoToSurface] Running Loop=1
2025-04-07T18:15:01.537Z,1744049701.537 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T18:15:01.537Z,1744049701.537 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T18:15:01.538Z,1744049701.538 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T18:15:01.538Z,1744049701.538 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T18:15:01.538Z,1744049701.538 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T18:15:01.539Z,1744049701.539 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T18:15:01.539Z,1744049701.539 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T18:15:01.539Z,1744049701.539 [Default:A.Wait] Running Loop=1
2025-04-07T18:15:01.539Z,1744049701.539 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:15:01.927Z,1744049701.927 [MultiRay](INFO): Powering down
2025-04-07T18:15:02.010Z,1744049702.010 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-04-07T18:15:02.011Z,1744049702.011 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-04-07T18:15:02.048Z,1744049702.048 [MultiRay](INFO): Powering down LCB2
2025-04-07T18:15:14.876Z,1744049714.876 [Default:A.Wait](INFO): Done Waiting.
2025-04-07T18:15:14.877Z,1744049714.877 [Default:A.Wait] Stopped
2025-04-07T18:15:14.877Z,1744049714.877 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:15:15.272Z,1744049715.272 [Default:CheckIn] Running Loop=1
2025-04-07T18:15:15.272Z,1744049715.272 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:15:15.272Z,1744049715.272 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:15:20.173Z,1744049720.173 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-04-07T18:15:20.174Z,1744049720.174 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-04-07T18:15:20.174Z,1744049720.174 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-04-07T18:16:06.786Z,1744049766.786 [DataOverHttps](IMPORTANT): SBD MTMSN=20250407T181605
2025-04-07T18:16:14.193Z,1744049774.193 [DataOverHttps](INFO): Received command: run Engineering/lab_test_optim.tl
2025-04-07T18:16:14.336Z,1744049774.336 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:16:14.341Z,1744049774.341 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:16:14.341Z,1744049774.341 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:16:14.343Z,1744049774.343 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:16:14.651Z,1744049774.651 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2025-04-07T18:16:14.654Z,1744049774.654 [BPC1](INFO): Received data from all battery sticks.
2025-04-07T18:16:14.665Z,1744049774.665 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
15
1
30
2
100
100
Waiting
for backseat to start up...
Trying to run Optim and Multiray forreal
1
Setting multiray red brightness to
2
Setting muliray white brightness to
Recording for
2025-04-07T18:16:14.670Z,1744049774.670 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-04-07T18:16:14.672Z,1744049774.672 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-04-07T18:16:14.682Z,1744049774.682 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-04-07T18:16:14.685Z,1744049774.685 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-04-07T18:16:14.711Z,1744049774.711 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-04-07T18:16:14.722Z,1744049774.722 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-04-07T18:16:14.724Z,1744049774.724 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-04-07T18:16:14.738Z,1744049774.738 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-04-07T18:16:14.738Z,1744049774.738 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-04-07T18:16:14.739Z,1744049774.739 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-04-07T18:16:14.740Z,1744049774.740 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-04-07T18:16:14.795Z,1744049774.795 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-04-07T18:16:14.799Z,1744049774.799 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-04-07T18:16:14.821Z,1744049774.821 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-04-07T18:16:14.838Z,1744049774.838 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-04-07T18:16:14.896Z,1744049774.896 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-04-07T18:16:14.908Z,1744049774.908 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-04-07T18:16:14.917Z,1744049774.917 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission lab_test_optim {
arguments {
MissionTimeout = 15 minute
"""
Backseat will stay on for this duration, independent of Optim state
"""
RecordTime = 1 minute
"""
How long to record after startup sequence (hopefully) turns on Optim camera
"""
BackseatWait = 30 second
"""
How long to wait for the backseat to power up before attempting to power the Optim
"""
LightMode = 2 count
"""
Mode for Multiray lights. 0 is off, 1 is red, 2 is white
"""
BrightnessWhite = 100 none_int
"""
White Multiray LED brightness, 0-100
"""
BrightnessRed = 100 none_int
"""
Red Multiray LED brightness, 0-100
"""
}
output {
RecordingEnabled = false
LightsEnabled = false
}
timeout duration=MissionTimeout
insert Insert/BackseatDriver.tl
assign in parallel BackseatDriver:EnableBackseat = true
readData strategy="MinError" {
while ( RecordingEnabled )
Sensor:PowerOnly.sampleLoad1
}
readData strategy="MinError" {
while ( LightsEnabled )
Sensor:MultiRay.lightModeLog
}
aggregate Startup {
run in sequence
syslog important "Waiting " + BackseatWait~s + " for backseat to start up..."
behavior Guidance:Wait {
run in sequence
set duration = BackseatWait
}
}
aggregate Run {
run in sequence
syslog important "Trying to run Optim and Multiray forreal"
assign in sequence RecordingEnabled = true
assign in sequence LightsEnabled = true
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode
aggregate setRed {
run in sequence
break if ( LightMode != 1 count )
assign in sequence Sensor:MultiRay.brightnessRed = BrightnessRed
syslog info "Setting multiray red brightness to" + BrightnessRed~count
}
aggregate setWhite {
run in sequence
break if ( LightMode != 2 count )
assign in sequence Sensor:MultiRay.brightnessWhite = BrightnessWhite
syslog info "Setting muliray white brightness to" + BrightnessWhite~count
}
syslog important "Recording for " + RecordTime~min
behavior Guidance:Wait {
run in sequence
set duration = RecordTime
}
}
behavior Guidance:Wait {
run in sequence
set duration = MissionTimeout
}
}
2025-04-07T18:16:14.919Z,1744049774.919 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:16:15.082Z,1744049775.082 [Default] Stopped
2025-04-07T18:16:15.082Z,1744049775.082 [Default](DEBUG): Aggregate::uninitialize Default
2025-04-07T18:16:15.083Z,1744049775.083 [Default:B.GoToSurface] Stopped
2025-04-07T18:16:15.083Z,1744049775.083 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T18:16:15.083Z,1744049775.083 [Default:CheckIn] Stopped
2025-04-07T18:16:15.083Z,1744049775.083 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:16:15.083Z,1744049775.083 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:16:15.083Z,1744049775.083 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-04-07T18:16:15.083Z,1744049775.083 [lab_test_optim] Running Loop=1
2025-04-07T18:16:15.083Z,1744049775.083 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-04-07T18:16:15.083Z,1744049775.083 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T18:16:15.084Z,1744049775.084 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-04-07T18:16:15.084Z,1744049775.084 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-04-07T18:16:15.084Z,1744049775.084 [lab_test_optim:B] Running Loop=1
2025-04-07T18:16:15.084Z,1744049775.084 [lab_test_optim:C] Running Loop=1
2025-04-07T18:16:15.084Z,1744049775.084 [lab_test_optim:D] Running Loop=1
2025-04-07T18:16:15.084Z,1744049775.084 [lab_test_optim:Startup] Running Loop=1
2025-04-07T18:16:15.084Z,1744049775.084 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-04-07T18:16:15.084Z,1744049775.084 [lab_test_optim:Startup:A] Running Loop=1
2025-04-07T18:16:15.089Z,1744049775.089 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up...
2025-04-07T18:16:15.089Z,1744049775.089 [lab_test_optim:Startup:A] Stopped
2025-04-07T18:16:15.089Z,1744049775.089 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-04-07T18:16:15.090Z,1744049775.090 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:16:15.090Z,1744049775.090 [lab_test_optim:D] Stopped
2025-04-07T18:16:15.090Z,1744049775.090 [lab_test_optim:C] Stopped
2025-04-07T18:16:15.090Z,1744049775.090 [lab_test_optim:B] Running Loop=1
2025-04-07T18:16:15.090Z,1744049775.090 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T18:16:15.090Z,1744049775.090 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-04-07T18:16:15.097Z,1744049775.097 [BackseatComponent](INFO): Powering up
2025-04-07T18:16:15.098Z,1744049775.098 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-04-07T18:16:31.629Z,1744049791.629 [PowerOnly](INFO): Powering down loadControl
2025-04-07T18:16:45.786Z,1744049805.786 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting.
2025-04-07T18:16:45.786Z,1744049805.786 [lab_test_optim:Startup:B.Wait] Stopped
2025-04-07T18:16:45.786Z,1744049805.786 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:16:45.786Z,1744049805.786 [lab_test_optim:Startup](INFO): Completed lab_test_optim:Startup
2025-04-07T18:16:45.786Z,1744049805.786 [lab_test_optim:Startup] Stopped
2025-04-07T18:16:45.787Z,1744049805.787 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-04-07T18:16:45.787Z,1744049805.787 [lab_test_optim:Run] Running Loop=1
2025-04-07T18:16:45.787Z,1744049805.787 [lab_test_optim:Run](DEBUG): Aggregate::initialize lab_test_optim:Run
2025-04-07T18:16:45.787Z,1744049805.787 [lab_test_optim:Run:A] Running Loop=1
2025-04-07T18:16:46.196Z,1744049806.196 [lab_test_optim:Run:A](IMPORTANT): Trying to run Optim and Multiray forreal
2025-04-07T18:16:46.196Z,1744049806.196 [lab_test_optim:Run:A] Stopped
2025-04-07T18:16:46.196Z,1744049806.196 [lab_test_optim:Run:B] Running Loop=1
2025-04-07T18:16:46.591Z,1744049806.591 [lab_test_optim:Run:B] Stopped
2025-04-07T18:16:46.591Z,1744049806.591 [lab_test_optim:Run:C] Running Loop=1
2025-04-07T18:16:46.990Z,1744049806.990 [lab_test_optim:Run:C] Stopped
2025-04-07T18:16:46.990Z,1744049806.990 [lab_test_optim:Run:D] Running Loop=1
2025-04-07T18:16:46.990Z,1744049806.990 [lab_test_optim:C] Running Loop=1
2025-04-07T18:16:46.990Z,1744049806.990 [lab_test_optim:C] Running Loop=1
2025-04-07T18:16:46.991Z,1744049806.991 [lab_test_optim:C](DEBUG): Initialize ReadDataComponent to sense PowerOnly.sampleLoad1
2025-04-07T18:16:47.371Z,1744049807.371 [PowerOnly](INFO): Powering up loadControl
2025-04-07T18:16:47.406Z,1744049807.406 [lab_test_optim:Run:D] Stopped
2025-04-07T18:16:47.406Z,1744049807.406 [lab_test_optim:Run:setRed] Running Loop=1
2025-04-07T18:16:47.406Z,1744049807.406 [lab_test_optim:Run:setRed](DEBUG): Aggregate::initialize lab_test_optim:Run:setRed
2025-04-07T18:16:47.406Z,1744049807.406 [lab_test_optim:Run:setRed:A] Running Loop=1
2025-04-07T18:16:47.406Z,1744049807.406 [lab_test_optim:D] Running Loop=1
2025-04-07T18:16:47.406Z,1744049807.406 [lab_test_optim:D] Running Loop=1
2025-04-07T18:16:47.407Z,1744049807.407 [lab_test_optim:D](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-04-07T18:16:47.815Z,1744049807.815 [lab_test_optim:Run:setRed] Stopped
2025-04-07T18:16:47.815Z,1744049807.815 [lab_test_optim:Run:setRed](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setRed
2025-04-07T18:16:47.815Z,1744049807.815 [lab_test_optim:Run:setRed:A] Stopped
2025-04-07T18:16:47.815Z,1744049807.815 [lab_test_optim:Run:setWhite] Running Loop=1
2025-04-07T18:16:47.815Z,1744049807.815 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::initialize lab_test_optim:Run:setWhite
2025-04-07T18:16:47.815Z,1744049807.815 [lab_test_optim:Run:setWhite:A] Running Loop=1
2025-04-07T18:16:48.243Z,1744049808.243 [lab_test_optim:Run:setWhite:A] Stopped
2025-04-07T18:16:48.243Z,1744049808.243 [lab_test_optim:Run:setWhite:B] Running Loop=1
2025-04-07T18:16:48.680Z,1744049808.680 [lab_test_optim:Run:setWhite:B](INFO): Setting muliray white brightness to 100.000000 count
2025-04-07T18:16:48.680Z,1744049808.680 [lab_test_optim:Run:setWhite:B] Stopped
2025-04-07T18:16:48.680Z,1744049808.680 [lab_test_optim:Run:setWhite](INFO): Completed lab_test_optim:Run:setWhite
2025-04-07T18:16:48.680Z,1744049808.680 [lab_test_optim:Run:setWhite] Stopped
2025-04-07T18:16:48.680Z,1744049808.680 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setWhite
2025-04-07T18:16:48.680Z,1744049808.680 [lab_test_optim:Run:G] Running Loop=1
2025-04-07T18:16:49.011Z,1744049809.011 [lab_test_optim:Run:G](IMPORTANT): Recording for 1.000000 min
2025-04-07T18:16:49.011Z,1744049809.011 [lab_test_optim:Run:G] Stopped
2025-04-07T18:16:49.011Z,1744049809.011 [lab_test_optim:Run:H.Wait] Running Loop=1
2025-04-07T18:16:49.011Z,1744049809.011 [lab_test_optim:Run:H.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:16:49.799Z,1744049809.799 [MultiRay](IMPORTANT): MultiRay white lights ON
2025-04-07T18:16:52.710Z,1744049812.710 [CommandExec](IMPORTANT): got command stop
2025-04-07T18:16:52.710Z,1744049812.710 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-04-07T18:16:53.041Z,1744049813.041 [MissionManager](INFO): MissionManager is completed.
2025-04-07T18:16:53.041Z,1744049813.041 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-04-07T18:16:53.041Z,1744049813.041 [lab_test_optim] Stopped
2025-04-07T18:16:53.041Z,1744049813.041 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-04-07T18:16:53.041Z,1744049813.041 [lab_test_optim:BackseatDriver] Stopped
2025-04-07T18:16:53.042Z,1744049813.042 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-04-07T18:16:53.042Z,1744049813.042 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-04-07T18:16:53.042Z,1744049813.042 [lab_test_optim:B] Stopped
2025-04-07T18:16:53.042Z,1744049813.042 [lab_test_optim:C] Stopped
2025-04-07T18:16:53.042Z,1744049813.042 [lab_test_optim:D] Stopped
2025-04-07T18:16:53.042Z,1744049813.042 [lab_test_optim:Run] Stopped
2025-04-07T18:16:53.042Z,1744049813.042 [lab_test_optim:Run](DEBUG): Aggregate::uninitialize lab_test_optim:Run
2025-04-07T18:16:53.042Z,1744049813.042 [lab_test_optim:Run:H.Wait] Stopped
2025-04-07T18:16:53.042Z,1744049813.042 [lab_test_optim:Run:H.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:16:53.444Z,1744049813.444 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T18:16:53.444Z,1744049813.444 [Default] Running Loop=1
2025-04-07T18:16:53.444Z,1744049813.444 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T18:16:53.444Z,1744049813.444 [Default:B.GoToSurface] Running Loop=1
2025-04-07T18:16:53.444Z,1744049813.444 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T18:16:53.444Z,1744049813.444 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T18:16:53.445Z,1744049813.445 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T18:16:53.445Z,1744049813.445 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T18:16:53.446Z,1744049813.446 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T18:16:53.446Z,1744049813.446 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T18:16:53.446Z,1744049813.446 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T18:16:53.447Z,1744049813.447 [Default:A.Wait] Running Loop=1
2025-04-07T18:16:53.447Z,1744049813.447 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:16:53.666Z,1744049813.666 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-04-07T18:16:53.667Z,1744049813.667 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-04-07T18:16:53.842Z,1744049813.842 [MultiRay](INFO): Powering down
2025-04-07T18:16:53.961Z,1744049813.961 [MultiRay](INFO): Powering down LCB2
2025-04-07T18:17:06.799Z,1744049826.799 [Default:A.Wait](INFO): Done Waiting.
2025-04-07T18:17:06.799Z,1744049826.799 [Default:A.Wait] Stopped
2025-04-07T18:17:06.799Z,1744049826.799 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:17:07.194Z,1744049827.194 [Default:CheckIn] Running Loop=1
2025-04-07T18:17:07.194Z,1744049827.194 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:17:07.195Z,1744049827.195 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:17:11.821Z,1744049831.821 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-04-07T18:17:11.822Z,1744049831.822 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-04-07T18:17:11.822Z,1744049831.822 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-04-07T18:17:26.299Z,1744049846.299 [DataOverHttps](IMPORTANT): SBD MTMSN=20250407T181725
2025-04-07T18:17:33.597Z,1744049853.597 [DataOverHttps](INFO): Received command: run Engineering/lab_test_optim.tl
2025-04-07T18:17:33.719Z,1744049853.719 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:17:33.720Z,1744049853.720 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:17:33.720Z,1744049853.720 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:17:33.721Z,1744049853.721 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:17:34.038Z,1744049854.038 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
15
1
30
2
100
100
Waiting
for backseat to start up...
Trying to run Optim and Multiray forreal
1
Setting multiray red brightness to
2
Setting muliray white brightness to
Recording for
2025-04-07T18:17:34.042Z,1744049854.042 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-04-07T18:17:34.044Z,1744049854.044 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-04-07T18:17:34.047Z,1744049854.047 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-04-07T18:17:34.049Z,1744049854.049 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-04-07T18:17:34.051Z,1744049854.051 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-04-07T18:17:34.054Z,1744049854.054 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-04-07T18:17:34.056Z,1744049854.056 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-04-07T18:17:34.058Z,1744049854.058 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-04-07T18:17:34.058Z,1744049854.058 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-04-07T18:17:34.059Z,1744049854.059 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-04-07T18:17:34.060Z,1744049854.060 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-04-07T18:17:34.174Z,1744049854.174 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-04-07T18:17:34.184Z,1744049854.184 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-04-07T18:17:34.191Z,1744049854.191 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-04-07T18:17:34.210Z,1744049854.210 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-04-07T18:17:34.253Z,1744049854.253 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-04-07T18:17:34.254Z,1744049854.254 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-04-07T18:17:34.264Z,1744049854.264 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission lab_test_optim {
arguments {
MissionTimeout = 15 minute
"""
Backseat will stay on for this duration, independent of Optim state
"""
RecordTime = 1 minute
"""
How long to record after startup sequence (hopefully) turns on Optim camera
"""
BackseatWait = 30 second
"""
How long to wait for the backseat to power up before attempting to power the Optim
"""
LightMode = 2 count
"""
Mode for Multiray lights. 0 is off, 1 is red, 2 is white
"""
BrightnessWhite = 100 none_int
"""
White Multiray LED brightness, 0-100
"""
BrightnessRed = 100 none_int
"""
Red Multiray LED brightness, 0-100
"""
}
output {
RecordingEnabled = false
LightsEnabled = false
}
timeout duration=MissionTimeout
insert Insert/BackseatDriver.tl
assign in parallel BackseatDriver:EnableBackseat = true
readData strategy="MinError" {
while ( RecordingEnabled )
Sensor:PowerOnly.sampleLoad1
}
readData strategy="MinError" {
while ( LightsEnabled )
Sensor:MultiRay.lightModeLog
}
aggregate Startup {
run in sequence
syslog important "Waiting " + BackseatWait~s + " for backseat to start up..."
behavior Guidance:Wait {
run in sequence
set duration = BackseatWait
}
}
aggregate Run {
run in sequence
syslog important "Trying to run Optim and Multiray forreal"
assign in sequence RecordingEnabled = true
assign in sequence LightsEnabled = true
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode
aggregate setRed {
run in sequence
break if ( LightMode != 1 count )
assign in sequence Sensor:MultiRay.brightnessRed = BrightnessRed
syslog info "Setting multiray red brightness to" + BrightnessRed~count
}
aggregate setWhite {
run in sequence
break if ( LightMode != 2 count )
assign in sequence Sensor:MultiRay.brightnessWhite = BrightnessWhite
syslog info "Setting muliray white brightness to" + BrightnessWhite~count
}
syslog important "Recording for " + RecordTime~min
behavior Guidance:Wait {
run in sequence
set duration = RecordTime
}
}
behavior Guidance:Wait {
run in sequence
set duration = MissionTimeout
}
}
2025-04-07T18:17:34.266Z,1744049854.266 [Default] Stopped
2025-04-07T18:17:34.266Z,1744049854.266 [Default](DEBUG): Aggregate::uninitialize Default
2025-04-07T18:17:34.267Z,1744049854.267 [Default:B.GoToSurface] Stopped
2025-04-07T18:17:34.267Z,1744049854.267 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T18:17:34.267Z,1744049854.267 [Default:CheckIn] Stopped
2025-04-07T18:17:34.267Z,1744049854.267 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:17:34.267Z,1744049854.267 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:17:34.267Z,1744049854.267 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-04-07T18:17:34.267Z,1744049854.267 [lab_test_optim] Running Loop=1
2025-04-07T18:17:34.267Z,1744049854.267 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-04-07T18:17:34.267Z,1744049854.267 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T18:17:34.268Z,1744049854.268 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-04-07T18:17:34.268Z,1744049854.268 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-04-07T18:17:34.268Z,1744049854.268 [lab_test_optim:B] Running Loop=1
2025-04-07T18:17:34.268Z,1744049854.268 [lab_test_optim:C] Running Loop=1
2025-04-07T18:17:34.268Z,1744049854.268 [lab_test_optim:D] Running Loop=1
2025-04-07T18:17:34.268Z,1744049854.268 [lab_test_optim:Startup] Running Loop=1
2025-04-07T18:17:34.268Z,1744049854.268 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-04-07T18:17:34.268Z,1744049854.268 [lab_test_optim:Startup:A] Running Loop=1
2025-04-07T18:17:34.271Z,1744049854.271 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:17:34.272Z,1744049854.272 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up...
2025-04-07T18:17:34.272Z,1744049854.272 [lab_test_optim:Startup:A] Stopped
2025-04-07T18:17:34.272Z,1744049854.272 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-04-07T18:17:34.273Z,1744049854.273 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:17:34.273Z,1744049854.273 [lab_test_optim:D] Stopped
2025-04-07T18:17:34.273Z,1744049854.273 [lab_test_optim:C] Stopped
2025-04-07T18:17:34.289Z,1744049854.289 [lab_test_optim:B] Running Loop=1
2025-04-07T18:17:34.289Z,1744049854.289 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T18:17:34.290Z,1744049854.290 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-04-07T18:17:34.313Z,1744049854.313 [BackseatComponent](INFO): Powering up
2025-04-07T18:17:34.314Z,1744049854.314 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-04-07T18:17:55.260Z,1744049875.260 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-04-07T18:17:55.260Z,1744049875.260 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T18:17:55.273Z,1744049875.273 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T18:17:55.677Z,1744049875.677 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T18:17:55.677Z,1744049875.677 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-04-07T18:18:04.962Z,1744049884.962 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting.
2025-04-07T18:18:04.962Z,1744049884.962 [lab_test_optim:Startup:B.Wait] Stopped
2025-04-07T18:18:04.962Z,1744049884.962 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:18:04.963Z,1744049884.963 [lab_test_optim:Startup](INFO): Completed lab_test_optim:Startup
2025-04-07T18:18:04.963Z,1744049884.963 [lab_test_optim:Startup] Stopped
2025-04-07T18:18:04.963Z,1744049884.963 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-04-07T18:18:04.963Z,1744049884.963 [lab_test_optim:Run] Running Loop=1
2025-04-07T18:18:04.963Z,1744049884.963 [lab_test_optim:Run](DEBUG): Aggregate::initialize lab_test_optim:Run
2025-04-07T18:18:04.963Z,1744049884.963 [lab_test_optim:Run:A] Running Loop=1
2025-04-07T18:18:05.367Z,1744049885.367 [lab_test_optim:Run:A](IMPORTANT): Trying to run Optim and Multiray forreal
2025-04-07T18:18:05.367Z,1744049885.367 [lab_test_optim:Run:A] Stopped
2025-04-07T18:18:05.368Z,1744049885.368 [lab_test_optim:Run:B] Running Loop=1
2025-04-07T18:18:05.771Z,1744049885.771 [lab_test_optim:Run:B] Stopped
2025-04-07T18:18:05.771Z,1744049885.771 [lab_test_optim:Run:C] Running Loop=1
2025-04-07T18:18:06.191Z,1744049886.191 [lab_test_optim:Run:C] Stopped
2025-04-07T18:18:06.191Z,1744049886.191 [lab_test_optim:Run:D] Running Loop=1
2025-04-07T18:18:06.191Z,1744049886.191 [lab_test_optim:C] Running Loop=1
2025-04-07T18:18:06.191Z,1744049886.191 [lab_test_optim:C] Running Loop=1
2025-04-07T18:18:06.191Z,1744049886.191 [lab_test_optim:C](DEBUG): Initialize ReadDataComponent to sense PowerOnly.sampleLoad1
2025-04-07T18:18:06.611Z,1744049886.611 [lab_test_optim:Run:D] Stopped
2025-04-07T18:18:06.612Z,1744049886.612 [lab_test_optim:Run:setRed] Running Loop=1
2025-04-07T18:18:06.612Z,1744049886.612 [lab_test_optim:Run:setRed](DEBUG): Aggregate::initialize lab_test_optim:Run:setRed
2025-04-07T18:18:06.612Z,1744049886.612 [lab_test_optim:Run:setRed:A] Running Loop=1
2025-04-07T18:18:06.612Z,1744049886.612 [lab_test_optim:D] Running Loop=1
2025-04-07T18:18:06.612Z,1744049886.612 [lab_test_optim:D] Running Loop=1
2025-04-07T18:18:06.613Z,1744049886.613 [lab_test_optim:D](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-04-07T18:18:06.991Z,1744049886.991 [lab_test_optim:Run:setRed] Stopped
2025-04-07T18:18:06.991Z,1744049886.991 [lab_test_optim:Run:setRed](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setRed
2025-04-07T18:18:06.991Z,1744049886.991 [lab_test_optim:Run:setRed:A] Stopped
2025-04-07T18:18:06.991Z,1744049886.991 [lab_test_optim:Run:setWhite] Running Loop=1
2025-04-07T18:18:06.991Z,1744049886.991 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::initialize lab_test_optim:Run:setWhite
2025-04-07T18:18:06.991Z,1744049886.991 [lab_test_optim:Run:setWhite:A] Running Loop=1
2025-04-07T18:18:07.411Z,1744049887.411 [lab_test_optim:Run:setWhite:A] Stopped
2025-04-07T18:18:07.411Z,1744049887.411 [lab_test_optim:Run:setWhite:B] Running Loop=1
2025-04-07T18:18:07.835Z,1744049887.835 [lab_test_optim:Run:setWhite:B](INFO): Setting muliray white brightness to 100.000000 count
2025-04-07T18:18:07.835Z,1744049887.835 [lab_test_optim:Run:setWhite:B] Stopped
2025-04-07T18:18:07.835Z,1744049887.835 [lab_test_optim:Run:setWhite](INFO): Completed lab_test_optim:Run:setWhite
2025-04-07T18:18:07.835Z,1744049887.835 [lab_test_optim:Run:setWhite] Stopped
2025-04-07T18:18:07.835Z,1744049887.835 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setWhite
2025-04-07T18:18:07.836Z,1744049887.836 [lab_test_optim:Run:G] Running Loop=1
2025-04-07T18:18:08.196Z,1744049888.196 [lab_test_optim:Run:G](IMPORTANT): Recording for 1.000000 min
2025-04-07T18:18:08.196Z,1744049888.196 [lab_test_optim:Run:G] Stopped
2025-04-07T18:18:08.196Z,1744049888.196 [lab_test_optim:Run:H.Wait] Running Loop=1
2025-04-07T18:18:08.196Z,1744049888.196 [lab_test_optim:Run:H.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:18:08.979Z,1744049888.979 [MultiRay](IMPORTANT): MultiRay white lights ON
2025-04-07T18:18:12.174Z,1744049892.174 [CommandExec](IMPORTANT): got command stop
2025-04-07T18:18:12.174Z,1744049892.174 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-04-07T18:18:12.257Z,1744049892.257 [MissionManager](INFO): MissionManager is completed.
2025-04-07T18:18:12.257Z,1744049892.257 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-04-07T18:18:12.257Z,1744049892.257 [lab_test_optim] Stopped
2025-04-07T18:18:12.257Z,1744049892.257 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-04-07T18:18:12.258Z,1744049892.258 [lab_test_optim:BackseatDriver] Stopped
2025-04-07T18:18:12.258Z,1744049892.258 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-04-07T18:18:12.258Z,1744049892.258 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-04-07T18:18:12.258Z,1744049892.258 [lab_test_optim:B] Stopped
2025-04-07T18:18:12.258Z,1744049892.258 [lab_test_optim:C] Stopped
2025-04-07T18:18:12.258Z,1744049892.258 [lab_test_optim:D] Stopped
2025-04-07T18:18:12.258Z,1744049892.258 [lab_test_optim:Run] Stopped
2025-04-07T18:18:12.258Z,1744049892.258 [lab_test_optim:Run](DEBUG): Aggregate::uninitialize lab_test_optim:Run
2025-04-07T18:18:12.258Z,1744049892.258 [lab_test_optim:Run:H.Wait] Stopped
2025-04-07T18:18:12.258Z,1744049892.258 [lab_test_optim:Run:H.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:18:12.643Z,1744049892.643 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T18:18:12.643Z,1744049892.643 [Default] Running Loop=1
2025-04-07T18:18:12.643Z,1744049892.643 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T18:18:12.643Z,1744049892.643 [Default:B.GoToSurface] Running Loop=1
2025-04-07T18:18:12.644Z,1744049892.644 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T18:18:12.644Z,1744049892.644 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T18:18:12.644Z,1744049892.644 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T18:18:12.644Z,1744049892.644 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T18:18:12.645Z,1744049892.645 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T18:18:12.673Z,1744049892.673 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T18:18:12.674Z,1744049892.674 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T18:18:12.674Z,1744049892.674 [Default:A.Wait] Running Loop=1
2025-04-07T18:18:12.674Z,1744049892.674 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:18:12.686Z,1744049892.686 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-04-07T18:18:12.686Z,1744049892.686 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-04-07T18:18:13.028Z,1744049893.028 [MultiRay](INFO): Powering down
2025-04-07T18:18:13.142Z,1744049893.142 [MultiRay](INFO): Powering down LCB2
2025-04-07T18:18:25.961Z,1744049905.961 [Default:A.Wait](INFO): Done Waiting.
2025-04-07T18:18:25.961Z,1744049905.961 [Default:A.Wait] Stopped
2025-04-07T18:18:25.961Z,1744049905.961 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:18:26.373Z,1744049906.373 [Default:CheckIn] Running Loop=1
2025-04-07T18:18:26.373Z,1744049906.373 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:18:26.373Z,1744049906.373 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:18:30.853Z,1744049910.853 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-04-07T18:18:30.854Z,1744049910.854 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-04-07T18:18:30.854Z,1744049910.854 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-04-07T18:19:21.038Z,1744049961.038 [DataOverHttps](IMPORTANT): SBD MTMSN=20250407T181920
2025-04-07T18:19:28.417Z,1744049968.417 [DataOverHttps](INFO): Received command: run Engineering/lab_test_optim.tl
2025-04-07T18:19:28.549Z,1744049968.549 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:19:28.549Z,1744049968.549 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:19:28.549Z,1744049968.549 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:19:28.551Z,1744049968.551 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:19:28.889Z,1744049968.889 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into:
15
1
30
2
100
100
Waiting
for backseat to start up...
Trying to run Optim and Multiray forreal
1
Setting multiray red brightness to
2
Setting muliray white brightness to
Recording for
2025-04-07T18:19:28.894Z,1744049968.894 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min
2025-04-07T18:19:28.896Z,1744049968.896 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min
2025-04-07T18:19:28.898Z,1744049968.898 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s
2025-04-07T18:19:28.900Z,1744049968.900 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count
2025-04-07T18:19:28.903Z,1744049968.903 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32
2025-04-07T18:19:28.905Z,1744049968.905 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32
2025-04-07T18:19:28.907Z,1744049968.907 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool
2025-04-07T18:19:28.909Z,1744049968.909 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool
2025-04-07T18:19:28.910Z,1744049968.910 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-04-07T18:19:28.910Z,1744049968.910 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-04-07T18:19:28.911Z,1744049968.911 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-04-07T18:19:29.010Z,1744049969.010 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-04-07T18:19:29.022Z,1744049969.022 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool
2025-04-07T18:19:29.024Z,1744049969.024 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-04-07T18:19:29.087Z,1744049969.087 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait.
2025-04-07T18:19:29.127Z,1744049969.127 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait.
2025-04-07T18:19:29.129Z,1744049969.129 [lab_test_optim:G.Wait](DEBUG): Construct Wait.
2025-04-07T18:19:29.150Z,1744049969.150 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission lab_test_optim {
arguments {
MissionTimeout = 15 minute
"""
Backseat will stay on for this duration, independent of Optim state
"""
RecordTime = 1 minute
"""
How long to record after startup sequence (hopefully) turns on Optim camera
"""
BackseatWait = 30 second
"""
How long to wait for the backseat to power up before attempting to power the Optim
"""
LightMode = 2 count
"""
Mode for Multiray lights. 0 is off, 1 is red, 2 is white
"""
BrightnessWhite = 100 none_int
"""
White Multiray LED brightness, 0-100
"""
BrightnessRed = 100 none_int
"""
Red Multiray LED brightness, 0-100
"""
}
output {
RecordingEnabled = false
LightsEnabled = false
}
timeout duration=MissionTimeout
insert Insert/BackseatDriver.tl
assign in parallel BackseatDriver:EnableBackseat = true
readData strategy="MinError" {
while ( RecordingEnabled )
Sensor:PowerOnly.sampleLoad1
}
readData strategy="MinError" {
while ( LightsEnabled )
Sensor:MultiRay.lightModeLog
}
aggregate Startup {
run in sequence
syslog important "Waiting " + BackseatWait~s + " for backseat to start up..."
behavior Guidance:Wait {
run in sequence
set duration = BackseatWait
}
}
aggregate Run {
run in sequence
syslog important "Trying to run Optim and Multiray forreal"
assign in sequence RecordingEnabled = true
assign in sequence LightsEnabled = true
assign in sequence Sensor:MultiRay.lightModeCommand = LightMode
aggregate setRed {
run in sequence
break if ( LightMode != 1 count )
assign in sequence Sensor:MultiRay.brightnessRed = BrightnessRed
syslog info "Setting multiray red brightness to" + BrightnessRed~count
}
aggregate setWhite {
run in sequence
break if ( LightMode != 2 count )
assign in sequence Sensor:MultiRay.brightnessWhite = BrightnessWhite
syslog info "Setting muliray white brightness to" + BrightnessWhite~count
}
syslog important "Recording for " + RecordTime~min
behavior Guidance:Wait {
run in sequence
set duration = RecordTime
}
}
behavior Guidance:Wait {
run in sequence
set duration = MissionTimeout
}
}
2025-04-07T18:19:29.151Z,1744049969.151 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl
2025-04-07T18:19:29.395Z,1744049969.395 [Default] Stopped
2025-04-07T18:19:29.395Z,1744049969.395 [Default](DEBUG): Aggregate::uninitialize Default
2025-04-07T18:19:29.395Z,1744049969.395 [Default:B.GoToSurface] Stopped
2025-04-07T18:19:29.395Z,1744049969.395 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-04-07T18:19:29.395Z,1744049969.395 [Default:CheckIn] Stopped
2025-04-07T18:19:29.395Z,1744049969.395 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:19:29.395Z,1744049969.395 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:19:29.395Z,1744049969.395 [MissionManager](IMPORTANT): Started mission lab_test_optim
2025-04-07T18:19:29.395Z,1744049969.395 [lab_test_optim] Running Loop=1
2025-04-07T18:19:29.396Z,1744049969.396 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim
2025-04-07T18:19:29.396Z,1744049969.396 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T18:19:29.396Z,1744049969.396 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver
2025-04-07T18:19:29.396Z,1744049969.396 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-04-07T18:19:29.396Z,1744049969.396 [lab_test_optim:B] Running Loop=1
2025-04-07T18:19:29.396Z,1744049969.396 [lab_test_optim:C] Running Loop=1
2025-04-07T18:19:29.396Z,1744049969.396 [lab_test_optim:D] Running Loop=1
2025-04-07T18:19:29.396Z,1744049969.396 [lab_test_optim:Startup] Running Loop=1
2025-04-07T18:19:29.396Z,1744049969.396 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup
2025-04-07T18:19:29.396Z,1744049969.396 [lab_test_optim:Startup:A] Running Loop=1
2025-04-07T18:19:29.397Z,1744049969.397 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up...
2025-04-07T18:19:29.398Z,1744049969.398 [lab_test_optim:Startup:A] Stopped
2025-04-07T18:19:29.398Z,1744049969.398 [lab_test_optim:Startup:B.Wait] Running Loop=1
2025-04-07T18:19:29.398Z,1744049969.398 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:19:29.398Z,1744049969.398 [lab_test_optim:D] Stopped
2025-04-07T18:19:29.398Z,1744049969.398 [lab_test_optim:C] Stopped
2025-04-07T18:19:29.398Z,1744049969.398 [lab_test_optim:B] Running Loop=1
2025-04-07T18:19:29.398Z,1744049969.398 [lab_test_optim:BackseatDriver] Running Loop=1
2025-04-07T18:19:29.398Z,1744049969.398 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-04-07T18:19:29.457Z,1744049969.457 [BackseatComponent](INFO): Powering up
2025-04-07T18:19:29.458Z,1744049969.458 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-04-07T18:19:35.043Z,1744049975.043 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-04-07T18:19:35.043Z,1744049975.043 [NAL9602] Data Fault, FailCount= 1
2025-04-07T18:19:35.043Z,1744049975.043 [NAL9602](ERROR): Data Fault
2025-04-07T18:19:35.124Z,1744049975.124 [CBIT](ERROR): Data Fault in component: NAL9602
2025-04-07T18:19:35.456Z,1744049975.456 [NAL9602](INFO): Powering down
2025-04-07T18:19:36.273Z,1744049976.273 [CBIT](INFO): Clearing failed state for component NAL9602
2025-04-07T18:19:36.273Z,1744049976.273 [NAL9602] No Fault, FailCount= 1
2025-04-07T18:19:42.714Z,1744049982.714 [PowerOnly](INFO): Powering down loadControl
2025-04-07T18:20:00.134Z,1744050000.134 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting.
2025-04-07T18:20:00.134Z,1744050000.134 [lab_test_optim:Startup:B.Wait] Stopped
2025-04-07T18:20:00.134Z,1744050000.134 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:20:00.135Z,1744050000.135 [lab_test_optim:Startup](INFO): Completed lab_test_optim:Startup
2025-04-07T18:20:00.135Z,1744050000.135 [lab_test_optim:Startup] Stopped
2025-04-07T18:20:00.135Z,1744050000.135 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup
2025-04-07T18:20:00.135Z,1744050000.135 [lab_test_optim:Run] Running Loop=1
2025-04-07T18:20:00.135Z,1744050000.135 [lab_test_optim:Run](DEBUG): Aggregate::initialize lab_test_optim:Run
2025-04-07T18:20:00.135Z,1744050000.135 [lab_test_optim:Run:A] Running Loop=1
2025-04-07T18:20:00.514Z,1744050000.514 [lab_test_optim:Run:A](IMPORTANT): Trying to run Optim and Multiray forreal
2025-04-07T18:20:00.514Z,1744050000.514 [lab_test_optim:Run:A] Stopped
2025-04-07T18:20:00.514Z,1744050000.514 [lab_test_optim:Run:B] Running Loop=1
2025-04-07T18:20:00.922Z,1744050000.922 [lab_test_optim:Run:B] Stopped
2025-04-07T18:20:00.922Z,1744050000.922 [lab_test_optim:Run:C] Running Loop=1
2025-04-07T18:20:01.330Z,1744050001.330 [lab_test_optim:Run:C] Stopped
2025-04-07T18:20:01.330Z,1744050001.330 [lab_test_optim:Run:D] Running Loop=1
2025-04-07T18:20:01.330Z,1744050001.330 [lab_test_optim:C] Running Loop=1
2025-04-07T18:20:01.330Z,1744050001.330 [lab_test_optim:C] Running Loop=1
2025-04-07T18:20:01.331Z,1744050001.331 [lab_test_optim:C](DEBUG): Initialize ReadDataComponent to sense PowerOnly.sampleLoad1
2025-04-07T18:20:01.703Z,1744050001.703 [PowerOnly](INFO): Powering up loadControl
2025-04-07T18:20:01.759Z,1744050001.759 [lab_test_optim:Run:D] Stopped
2025-04-07T18:20:01.759Z,1744050001.759 [lab_test_optim:Run:setRed] Running Loop=1
2025-04-07T18:20:01.759Z,1744050001.759 [lab_test_optim:Run:setRed](DEBUG): Aggregate::initialize lab_test_optim:Run:setRed
2025-04-07T18:20:01.759Z,1744050001.759 [lab_test_optim:Run:setRed:A] Running Loop=1
2025-04-07T18:20:01.759Z,1744050001.759 [lab_test_optim:D] Running Loop=1
2025-04-07T18:20:01.759Z,1744050001.759 [lab_test_optim:D] Running Loop=1
2025-04-07T18:20:01.760Z,1744050001.760 [lab_test_optim:D](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog
2025-04-07T18:20:02.116Z,1744050002.116 [lab_test_optim:Run:setRed] Stopped
2025-04-07T18:20:02.117Z,1744050002.117 [lab_test_optim:Run:setRed](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setRed
2025-04-07T18:20:02.117Z,1744050002.117 [lab_test_optim:Run:setRed:A] Stopped
2025-04-07T18:20:02.121Z,1744050002.121 [lab_test_optim:Run:setWhite] Running Loop=1
2025-04-07T18:20:02.121Z,1744050002.121 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::initialize lab_test_optim:Run:setWhite
2025-04-07T18:20:02.121Z,1744050002.121 [lab_test_optim:Run:setWhite:A] Running Loop=1
2025-04-07T18:20:02.575Z,1744050002.575 [lab_test_optim:Run:setWhite:A] Stopped
2025-04-07T18:20:02.575Z,1744050002.575 [lab_test_optim:Run:setWhite:B] Running Loop=1
2025-04-07T18:20:02.964Z,1744050002.964 [lab_test_optim:Run:setWhite:B](INFO): Setting muliray white brightness to 100.000000 count
2025-04-07T18:20:02.964Z,1744050002.964 [lab_test_optim:Run:setWhite:B] Stopped
2025-04-07T18:20:02.964Z,1744050002.964 [lab_test_optim:Run:setWhite](INFO): Completed lab_test_optim:Run:setWhite
2025-04-07T18:20:02.964Z,1744050002.964 [lab_test_optim:Run:setWhite] Stopped
2025-04-07T18:20:02.964Z,1744050002.964 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setWhite
2025-04-07T18:20:02.964Z,1744050002.964 [lab_test_optim:Run:G] Running Loop=1
2025-04-07T18:20:03.331Z,1744050003.331 [lab_test_optim:Run:G](IMPORTANT): Recording for 1.000000 min
2025-04-07T18:20:03.331Z,1744050003.331 [lab_test_optim:Run:G] Stopped
2025-04-07T18:20:03.331Z,1744050003.331 [lab_test_optim:Run:H.Wait] Running Loop=1
2025-04-07T18:20:03.331Z,1744050003.331 [lab_test_optim:Run:H.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:20:04.132Z,1744050004.132 [MultiRay](IMPORTANT): MultiRay white lights ON
2025-04-07T18:20:05.747Z,1744050005.747 [NAL9602](INFO): Powering up NAL9602
2025-04-07T18:20:07.942Z,1744050007.942 [CommandExec](IMPORTANT): got command stop
2025-04-07T18:20:07.942Z,1744050007.942 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-04-07T18:20:08.185Z,1744050008.185 [MissionManager](INFO): MissionManager is completed.
2025-04-07T18:20:08.185Z,1744050008.185 [MissionManager](INFO): Uninitializing Mission lab_test_optim
2025-04-07T18:20:08.185Z,1744050008.185 [lab_test_optim] Stopped
2025-04-07T18:20:08.185Z,1744050008.185 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim
2025-04-07T18:20:08.185Z,1744050008.185 [lab_test_optim:BackseatDriver] Stopped
2025-04-07T18:20:08.186Z,1744050008.186 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver
2025-04-07T18:20:08.186Z,1744050008.186 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped
2025-04-07T18:20:08.186Z,1744050008.186 [lab_test_optim:B] Stopped
2025-04-07T18:20:08.186Z,1744050008.186 [lab_test_optim:C] Stopped
2025-04-07T18:20:08.186Z,1744050008.186 [lab_test_optim:D] Stopped
2025-04-07T18:20:08.186Z,1744050008.186 [lab_test_optim:Run] Stopped
2025-04-07T18:20:08.186Z,1744050008.186 [lab_test_optim:Run](DEBUG): Aggregate::uninitialize lab_test_optim:Run
2025-04-07T18:20:08.186Z,1744050008.186 [lab_test_optim:Run:H.Wait] Stopped
2025-04-07T18:20:08.186Z,1744050008.186 [lab_test_optim:Run:H.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:20:08.582Z,1744050008.582 [MissionManager](IMPORTANT): Started mission Default
2025-04-07T18:20:08.583Z,1744050008.583 [Default] Running Loop=1
2025-04-07T18:20:08.583Z,1744050008.583 [Default](DEBUG): Aggregate::initialize Default
2025-04-07T18:20:08.583Z,1744050008.583 [Default:B.GoToSurface] Running Loop=1
2025-04-07T18:20:08.583Z,1744050008.583 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-04-07T18:20:08.583Z,1744050008.583 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-04-07T18:20:08.583Z,1744050008.583 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-04-07T18:20:08.584Z,1744050008.584 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-04-07T18:20:08.584Z,1744050008.584 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-04-07T18:20:08.584Z,1744050008.584 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-04-07T18:20:08.585Z,1744050008.585 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-04-07T18:20:08.585Z,1744050008.585 [Default:A.Wait] Running Loop=1
2025-04-07T18:20:08.585Z,1744050008.585 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:20:08.984Z,1744050008.984 [MultiRay](INFO): Powering down
2025-04-07T18:20:09.102Z,1744050009.102 [MultiRay](INFO): Powering down LCB2
2025-04-07T18:20:10.322Z,1744050010.322 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-04-07T18:20:10.323Z,1744050010.323 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-04-07T18:20:16.655Z,1744050016.655 [NAL9602](INFO): NAL9602 initialized
2025-04-07T18:20:21.916Z,1744050021.916 [Default:A.Wait](INFO): Done Waiting.
2025-04-07T18:20:21.916Z,1744050021.916 [Default:A.Wait] Stopped
2025-04-07T18:20:21.916Z,1744050021.916 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:20:22.320Z,1744050022.320 [Default:CheckIn] Running Loop=1
2025-04-07T18:20:22.320Z,1744050022.320 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:20:22.320Z,1744050022.320 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:20:28.482Z,1744050028.482 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-04-07T18:20:28.482Z,1744050028.482 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-04-07T18:20:28.482Z,1744050028.482 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-04-07T18:20:56.255Z,1744050056.255 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-04-07T18:20:56.255Z,1744050056.255 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T18:20:56.266Z,1744050056.266 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T18:20:56.676Z,1744050056.676 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T18:20:56.676Z,1744050056.676 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-04-07T18:21:38.669Z,1744050098.669 [PowerOnly](INFO): Powering down loadControl
2025-04-07T18:23:57.257Z,1744050237.257 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-04-07T18:23:57.257Z,1744050237.257 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T18:23:57.268Z,1744050237.268 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T18:23:57.685Z,1744050237.685 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T18:23:57.685Z,1744050237.685 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-04-07T18:25:22.495Z,1744050322.495 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-04-07T18:20:22.3Z
2025-04-07T18:25:22.495Z,1744050322.495 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:25:22.496Z,1744050322.496 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:25:22.899Z,1744050322.899 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-04-07T18:25:23.428Z,1744050323.428 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250407T180841/Courier0000.lzma
2025-04-07T18:25:24.183Z,1744050324.183 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0000.lzma.bak
2025-04-07T18:25:24.183Z,1744050324.183 [DataOverHttps](INFO): SBD MOMSN=24562602
2025-04-07T18:25:42.234Z,1744050342.234 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20250407T180841/Courier0004.lzma
2025-04-07T18:25:43.235Z,1744050343.235 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0004.lzma.bak
2025-04-07T18:25:43.235Z,1744050343.235 [DataOverHttps](INFO): SBD MOMSN=24562609
2025-04-07T18:25:59.522Z,1744050359.522 [DataOverHttps](INFO): Sending 337 bytes from file Logs/20250407T172037/Express0008.lzma
2025-04-07T18:26:00.523Z,1744050360.523 [DataOverHttps](INFO): Moved sent file to Logs/20250407T172037/Express0008.lzma.bak
2025-04-07T18:26:00.523Z,1744050360.523 [DataOverHttps](INFO): SBD MOMSN=24562611
2025-04-07T18:26:16.182Z,1744050376.182 [DataOverHttps](INFO): Sending 878 bytes from file Logs/20250407T173607/Express0001.lzma
2025-04-07T18:26:17.183Z,1744050377.183 [DataOverHttps](INFO): Moved sent file to Logs/20250407T173607/Express0001.lzma.bak
2025-04-07T18:26:17.183Z,1744050377.183 [DataOverHttps](INFO): SBD MOMSN=24562633
2025-04-07T18:26:32.838Z,1744050392.838 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20250407T173607/Express0005.lzma
2025-04-07T18:26:33.839Z,1744050393.839 [DataOverHttps](INFO): Moved sent file to Logs/20250407T173607/Express0005.lzma.bak
2025-04-07T18:26:33.839Z,1744050393.839 [DataOverHttps](INFO): SBD MOMSN=24562655
2025-04-07T18:26:50.794Z,1744050410.794 [DataOverHttps](INFO): Sending 844 bytes from file Logs/20250407T173607/Express0008.lzma
2025-04-07T18:26:52.799Z,1744050412.799 [DataOverHttps](INFO): Moved sent file to Logs/20250407T173607/Express0008.lzma.bak
2025-04-07T18:26:52.799Z,1744050412.799 [DataOverHttps](INFO): SBD MOMSN=24562660
2025-04-07T18:26:58.318Z,1744050418.318 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2025-04-07T18:26:58.318Z,1744050418.318 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-04-07T18:26:58.333Z,1744050418.333 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-04-07T18:26:58.744Z,1744050418.744 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-04-07T18:26:58.744Z,1744050418.744 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2025-04-07T18:27:09.516Z,1744050429.516 [DataOverHttps](INFO): Sending 1005 bytes from file Logs/20250407T174357/Express0001.lzma
2025-04-07T18:27:10.515Z,1744050430.515 [DataOverHttps](INFO): Moved sent file to Logs/20250407T174357/Express0001.lzma.bak
2025-04-07T18:27:10.515Z,1744050430.515 [DataOverHttps](INFO): SBD MOMSN=24562702
2025-04-07T18:27:26.153Z,1744050446.153 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250407T174357/Express0004.lzma
2025-04-07T18:27:27.156Z,1744050447.156 [DataOverHttps](INFO): Moved sent file to Logs/20250407T174357/Express0004.lzma.bak
2025-04-07T18:27:27.156Z,1744050447.156 [DataOverHttps](INFO): SBD MOMSN=24562745
2025-04-07T18:27:35.462Z,1744050455.462 [DataOverHttps](IMPORTANT): SBD MTMSN=20250407T182734
2025-04-07T18:27:46.237Z,1744050466.237 [DataOverHttps](INFO): Sending 113 bytes from file Logs/20250407T174357/Express0007.lzma
2025-04-07T18:27:46.239Z,1744050466.239 [DataOverHttps](INFO): Received command: ibit
2025-04-07T18:27:46.282Z,1744050466.282 [CommandExec](IMPORTANT): got command ibit
2025-04-07T18:27:46.476Z,1744050466.476 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-04-07T18:27:46.476Z,1744050466.476 [IBIT](IMPORTANT): Beginning control surface checks.
2025-04-07T18:27:46.527Z,1744050466.527 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-07T18:27:47.601Z,1744050467.601 [DataOverHttps](INFO): Moved sent file to Logs/20250407T174357/Express0007.lzma.bak
2025-04-07T18:27:47.602Z,1744050467.602 [DataOverHttps](INFO): SBD MOMSN=24562755
2025-04-07T18:27:51.073Z,1744050471.073 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006625
CHAN A1 (24V): 0.000625
CHAN A2 (12V): -0.005410
CHAN A3 (5V): -0.002527
CHAN B0 (3.3V): -0.001229
CHAN B1 (3.15aV): -0.001809
CHAN B2 (3.15bV): -0.001175
CHAN B3 (GND): -0.000774
OPEN: 0.005192
Full Scale: +/- 1 mA
2025-04-07T18:27:59.778Z,1744050479.778 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182758.00,A,3648.14425,N,12147.25184,W,1.225,175.77,070425,,,A*7A
2025-04-07T18:27:59.785Z,1744050479.785 [NAL9602](INFO): GPS fix at 20250407T182758: (36.802404, -121.787531)
2025-04-07T18:28:03.004Z,1744050483.004 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182801.00,A,3648.14367,N,12147.24989,W,1.730,175.77,070425,,,A*7D
2025-04-07T18:28:03.007Z,1744050483.007 [NAL9602](INFO): GPS fix at 20250407T182801: (36.802394, -121.787498)
2025-04-07T18:28:03.373Z,1744050483.373 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250407T180841/Courier0010.lzma
2025-04-07T18:28:04.483Z,1744050484.483 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0010.lzma.bak
2025-04-07T18:28:04.483Z,1744050484.483 [DataOverHttps](INFO): SBD MOMSN=24562763
2025-04-07T18:28:05.828Z,1744050485.828 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182804.00,A,3648.14281,N,12147.24792,W,3.188,130.67,070425,,,A*72
2025-04-07T18:28:05.839Z,1744050485.839 [NAL9602](INFO): GPS fix at 20250407T182804: (36.802380, -121.787465)
2025-04-07T18:28:09.064Z,1744050489.064 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182807.00,A,3648.14216,N,12147.24530,W,2.002,118.74,070425,,,A*7F
2025-04-07T18:28:09.079Z,1744050489.079 [NAL9602](INFO): GPS fix at 20250407T182807: (36.802369, -121.787422)
2025-04-07T18:28:11.891Z,1744050491.891 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182810.00,A,3648.14248,N,12147.24318,W,1.497,118.74,070425,,,A*75
2025-04-07T18:28:11.893Z,1744050491.893 [NAL9602](INFO): GPS fix at 20250407T182810: (36.802375, -121.787386)
2025-04-07T18:28:14.720Z,1744050494.720 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182813.00,A,3648.14246,N,12147.24269,W,1.050,118.74,070425,,,A*70
2025-04-07T18:28:14.723Z,1744050494.723 [NAL9602](INFO): GPS fix at 20250407T182813: (36.802374, -121.787378)
2025-04-07T18:28:17.948Z,1744050497.948 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182816.00,A,3648.14216,N,12147.24294,W,0.097,118.74,070425,,,A*78
2025-04-07T18:28:17.950Z,1744050497.950 [NAL9602](INFO): GPS fix at 20250407T182816: (36.802369, -121.787382)
2025-04-07T18:28:20.697Z,1744050500.697 [DataOverHttps](INFO): Sending 65 bytes from file Logs/20250407T174357/Express0008.lzma
2025-04-07T18:28:20.779Z,1744050500.779 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182819.00,A,3648.14207,N,12147.24335,W,1.050,118.74,070425,,,A*77
2025-04-07T18:28:20.781Z,1744050500.781 [NAL9602](INFO): GPS fix at 20250407T182819: (36.802368, -121.787389)
2025-04-07T18:28:21.703Z,1744050501.703 [DataOverHttps](INFO): Moved sent file to Logs/20250407T174357/Express0008.lzma.bak
2025-04-07T18:28:21.703Z,1744050501.703 [DataOverHttps](INFO): SBD MOMSN=24562791
2025-04-07T18:28:24.012Z,1744050504.012 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182822.00,A,3648.14203,N,12147.24395,W,0.097,118.74,070425,,,A*7B
2025-04-07T18:28:24.015Z,1744050504.015 [NAL9602](INFO): GPS fix at 20250407T182822: (36.802367, -121.787399)
2025-04-07T18:28:26.840Z,1744050506.840 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182825.00,A,3648.14201,N,12147.24430,W,0.739,118.74,070425,,,A*75
2025-04-07T18:28:26.843Z,1744050506.843 [NAL9602](INFO): GPS fix at 20250407T182825: (36.802367, -121.787405)
2025-04-07T18:28:30.068Z,1744050510.068 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182828.00,A,3648.14221,N,12147.24479,W,0.214,118.74,070425,,,A*7D
2025-04-07T18:28:30.071Z,1744050510.071 [NAL9602](INFO): GPS fix at 20250407T182828: (36.802370, -121.787413)
2025-04-07T18:28:32.897Z,1744050512.897 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182831.00,A,3648.14226,N,12147.24554,W,0.311,118.74,070425,,,A*78
2025-04-07T18:28:32.899Z,1744050512.899 [NAL9602](INFO): GPS fix at 20250407T182831: (36.802371, -121.787426)
2025-04-07T18:28:35.724Z,1744050515.724 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182834.00,A,3648.14207,N,12147.24618,W,0.428,118.74,070425,,,A*78
2025-04-07T18:28:35.739Z,1744050515.739 [NAL9602](INFO): GPS fix at 20250407T182834: (36.802368, -121.787436)
2025-04-07T18:28:37.686Z,1744050517.686 [DataOverHttps](INFO): Sending 519 bytes from file Logs/20250407T174357/Express0010.lzma
2025-04-07T18:28:38.687Z,1744050518.687 [DataOverHttps](INFO): Moved sent file to Logs/20250407T174357/Express0010.lzma.bak
2025-04-07T18:28:38.687Z,1744050518.687 [DataOverHttps](INFO): SBD MOMSN=24562794
2025-04-07T18:28:38.971Z,1744050518.971 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182837.00,A,3648.14194,N,12147.24685,W,0.156,118.74,070425,,,A*7A
2025-04-07T18:28:38.974Z,1744050518.974 [NAL9602](INFO): GPS fix at 20250407T182837: (36.802366, -121.787447)
2025-04-07T18:28:41.792Z,1744050521.792 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182840.00,A,3648.14189,N,12147.24713,W,0.447,118.74,070425,,,A*7D
2025-04-07T18:28:41.799Z,1744050521.799 [NAL9602](INFO): GPS fix at 20250407T182840: (36.802365, -121.787452)
2025-04-07T18:28:45.020Z,1744050525.020 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182843.00,A,3648.14221,N,12147.24611,W,0.855,118.74,070425,,,A*73
2025-04-07T18:28:45.023Z,1744050525.023 [NAL9602](INFO): GPS fix at 20250407T182843: (36.802370, -121.787435)
2025-04-07T18:28:47.845Z,1744050527.845 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182846.00,A,3648.14209,N,12147.24523,W,1.127,118.74,070425,,,A*73
2025-04-07T18:28:47.847Z,1744050527.847 [NAL9602](INFO): GPS fix at 20250407T182846: (36.802368, -121.787420)
2025-04-07T18:28:51.080Z,1744050531.080 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182849.00,A,3648.14043,N,12147.24467,W,2.974,147.90,070425,,,A*7C
2025-04-07T18:28:51.082Z,1744050531.082 [NAL9602](INFO): GPS fix at 20250407T182849: (36.802340, -121.787411)
2025-04-07T18:28:53.904Z,1744050533.904 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182852.00,A,3648.13794,N,12147.24351,W,2.916,153.80,070425,,,A*7E
2025-04-07T18:28:53.907Z,1744050533.907 [NAL9602](INFO): GPS fix at 20250407T182852: (36.802299, -121.787392)
2025-04-07T18:28:54.723Z,1744050534.723 [DataOverHttps](INFO): Sending 877 bytes from file Logs/20250407T174842/Express0001.lzma
2025-04-07T18:28:55.723Z,1744050535.723 [DataOverHttps](INFO): Moved sent file to Logs/20250407T174842/Express0001.lzma.bak
2025-04-07T18:28:55.723Z,1744050535.723 [DataOverHttps](INFO): SBD MOMSN=24562837
2025-04-07T18:28:56.752Z,1744050536.752 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182855.00,A,3648.13789,N,12147.24041,W,2.527,100.09,070425,,,A*7E
2025-04-07T18:28:56.757Z,1744050536.757 [NAL9602](INFO): GPS fix at 20250407T182855: (36.802298, -121.787340)
2025-04-07T18:28:59.984Z,1744050539.984 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182858.00,A,3648.13874,N,12147.23761,W,2.488,73.37,070425,,,A*40
2025-04-07T18:28:59.987Z,1744050539.987 [NAL9602](INFO): GPS fix at 20250407T182858: (36.802312, -121.787294)
2025-04-07T18:29:02.820Z,1744050542.820 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182901.00,A,3648.13953,N,12147.23641,W,1.283,69.29,070425,,,A*40
2025-04-07T18:29:02.822Z,1744050542.822 [NAL9602](INFO): GPS fix at 20250407T182901: (36.802326, -121.787273)
2025-04-07T18:29:06.045Z,1744050546.045 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182904.00,A,3648.14018,N,12147.23573,W,1.127,69.29,070425,,,A*4B
2025-04-07T18:29:06.047Z,1744050546.047 [NAL9602](INFO): GPS fix at 20250407T182904: (36.802336, -121.787262)
2025-04-07T18:29:08.904Z,1744050548.904 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182907.00,A,3648.14078,N,12147.23521,W,0.700,69.29,070425,,,A*4B
2025-04-07T18:29:08.907Z,1744050548.907 [NAL9602](INFO): GPS fix at 20250407T182907: (36.802346, -121.787254)
2025-04-07T18:29:11.725Z,1744050551.725 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182910.00,A,3648.14087,N,12147.23465,W,0.136,69.29,070425,,,A*4F
2025-04-07T18:29:11.727Z,1744050551.727 [NAL9602](INFO): GPS fix at 20250407T182910: (36.802348, -121.787244)
2025-04-07T18:29:11.775Z,1744050551.775 [DataOverHttps](INFO): Sending 804 bytes from file Logs/20250407T174842/Express0005.lzma
2025-04-07T18:29:12.775Z,1744050552.775 [DataOverHttps](INFO): Moved sent file to Logs/20250407T174842/Express0005.lzma.bak
2025-04-07T18:29:12.775Z,1744050552.775 [DataOverHttps](INFO): SBD MOMSN=24562859
2025-04-07T18:29:14.959Z,1744050554.959 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182913.00,A,3648.14103,N,12147.23414,W,0.389,69.29,070425,,,A*41
2025-04-07T18:29:14.961Z,1744050554.961 [NAL9602](INFO): GPS fix at 20250407T182913: (36.802351, -121.787236)
2025-04-07T18:29:17.788Z,1744050557.788 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182916.00,A,3648.14126,N,12147.23337,W,0.408,69.29,070425,,,A*4B
2025-04-07T18:29:17.791Z,1744050557.791 [NAL9602](INFO): GPS fix at 20250407T182916: (36.802354, -121.787223)
2025-04-07T18:29:21.016Z,1744050561.016 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182919.00,A,3648.14132,N,12147.23332,W,0.136,69.29,070425,,,D*49
2025-04-07T18:29:21.018Z,1744050561.018 [NAL9602](INFO): GPS fix at 20250407T182919: (36.802355, -121.787222)
2025-04-07T18:29:23.845Z,1744050563.845 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182922.00,A,3648.14128,N,12147.23279,W,0.117,69.29,070425,,,D*47
2025-04-07T18:29:23.847Z,1744050563.847 [NAL9602](INFO): GPS fix at 20250407T182922: (36.802355, -121.787213)
2025-04-07T18:29:27.076Z,1744050567.076 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182925.00,A,3648.14035,N,12147.23142,W,0.078,69.29,070425,,,D*4E
2025-04-07T18:29:27.078Z,1744050567.078 [NAL9602](INFO): GPS fix at 20250407T182925: (36.802339, -121.787190)
2025-04-07T18:29:29.578Z,1744050569.578 [DataOverHttps](INFO): Sending 874 bytes from file Logs/20250407T175457/Express0001.lzma
2025-04-07T18:29:29.907Z,1744050569.907 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182928.00,A,3648.14044,N,12147.23055,W,0.000,69.29,070425,,,D*4D
2025-04-07T18:29:29.909Z,1744050569.909 [NAL9602](INFO): GPS fix at 20250407T182928: (36.802341, -121.787176)
2025-04-07T18:29:30.579Z,1744050570.579 [DataOverHttps](INFO): Moved sent file to Logs/20250407T175457/Express0001.lzma.bak
2025-04-07T18:29:30.579Z,1744050570.579 [DataOverHttps](INFO): SBD MOMSN=24562896
2025-04-07T18:29:32.733Z,1744050572.733 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182931.00,A,3648.14058,N,12147.23025,W,0.019,69.29,070425,,,D*47
2025-04-07T18:29:32.736Z,1744050572.736 [NAL9602](INFO): GPS fix at 20250407T182931: (36.802343, -121.787171)
2025-04-07T18:29:35.968Z,1744050575.968 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182934.00,A,3648.14068,N,12147.23012,W,0.078,69.29,070425,,,D*42
2025-04-07T18:29:35.971Z,1744050575.971 [NAL9602](INFO): GPS fix at 20250407T182934: (36.802345, -121.787169)
2025-04-07T18:29:37.650Z,1744050577.650 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2025-04-07T18:29:38.010Z,1744050578.010 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.611000
2025-04-07T18:29:38.010Z,1744050578.010 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2025-04-07T18:29:38.010Z,1744050578.010 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2025-04-07T18:29:38.438Z,1744050578.438 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2025-04-07T18:29:38.439Z,1744050578.439 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2025-04-07T18:29:38.439Z,1744050578.439 [IBIT](IMPORTANT): Pressure:9.928683 PSI
2025-04-07T18:29:38.439Z,1744050578.439 [IBIT](IMPORTANT): Humidity:8.698571 %
2025-04-07T18:29:38.808Z,1744050578.808 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182937.00,A,3648.14062,N,12147.23012,W,0.136,69.29,070425,,,D*40
2025-04-07T18:29:38.810Z,1744050578.810 [NAL9602](INFO): GPS fix at 20250407T182937: (36.802344, -121.787169)
2025-04-07T18:29:38.878Z,1744050578.878 [IBIT](IMPORTANT): Vehicle Pitch:-1.026711 degrees
2025-04-07T18:29:38.879Z,1744050578.879 [IBIT](IMPORTANT): Vehicle Roll:-1.389865 degrees
2025-04-07T18:29:38.879Z,1744050578.879 [IBIT](IMPORTANT): Vehicle Heading:3.259120 degrees
2025-04-07T18:29:39.234Z,1744050579.234 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2025-04-07T18:29:39.235Z,1744050579.235 [IBIT](IMPORTANT): buoyancyNeutral: 241.314621 cc
2025-04-07T18:29:39.235Z,1744050579.235 [IBIT](IMPORTANT): massDefault: 1.035238 cm
2025-04-07T18:29:39.235Z,1744050579.235 [IBIT](IMPORTANT): stopDepth: 290.000000 m
2025-04-07T18:29:39.235Z,1744050579.235 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2025-04-07T18:29:39.235Z,1744050579.235 [IBIT](IMPORTANT): IBIT FAILED
2025-04-07T18:29:49.833Z,1744050589.833 [DataOverHttps](INFO): Sending 296 bytes from file Logs/20250407T175457/Express0005.lzma
2025-04-07T18:29:50.835Z,1744050590.835 [DataOverHttps](INFO): Moved sent file to Logs/20250407T175457/Express0005.lzma.bak
2025-04-07T18:29:50.835Z,1744050590.835 [DataOverHttps](INFO): SBD MOMSN=24562918
2025-04-07T18:29:52.615Z,1744050592.615 [CommandExec](IMPORTANT): got command show variable sigquality
2025-04-07T18:29:52.784Z,1744050592.784 [CommandExec](IMPORTANT): NAL9602.sigQuality (count)
2025-04-07T18:30:02.171Z,1744050602.171 [CommandExec](IMPORTANT): got command report touch NAL9602.sigQuality
2025-04-07T18:30:03.522Z,1744050603.522 [CommandExec](IMPORTANT): got command ibit
2025-04-07T18:30:03.526Z,1744050603.526 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-04-07T18:30:03.526Z,1744050603.526 [IBIT](IMPORTANT): Beginning control surface checks.
2025-04-07T18:30:03.553Z,1744050603.553 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-07T18:30:05.120Z,1744050605.120 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183003.00,A,3648.14017,N,12147.23022,W,0.078,69.29,070425,,,D*45
2025-04-07T18:30:05.126Z,1744050605.126 [NAL9602](INFO): GPS fix at 20250407T183003: (36.802336, -121.787170)
2025-04-07T18:30:07.223Z,1744050607.223 [DataOverHttps](INFO): Sending 1005 bytes from file Logs/20250407T175457/Express0008.lzma
2025-04-07T18:30:07.936Z,1744050607.936 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183006.00,A,3648.14003,N,12147.23035,W,0.078,69.29,070425,,,D*43
2025-04-07T18:30:07.938Z,1744050607.938 [NAL9602](INFO): GPS fix at 20250407T183006: (36.802334, -121.787172)
2025-04-07T18:30:08.117Z,1744050608.117 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006230
CHAN A1 (24V): 0.000739
CHAN A2 (12V): -0.005784
CHAN A3 (5V): -0.002652
CHAN B0 (3.3V): -0.001726
CHAN B1 (3.15aV): -0.000997
CHAN B2 (3.15bV): -0.001637
CHAN B3 (GND): -0.000188
OPEN: 0.005176
Full Scale: +/- 1 mA
2025-04-07T18:30:08.223Z,1744050608.223 [DataOverHttps](INFO): Moved sent file to Logs/20250407T175457/Express0008.lzma.bak
2025-04-07T18:30:08.223Z,1744050608.223 [DataOverHttps](INFO): SBD MOMSN=24562927
2025-04-07T18:30:10.765Z,1744050610.765 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183009.00,A,3648.13996,N,12147.23037,W,0.058,69.29,070425,,,D*4E
2025-04-07T18:30:10.767Z,1744050610.767 [NAL9602](INFO): GPS fix at 20250407T183009: (36.802333, -121.787173)
2025-04-07T18:30:13.996Z,1744050613.996 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183012.00,A,3648.14001,N,12147.23043,W,0.039,69.29,070425,,,D*40
2025-04-07T18:30:14.011Z,1744050614.011 [NAL9602](INFO): GPS fix at 20250407T183012: (36.802334, -121.787174)
2025-04-07T18:30:16.826Z,1744050616.826 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183015.00,A,3648.14003,N,12147.23044,W,0.058,69.29,070425,,,D*45
2025-04-07T18:30:16.828Z,1744050616.828 [NAL9602](INFO): GPS fix at 20250407T183015: (36.802334, -121.787174)
2025-04-07T18:30:20.060Z,1744050620.060 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183018.00,A,3648.14009,N,12147.23045,W,0.039,69.29,070425,,,D*44
2025-04-07T18:30:20.063Z,1744050620.063 [NAL9602](INFO): GPS fix at 20250407T183018: (36.802335, -121.787174)
2025-04-07T18:30:22.884Z,1744050622.884 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183021.00,A,3648.14015,N,12147.23045,W,0.039,69.29,070425,,,D*43
2025-04-07T18:30:22.886Z,1744050622.886 [NAL9602](INFO): GPS fix at 20250407T183021: (36.802336, -121.787174)
2025-04-07T18:30:24.250Z,1744050624.250 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250407T175457/Express0011.lzma
2025-04-07T18:30:25.247Z,1744050625.247 [DataOverHttps](INFO): Moved sent file to Logs/20250407T175457/Express0011.lzma.bak
2025-04-07T18:30:25.247Z,1744050625.247 [DataOverHttps](INFO): SBD MOMSN=24562987
2025-04-07T18:30:26.119Z,1744050626.119 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183024.00,A,3648.14021,N,12147.23051,W,0.039,69.29,070425,,,D*44
2025-04-07T18:30:26.121Z,1744050626.121 [NAL9602](INFO): GPS fix at 20250407T183024: (36.802337, -121.787175)
2025-04-07T18:30:28.948Z,1744050628.948 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183027.00,A,3648.14028,N,12147.23049,W,0.019,69.29,070425,,,D*45
2025-04-07T18:30:28.951Z,1744050628.951 [NAL9602](INFO): GPS fix at 20250407T183027: (36.802338, -121.787175)
2025-04-07T18:30:31.776Z,1744050631.776 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183030.00,A,3648.14030,N,12147.23055,W,0.019,69.29,070425,,,D*47
2025-04-07T18:30:31.778Z,1744050631.778 [NAL9602](INFO): GPS fix at 20250407T183030: (36.802338, -121.787176)
2025-04-07T18:30:35.013Z,1744050635.013 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183033.00,A,3648.14031,N,12147.23060,W,0.019,69.29,070425,,,D*43
2025-04-07T18:30:35.015Z,1744050635.015 [NAL9602](INFO): GPS fix at 20250407T183033: (36.802338, -121.787177)
2025-04-07T18:30:37.843Z,1744050637.843 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183036.00,A,3648.14031,N,12147.23076,W,0.019,69.29,070425,,,D*41
2025-04-07T18:30:37.846Z,1744050637.846 [NAL9602](INFO): GPS fix at 20250407T183036: (36.802338, -121.787179)
2025-04-07T18:30:41.074Z,1744050641.074 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183039.00,A,3648.14044,N,12147.23082,W,0.156,69.29,070425,,,D*4D
2025-04-07T18:30:41.076Z,1744050641.076 [NAL9602](INFO): GPS fix at 20250407T183039: (36.802341, -121.787180)
2025-04-07T18:30:41.361Z,1744050641.361 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250407T175457/Express0014.lzma
2025-04-07T18:30:42.363Z,1744050642.363 [DataOverHttps](INFO): Moved sent file to Logs/20250407T175457/Express0014.lzma.bak
2025-04-07T18:30:42.363Z,1744050642.363 [DataOverHttps](INFO): SBD MOMSN=24562995
2025-04-07T18:30:43.895Z,1744050643.895 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183042.00,A,3648.14049,N,12147.23079,W,0.136,69.29,070425,,,D*4E
2025-04-07T18:30:43.897Z,1744050643.897 [NAL9602](INFO): GPS fix at 20250407T183042: (36.802341, -121.787180)
2025-04-07T18:30:47.128Z,1744050647.128 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183045.00,A,3648.14058,N,12147.23067,W,0.039,69.29,070425,,,D*48
2025-04-07T18:30:47.131Z,1744050647.131 [NAL9602](INFO): GPS fix at 20250407T183045: (36.802343, -121.787178)
2025-04-07T18:30:49.953Z,1744050649.953 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183048.00,A,3648.14069,N,12147.23050,W,0.039,69.29,070425,,,D*43
2025-04-07T18:30:49.956Z,1744050649.956 [NAL9602](INFO): GPS fix at 20250407T183048: (36.802345, -121.787175)
2025-04-07T18:30:50.778Z,1744050650.778 [CommandExec](IMPORTANT): got command report
2025-04-07T18:30:50.778Z,1744050650.778 [Reporter](INFO): NAL9602.sigQuality reporting when touched
2025-04-07T18:30:52.780Z,1744050652.780 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183051.00,A,3648.14075,N,12147.23026,W,0.058,69.29,070425,,,D*40
2025-04-07T18:30:52.783Z,1744050652.783 [NAL9602](INFO): GPS fix at 20250407T183051: (36.802346, -121.787171)
2025-04-07T18:30:56.016Z,1744050656.016 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183054.00,A,3648.14076,N,12147.23006,W,0.097,69.29,070425,,,D*47
2025-04-07T18:30:56.019Z,1744050656.019 [NAL9602](INFO): GPS fix at 20250407T183054: (36.802346, -121.787168)
2025-04-07T18:30:58.351Z,1744050658.351 [DataOverHttps](INFO): Sending 897 bytes from file Logs/20250407T180841/Express0001.lzma
2025-04-07T18:30:58.840Z,1744050658.840 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183057.00,A,3648.14074,N,12147.23007,W,0.058,69.29,070425,,,D*44
2025-04-07T18:30:58.851Z,1744050658.851 [NAL9602](INFO): GPS fix at 20250407T183057: (36.802346, -121.787168)
2025-04-07T18:30:59.351Z,1744050659.351 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0001.lzma.bak
2025-04-07T18:30:59.351Z,1744050659.351 [DataOverHttps](INFO): SBD MOMSN=24563001
2025-04-07T18:31:02.077Z,1744050662.077 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183100.00,A,3648.14065,N,12147.23012,W,0.000,69.29,070425,,,D*4E
2025-04-07T18:31:02.088Z,1744050662.088 [NAL9602](INFO): GPS fix at 20250407T183100: (36.802344, -121.787169)
2025-04-07T18:31:04.918Z,1744050664.918 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183103.00,A,3648.14068,N,12147.23009,W,0.097,69.29,070425,,,D*44
2025-04-07T18:31:04.920Z,1744050664.920 [NAL9602](INFO): GPS fix at 20250407T183103: (36.802345, -121.787168)
2025-04-07T18:31:08.135Z,1744050668.135 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183106.00,A,3648.14058,N,12147.23029,W,0.097,69.29,070425,,,D*40
2025-04-07T18:31:08.137Z,1744050668.137 [NAL9602](INFO): GPS fix at 20250407T183106: (36.802343, -121.787171)
2025-04-07T18:31:10.969Z,1744050670.969 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183109.00,A,3648.14047,N,12147.23042,W,0.097,69.29,070425,,,D*4C
2025-04-07T18:31:10.971Z,1744050670.971 [NAL9602](INFO): GPS fix at 20250407T183109: (36.802341, -121.787174)
2025-04-07T18:31:13.788Z,1744050673.788 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183112.00,A,3648.14044,N,12147.23048,W,0.019,69.29,070425,,,D*49
2025-04-07T18:31:13.791Z,1744050673.791 [NAL9602](INFO): GPS fix at 20250407T183112: (36.802341, -121.787175)
2025-04-07T18:31:15.371Z,1744050675.371 [DataOverHttps](INFO): Sending 1070 bytes from file Logs/20250407T180841/Express0005.lzma
2025-04-07T18:31:16.371Z,1744050676.371 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0005.lzma.bak
2025-04-07T18:31:16.371Z,1744050676.371 [DataOverHttps](INFO): SBD MOMSN=24563027
2025-04-07T18:31:17.021Z,1744050677.021 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183115.00,A,3648.14048,N,12147.23055,W,0.058,69.29,070425,,,D*4B
2025-04-07T18:31:17.024Z,1744050677.024 [NAL9602](INFO): GPS fix at 20250407T183115: (36.802341, -121.787176)
2025-04-07T18:31:19.856Z,1744050679.856 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183118.00,A,3648.14050,N,12147.23050,W,0.097,69.29,070425,,,D*49
2025-04-07T18:31:19.863Z,1744050679.863 [NAL9602](INFO): GPS fix at 20250407T183118: (36.802342, -121.787175)
2025-04-07T18:31:23.092Z,1744050683.092 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183121.00,A,3648.14054,N,12147.23040,W,0.078,69.29,070425,,,D*47
2025-04-07T18:31:23.094Z,1744050683.094 [NAL9602](INFO): GPS fix at 20250407T183121: (36.802342, -121.787173)
2025-04-07T18:31:25.910Z,1744050685.910 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183124.00,A,3648.14070,N,12147.23038,W,0.039,69.29,070425,,,D*4E
2025-04-07T18:31:25.912Z,1744050685.912 [NAL9602](INFO): GPS fix at 20250407T183124: (36.802345, -121.787173)
2025-04-07T18:31:29.144Z,1744050689.144 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183127.00,A,3648.14095,N,12147.23027,W,0.253,69.29,070425,,,D*46
2025-04-07T18:31:29.146Z,1744050689.146 [NAL9602](INFO): GPS fix at 20250407T183127: (36.802349, -121.787171)
2025-04-07T18:31:31.976Z,1744050691.976 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183130.00,A,3648.14099,N,12147.23036,W,0.058,69.29,070425,,,D*45
2025-04-07T18:31:31.979Z,1744050691.979 [NAL9602](INFO): GPS fix at 20250407T183130: (36.802350, -121.787173)
2025-04-07T18:31:32.345Z,1744050692.345 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250407T180841/Express0008.lzma
2025-04-07T18:31:33.347Z,1744050693.347 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0008.lzma.bak
2025-04-07T18:31:33.347Z,1744050693.347 [DataOverHttps](INFO): SBD MOMSN=24563090
2025-04-07T18:31:34.797Z,1744050694.797 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183133.00,A,3648.14107,N,12147.23042,W,0.078,69.29,070425,,,D*41
2025-04-07T18:31:34.799Z,1744050694.799 [NAL9602](INFO): GPS fix at 20250407T183133: (36.802351, -121.787174)
2025-04-07T18:31:38.032Z,1744050698.032 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183136.00,A,3648.14123,N,12147.23037,W,0.039,69.29,070425,,,D*45
2025-04-07T18:31:38.035Z,1744050698.035 [NAL9602](INFO): GPS fix at 20250407T183136: (36.802354, -121.787173)
2025-04-07T18:31:40.319Z,1744050700.319 [CommandExec](IMPORTANT): got command get NAL9602.sigQuality
2025-04-07T18:31:40.320Z,1744050700.320 [CommandExec](IMPORTANT): NAL9602.sigQuality 0 count
2025-04-07T18:31:40.890Z,1744050700.890 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183139.00,A,3648.14139,N,12147.23034,W,0.039,69.29,070425,,,D*42
2025-04-07T18:31:40.892Z,1744050700.892 [NAL9602](INFO): GPS fix at 20250407T183139: (36.802357, -121.787172)
2025-04-07T18:31:43.662Z,1744050703.662 [CommandExec](IMPORTANT): got command report
2025-04-07T18:31:43.662Z,1744050703.662 [Reporter](INFO): NAL9602.sigQuality reporting when touched
2025-04-07T18:31:44.114Z,1744050704.114 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183142.00,A,3648.14153,N,12147.23030,W,0.117,69.29,070425,,,D*4B
2025-04-07T18:31:44.116Z,1744050704.116 [NAL9602](INFO): GPS fix at 20250407T183142: (36.802359, -121.787172)
2025-04-07T18:31:46.941Z,1744050706.941 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183145.00,A,3648.14156,N,12147.23025,W,0.039,69.29,070425,,,D*40
2025-04-07T18:31:46.944Z,1744050706.944 [NAL9602](INFO): GPS fix at 20250407T183145: (36.802359, -121.787171)
2025-04-07T18:31:49.772Z,1744050709.772 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183148.00,A,3648.14164,N,12147.23032,W,0.078,69.29,070425,,,D*4F
2025-04-07T18:31:49.775Z,1744050709.775 [NAL9602](INFO): GPS fix at 20250407T183148: (36.802361, -121.787172)
2025-04-07T18:31:53.008Z,1744050713.008 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183151.00,A,3648.14163,N,12147.23043,W,0.039,69.29,070425,,,D*43
2025-04-07T18:31:53.011Z,1744050713.011 [NAL9602](INFO): GPS fix at 20250407T183151: (36.802360, -121.787174)
2025-04-07T18:31:53.825Z,1744050713.825 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20250407T180841/Express0011.lzma
2025-04-07T18:31:54.827Z,1744050714.827 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0011.lzma.bak
2025-04-07T18:31:54.827Z,1744050714.827 [DataOverHttps](INFO): SBD MOMSN=24563092
2025-04-07T18:31:55.036Z,1744050715.036 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2025-04-07T18:31:55.452Z,1744050715.452 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.611000
2025-04-07T18:31:55.453Z,1744050715.453 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2025-04-07T18:31:55.453Z,1744050715.453 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2025-04-07T18:31:55.828Z,1744050715.828 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183154.00,A,3648.14170,N,12147.23042,W,0.019,69.29,070425,,,D*47
2025-04-07T18:31:55.856Z,1744050715.856 [NAL9602](INFO): GPS fix at 20250407T183154: (36.802362, -121.787174)
2025-04-07T18:31:55.882Z,1744050715.882 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2025-04-07T18:31:55.882Z,1744050715.882 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2025-04-07T18:31:55.883Z,1744050715.883 [IBIT](IMPORTANT): Pressure:9.902455 PSI
2025-04-07T18:31:55.883Z,1744050715.883 [IBIT](IMPORTANT): Humidity:8.674154 %
2025-04-07T18:31:56.271Z,1744050716.271 [IBIT](IMPORTANT): Vehicle Pitch:-1.041417 degrees
2025-04-07T18:31:56.271Z,1744050716.271 [IBIT](IMPORTANT): Vehicle Roll:-1.370939 degrees
2025-04-07T18:31:56.272Z,1744050716.272 [IBIT](IMPORTANT): Vehicle Heading:3.233220 degrees
2025-04-07T18:31:56.665Z,1744050716.665 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2025-04-07T18:31:56.666Z,1744050716.666 [IBIT](IMPORTANT): buoyancyNeutral: 241.314621 cc
2025-04-07T18:31:56.666Z,1744050716.666 [IBIT](IMPORTANT): massDefault: 1.035238 cm
2025-04-07T18:31:56.666Z,1744050716.666 [IBIT](IMPORTANT): stopDepth: 290.000000 m
2025-04-07T18:31:56.667Z,1744050716.667 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2025-04-07T18:31:56.667Z,1744050716.667 [IBIT](IMPORTANT): IBIT FAILED
2025-04-07T18:31:57.053Z,1744050717.053 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:31:57.053Z,1744050717.053 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:31:57.053Z,1744050717.053 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:32:08.050Z,1744050728.050 [CommandExec](IMPORTANT): got command failComponent
2025-04-07T18:32:08.050Z,1744050728.050 [CommandExec](IMPORTANT): Failed components:
2025-04-07T18:32:08.050Z,1744050728.050 [CommandExec](IMPORTANT): No failed Components.
2025-04-07T18:32:28.550Z,1744050748.550 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:32:28.571Z,1744050748.571 [Reporter](INFO): NAL9602.sigQuality 0 count
2025-04-07T18:32:35.366Z,1744050755.366 [CommandExec](IMPORTANT): got command ibit
2025-04-07T18:32:35.451Z,1744050755.451 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-04-07T18:32:35.451Z,1744050755.451 [IBIT](IMPORTANT): Beginning control surface checks.
2025-04-07T18:32:35.472Z,1744050755.472 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-04-07T18:32:37.042Z,1744050757.042 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183235.00,A,3648.14147,N,12147.22985,W,0.058,69.29,070425,,,D*41
2025-04-07T18:32:37.044Z,1744050757.044 [NAL9602](INFO): GPS fix at 20250407T183235: (36.802358, -121.787164)
2025-04-07T18:32:40.045Z,1744050760.045 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007225
CHAN A1 (24V): 0.000883
CHAN A2 (12V): -0.005528
CHAN A3 (5V): -0.002574
CHAN B0 (3.3V): -0.000864
CHAN B1 (3.15aV): -0.001538
CHAN B2 (3.15bV): -0.001196
CHAN B3 (GND): -0.000580
OPEN: 0.004983
Full Scale: +/- 1 mA
2025-04-07T18:32:43.158Z,1744050763.158 [Reporter](INFO): NAL9602.sigQuality 0 count
2025-04-07T18:32:51.640Z,1744050771.640 [Reporter](INFO): NAL9602.sigQuality 1 count
2025-04-07T18:32:56.131Z,1744050776.131 [Reporter](INFO): NAL9602.sigQuality 1 count
2025-04-07T18:33:00.630Z,1744050780.630 [Reporter](INFO): NAL9602.sigQuality 1 count
2025-04-07T18:33:04.719Z,1744050784.719 [Reporter](INFO): NAL9602.sigQuality 1 count
2025-04-07T18:33:08.647Z,1744050788.647 [Reporter](INFO): NAL9602.sigQuality 2 count
2025-04-07T18:33:21.502Z,1744050801.502 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802357 Longitude: -121.787163
2025-04-07T18:33:21.895Z,1744050801.895 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.611000
2025-04-07T18:33:21.895Z,1744050801.895 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2025-04-07T18:33:21.895Z,1744050801.895 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2025-04-07T18:33:22.302Z,1744050802.302 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2025-04-07T18:33:22.302Z,1744050802.302 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2025-04-07T18:33:22.303Z,1744050802.303 [IBIT](IMPORTANT): Pressure:9.885340 PSI
2025-04-07T18:33:22.303Z,1744050802.303 [IBIT](IMPORTANT): Humidity:8.637529 %
2025-04-07T18:33:22.710Z,1744050802.710 [IBIT](IMPORTANT): Vehicle Pitch:-1.050382 degrees
2025-04-07T18:33:22.710Z,1744050802.710 [IBIT](IMPORTANT): Vehicle Roll:-1.416658 degrees
2025-04-07T18:33:22.710Z,1744050802.710 [IBIT](IMPORTANT): Vehicle Heading:3.204807 degrees
2025-04-07T18:33:23.120Z,1744050803.120 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2025-04-07T18:33:23.122Z,1744050803.122 [IBIT](IMPORTANT): buoyancyNeutral: 241.314621 cc
2025-04-07T18:33:23.122Z,1744050803.122 [IBIT](IMPORTANT): massDefault: 1.035238 cm
2025-04-07T18:33:23.122Z,1744050803.122 [IBIT](IMPORTANT): stopDepth: 290.000000 m
2025-04-07T18:33:23.122Z,1744050803.122 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2025-04-07T18:33:23.123Z,1744050803.123 [IBIT](IMPORTANT): IBIT PASSED
2025-04-07T18:33:23.904Z,1744050803.904 [NAL9602](INFO): SBD MO Status=0, MOMSN=18820, MT Status=0, MTMSN=0
2025-04-07T18:33:23.904Z,1744050803.904 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:33:54.618Z,1744050834.618 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:33:54.695Z,1744050834.695 [Reporter](INFO): NAL9602.sigQuality 0 count
2025-04-07T18:34:34.054Z,1744050874.054 [DataOverHttps](IMPORTANT): SBD MTMSN=20250407T183433
2025-04-07T18:34:41.529Z,1744050881.529 [DataOverHttps](INFO): Received command: report clear
2025-04-07T18:34:41.582Z,1744050881.582 [CommandExec](IMPORTANT): got command report clear
2025-04-07T18:36:57.652Z,1744051017.652 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:36:57.652Z,1744051017.652 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:36:57.652Z,1744051017.652 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:36:57.652Z,1744051017.652 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:36:58.048Z,1744051018.048 [Default:CheckIn:D] Stopped
2025-04-07T18:36:58.048Z,1744051018.048 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:36:58.447Z,1744051018.447 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.824419 min
2025-04-07T18:36:58.447Z,1744051018.447 [Default:CheckIn:E] Stopped
2025-04-07T18:36:58.448Z,1744051018.448 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:36:58.448Z,1744051018.448 [Default:CheckIn] Stopped
2025-04-07T18:36:58.448Z,1744051018.448 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:36:58.448Z,1744051018.448 [Default:CheckIn](INFO): Running loop #2
2025-04-07T18:36:58.448Z,1744051018.448 [Default:CheckIn] Running Loop=2
2025-04-07T18:36:58.448Z,1744051018.448 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:36:58.448Z,1744051018.448 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:37:00.460Z,1744051020.460 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183658.00,A,3648.14959,N,12147.22658,W,0.117,29.52,070425,,,D*44
2025-04-07T18:37:00.463Z,1744051020.463 [NAL9602](INFO): GPS fix at 20250407T183658: (36.802493, -121.787110)
2025-04-07T18:37:00.511Z,1744051020.511 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:37:00.511Z,1744051020.511 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:37:03.383Z,1744051023.383 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20250407T180841/Courier0013.lzma
2025-04-07T18:37:04.123Z,1744051024.123 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0013.lzma.bak
2025-04-07T18:37:04.123Z,1744051024.123 [DataOverHttps](INFO): SBD MOMSN=24563165
2025-04-07T18:37:15.262Z,1744051035.262 [NAL9602](INFO): SBD MO Status=0, MOMSN=18821, MT Status=0, MTMSN=0
2025-04-07T18:37:15.262Z,1744051035.262 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:37:20.082Z,1744051040.082 [DataOverHttps](INFO): Sending 2408 bytes from file Logs/20250407T180841/Express0014.lzma
2025-04-07T18:37:21.079Z,1744051041.079 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0014.lzma.bak
2025-04-07T18:37:21.079Z,1744051041.079 [DataOverHttps](INFO): SBD MOMSN=24563170
2025-04-07T18:37:36.993Z,1744051056.993 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20250407T180841/Express0017.lzma
2025-04-07T18:37:37.995Z,1744051057.995 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0017.lzma.bak
2025-04-07T18:37:37.995Z,1744051057.995 [DataOverHttps](INFO): SBD MOMSN=24563321
2025-04-07T18:37:39.105Z,1744051059.105 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:37:39.105Z,1744051059.105 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:37:39.105Z,1744051059.105 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:37:46.021Z,1744051066.021 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:42:39.753Z,1744051359.753 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:42:39.753Z,1744051359.753 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:42:39.753Z,1744051359.753 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:42:39.754Z,1744051359.754 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:42:40.148Z,1744051360.148 [Default:CheckIn:D] Stopped
2025-04-07T18:42:40.148Z,1744051360.148 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:42:40.544Z,1744051360.544 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.526086 min
2025-04-07T18:42:40.544Z,1744051360.544 [Default:CheckIn:E] Stopped
2025-04-07T18:42:40.544Z,1744051360.544 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:42:40.544Z,1744051360.544 [Default:CheckIn] Stopped
2025-04-07T18:42:40.545Z,1744051360.545 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:42:40.545Z,1744051360.545 [Default:CheckIn](INFO): Running loop #3
2025-04-07T18:42:40.545Z,1744051360.545 [Default:CheckIn] Running Loop=3
2025-04-07T18:42:40.545Z,1744051360.545 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:42:40.545Z,1744051360.545 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:42:42.558Z,1744051362.558 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184241.00,A,3648.15068,N,12147.22359,W,0.991,21.32,070425,,,D*49
2025-04-07T18:42:42.561Z,1744051362.561 [NAL9602](INFO): GPS fix at 20250407T184241: (36.802511, -121.787060)
2025-04-07T18:42:42.571Z,1744051362.571 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:42:42.571Z,1744051362.571 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:42:50.037Z,1744051370.037 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250407T180841/Courier0019.lzma
2025-04-07T18:42:51.039Z,1744051371.039 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0019.lzma.bak
2025-04-07T18:42:51.039Z,1744051371.039 [DataOverHttps](INFO): SBD MOMSN=24563358
2025-04-07T18:43:07.117Z,1744051387.117 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250407T180841/Express0020.lzma
2025-04-07T18:43:08.119Z,1744051388.119 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0020.lzma.bak
2025-04-07T18:43:08.119Z,1744051388.119 [DataOverHttps](INFO): SBD MOMSN=24563361
2025-04-07T18:43:09.232Z,1744051389.232 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:43:09.232Z,1744051389.232 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:43:09.232Z,1744051389.232 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:43:15.281Z,1744051395.281 [NAL9602](INFO): SBD MO Status=2, MOMSN=18822, MT Status=2, MTMSN=0
2025-04-07T18:43:15.281Z,1744051395.281 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T18:43:24.173Z,1744051404.173 [NAL9602](INFO): SBD MO Status=0, MOMSN=18822, MT Status=0, MTMSN=0
2025-04-07T18:43:24.174Z,1744051404.174 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:43:54.908Z,1744051434.908 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:48:09.851Z,1744051689.851 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:48:09.851Z,1744051689.851 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:48:09.851Z,1744051689.851 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:48:09.851Z,1744051689.851 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:48:10.282Z,1744051690.282 [Default:CheckIn:D] Stopped
2025-04-07T18:48:10.282Z,1744051690.282 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:48:10.652Z,1744051690.652 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.028326 min
2025-04-07T18:48:10.653Z,1744051690.653 [Default:CheckIn:E] Stopped
2025-04-07T18:48:10.653Z,1744051690.653 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:48:10.653Z,1744051690.653 [Default:CheckIn] Stopped
2025-04-07T18:48:10.653Z,1744051690.653 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:48:10.653Z,1744051690.653 [Default:CheckIn](INFO): Running loop #4
2025-04-07T18:48:10.653Z,1744051690.653 [Default:CheckIn] Running Loop=4
2025-04-07T18:48:10.653Z,1744051690.653 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:48:10.654Z,1744051690.654 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:48:12.663Z,1744051692.663 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184811.00,A,3648.14198,N,12147.20814,W,0.039,118.62,070425,,,D*7C
2025-04-07T18:48:12.666Z,1744051692.666 [NAL9602](INFO): GPS fix at 20250407T184811: (36.802366, -121.786802)
2025-04-07T18:48:12.675Z,1744051692.675 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:48:12.675Z,1744051692.675 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:48:19.561Z,1744051699.561 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250407T180841/Courier0022.lzma
2025-04-07T18:48:20.563Z,1744051700.563 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0022.lzma.bak
2025-04-07T18:48:20.563Z,1744051700.563 [DataOverHttps](INFO): SBD MOMSN=24563448
2025-04-07T18:48:29.229Z,1744051709.229 [NAL9602](INFO): SBD MO Status=0, MOMSN=18823, MT Status=0, MTMSN=0
2025-04-07T18:48:29.229Z,1744051709.229 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:48:36.533Z,1744051716.533 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250407T180841/Express0023.lzma
2025-04-07T18:48:37.535Z,1744051717.535 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0023.lzma.bak
2025-04-07T18:48:37.535Z,1744051717.535 [DataOverHttps](INFO): SBD MOMSN=24563451
2025-04-07T18:48:38.931Z,1744051718.931 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:48:38.931Z,1744051718.931 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:48:38.931Z,1744051718.931 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:48:59.930Z,1744051739.930 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:53:39.567Z,1744052019.567 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:53:39.567Z,1744052019.567 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:53:39.567Z,1744052019.567 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:53:39.567Z,1744052019.567 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:53:39.960Z,1744052019.960 [Default:CheckIn:D] Stopped
2025-04-07T18:53:39.961Z,1744052019.961 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:53:40.368Z,1744052020.368 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.522963 min
2025-04-07T18:53:40.368Z,1744052020.368 [Default:CheckIn:E] Stopped
2025-04-07T18:53:40.368Z,1744052020.368 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:53:40.368Z,1744052020.368 [Default:CheckIn] Stopped
2025-04-07T18:53:40.368Z,1744052020.368 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:53:40.368Z,1744052020.368 [Default:CheckIn](INFO): Running loop #5
2025-04-07T18:53:40.368Z,1744052020.368 [Default:CheckIn] Running Loop=5
2025-04-07T18:53:40.369Z,1744052020.369 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:53:40.369Z,1744052020.369 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:53:42.370Z,1744052022.370 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185341.00,A,3648.15002,N,12147.20525,W,0.058,118.62,070425,,,D*78
2025-04-07T18:53:42.372Z,1744052022.372 [NAL9602](INFO): GPS fix at 20250407T185341: (36.802500, -121.786754)
2025-04-07T18:53:42.418Z,1744052022.418 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:53:42.419Z,1744052022.419 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:53:51.873Z,1744052031.873 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250407T180841/Courier0025.lzma
2025-04-07T18:53:52.875Z,1744052032.875 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0025.lzma.bak
2025-04-07T18:53:52.875Z,1744052032.875 [DataOverHttps](INFO): SBD MOMSN=24563480
2025-04-07T18:54:08.673Z,1744052048.673 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250407T180841/Express0026.lzma
2025-04-07T18:54:09.086Z,1744052049.086 [NAL9602](INFO): SBD MO Status=0, MOMSN=18824, MT Status=0, MTMSN=0
2025-04-07T18:54:09.086Z,1744052049.086 [NAL9602](INFO): No messages in MT queue
2025-04-07T18:54:09.675Z,1744052049.675 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0026.lzma.bak
2025-04-07T18:54:09.675Z,1744052049.675 [DataOverHttps](INFO): SBD MOMSN=24563484
2025-04-07T18:54:10.728Z,1744052050.728 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:54:10.729Z,1744052050.729 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:54:10.729Z,1744052050.729 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T18:54:39.778Z,1744052079.778 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T18:59:11.276Z,1744052351.276 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T18:59:11.276Z,1744052351.276 [Default:CheckIn:C.Wait] Stopped
2025-04-07T18:59:11.276Z,1744052351.276 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T18:59:11.276Z,1744052351.276 [Default:CheckIn:D] Running Loop=1
2025-04-07T18:59:11.681Z,1744052351.681 [Default:CheckIn:D] Stopped
2025-04-07T18:59:11.682Z,1744052351.682 [Default:CheckIn:E] Running Loop=1
2025-04-07T18:59:12.098Z,1744052352.098 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.051632 min
2025-04-07T18:59:12.098Z,1744052352.098 [Default:CheckIn:E] Stopped
2025-04-07T18:59:12.098Z,1744052352.098 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T18:59:12.098Z,1744052352.098 [Default:CheckIn] Stopped
2025-04-07T18:59:12.098Z,1744052352.098 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T18:59:12.098Z,1744052352.098 [Default:CheckIn](INFO): Running loop #6
2025-04-07T18:59:12.098Z,1744052352.098 [Default:CheckIn] Running Loop=6
2025-04-07T18:59:12.099Z,1744052352.099 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T18:59:12.099Z,1744052352.099 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T18:59:14.100Z,1744052354.100 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185913.00,A,3648.15155,N,12147.21923,W,0.058,118.62,070425,,,A*78
2025-04-07T18:59:14.103Z,1744052354.103 [NAL9602](INFO): GPS fix at 20250407T185913: (36.802526, -121.786987)
2025-04-07T18:59:14.134Z,1744052354.134 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T18:59:14.134Z,1744052354.134 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T18:59:21.044Z,1744052361.044 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250407T180841/Courier0028.lzma
2025-04-07T18:59:22.047Z,1744052362.047 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0028.lzma.bak
2025-04-07T18:59:22.047Z,1744052362.047 [DataOverHttps](INFO): SBD MOMSN=24563572
2025-04-07T18:59:37.977Z,1744052377.977 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250407T180841/Express0029.lzma
2025-04-07T18:59:38.979Z,1744052378.979 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0029.lzma.bak
2025-04-07T18:59:38.979Z,1744052378.979 [DataOverHttps](INFO): SBD MOMSN=24563576
2025-04-07T18:59:39.552Z,1744052379.552 [NAL9602](INFO): SBD MO Status=2, MOMSN=18825, MT Status=2, MTMSN=0
2025-04-07T18:59:39.552Z,1744052379.552 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T18:59:40.398Z,1744052380.398 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T18:59:40.398Z,1744052380.398 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T18:59:40.398Z,1744052380.398 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:00:16.768Z,1744052416.768 [NAL9602](INFO): SBD MO Status=0, MOMSN=18825, MT Status=0, MTMSN=0
2025-04-07T19:00:16.768Z,1744052416.768 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:00:47.473Z,1744052447.473 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:04:40.998Z,1744052680.998 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:04:40.998Z,1744052680.998 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:04:40.998Z,1744052680.998 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:04:40.999Z,1744052680.999 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:04:41.414Z,1744052681.414 [Default:CheckIn:D] Stopped
2025-04-07T19:04:41.414Z,1744052681.414 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:04:41.802Z,1744052681.802 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.547192 min
2025-04-07T19:04:41.802Z,1744052681.802 [Default:CheckIn:E] Stopped
2025-04-07T19:04:41.802Z,1744052681.802 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:04:41.802Z,1744052681.802 [Default:CheckIn] Stopped
2025-04-07T19:04:41.802Z,1744052681.802 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:04:41.802Z,1744052681.802 [Default:CheckIn](INFO): Running loop #7
2025-04-07T19:04:41.802Z,1744052681.802 [Default:CheckIn] Running Loop=7
2025-04-07T19:04:41.802Z,1744052681.802 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:04:41.802Z,1744052681.802 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:04:43.816Z,1744052683.816 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190443.00,A,3648.15260,N,12147.22064,W,0.019,118.62,070425,,,A*7D
2025-04-07T19:04:43.818Z,1744052683.818 [NAL9602](INFO): GPS fix at 20250407T190443: (36.802543, -121.787011)
2025-04-07T19:04:43.828Z,1744052683.828 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:04:43.828Z,1744052683.828 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:04:51.377Z,1744052691.377 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250407T180841/Courier0031.lzma
2025-04-07T19:04:52.379Z,1744052692.379 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0031.lzma.bak
2025-04-07T19:04:52.379Z,1744052692.379 [DataOverHttps](INFO): SBD MOMSN=24563619
2025-04-07T19:04:56.740Z,1744052696.740 [NAL9602](INFO): SBD MO Status=0, MOMSN=18826, MT Status=0, MTMSN=0
2025-04-07T19:04:56.740Z,1744052696.740 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:05:08.457Z,1744052708.457 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250407T180841/Express0032.lzma
2025-04-07T19:05:09.459Z,1744052709.459 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0032.lzma.bak
2025-04-07T19:05:09.459Z,1744052709.459 [DataOverHttps](INFO): SBD MOMSN=24563628
2025-04-07T19:05:10.519Z,1744052710.519 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:05:10.519Z,1744052710.519 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:05:10.519Z,1744052710.519 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:05:27.446Z,1744052727.446 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:10:11.103Z,1744053011.103 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:10:11.104Z,1744053011.104 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:10:11.104Z,1744053011.104 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:10:11.104Z,1744053011.104 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:10:11.516Z,1744053011.516 [Default:CheckIn:D] Stopped
2025-04-07T19:10:11.516Z,1744053011.516 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:10:11.939Z,1744053011.939 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.048893 min
2025-04-07T19:10:11.939Z,1744053011.939 [Default:CheckIn:E] Stopped
2025-04-07T19:10:11.939Z,1744053011.939 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:10:11.939Z,1744053011.939 [Default:CheckIn] Stopped
2025-04-07T19:10:11.940Z,1744053011.940 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:10:11.940Z,1744053011.940 [Default:CheckIn](INFO): Running loop #8
2025-04-07T19:10:11.940Z,1744053011.940 [Default:CheckIn] Running Loop=8
2025-04-07T19:10:11.940Z,1744053011.940 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:10:11.940Z,1744053011.940 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:10:13.925Z,1744053013.925 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191013.00,A,3648.15525,N,12147.21067,W,1.788,29.21,070425,,,A*41
2025-04-07T19:10:13.927Z,1744053013.927 [NAL9602](INFO): GPS fix at 20250407T191013: (36.802588, -121.786845)
2025-04-07T19:10:13.959Z,1744053013.959 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:10:13.959Z,1744053013.959 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:10:21.177Z,1744053021.177 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250407T180841/Courier0034.lzma
2025-04-07T19:10:22.179Z,1744053022.179 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0034.lzma.bak
2025-04-07T19:10:22.179Z,1744053022.179 [DataOverHttps](INFO): SBD MOMSN=24563708
2025-04-07T19:10:34.936Z,1744053034.936 [NAL9602](INFO): SBD MO Status=0, MOMSN=18827, MT Status=0, MTMSN=0
2025-04-07T19:10:34.936Z,1744053034.936 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:10:38.181Z,1744053038.181 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250407T180841/Express0035.lzma
2025-04-07T19:10:39.183Z,1744053039.183 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0035.lzma.bak
2025-04-07T19:10:39.183Z,1744053039.183 [DataOverHttps](INFO): SBD MOMSN=24563714
2025-04-07T19:10:40.227Z,1744053040.227 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:10:40.227Z,1744053040.227 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:10:40.227Z,1744053040.227 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:11:05.636Z,1744053065.636 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:15:40.822Z,1744053340.822 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:15:40.822Z,1744053340.822 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:15:40.822Z,1744053340.822 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:15:40.822Z,1744053340.822 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:15:41.245Z,1744053341.245 [Default:CheckIn:D] Stopped
2025-04-07T19:15:41.245Z,1744053341.245 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:15:41.680Z,1744053341.680 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.544377 min
2025-04-07T19:15:41.680Z,1744053341.680 [Default:CheckIn:E] Stopped
2025-04-07T19:15:41.680Z,1744053341.680 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:15:41.680Z,1744053341.680 [Default:CheckIn] Stopped
2025-04-07T19:15:41.681Z,1744053341.681 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:15:41.685Z,1744053341.685 [Default:CheckIn](INFO): Running loop #9
2025-04-07T19:15:41.685Z,1744053341.685 [Default:CheckIn] Running Loop=9
2025-04-07T19:15:41.685Z,1744053341.685 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:15:41.685Z,1744053341.685 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:15:43.636Z,1744053343.636 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191542.00,A,3648.52106,N,12147.21447,W,7.795,229.16,070425,,,D*79
2025-04-07T19:15:43.638Z,1744053343.638 [NAL9602](INFO): GPS fix at 20250407T191542: (36.808684, -121.786908)
2025-04-07T19:15:43.681Z,1744053343.681 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:15:43.682Z,1744053343.682 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:15:51.292Z,1744053351.292 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250407T180841/Courier0037.lzma
2025-04-07T19:15:52.295Z,1744053352.295 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0037.lzma.bak
2025-04-07T19:15:52.295Z,1744053352.295 [DataOverHttps](INFO): SBD MOMSN=24563757
2025-04-07T19:16:08.283Z,1744053368.283 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20250407T180841/Express0038.lzma
2025-04-07T19:16:09.094Z,1744053369.094 [NAL9602](INFO): SBD MO Status=0, MOMSN=18828, MT Status=0, MTMSN=0
2025-04-07T19:16:09.094Z,1744053369.094 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:16:09.275Z,1744053369.275 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0038.lzma.bak
2025-04-07T19:16:09.275Z,1744053369.275 [DataOverHttps](INFO): SBD MOMSN=24563764
2025-04-07T19:16:10.340Z,1744053370.340 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:16:10.340Z,1744053370.340 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:16:10.341Z,1744053370.341 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:16:39.796Z,1744053399.796 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:21:10.925Z,1744053670.925 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:21:10.925Z,1744053670.925 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:21:10.925Z,1744053670.925 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:21:10.926Z,1744053670.926 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:21:11.304Z,1744053671.304 [Default:CheckIn:D] Stopped
2025-04-07T19:21:11.305Z,1744053671.305 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:21:11.706Z,1744053671.706 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.045361 min
2025-04-07T19:21:11.707Z,1744053671.707 [Default:CheckIn:E] Stopped
2025-04-07T19:21:11.707Z,1744053671.707 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:21:11.707Z,1744053671.707 [Default:CheckIn] Stopped
2025-04-07T19:21:11.707Z,1744053671.707 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:21:11.707Z,1744053671.707 [Default:CheckIn](INFO): Running loop #10
2025-04-07T19:21:11.707Z,1744053671.707 [Default:CheckIn] Running Loop=10
2025-04-07T19:21:11.707Z,1744053671.707 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:21:11.707Z,1744053671.707 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:21:13.726Z,1744053673.726 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192113.00,A,3648.02280,N,12148.76543,W,28.322,245.64,070425,,,D*40
2025-04-07T19:21:13.728Z,1744053673.728 [NAL9602](INFO): GPS fix at 20250407T192113: (36.800380, -121.812757)
2025-04-07T19:21:13.738Z,1744053673.738 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:21:13.738Z,1744053673.738 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:21:21.037Z,1744053681.037 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250407T180841/Courier0040.lzma
2025-04-07T19:21:22.039Z,1744053682.039 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0040.lzma.bak
2025-04-07T19:21:22.039Z,1744053682.039 [DataOverHttps](INFO): SBD MOMSN=24563844
2025-04-07T19:21:28.673Z,1744053688.673 [NAL9602](INFO): SBD MO Status=0, MOMSN=18829, MT Status=0, MTMSN=0
2025-04-07T19:21:28.673Z,1744053688.673 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:21:38.089Z,1744053698.089 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250407T180841/Express0041.lzma
2025-04-07T19:21:39.091Z,1744053699.091 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0041.lzma.bak
2025-04-07T19:21:39.091Z,1744053699.091 [DataOverHttps](INFO): SBD MOMSN=24563849
2025-04-07T19:21:40.412Z,1744053700.412 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:21:40.412Z,1744053700.412 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:21:40.412Z,1744053700.412 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:21:59.442Z,1744053719.442 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:23:40.057Z,1744053820.057 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2025-04-07T19:23:40.059Z,1744053820.059 [BPC1](INFO): Received data from all battery sticks.
2025-04-07T19:26:41.037Z,1744054001.037 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:26:41.037Z,1744054001.037 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:26:41.037Z,1744054001.037 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:26:41.037Z,1744054001.037 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:26:41.444Z,1744054001.444 [Default:CheckIn:D] Stopped
2025-04-07T19:26:41.444Z,1744054001.444 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:26:41.846Z,1744054001.846 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.547685 min
2025-04-07T19:26:41.846Z,1744054001.846 [Default:CheckIn:E] Stopped
2025-04-07T19:26:41.846Z,1744054001.846 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:26:41.846Z,1744054001.846 [Default:CheckIn] Stopped
2025-04-07T19:26:41.847Z,1744054001.847 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:26:41.847Z,1744054001.847 [Default:CheckIn](INFO): Running loop #11
2025-04-07T19:26:41.847Z,1744054001.847 [Default:CheckIn] Running Loop=11
2025-04-07T19:26:41.847Z,1744054001.847 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:26:41.847Z,1744054001.847 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:26:43.904Z,1744054003.904 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192643.00,A,3647.54262,N,12151.74762,W,26.281,284.01,070425,,,D*41
2025-04-07T19:26:43.923Z,1744054003.923 [NAL9602](INFO): GPS fix at 20250407T192643: (36.792377, -121.862460)
2025-04-07T19:26:43.956Z,1744054003.956 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:26:43.957Z,1744054003.957 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:26:51.657Z,1744054011.657 [DataOverHttps](INFO): Sending 86 bytes from file Logs/20250407T180841/Courier0043.lzma
2025-04-07T19:26:52.659Z,1744054012.659 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0043.lzma.bak
2025-04-07T19:26:52.659Z,1744054012.659 [DataOverHttps](INFO): SBD MOMSN=24563897
2025-04-07T19:27:08.489Z,1744054028.489 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20250407T180841/Express0044.lzma
2025-04-07T19:27:08.506Z,1744054028.506 [NAL9602](INFO): SBD MO Status=0, MOMSN=18830, MT Status=0, MTMSN=0
2025-04-07T19:27:08.507Z,1744054028.507 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:27:09.491Z,1744054029.491 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0044.lzma.bak
2025-04-07T19:27:09.491Z,1744054029.491 [DataOverHttps](INFO): SBD MOMSN=24563900
2025-04-07T19:27:10.551Z,1744054030.551 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:27:10.551Z,1744054030.551 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:27:10.551Z,1744054030.551 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:27:39.203Z,1744054059.203 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:32:11.181Z,1744054331.181 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:32:11.181Z,1744054331.181 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:32:11.181Z,1744054331.181 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:32:11.182Z,1744054331.182 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:32:11.594Z,1744054331.594 [Default:CheckIn:D] Stopped
2025-04-07T19:32:11.594Z,1744054331.594 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:32:11.987Z,1744054331.987 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.050187 min
2025-04-07T19:32:11.988Z,1744054331.988 [Default:CheckIn:E] Stopped
2025-04-07T19:32:11.988Z,1744054331.988 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:32:11.988Z,1744054331.988 [Default:CheckIn] Stopped
2025-04-07T19:32:11.988Z,1744054331.988 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:32:11.988Z,1744054331.988 [Default:CheckIn](INFO): Running loop #12
2025-04-07T19:32:11.988Z,1744054331.988 [Default:CheckIn] Running Loop=12
2025-04-07T19:32:11.988Z,1744054331.988 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:32:11.988Z,1744054331.988 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:32:14.008Z,1744054334.008 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193213.00,A,3647.80625,N,12152.70459,W,2.158,176.71,070425,,,D*7B
2025-04-07T19:32:14.012Z,1744054334.012 [NAL9602](INFO): GPS fix at 20250407T193213: (36.796771, -121.878410)
2025-04-07T19:32:14.022Z,1744054334.022 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:32:14.022Z,1744054334.022 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:32:20.953Z,1744054340.953 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250407T180841/Courier0046.lzma
2025-04-07T19:32:21.955Z,1744054341.955 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0046.lzma.bak
2025-04-07T19:32:21.955Z,1744054341.955 [DataOverHttps](INFO): SBD MOMSN=24563961
2025-04-07T19:32:40.973Z,1744054360.973 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20250407T180841/Express0047.lzma
2025-04-07T19:32:41.480Z,1744054361.480 [NAL9602](INFO): SBD MO Status=0, MOMSN=18831, MT Status=0, MTMSN=0
2025-04-07T19:32:41.480Z,1744054361.480 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:32:41.975Z,1744054361.975 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0047.lzma.bak
2025-04-07T19:32:41.975Z,1744054361.975 [DataOverHttps](INFO): SBD MOMSN=24563964
2025-04-07T19:32:43.103Z,1744054363.103 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:32:43.103Z,1744054363.103 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:32:43.104Z,1744054363.104 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:33:12.175Z,1744054392.175 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:33:52.026Z,1744054432.026 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.663116
2025-04-07T19:34:24.153Z,1744054464.153 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-04-07T19:35:34.793Z,1744054534.793 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-04-07T19:36:09.933Z,1744054569.933 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-04-07T19:36:45.073Z,1744054605.073 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-04-07T19:36:57.486Z,1744054617.486 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003484
2025-04-07T19:37:43.680Z,1744054663.680 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:37:43.681Z,1744054663.681 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:37:43.681Z,1744054663.681 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:37:43.698Z,1744054663.698 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:37:44.081Z,1744054664.081 [Default:CheckIn:D] Stopped
2025-04-07T19:37:44.081Z,1744054664.081 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:37:44.482Z,1744054664.482 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.591634 min
2025-04-07T19:37:44.482Z,1744054664.482 [Default:CheckIn:E] Stopped
2025-04-07T19:37:44.483Z,1744054664.483 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:37:44.483Z,1744054664.483 [Default:CheckIn] Stopped
2025-04-07T19:37:44.484Z,1744054664.484 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:37:44.485Z,1744054664.485 [Default:CheckIn](INFO): Running loop #13
2025-04-07T19:37:44.486Z,1744054664.486 [Default:CheckIn] Running Loop=13
2025-04-07T19:37:44.486Z,1744054664.486 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:37:44.487Z,1744054664.487 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:37:46.503Z,1744054666.503 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193745.00,A,3647.82079,N,12150.73364,W,0.175,288.86,070425,,,A*7A
2025-04-07T19:37:46.505Z,1744054666.505 [NAL9602](INFO): GPS fix at 20250407T193745: (36.797013, -121.845561)
2025-04-07T19:37:46.515Z,1744054666.515 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:37:46.515Z,1744054666.515 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:37:56.055Z,1744054676.055 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250407T180841/Courier0049.lzma
2025-04-07T19:37:58.058Z,1744054678.058 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.575912
2025-04-07T19:38:11.140Z,1744054691.140 [NAL9602](INFO): SBD MO Status=2, MOMSN=18832, MT Status=2, MTMSN=0
2025-04-07T19:38:11.140Z,1744054691.140 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T19:38:28.105Z,1744054708.105 [NAL9602](INFO): SBD MO Status=2, MOMSN=18832, MT Status=2, MTMSN=0
2025-04-07T19:38:28.105Z,1744054708.105 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-04-07T19:38:55.722Z,1744054735.722 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003495
2025-04-07T19:39:03.149Z,1744054743.149 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250407T180841/Courier0049.lzma
2025-04-07T19:39:04.151Z,1744054744.151 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0049.lzma.bak
2025-04-07T19:39:04.151Z,1744054744.151 [DataOverHttps](INFO): SBD MOMSN=24564005
2025-04-07T19:39:22.129Z,1744054762.129 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20250407T180841/Express0050.lzma
2025-04-07T19:39:23.131Z,1744054763.131 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Express0050.lzma.bak
2025-04-07T19:39:23.131Z,1744054763.131 [DataOverHttps](INFO): SBD MOMSN=24564011
2025-04-07T19:39:24.276Z,1744054764.276 [Default:CheckIn:Read_Iridium] Stopped
2025-04-07T19:39:24.276Z,1744054764.276 [Default:CheckIn:C.Wait] Running Loop=1
2025-04-07T19:39:24.276Z,1744054764.276 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-04-07T19:39:57.816Z,1744054797.816 [NAL9602](INFO): SBD MO Status=0, MOMSN=18832, MT Status=0, MTMSN=0
2025-04-07T19:39:57.816Z,1744054797.816 [NAL9602](INFO): No messages in MT queue
2025-04-07T19:40:28.518Z,1744054828.518 [NAL9602](INFO): Not Powering down - fast GPS
2025-04-07T19:42:17.369Z,1744054937.369 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2025-04-07T19:42:18.374Z,1744054938.374 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.003349
2025-04-07T19:42:29.826Z,1744054949.826 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003478
2025-04-07T19:44:24.898Z,1744055064.898 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-04-07T19:44:24.898Z,1744055064.898 [Default:CheckIn:C.Wait] Stopped
2025-04-07T19:44:24.899Z,1744055064.899 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-04-07T19:44:24.899Z,1744055064.899 [Default:CheckIn:D] Running Loop=1
2025-04-07T19:44:25.311Z,1744055065.311 [Default:CheckIn:D] Stopped
2025-04-07T19:44:25.311Z,1744055065.311 [Default:CheckIn:E] Running Loop=1
2025-04-07T19:44:25.708Z,1744055065.708 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.278809 min
2025-04-07T19:44:25.708Z,1744055065.708 [Default:CheckIn:E] Stopped
2025-04-07T19:44:25.708Z,1744055065.708 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-04-07T19:44:25.708Z,1744055065.708 [Default:CheckIn] Stopped
2025-04-07T19:44:25.708Z,1744055065.708 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-04-07T19:44:25.708Z,1744055065.708 [Default:CheckIn](INFO): Running loop #14
2025-04-07T19:44:25.708Z,1744055065.708 [Default:CheckIn] Running Loop=14
2025-04-07T19:44:25.708Z,1744055065.708 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-04-07T19:44:25.708Z,1744055065.708 [Default:CheckIn:Read_GPS] Running Loop=1
2025-04-07T19:44:27.724Z,1744055067.724 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194427.00,A,3647.82116,N,12150.66744,W,0.330,73.79,070425,,,D*40
2025-04-07T19:44:27.727Z,1744055067.727 [NAL9602](INFO): GPS fix at 20250407T194427: (36.797019, -121.844457)
2025-04-07T19:44:27.737Z,1744055067.737 [Default:CheckIn:Read_GPS] Stopped
2025-04-07T19:44:27.737Z,1744055067.737 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-04-07T19:44:35.001Z,1744055075.001 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250407T180841/Courier0052.lzma
2025-04-07T19:44:36.003Z,1744055076.003 [DataOverHttps](INFO): Moved sent file to Logs/20250407T180841/Courier0052.lzma.bak
2025-04-07T19:44:36.003Z,1744055076.003 [DataOverHttps](IMPORTANT): SBD MOMSN=24564103, MTMSN=20250407T194435
2025-04-07T19:44:43.433Z,1744055083.433 [DataOverHttps](INFO): Received command: restart logs