2023-06-23T14:01:00.457Z,1687528860.457 [Supervisor](DEBUG): Initializing supervisor.
2023-06-23T14:01:00.462Z,1687528860.462 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-06-23T14:01:00.462Z,1687528860.462 [SyncHandler](INFO): Protected caller Thread ID is 3851
2023-06-23T14:01:00.463Z,1687528860.463 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-06-23T14:01:00.463Z,1687528860.463 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-06-23T14:01:00.464Z,1687528860.464 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3852
2023-06-23T14:01:00.468Z,1687528860.468 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-06-23T14:01:00.494Z,1687528860.494 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-06-23T14:01:00.501Z,1687528860.501 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-06-23T14:01:00.501Z,1687528860.501 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 3853
2023-06-23T14:01:00.506Z,1687528860.506 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-06-23T14:01:00.507Z,1687528860.507 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-06-23T14:01:00.507Z,1687528860.507 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3854
2023-06-23T14:01:00.509Z,1687528860.509 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-06-23T14:01:00.510Z,1687528860.510 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-06-23T14:01:00.510Z,1687528860.510 [logger ThreadHandler](INFO): Protected caller Thread ID is 3855
2023-06-23T14:01:00.514Z,1687528860.514 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-06-23T14:01:00.514Z,1687528860.514 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-06-23T14:01:00.516Z,1687528860.516 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-06-23T14:01:01.304Z,1687528861.304 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-06-23T14:01:01.305Z,1687528861.305 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-06-23T14:01:01.691Z,1687528861.691 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-06-23T14:01:01.692Z,1687528861.692 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-06-23T14:01:01.823Z,1687528861.823 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-06-23T14:01:02.107Z,1687528862.107 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-06-23T14:01:02.108Z,1687528862.108 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-06-23T14:01:02.187Z,1687528862.187 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-06-23T14:01:02.284Z,1687528862.284 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-06-23T14:01:02.285Z,1687528862.285 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-06-23T14:01:02.638Z,1687528862.638 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-06-23T14:01:02.638Z,1687528862.638 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-06-23T14:01:02.772Z,1687528862.772 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-06-23T14:01:02.773Z,1687528862.773 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-06-23T14:01:03.252Z,1687528863.252 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-06-23T14:01:03.252Z,1687528863.252 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-06-23T14:01:03.432Z,1687528863.432 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-06-23T14:01:03.432Z,1687528863.432 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-06-23T14:01:03.823Z,1687528863.823 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-06-23T14:01:03.823Z,1687528863.823 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-06-23T14:01:04.112Z,1687528864.112 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-06-23T14:01:04.112Z,1687528864.112 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-06-23T14:01:04.221Z,1687528864.221 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-06-23T14:01:04.222Z,1687528864.222 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-06-23T14:01:05.430Z,1687528865.430 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-06-23T14:01:05.431Z,1687528865.431 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-06-23T14:01:05.755Z,1687528865.755 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-06-23T14:01:05.756Z,1687528865.756 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-06-23T14:01:05.977Z,1687528865.977 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-06-23T14:01:05.979Z,1687528865.979 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2023-06-23T14:01:05.980Z,1687528865.980 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2023-06-23T14:01:06.100Z,1687528866.100 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2023-06-23T14:01:06.184Z,1687528866.184 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2023-06-23T14:01:06.321Z,1687528866.321 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2023-06-23T14:01:06.408Z,1687528866.408 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2023-06-23T14:01:06.673Z,1687528866.673 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-06-23T14:01:06.674Z,1687528866.674 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2023-06-23T14:01:06.776Z,1687528866.776 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2023-06-23T14:01:06.882Z,1687528866.882 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2023-06-23T14:01:06.907Z,1687528866.907 [Config/Navigation](ERROR): Unterminated quote: "US2MI01M,US2MI80M,US4MI57M,US4MI56M,US4MI90M,US4MI89M,
2023-06-23T14:01:06.991Z,1687528866.991 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2023-06-23T14:01:07.135Z,1687528867.135 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2023-06-23T14:01:07.232Z,1687528867.232 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2023-06-23T14:01:07.331Z,1687528867.331 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2023-06-23T14:01:07.332Z,1687528867.332 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-06-23T14:01:07.340Z,1687528867.340 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-06-23T14:01:07.351Z,1687528867.351 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-06-23T14:01:07.351Z,1687528867.351 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-06-23T14:01:07.452Z,1687528867.452 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-06-23T14:01:07.452Z,1687528867.452 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-06-23T14:01:07.502Z,1687528867.502 [VerticalControl](DEBUG): Construct VerticalControl.
2023-06-23T14:01:07.562Z,1687528867.562 [VerticalControl] Loaded
2023-06-23T14:01:07.562Z,1687528867.562 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-06-23T14:01:07.565Z,1687528867.565 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-06-23T14:01:07.606Z,1687528867.606 [HorizontalControl] Loaded
2023-06-23T14:01:07.607Z,1687528867.607 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-06-23T14:01:07.609Z,1687528867.609 [SpeedControl](DEBUG): Construct SpeedControl.
2023-06-23T14:01:07.612Z,1687528867.612 [SpeedControl] Loaded
2023-06-23T14:01:07.613Z,1687528867.613 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-06-23T14:01:07.615Z,1687528867.615 [LoopControl](DEBUG): Construct LoopControl.
2023-06-23T14:01:07.616Z,1687528867.616 [LoopControl] Loaded
2023-06-23T14:01:07.616Z,1687528867.616 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-06-23T14:01:07.616Z,1687528867.616 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-06-23T14:01:07.617Z,1687528867.617 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-06-23T14:01:07.769Z,1687528867.769 [BuoyancyServo] Loaded
2023-06-23T14:01:07.769Z,1687528867.769 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-06-23T14:01:07.790Z,1687528867.790 [ElevatorServo] Loaded
2023-06-23T14:01:07.790Z,1687528867.790 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-06-23T14:01:07.809Z,1687528867.809 [MassServo] Loaded
2023-06-23T14:01:07.809Z,1687528867.809 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-06-23T14:01:07.828Z,1687528867.828 [RudderServo] Loaded
2023-06-23T14:01:07.828Z,1687528867.828 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-06-23T14:01:07.843Z,1687528867.843 [ThrusterHE] Loaded
2023-06-23T14:01:07.843Z,1687528867.843 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-06-23T14:01:07.843Z,1687528867.843 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-06-23T14:01:07.844Z,1687528867.844 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-06-23T14:01:07.894Z,1687528867.894 [DepthRateCalculator] Loaded
2023-06-23T14:01:07.895Z,1687528867.895 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-06-23T14:01:07.899Z,1687528867.899 [PitchRateCalculator] Loaded
2023-06-23T14:01:07.900Z,1687528867.900 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-06-23T14:01:07.909Z,1687528867.909 [SpeedCalculator] Loaded
2023-06-23T14:01:07.910Z,1687528867.910 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-06-23T14:01:07.914Z,1687528867.914 [YawRateCalculator] Loaded
2023-06-23T14:01:07.914Z,1687528867.914 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-06-23T14:01:07.932Z,1687528867.932 [ElevatorOffsetCalculator] Loaded
2023-06-23T14:01:07.932Z,1687528867.932 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-06-23T14:01:07.933Z,1687528867.933 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-06-23T14:01:07.933Z,1687528867.933 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-06-23T14:01:08.046Z,1687528868.046 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-06-23T14:01:08.046Z,1687528868.046 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-06-23T14:01:08.060Z,1687528868.060 [NavChart] Loaded
2023-06-23T14:01:08.060Z,1687528868.060 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-06-23T14:01:08.066Z,1687528868.066 [UniversalFixResidualReporter] Loaded
2023-06-23T14:01:08.066Z,1687528868.066 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-06-23T14:01:08.067Z,1687528868.067 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-06-23T14:01:08.067Z,1687528868.067 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-06-23T14:01:08.487Z,1687528868.487 [AHRS_M2] Loaded
2023-06-23T14:01:08.488Z,1687528868.488 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-06-23T14:01:08.523Z,1687528868.523 [BackseatComponent] Loaded
2023-06-23T14:01:08.523Z,1687528868.523 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-06-23T14:01:08.524Z,1687528868.524 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408E54E0
2023-06-23T14:01:08.525Z,1687528868.525 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 3937
2023-06-23T14:01:08.528Z,1687528868.528 [LcmUniversalReporter] Loaded
2023-06-23T14:01:08.528Z,1687528868.528 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-06-23T14:01:09.354Z,1687528869.354 [BPC1] Loaded
2023-06-23T14:01:09.355Z,1687528869.355 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-06-23T14:01:09.429Z,1687528869.429 [DataOverHttps] Loaded
2023-06-23T14:01:09.429Z,1687528869.429 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-06-23T14:01:09.430Z,1687528869.430 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409154E0
2023-06-23T14:01:09.431Z,1687528869.431 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3938
2023-06-23T14:01:09.452Z,1687528869.452 [Depth_Keller] Loaded
2023-06-23T14:01:09.452Z,1687528869.452 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-06-23T14:01:09.457Z,1687528869.457 [DropWeight] Loaded
2023-06-23T14:01:09.457Z,1687528869.457 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-06-23T14:01:09.519Z,1687528869.519 [NAL9602] Loaded
2023-06-23T14:01:09.520Z,1687528869.520 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-06-23T14:01:09.549Z,1687528869.549 [Onboard] Loaded
2023-06-23T14:01:09.549Z,1687528869.549 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-06-23T14:01:09.550Z,1687528869.550 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409454E0
2023-06-23T14:01:09.551Z,1687528869.551 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 3939
2023-06-23T14:01:09.563Z,1687528869.563 [Power24vConverter] Loaded
2023-06-23T14:01:09.563Z,1687528869.563 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-06-23T14:01:09.576Z,1687528869.576 [Radio_Surface] Loaded
2023-06-23T14:01:09.576Z,1687528869.576 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-06-23T14:01:09.577Z,1687528869.577 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409754E0
2023-06-23T14:01:09.578Z,1687528869.578 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3940
2023-06-23T14:01:09.591Z,1687528869.591 [Sonardyne_Nano] Loaded
2023-06-23T14:01:09.592Z,1687528869.592 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2023-06-23T14:01:09.592Z,1687528869.592 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-06-23T14:01:09.593Z,1687528869.593 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-06-23T14:01:09.650Z,1687528869.650 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-06-23T14:01:09.650Z,1687528869.650 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-06-23T14:01:09.798Z,1687528869.798 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-06-23T14:01:09.799Z,1687528869.799 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-06-23T14:01:09.825Z,1687528869.825 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-06-23T14:01:09.826Z,1687528869.826 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-06-23T14:01:09.994Z,1687528869.994 [CTD_Seabird] Loaded
2023-06-23T14:01:09.994Z,1687528869.994 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-06-23T14:01:09.995Z,1687528869.995 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AA94E0
2023-06-23T14:01:09.996Z,1687528869.996 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3941
2023-06-23T14:01:10.016Z,1687528870.016 [PAR_Licor] Loaded
2023-06-23T14:01:10.016Z,1687528870.016 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-06-23T14:01:10.047Z,1687528870.047 [WetLabsBB2FL] Loaded
2023-06-23T14:01:10.047Z,1687528870.047 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-06-23T14:01:10.048Z,1687528870.048 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AD94E0
2023-06-23T14:01:10.049Z,1687528870.049 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3942
2023-06-23T14:01:10.050Z,1687528870.050 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-06-23T14:01:10.050Z,1687528870.050 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-06-23T14:01:10.355Z,1687528870.355 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-06-23T14:01:10.355Z,1687528870.355 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-06-23T14:01:10.800Z,1687528870.800 [SBIT](DEBUG): Construct Startup Built In Test.
2023-06-23T14:01:10.813Z,1687528870.813 [SBIT] Loaded
2023-06-23T14:01:10.813Z,1687528870.813 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-06-23T14:01:10.816Z,1687528870.816 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-06-23T14:01:10.829Z,1687528870.829 [IBIT] Loaded
2023-06-23T14:01:10.829Z,1687528870.829 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-06-23T14:01:10.835Z,1687528870.835 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-06-23T14:01:11.008Z,1687528871.008 [CBIT] Loaded
2023-06-23T14:01:11.009Z,1687528871.009 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-06-23T14:01:11.021Z,1687528871.021 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-06-23T14:01:11.155Z,1687528871.155 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-06-23T14:01:11.158Z,1687528871.158 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-06-23T14:01:11.170Z,1687528871.170 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-06-23T14:01:11.171Z,1687528871.171 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BC44E0
2023-06-23T14:01:11.171Z,1687528871.171 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3943
2023-06-23T14:01:11.176Z,1687528871.176 [Supervisor](INFO): Main Thread ID is 830
2023-06-23T14:01:11.176Z,1687528871.176 [Supervisor](DEBUG): Running supervisor.
2023-06-23T14:01:11.177Z,1687528871.177 [CommandExec ThreadHandler](INFO): Handler Thread ID is 3944
2023-06-23T14:01:11.177Z,1687528871.177 [CommandExec](INFO): Initializing the command executive.
2023-06-23T14:01:11.179Z,1687528871.179 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3945
2023-06-23T14:01:11.182Z,1687528871.182 [controlThread ThreadHandler](INFO): Handler Thread ID is 3946
2023-06-23T14:01:11.183Z,1687528871.183 [controlThread](DEBUG): Initializing ControlThread
2023-06-23T14:01:11.183Z,1687528871.183 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-06-23T14:01:11.185Z,1687528871.185 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-06-23T14:01:11.186Z,1687528871.186 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-06-23T14:01:11.186Z,1687528871.186 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-06-23T14:01:11.188Z,1687528871.188 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-06-23T14:01:11.188Z,1687528871.188 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-06-23T14:01:11.188Z,1687528871.188 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-06-23T14:01:11.189Z,1687528871.189 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-06-23T14:01:11.189Z,1687528871.189 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-06-23T14:01:11.190Z,1687528871.190 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-06-23T14:01:11.191Z,1687528871.191 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-06-23T14:01:11.197Z,1687528871.197 [SBIT](INFO): Initialize SBIT Component.
2023-06-23T14:01:11.198Z,1687528871.198 [SBIT](IMPORTANT): git: 2023-06-22
2023-06-23T14:01:11.198Z,1687528871.198 [SBIT](INFO): git hash: 6e9037c118cca75fa4ac89fea42f4403cb21b2f0
2023-06-23T14:01:11.198Z,1687528871.198 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-06-23T14:01:11.199Z,1687528871.199 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-06-23T14:01:11.201Z,1687528871.201 [SBIT](INFO): Beginning SBIT in 95.000000 seconds.
2023-06-23T14:01:11.201Z,1687528871.201 [IBIT](INFO): Initialize IBIT Component.
2023-06-23T14:01:11.202Z,1687528871.202 [CBIT](DEBUG): Initialize CBIT Component.
2023-06-23T14:01:11.203Z,1687528871.203 [logger ThreadHandler](INFO): Handler Thread ID is 3947
2023-06-23T14:01:11.213Z,1687528871.213 [CBIT](DEBUG): Initialized mux pins.
2023-06-23T14:01:11.213Z,1687528871.213 [CBIT](DEBUG): Initializing the watchdog timer.
2023-06-23T14:01:11.221Z,1687528871.221 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 3948
2023-06-23T14:01:11.233Z,1687528871.233 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3949
2023-06-23T14:01:11.234Z,1687528871.234 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-06-23T14:01:11.237Z,1687528871.237 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-06-23T14:01:11.237Z,1687528871.237 [CBIT](DEBUG): Initializing heartbeat.
2023-06-23T14:01:11.245Z,1687528871.245 [Onboard ThreadHandler](INFO): Handler Thread ID is 3950
2023-06-23T14:01:11.263Z,1687528871.263 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3951
2023-06-23T14:01:11.282Z,1687528871.282 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3952
2023-06-23T14:01:11.283Z,1687528871.283 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-06-23T14:01:11.287Z,1687528871.287 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3954
2023-06-23T14:01:11.289Z,1687528871.289 [WetLabsBB2FL](INFO): Powering up
2023-06-23T14:01:11.291Z,1687528871.291 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3956
2023-06-23T14:01:11.293Z,1687528871.293 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-06-23T14:01:11.293Z,1687528871.293 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-06-23T14:01:11.294Z,1687528871.294 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-06-23T14:01:11.294Z,1687528871.294 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-06-23T14:01:11.294Z,1687528871.294 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-06-23T14:01:11.294Z,1687528871.294 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-06-23T14:01:11.294Z,1687528871.294 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-06-23T14:01:11.294Z,1687528871.294 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-06-23T14:01:11.309Z,1687528871.309 [CBIT](DEBUG): Deactivating GF circuits.
2023-06-23T14:01:11.309Z,1687528871.309 [CBIT](DEBUG): Deactivating emergency mode.
2023-06-23T14:01:11.349Z,1687528871.349 [CBIT](DEBUG): Backplane powered.
2023-06-23T14:01:11.350Z,1687528871.350 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-06-23T14:01:11.363Z,1687528871.363 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-23T14:01:11.387Z,1687528871.387 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2023-06-23T14:01:11.387Z,1687528871.387 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-06-23T14:01:11.461Z,1687528871.461 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-06-23T14:01:11.462Z,1687528871.462 [Default:A.Wait](DEBUG): Construct Wait.
2023-06-23T14:01:11.464Z,1687528871.464 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-23T14:01:11.516Z,1687528871.516 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-06-23T14:01:11.519Z,1687528871.519 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-06-23T14:01:11.554Z,1687528871.554 [Default:E.Execute](DEBUG): Construct Execute.
2023-06-23T14:01:11.574Z,1687528871.574 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P4H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2023-06-23T14:01:11.578Z,1687528871.578 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,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,LcmUniversalReporter,Reporter,LogSplitter,
2023-06-23T14:01:11.601Z,1687528871.601 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-06-23T14:01:11.669Z,1687528871.669 [Radio_Surface](INFO): Powering up
2023-06-23T14:01:11.674Z,1687528871.674 [Depth_Keller](ERROR): Pressure or depth reading out of range: 962.811646 decibar, 0.000000 m
2023-06-23T14:01:11.675Z,1687528871.675 [Power24vConverter](INFO): Powering up.
2023-06-23T14:01:11.676Z,1687528871.676 [Sonardyne_Nano](INFO): Initializing.
2023-06-23T14:01:11.722Z,1687528871.722 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-06-23T14:01:11.767Z,1687528871.767 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-06-23T14:01:11.773Z,1687528871.773 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-06-23T14:01:11.774Z,1687528871.774 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-06-23T14:01:11.781Z,1687528871.781 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-06-23T14:01:11.782Z,1687528871.782 [MassServo](DEBUG): Initializing EZServoServo.
2023-06-23T14:01:11.790Z,1687528871.790 [MassServo](DEBUG): Initializing MassServo.
2023-06-23T14:01:11.791Z,1687528871.791 [RudderServo](DEBUG): Initializing EZServoServo.
2023-06-23T14:01:11.797Z,1687528871.797 [RudderServo](DEBUG): Initializing RudderServo.
2023-06-23T14:01:11.798Z,1687528871.798 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-06-23T14:01:11.805Z,1687528871.805 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-06-23T14:01:13.397Z,1687528873.397 [WetLabsBB2FL](INFO): Powering down
2023-06-23T14:01:13.608Z,1687528873.608 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2023-06-23T14:01:17.478Z,1687528877.478 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-06-23T14:01:39.871Z,1687528899.871 [NAL9602](INFO): Powering up NAL9602
2023-06-23T14:01:50.787Z,1687528910.787 [NAL9602](INFO): NAL9602 initialized
2023-06-23T14:02:14.216Z,1687528934.216 [NAL9602](INFO): SBD MO Status=0, MOMSN=12393, MT Status=0, MTMSN=0
2023-06-23T14:02:14.216Z,1687528934.216 [NAL9602](INFO): No messages in MT queue
2023-06-23T14:02:15.428Z,1687528935.428 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140203.00,A,4313.59245,N,08620.29817,W,0.700,0.00,230623,,,A*7A
2023-06-23T14:02:15.439Z,1687528935.439 [NAL9602](INFO): GPS fix at 20230623T140203: (43.226541, -86.338303)
2023-06-23T14:02:46.954Z,1687528966.954 [SBIT](IMPORTANT): Beginning Startup BIT
2023-06-23T14:02:46.959Z,1687528966.959 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-23T14:02:48.154Z,1687528968.154 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-23T14:02:57.888Z,1687528977.888 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.767290
CHAN A1 (24V): 0.712875
CHAN A2 (12V): 0.553232
CHAN A3 (5V): 0.182586
CHAN B0 (3.3V): 0.114820
CHAN B1 (3.15aV): 0.121438
CHAN B2 (3.15bV): 0.121408
CHAN B3 (GND): -0.024051
OPEN: 0.016759
Full Scale: +/- 1 mA
2023-06-23T14:03:40.693Z,1687529020.693 [SBIT](IMPORTANT): SBIT PASSED
2023-06-23T14:03:40.693Z,1687529020.693 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-06-23T14:03:40.694Z,1687529020.694 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2023-06-23T14:03:40.694Z,1687529020.694 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2023-06-23T14:03:40.694Z,1687529020.694 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 50.000000 meter;

2023-06-23T14:03:40.694Z,1687529020.694 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;

2023-06-23T14:03:40.694Z,1687529020.694 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=247.664569 cubic_centimeter;

2023-06-23T14:03:40.694Z,1687529020.694 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.1 angular_degree;

2023-06-23T14:03:40.695Z,1687529020.695 [SBIT](IMPORTANT): VerticalControl.massDefault=18.789208 millimeter;

2023-06-23T14:03:41.108Z,1687529021.108 [MissionManager](IMPORTANT): Started mission Startup
2023-06-23T14:03:41.108Z,1687529021.108 [Startup] Running Loop=1
2023-06-23T14:03:41.108Z,1687529021.108 [Startup](DEBUG): Aggregate::initialize Startup
2023-06-23T14:03:41.108Z,1687529021.108 [Startup:A.GoToSurface] Running Loop=1
2023-06-23T14:03:41.109Z,1687529021.109 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-23T14:03:41.109Z,1687529021.109 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-23T14:03:41.110Z,1687529021.110 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-23T14:03:41.110Z,1687529021.110 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-23T14:03:41.110Z,1687529021.110 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-23T14:03:41.111Z,1687529021.111 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-23T14:03:41.112Z,1687529021.112 [Startup:StartupSatComms] Running Loop=1
2023-06-23T14:03:41.112Z,1687529021.112 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-06-23T14:03:41.112Z,1687529021.112 [Startup:StartupSatComms:A] Running Loop=1
2023-06-23T14:03:41.508Z,1687529021.508 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-06-23T14:03:43.100Z,1687529023.100 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140330.00,A,4313.61119,N,08620.31972,W,0.389,286.82,230623,,,A*72
2023-06-23T14:03:43.102Z,1687529023.102 [NAL9602](INFO): GPS fix at 20230623T140330: (43.226853, -86.338662)
2023-06-23T14:03:43.113Z,1687529023.113 [Startup:StartupSatComms:A] Stopped
2023-06-23T14:03:43.113Z,1687529023.113 [Startup:StartupSatComms:B] Running Loop=1
2023-06-23T14:03:43.534Z,1687529023.534 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-23T14:04:04.968Z,1687529044.968 [NAL9602](INFO): SBD MO Status=2, MOMSN=12394, MT Status=2, MTMSN=0
2023-06-23T14:04:04.968Z,1687529044.968 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-23T14:04:43.348Z,1687529083.348 [Startup:StartupSatComms:B](INFO): Timed out from 2023-06-23T14:03:43.1Z
2023-06-23T14:04:43.348Z,1687529083.348 [Startup:StartupSatComms:B] Stopped
2023-06-23T14:04:43.348Z,1687529083.348 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-06-23T14:04:43.348Z,1687529083.348 [Startup:StartupSatComms] Stopped
2023-06-23T14:04:43.348Z,1687529083.348 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-06-23T14:04:43.349Z,1687529083.349 [Startup](INFO): Completed Startup
2023-06-23T14:04:43.349Z,1687529083.349 [MissionManager](INFO): Startup is completed.
2023-06-23T14:04:43.349Z,1687529083.349 [MissionManager](INFO): Uninitializing Mission Startup
2023-06-23T14:04:43.349Z,1687529083.349 [Startup] Stopped
2023-06-23T14:04:43.349Z,1687529083.349 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-06-23T14:04:43.349Z,1687529083.349 [Startup:A.GoToSurface] Stopped
2023-06-23T14:04:43.349Z,1687529083.349 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-23T14:04:43.760Z,1687529083.760 [MissionManager](IMPORTANT): Started mission Default
2023-06-23T14:04:43.760Z,1687529083.760 [Default] Running Loop=1
2023-06-23T14:04:43.760Z,1687529083.760 [Default](DEBUG): Aggregate::initialize Default
2023-06-23T14:04:43.760Z,1687529083.760 [Default:B.GoToSurface] Running Loop=1
2023-06-23T14:04:43.760Z,1687529083.760 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-23T14:04:43.760Z,1687529083.760 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-23T14:04:43.761Z,1687529083.761 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-23T14:04:43.762Z,1687529083.762 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-23T14:04:43.762Z,1687529083.762 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-23T14:04:43.762Z,1687529083.762 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-23T14:04:43.763Z,1687529083.763 [Default:A.Wait] Running Loop=1
2023-06-23T14:04:43.763Z,1687529083.763 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-06-23T14:04:57.148Z,1687529097.148 [Default:A.Wait](INFO): Done Waiting.
2023-06-23T14:04:57.148Z,1687529097.148 [Default:A.Wait] Stopped
2023-06-23T14:04:57.148Z,1687529097.148 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-06-23T14:04:57.566Z,1687529097.566 [Default:CheckIn] Running Loop=1
2023-06-23T14:04:57.566Z,1687529097.566 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-23T14:04:57.566Z,1687529097.566 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-23T14:04:57.977Z,1687529097.977 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-06-23T14:04:59.597Z,1687529099.597 [NAL9602](INFO): SBD MO Status=1, MOMSN=12394, MT Status=0, MTMSN=0
2023-06-23T14:04:59.647Z,1687529099.647 [NAL9602](INFO): Sent 39 bytes from file Logs/20230623T135450/Courier0007.lzma
2023-06-23T14:04:59.647Z,1687529099.647 [NAL9602](INFO): Packets left to send: 0
2023-06-23T14:05:00.775Z,1687529100.775 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140448.00,A,4313.61149,N,08620.32004,W,0.428,286.82,230623,,,A*78
2023-06-23T14:05:00.778Z,1687529100.778 [NAL9602](INFO): GPS fix at 20230623T140448: (43.226858, -86.338667)
2023-06-23T14:05:00.808Z,1687529100.808 [Default:CheckIn:Read_GPS] Stopped
2023-06-23T14:05:00.808Z,1687529100.808 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-23T14:05:01.218Z,1687529101.218 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-23T14:06:10.293Z,1687529170.293 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003038
2023-06-23T14:06:15.204Z,1687529175.204 [NAL9602](INFO): SBD MO Status=2, MOMSN=12395, MT Status=2, MTMSN=0
2023-06-23T14:06:15.204Z,1687529175.204 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-23T14:06:17.721Z,1687529177.721 [DataOverHttps](INFO): Sending 270 bytes from file Logs/20230623T140100/Courier0000.lzma
2023-06-23T14:06:18.723Z,1687529178.723 [DataOverHttps](INFO): Moved sent file to Logs/20230623T140100/Courier0000.lzma.bak
2023-06-23T14:06:18.723Z,1687529178.723 [DataOverHttps](INFO): SBD MOMSN=18421044
2023-06-23T14:06:34.468Z,1687529194.468 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230623T140100/Courier0004.lzma
2023-06-23T14:06:35.471Z,1687529195.471 [DataOverHttps](INFO): Moved sent file to Logs/20230623T140100/Courier0004.lzma.bak
2023-06-23T14:06:35.471Z,1687529195.471 [DataOverHttps](INFO): SBD MOMSN=18421051
2023-06-23T14:06:45.918Z,1687529205.918 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-23T14:07:01.781Z,1687529221.781 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20230623T135450/Express0008.lzma
2023-06-23T14:07:02.789Z,1687529222.789 [DataOverHttps](INFO): Moved sent file to Logs/20230623T135450/Express0008.lzma.bak
2023-06-23T14:07:02.789Z,1687529222.789 [DataOverHttps](INFO): SBD MOMSN=18421059
2023-06-23T14:07:22.978Z,1687529242.978 [DataOverHttps](INFO): Sending 913 bytes from file Logs/20230623T140100/Express0001.lzma
2023-06-23T14:07:23.979Z,1687529243.979 [DataOverHttps](INFO): Moved sent file to Logs/20230623T140100/Express0001.lzma.bak
2023-06-23T14:07:23.979Z,1687529243.979 [DataOverHttps](INFO): SBD MOMSN=18421064
2023-06-23T14:07:39.628Z,1687529259.628 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20230623T140100/Express0005.lzma
2023-06-23T14:07:40.631Z,1687529260.631 [DataOverHttps](INFO): Moved sent file to Logs/20230623T140100/Express0005.lzma.bak
2023-06-23T14:07:40.631Z,1687529260.631 [DataOverHttps](INFO): SBD MOMSN=18421082
2023-06-23T14:07:41.901Z,1687529261.901 [Default:CheckIn:Read_Iridium] Stopped
2023-06-23T14:07:41.901Z,1687529261.901 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-23T14:07:41.901Z,1687529261.901 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-23T14:09:42.279Z,1687529382.279 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-23T14:09:48.743Z,1687529388.743 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-23T14:09:48.750Z,1687529388.750 [BPC1](INFO): Calculating totals. Valid battery stick count: 52. Valid reserve battery stick count: 6.
2023-06-23T14:09:48.753Z,1687529388.753 [BPC1](INFO): Received data from all battery sticks.
2023-06-23T14:11:12.778Z,1687529472.778 [Power24vConverter](INFO): Powering down.
2023-06-23T14:12:42.548Z,1687529562.548 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-23T14:12:42.549Z,1687529562.549 [Default:CheckIn:C.Wait] Stopped
2023-06-23T14:12:42.549Z,1687529562.549 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-23T14:12:42.549Z,1687529562.549 [Default:CheckIn:D] Running Loop=1
2023-06-23T14:12:42.959Z,1687529562.959 [Default:CheckIn:D] Stopped
2023-06-23T14:12:42.959Z,1687529562.959 [Default:CheckIn:E] Running Loop=1
2023-06-23T14:12:43.344Z,1687529563.344 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.986651 min 
2023-06-23T14:12:43.344Z,1687529563.344 [Default:CheckIn:E] Stopped
2023-06-23T14:12:43.344Z,1687529563.344 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-23T14:12:43.344Z,1687529563.344 [Default:CheckIn] Stopped
2023-06-23T14:12:43.345Z,1687529563.345 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-23T14:12:43.353Z,1687529563.353 [Default:CheckIn](INFO): Running loop #2
2023-06-23T14:12:43.353Z,1687529563.353 [Default:CheckIn] Running Loop=2
2023-06-23T14:12:43.353Z,1687529563.353 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-23T14:12:43.353Z,1687529563.353 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-23T14:12:45.356Z,1687529565.356 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141234.00,A,4313.61456,N,08620.31647,W,0.233,286.82,230623,,,A*71
2023-06-23T14:12:45.358Z,1687529565.358 [NAL9602](INFO): GPS fix at 20230623T141234: (43.226909, -86.338608)
2023-06-23T14:12:45.377Z,1687529565.377 [Default:CheckIn:Read_GPS] Stopped
2023-06-23T14:12:45.377Z,1687529565.377 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-23T14:12:56.545Z,1687529576.545 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230623T140100/Courier0007.lzma
2023-06-23T14:12:57.547Z,1687529577.547 [DataOverHttps](INFO): Moved sent file to Logs/20230623T140100/Courier0007.lzma.bak
2023-06-23T14:12:57.547Z,1687529577.547 [DataOverHttps](INFO): SBD MOMSN=18421090
2023-06-23T14:13:09.240Z,1687529589.240 [NAL9602](INFO): SBD MO Status=2, MOMSN=12395, MT Status=2, MTMSN=0
2023-06-23T14:13:09.240Z,1687529589.240 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-23T14:13:14.373Z,1687529594.373 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20230623T140100/Express0008.lzma
2023-06-23T14:13:15.375Z,1687529595.375 [DataOverHttps](INFO): Moved sent file to Logs/20230623T140100/Express0008.lzma.bak
2023-06-23T14:13:15.375Z,1687529595.375 [DataOverHttps](INFO): SBD MOMSN=18421093
2023-06-23T14:13:16.949Z,1687529596.949 [Default:CheckIn:Read_Iridium] Stopped
2023-06-23T14:13:16.949Z,1687529596.949 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-23T14:13:16.949Z,1687529596.949 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-23T14:14:04.992Z,1687529644.992 [NAL9602](INFO): SBD MO Status=1, MOMSN=12395, MT Status=0, MTMSN=0
2023-06-23T14:14:04.992Z,1687529644.992 [NAL9602](INFO): No messages in MT queue
2023-06-23T14:14:35.694Z,1687529675.694 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-23T14:18:17.623Z,1687529897.623 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-23T14:18:17.623Z,1687529897.623 [Default:CheckIn:C.Wait] Stopped
2023-06-23T14:18:17.623Z,1687529897.623 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-23T14:18:17.623Z,1687529897.623 [Default:CheckIn:D] Running Loop=1
2023-06-23T14:18:18.060Z,1687529898.060 [Default:CheckIn:D] Stopped
2023-06-23T14:18:18.060Z,1687529898.060 [Default:CheckIn:E] Running Loop=1
2023-06-23T14:18:18.445Z,1687529898.445 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.571666 min 
2023-06-23T14:18:18.445Z,1687529898.445 [Default:CheckIn:E] Stopped
2023-06-23T14:18:18.445Z,1687529898.445 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-23T14:18:18.445Z,1687529898.445 [Default:CheckIn] Stopped
2023-06-23T14:18:18.445Z,1687529898.445 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-23T14:18:18.445Z,1687529898.445 [Default:CheckIn](INFO): Running loop #3
2023-06-23T14:18:18.445Z,1687529898.445 [Default:CheckIn] Running Loop=3
2023-06-23T14:18:18.446Z,1687529898.446 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-23T14:18:18.446Z,1687529898.446 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-23T14:18:20.448Z,1687529900.448 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141809.00,A,4313.61957,N,08620.31673,W,0.078,286.82,230623,,,A*73
2023-06-23T14:18:20.451Z,1687529900.451 [NAL9602](INFO): GPS fix at 20230623T141809: (43.226993, -86.338612)
2023-06-23T14:18:20.481Z,1687529900.481 [Default:CheckIn:Read_GPS] Stopped
2023-06-23T14:18:20.481Z,1687529900.481 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-23T14:18:27.420Z,1687529907.420 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230623T140100/Courier0010.lzma
2023-06-23T14:18:28.423Z,1687529908.423 [DataOverHttps](INFO): Moved sent file to Logs/20230623T140100/Courier0010.lzma.bak
2023-06-23T14:18:28.423Z,1687529908.423 [DataOverHttps](INFO): SBD MOMSN=18421153
2023-06-23T14:18:50.769Z,1687529930.769 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20230623T140100/Express0011.lzma
2023-06-23T14:18:51.664Z,1687529931.664 [NAL9602](INFO): SBD MO Status=1, MOMSN=12396, MT Status=0, MTMSN=0
2023-06-23T14:18:51.664Z,1687529931.664 [NAL9602](INFO): No messages in MT queue
2023-06-23T14:18:51.771Z,1687529931.771 [DataOverHttps](INFO): Moved sent file to Logs/20230623T140100/Express0011.lzma.bak
2023-06-23T14:18:51.771Z,1687529931.771 [DataOverHttps](INFO): SBD MOMSN=18421156
2023-06-23T14:18:53.306Z,1687529933.306 [Default:CheckIn:Read_Iridium] Stopped
2023-06-23T14:18:53.306Z,1687529933.306 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-23T14:18:53.306Z,1687529933.306 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-23T14:19:22.450Z,1687529962.450 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-23T14:20:12.214Z,1687530012.214 [DataOverHttps](IMPORTANT): SBD MTMSN=20230623T142011
2023-06-23T14:20:19.477Z,1687530019.477 [DataOverHttps](INFO): Received command: restart sys
2023-06-23T14:20:19.522Z,1687530019.522 [CommandExec](IMPORTANT): got command restart system
2023