2022-04-19T15:08:03.790Z,1650380883.790 [Supervisor](DEBUG): Initializing supervisor.
2022-04-19T15:08:03.794Z,1650380883.794 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-04-19T15:08:03.795Z,1650380883.795 [SyncHandler](INFO): Protected caller Thread ID is 4790
2022-04-19T15:08:03.795Z,1650380883.795 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-04-19T15:08:03.796Z,1650380883.796 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-04-19T15:08:03.796Z,1650380883.796 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4791
2022-04-19T15:08:03.800Z,1650380883.800 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-04-19T15:08:03.818Z,1650380883.818 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-04-19T15:08:03.819Z,1650380883.819 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-04-19T15:08:03.820Z,1650380883.820 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 4792
2022-04-19T15:08:03.824Z,1650380883.824 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-04-19T15:08:03.825Z,1650380883.825 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-04-19T15:08:03.825Z,1650380883.825 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4793
2022-04-19T15:08:03.827Z,1650380883.827 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-04-19T15:08:03.828Z,1650380883.828 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-04-19T15:08:03.829Z,1650380883.829 [logger ThreadHandler](INFO): Protected caller Thread ID is 4794
2022-04-19T15:08:03.832Z,1650380883.832 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-04-19T15:08:03.832Z,1650380883.832 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-04-19T15:08:03.835Z,1650380883.835 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-04-19T15:08:04.315Z,1650380884.315 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-04-19T15:08:04.316Z,1650380884.316 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-04-19T15:08:04.397Z,1650380884.397 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-04-19T15:08:04.727Z,1650380884.727 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-04-19T15:08:04.728Z,1650380884.728 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-04-19T15:08:04.836Z,1650380884.836 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-04-19T15:08:04.837Z,1650380884.837 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-04-19T15:08:05.038Z,1650380885.038 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-04-19T15:08:05.039Z,1650380885.039 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-04-19T15:08:05.587Z,1650380885.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-04-19T15:08:05.588Z,1650380885.588 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-04-19T15:08:05.857Z,1650380885.857 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-04-19T15:08:05.858Z,1650380885.858 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-04-19T15:08:06.078Z,1650380886.078 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-04-19T15:08:06.079Z,1650380886.079 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-04-19T15:08:06.270Z,1650380886.270 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-04-19T15:08:06.271Z,1650380886.271 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-04-19T15:08:06.370Z,1650380886.370 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-04-19T15:08:06.371Z,1650380886.371 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-04-19T15:08:06.593Z,1650380886.593 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-04-19T15:08:06.594Z,1650380886.594 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-04-19T15:08:06.994Z,1650380886.994 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-04-19T15:08:06.995Z,1650380886.995 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-04-19T15:08:07.077Z,1650380887.077 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-04-19T15:08:07.212Z,1650380887.212 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-04-19T15:08:07.213Z,1650380887.213 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-04-19T15:08:08.794Z,1650380888.794 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-04-19T15:08:08.795Z,1650380888.795 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-04-19T15:08:09.174Z,1650380889.174 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-04-19T15:08:09.176Z,1650380889.176 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/
2022-04-19T15:08:09.179Z,1650380889.179 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg
2022-04-19T15:08:09.389Z,1650380889.389 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg
2022-04-19T15:08:09.492Z,1650380889.492 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg
2022-04-19T15:08:09.598Z,1650380889.598 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg
2022-04-19T15:08:09.701Z,1650380889.701 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg
2022-04-19T15:08:09.969Z,1650380889.969 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-04-19T15:08:09.970Z,1650380889.970 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg
2022-04-19T15:08:10.082Z,1650380890.082 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg
2022-04-19T15:08:10.185Z,1650380890.185 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg
2022-04-19T15:08:10.313Z,1650380890.313 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg
2022-04-19T15:08:10.430Z,1650380890.430 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg
2022-04-19T15:08:10.516Z,1650380890.516 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg
2022-04-19T15:08:10.603Z,1650380890.603 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg
2022-04-19T15:08:10.717Z,1650380890.717 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg
2022-04-19T15:08:10.817Z,1650380890.817 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg
2022-04-19T15:08:11.026Z,1650380891.026 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg
2022-04-19T15:08:11.190Z,1650380891.190 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-04-19T15:08:11.201Z,1650380891.201 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-04-19T15:08:11.607Z,1650380891.607 [AHRS_M2] Loaded
2022-04-19T15:08:11.607Z,1650380891.607 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-04-19T15:08:11.641Z,1650380891.641 [BackseatComponent] Loaded
2022-04-19T15:08:11.641Z,1650380891.641 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-04-19T15:08:11.642Z,1650380891.642 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 407E14E0
2022-04-19T15:08:11.642Z,1650380891.642 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 4888
2022-04-19T15:08:11.645Z,1650380891.645 [LcmUniversalReporter] Loaded
2022-04-19T15:08:11.645Z,1650380891.645 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-04-19T15:08:12.770Z,1650380892.770 [BPC1] Loaded
2022-04-19T15:08:12.770Z,1650380892.770 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-04-19T15:08:12.852Z,1650380892.852 [DataOverHttps] Loaded
2022-04-19T15:08:12.852Z,1650380892.852 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-04-19T15:08:12.853Z,1650380892.853 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408114E0
2022-04-19T15:08:12.854Z,1650380892.854 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4889
2022-04-19T15:08:12.873Z,1650380892.873 [Depth_Keller] Loaded
2022-04-19T15:08:12.873Z,1650380892.873 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-04-19T15:08:12.878Z,1650380892.878 [DropWeight] Loaded
2022-04-19T15:08:12.878Z,1650380892.878 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-04-19T15:08:12.925Z,1650380892.925 [Micromodem] Loaded
2022-04-19T15:08:12.926Z,1650380892.926 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2022-04-19T15:08:12.983Z,1650380892.983 [NAL9602] Loaded
2022-04-19T15:08:12.983Z,1650380892.983 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-04-19T15:08:13.010Z,1650380893.010 [Onboard] Loaded
2022-04-19T15:08:13.011Z,1650380893.011 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-04-19T15:08:13.012Z,1650380893.012 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408414E0
2022-04-19T15:08:13.012Z,1650380893.012 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 4890
2022-04-19T15:08:13.018Z,1650380893.018 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2022-04-19T15:08:13.028Z,1650380893.028 [PowerOnly] Loaded
2022-04-19T15:08:13.029Z,1650380893.029 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2022-04-19T15:08:13.039Z,1650380893.039 [Power24vConverter] Loaded
2022-04-19T15:08:13.040Z,1650380893.040 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-04-19T15:08:13.053Z,1650380893.053 [Radio_Surface] Loaded
2022-04-19T15:08:13.053Z,1650380893.053 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-04-19T15:08:13.054Z,1650380893.054 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408714E0
2022-04-19T15:08:13.055Z,1650380893.055 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4891
2022-04-19T15:08:13.096Z,1650380893.096 [RDI_Pathfinder] Loaded
2022-04-19T15:08:13.097Z,1650380893.097 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2022-04-19T15:08:13.122Z,1650380893.122 [RDI_PathfinderUp] Loaded
2022-04-19T15:08:13.123Z,1650380893.123 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2022-04-19T15:08:13.123Z,1650380893.123 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-04-19T15:08:13.124Z,1650380893.124 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-04-19T15:08:13.134Z,1650380893.134 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-04-19T15:08:13.135Z,1650380893.135 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-04-19T15:08:13.244Z,1650380893.244 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-04-19T15:08:13.245Z,1650380893.245 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-04-19T15:08:13.268Z,1650380893.268 [LBLNavigation] Loaded
2022-04-19T15:08:13.268Z,1650380893.268 [ComponentRegistry](DEBUG): SyncComponent "LBLNavigation" handled in the control thread.
2022-04-19T15:08:13.281Z,1650380893.281 [NavChart] Loaded
2022-04-19T15:08:13.281Z,1650380893.281 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-04-19T15:08:13.287Z,1650380893.287 [UniversalFixResidualReporter] Loaded
2022-04-19T15:08:13.287Z,1650380893.287 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-04-19T15:08:13.297Z,1650380893.297 [WorkSite] Loaded
2022-04-19T15:08:13.298Z,1650380893.298 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2022-04-19T15:08:13.298Z,1650380893.298 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-04-19T15:08:13.298Z,1650380893.298 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-04-19T15:08:13.393Z,1650380893.393 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-04-19T15:08:13.393Z,1650380893.393 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-04-19T15:08:13.518Z,1650380893.518 [BuoyancyServo] Loaded
2022-04-19T15:08:13.518Z,1650380893.518 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-04-19T15:08:13.539Z,1650380893.539 [ElevatorServo] Loaded
2022-04-19T15:08:13.540Z,1650380893.540 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-04-19T15:08:13.560Z,1650380893.560 [MassServo] Loaded
2022-04-19T15:08:13.560Z,1650380893.560 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-04-19T15:08:13.580Z,1650380893.580 [RudderServo] Loaded
2022-04-19T15:08:13.580Z,1650380893.580 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-04-19T15:08:13.596Z,1650380893.596 [ThrusterHE] Loaded
2022-04-19T15:08:13.597Z,1650380893.597 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-04-19T15:08:13.597Z,1650380893.597 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-04-19T15:08:13.597Z,1650380893.597 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-04-19T15:08:13.763Z,1650380893.763 [CTD_Seabird] Loaded
2022-04-19T15:08:13.763Z,1650380893.763 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-04-19T15:08:13.764Z,1650380893.764 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409AF4E0
2022-04-19T15:08:13.764Z,1650380893.764 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4892
2022-04-19T15:08:13.784Z,1650380893.784 [PAR_Licor] Loaded
2022-04-19T15:08:13.784Z,1650380893.784 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-04-19T15:08:13.815Z,1650380893.815 [WetLabsSeaOWL_UV_A] Loaded
2022-04-19T15:08:13.816Z,1650380893.816 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2022-04-19T15:08:13.817Z,1650380893.817 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409DF4E0
2022-04-19T15:08:13.817Z,1650380893.817 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 4893
2022-04-19T15:08:13.818Z,1650380893.818 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-04-19T15:08:13.818Z,1650380893.818 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-04-19T15:08:14.123Z,1650380894.123 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-04-19T15:08:14.123Z,1650380894.123 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-04-19T15:08:14.173Z,1650380894.173 [DepthRateCalculator] Loaded
2022-04-19T15:08:14.174Z,1650380894.174 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-04-19T15:08:14.179Z,1650380894.179 [PitchRateCalculator] Loaded
2022-04-19T15:08:14.179Z,1650380894.179 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-04-19T15:08:14.188Z,1650380894.188 [SpeedCalculator] Loaded
2022-04-19T15:08:14.189Z,1650380894.189 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-04-19T15:08:14.202Z,1650380894.202 [TempGradientCalculator] Loaded
2022-04-19T15:08:14.202Z,1650380894.202 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2022-04-19T15:08:14.217Z,1650380894.217 [VerticalHomogeneityIndexCalculator] Loaded
2022-04-19T15:08:14.217Z,1650380894.217 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2022-04-19T15:08:14.222Z,1650380894.222 [YawRateCalculator] Loaded
2022-04-19T15:08:14.222Z,1650380894.222 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-04-19T15:08:14.244Z,1650380894.244 [ElevatorOffsetCalculator] Loaded
2022-04-19T15:08:14.244Z,1650380894.244 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-04-19T15:08:14.245Z,1650380894.245 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-04-19T15:08:14.245Z,1650380894.245 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-04-19T15:08:14.384Z,1650380894.384 [SBIT](DEBUG): Construct Startup Built In Test.
2022-04-19T15:08:14.396Z,1650380894.396 [SBIT] Loaded
2022-04-19T15:08:14.396Z,1650380894.396 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-04-19T15:08:14.399Z,1650380894.399 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-04-19T15:08:14.412Z,1650380894.412 [IBIT] Loaded
2022-04-19T15:08:14.412Z,1650380894.412 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-04-19T15:08:14.418Z,1650380894.418 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-04-19T15:08:14.523Z,1650380894.523 [CBIT] Loaded
2022-04-19T15:08:14.523Z,1650380894.523 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-04-19T15:08:14.524Z,1650380894.524 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-04-19T15:08:14.524Z,1650380894.524 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-04-19T15:08:14.580Z,1650380894.580 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-04-19T15:08:14.580Z,1650380894.580 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-04-19T15:08:14.894Z,1650380894.894 [InternalEnvSim] Loaded
2022-04-19T15:08:14.894Z,1650380894.894 [ComponentRegistry](DEBUG): SyncComponent "InternalEnvSim" handled in the control thread.
2022-04-19T15:08:14.895Z,1650380894.895 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-04-19T15:08:14.895Z,1650380894.895 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-04-19T15:08:15.144Z,1650380895.144 [VerticalControl](DEBUG): Construct VerticalControl.
2022-04-19T15:08:15.313Z,1650380895.313 [VerticalControl] Loaded
2022-04-19T15:08:15.314Z,1650380895.314 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-04-19T15:08:15.317Z,1650380895.317 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-04-19T15:08:15.364Z,1650380895.364 [HorizontalControl] Loaded
2022-04-19T15:08:15.364Z,1650380895.364 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-04-19T15:08:15.366Z,1650380895.366 [SpeedControl](DEBUG): Construct SpeedControl.
2022-04-19T15:08:15.368Z,1650380895.368 [SpeedControl] Loaded
2022-04-19T15:08:15.368Z,1650380895.368 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-04-19T15:08:15.383Z,1650380895.383 [LoopControl](DEBUG): Construct LoopControl.
2022-04-19T15:08:15.384Z,1650380895.384 [LoopControl] Loaded
2022-04-19T15:08:15.384Z,1650380895.384 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-04-19T15:08:15.384Z,1650380895.384 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-04-19T15:08:15.385Z,1650380895.385 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-04-19T15:08:15.566Z,1650380895.566 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-04-19T15:08:15.572Z,1650380895.572 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-04-19T15:08:15.575Z,1650380895.575 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-04-19T15:08:15.585Z,1650380895.585 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-04-19T15:08:15.586Z,1650380895.586 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BA64E0
2022-04-19T15:08:15.587Z,1650380895.587 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4894
2022-04-19T15:08:15.591Z,1650380895.591 [Supervisor](INFO): Main Thread ID is 829
2022-04-19T15:08:15.591Z,1650380895.591 [Supervisor](DEBUG): Running supervisor.
2022-04-19T15:08:15.592Z,1650380895.592 [CommandExec ThreadHandler](INFO): Handler Thread ID is 4895
2022-04-19T15:08:15.592Z,1650380895.592 [CommandExec](INFO): Initializing the command executive.
2022-04-19T15:08:15.594Z,1650380895.594 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4896
2022-04-19T15:08:15.596Z,1650380895.596 [controlThread ThreadHandler](INFO): Handler Thread ID is 4897
2022-04-19T15:08:15.596Z,1650380895.596 [controlThread](DEBUG): Initializing ControlThread
2022-04-19T15:08:15.605Z,1650380895.605 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-04-19T15:08:15.605Z,1650380895.605 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-04-19T15:08:15.605Z,1650380895.605 [WorkSite](DEBUG): Initializing WorkSite component.
2022-04-19T15:08:15.609Z,1650380895.609 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-04-19T15:08:15.609Z,1650380895.609 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-04-19T15:08:15.610Z,1650380895.610 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-04-19T15:08:15.610Z,1650380895.610 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2022-04-19T15:08:15.610Z,1650380895.610 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2022-04-19T15:08:15.611Z,1650380895.611 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-04-19T15:08:15.611Z,1650380895.611 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-04-19T15:08:15.612Z,1650380895.612 [SBIT](INFO): Initialize SBIT Component.
2022-04-19T15:08:15.613Z,1650380895.613 [SBIT](IMPORTANT): git: 2022-04-13
2022-04-19T15:08:15.613Z,1650380895.613 [SBIT](INFO): git hash: d1e60664077c229c1f2059d1d9396c3c0e4e8f0d
2022-04-19T15:08:15.613Z,1650380895.613 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-04-19T15:08:15.614Z,1650380895.614 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2022-04-19T15:08:15.615Z,1650380895.615 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2022-04-19T15:08:15.616Z,1650380895.616 [IBIT](INFO): Initialize IBIT Component.
2022-04-19T15:08:15.617Z,1650380895.617 [CBIT](DEBUG): Initialize CBIT Component.
2022-04-19T15:08:15.618Z,1650380895.618 [logger ThreadHandler](INFO): Handler Thread ID is 4898
2022-04-19T15:08:15.629Z,1650380895.629 [CBIT](DEBUG): Initialized mux pins.
2022-04-19T15:08:15.629Z,1650380895.629 [CBIT](DEBUG): Initializing the watchdog timer.
2022-04-19T15:08:15.637Z,1650380895.637 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 4899
2022-04-19T15:08:15.649Z,1650380895.649 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4900
2022-04-19T15:08:15.650Z,1650380895.650 [DataOverHttps](DEBUG): dashIP=128.128.181.226 starts with a digit so assuming it is a numeric IP
2022-04-19T15:08:15.653Z,1650380895.653 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-04-19T15:08:15.653Z,1650380895.653 [CBIT](DEBUG): Initializing heartbeat.
2022-04-19T15:08:15.661Z,1650380895.661 [Onboard ThreadHandler](INFO): Handler Thread ID is 4901
2022-04-19T15:08:15.679Z,1650380895.679 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4902
2022-04-19T15:08:15.701Z,1650380895.701 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4903
2022-04-19T15:08:15.702Z,1650380895.702 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-04-19T15:08:15.706Z,1650380895.706 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 4905
2022-04-19T15:08:15.713Z,1650380895.713 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4906
2022-04-19T15:08:15.722Z,1650380895.722 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-04-19T15:08:15.722Z,1650380895.722 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-04-19T15:08:15.722Z,1650380895.722 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-04-19T15:08:15.722Z,1650380895.722 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-04-19T15:08:15.722Z,1650380895.722 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-04-19T15:08:15.723Z,1650380895.723 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-04-19T15:08:15.723Z,1650380895.723 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2022-04-19T15:08:15.723Z,1650380895.723 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2022-04-19T15:08:15.723Z,1650380895.723 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-04-19T15:08:15.723Z,1650380895.723 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-04-19T15:08:15.723Z,1650380895.723 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2022-04-19T15:08:15.724Z,1650380895.724 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2022-04-19T15:08:15.724Z,1650380895.724 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2022-04-19T15:08:15.724Z,1650380895.724 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2022-04-19T15:08:15.724Z,1650380895.724 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2022-04-19T15:08:15.724Z,1650380895.724 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2022-04-19T15:08:15.725Z,1650380895.725 [CBIT](DEBUG): Deactivating GF circuits.
2022-04-19T15:08:15.725Z,1650380895.725 [CBIT](DEBUG): Deactivating emergency mode.
2022-04-19T15:08:15.761Z,1650380895.761 [CBIT](DEBUG): Backplane powered.
2022-04-19T15:08:15.761Z,1650380895.761 [InternalEnvSim](DEBUG):  InternaEnvlSim initializing...
2022-04-19T15:08:15.897Z,1650380895.897 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-04-19T15:08:15.899Z,1650380895.899 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-04-19T15:08:15.899Z,1650380895.899 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-04-19T15:08:15.900Z,1650380895.900 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-04-19T15:08:15.901Z,1650380895.901 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-04-19T15:08:15.969Z,1650380895.969 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-04-19T15:08:15.991Z,1650380895.991 [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>


2022-04-19T15:08:15.992Z,1650380895.992 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-04-19T15:08:16.085Z,1650380896.085 [Radio_Surface](INFO): Powering up
2022-04-19T15:08:16.085Z,1650380896.085 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-04-19T15:08:16.087Z,1650380896.087 [Default:A.Wait](DEBUG): Construct Wait.
2022-04-19T15:08:16.101Z,1650380896.101 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-04-19T15:08:16.129Z,1650380896.129 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-04-19T15:08:16.131Z,1650380896.131 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-04-19T15:08:16.153Z,1650380896.153 [Default:E.Execute](DEBUG): Construct Execute.
2022-04-19T15:08:16.156Z,1650380896.156 [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="P2H">
                <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>


2022-04-19T15:08:16.178Z,1650380896.178 [controlThread](DEBUG): Component order: CycleStarter,InternalEnvSim,AHRS_M2,BPC1,Depth_Keller,DropWeight,Micromodem,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,RDI_PathfinderUp,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,LBLNavigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-04-19T15:08:16.189Z,1650380896.189 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-04-19T15:08:16.368Z,1650380896.368 [Power24vConverter](INFO): Powering up.
2022-04-19T15:08:16.446Z,1650380896.446 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-04-19T15:08:16.453Z,1650380896.453 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-04-19T15:08:16.454Z,1650380896.454 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-04-19T15:08:16.461Z,1650380896.461 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-04-19T15:08:16.462Z,1650380896.462 [MassServo](DEBUG): Initializing EZServoServo.
2022-04-19T15:08:16.469Z,1650380896.469 [MassServo](DEBUG): Initializing MassServo.
2022-04-19T15:08:16.470Z,1650380896.470 [RudderServo](DEBUG): Initializing EZServoServo.
2022-04-19T15:08:16.477Z,1650380896.477 [RudderServo](DEBUG): Initializing RudderServo.
2022-04-19T15:08:16.478Z,1650380896.478 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-04-19T15:08:16.485Z,1650380896.485 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-04-19T15:08:16.615Z,1650380896.615 [Micromodem](INFO): Powering up
2022-04-19T15:08:16.615Z,1650380896.615 [Micromodem](DEBUG): Initializing Micromodem.
2022-04-19T15:08:17.325Z,1650380897.325 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-04-19T15:08:17.325Z,1650380897.325 [RudderServo](FAULT): Rudder failed to initialize
2022-04-19T15:08:17.325Z,1650380897.325 [RudderServo] Communications Fault, FailCount= 1
2022-04-19T15:08:17.325Z,1650380897.325 [RudderServo](ERROR): Communications Fault
2022-04-19T15:08:17.329Z,1650380897.329 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-04-19T15:08:17.566Z,1650380897.566 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-04-19T15:08:17.566Z,1650380897.566 [RudderServo](INFO): Powering down
2022-04-19T15:08:18.253Z,1650380898.253 [RudderServo](DEBUG): Initializing EZServoServo.
2022-04-19T15:08:18.374Z,1650380898.374 [RudderServo](DEBUG): Initializing RudderServo.
2022-04-19T15:08:18.378Z,1650380898.378 [CBIT](INFO): Clearing failed state for component RudderServo
2022-04-19T15:08:18.378Z,1650380898.378 [RudderServo] No Fault, FailCount= 1
2022-04-19T15:08:21.481Z,1650380901.481 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2022-04-19T15:08:21.883Z,1650380901.883 [Micromodem](INFO): Nmea in: $CATMG,2022-04-19T15:08:22.135057Z,RTC,RTC*57

2022-04-19T15:08:21.884Z,1650380901.884 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2022-04-19T15:08:22.135057Z,RTC,RTC*57

2022-04-19T15:08:22.126Z,1650380902.126 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-04-19T15:08:22.283Z,1650380902.283 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2022-04-19T15:08:22.283Z,1650380902.283 [Micromodem](INFO): Nmea out: $CCCFG,POW,20*08

2022-04-19T15:08:22.687Z,1650380902.687 [Micromodem](INFO): Nmea in: $CACFG,POW,20*0A

2022-04-19T15:08:22.687Z,1650380902.687 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2022-04-19T15:08:22.734Z,1650380902.734 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2022-04-19T15:08:23.091Z,1650380903.091 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2022-04-19T15:08:23.091Z,1650380903.091 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2022-04-19T15:08:23.495Z,1650380903.495 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2022-04-19T15:08:23.495Z,1650380903.495 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2022-04-19T15:08:23.899Z,1650380903.899 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2022-04-19T15:08:23.899Z,1650380903.899 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2022-04-19T15:08:24.291Z,1650380904.291 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2022-04-19T15:08:24.291Z,1650380904.291 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47

2022-04-19T15:08:24.695Z,1650380904.695 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45

2022-04-19T15:08:24.695Z,1650380904.695 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2022-04-19T15:08:25.087Z,1650380905.087 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2022-04-19T15:08:25.088Z,1650380905.088 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2022-04-19T15:08:25.491Z,1650380905.491 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2022-04-19T15:08:25.491Z,1650380905.491 [Micromodem](INFO): Nmea out: $CCCLK,2022,04,19,15,08,26*42

2022-04-19T15:08:25.891Z,1650380905.891 [Micromodem](INFO): Nmea in: $CACLK,2022,4,19,15,8,26*40

2022-04-19T15:08:26.703Z,1650380906.703 [Micromodem](INFO): Nmea in: $CATMS,0,2022-04-19T15:08:27Z*71

2022-04-19T15:08:26.705Z,1650380906.705 [Micromodem](INFO): Nmea in: $CATMG,2022-04-19T15:08:27.027937Z,USER_CMD,RTC*1E

2022-04-19T15:08:43.259Z,1650380923.259 [NAL9602](INFO): Powering up NAL9602
2022-04-19T15:08:44.116Z,1650380924.116 [SBIT](IMPORTANT): Beginning Startup BIT
2022-04-19T15:08:44.129Z,1650380924.129 [CBIT](IMPORTANT): Beginning ground fault scan
2022-04-19T15:08:50.997Z,1650380930.997 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-19T15:08:51.356Z,1650380931.356 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:08:51.360Z,1650380931.360 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419150851.159423,06,148,21,0112,0150,141,01,01,00,02,-1,-01,-01,1,3,6,0,150,19.9,0.50,-100,2.50,-01,-0.45,51,14500,4000*6A

2022-04-19T15:08:54.175Z,1650380934.175 [NAL9602](INFO): NAL9602 initialized
2022-04-19T15:08:55.060Z,1650380935.060 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.025146
CHAN A1 (24V): 0.052198
CHAN A2 (12V): 0.021274
CHAN A3 (5V): 0.004276
CHAN B0 (3.3V): 0.003628
CHAN B1 (3.15aV): 0.003261
CHAN B2 (3.15bV): 0.003553
CHAN B3 (GND): -0.001256
OPEN: 0.005860
Full Scale: +/- 1 mA
2022-04-19T15:09:05.889Z,1650380945.889 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-19T15:09:11.546Z,1650380951.546 [NAL9602](INFO): SBD MO Status=0, MOMSN=36452, MT Status=0, MTMSN=0
2022-04-19T15:09:11.547Z,1650380951.547 [NAL9602](INFO): No messages in MT queue
2022-04-19T15:09:38.260Z,1650380978.260 [SBIT](IMPORTANT): SBIT PASSED
2022-04-19T15:09:38.261Z,1650380978.261 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-04-19T15:09:38.261Z,1650380978.261 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2022-04-19T15:09:38.262Z,1650380978.262 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=1 bool;

2022-04-19T15:09:38.262Z,1650380978.262 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.050000 practical_salinity_unit;

2022-04-19T15:09:38.262Z,1650380978.262 [SBIT](IMPORTANT): Express linearApproximation WetLabsSeaOWL_UV_A.mass_concentration_of_petroleum_hydrocarbons_in_sea_water 0.000500 kilogram_per_cubic_meter;

2022-04-19T15:09:38.262Z,1650380978.262 [SBIT](IMPORTANT): Express none mass_concentration_of_chlorophyll_in_sea_water;

2022-04-19T15:09:38.262Z,1650380978.262 [SBIT](IMPORTANT): InternalEnvSim.loadAtStartup=1 bool;

2022-04-19T15:09:38.262Z,1650380978.262 [SBIT](IMPORTANT): InternalEnvSim.timeAdjust=1.5 day;

2022-04-19T15:09:38.262Z,1650380978.262 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=190.658274 cubic_centimeter;

2022-04-19T15:09:38.262Z,1650380978.262 [SBIT](IMPORTANT): VerticalControl.massDefault=2.122748 millimeter;

2022-04-19T15:09:38.660Z,1650380978.660 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2022-04-19T15:09:38.674Z,1650380978.674 [WorkSite](IMPORTANT): WorkSite fix at 20220419T150701: (41.530991, -70.790026)
2022-04-19T15:09:38.675Z,1650380978.675 [MissionManager](IMPORTANT): Started mission Startup
2022-04-19T15:09:38.676Z,1650380978.676 [Startup] Running Loop=1
2022-04-19T15:09:38.676Z,1650380978.676 [Startup](DEBUG): Aggregate::initialize Startup
2022-04-19T15:09:38.676Z,1650380978.676 [Startup:A.GoToSurface] Running Loop=1
2022-04-19T15:09:38.676Z,1650380978.676 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-19T15:09:38.681Z,1650380978.681 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-04-19T15:09:38.682Z,1650380978.682 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-04-19T15:09:38.683Z,1650380978.683 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-04-19T15:09:38.684Z,1650380978.684 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-19T15:09:38.690Z,1650380978.690 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-19T15:09:38.698Z,1650380978.698 [Startup:StartupSatComms] Running Loop=1
2022-04-19T15:09:38.698Z,1650380978.698 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-04-19T15:09:38.699Z,1650380978.699 [Startup:StartupSatComms:A] Running Loop=1
2022-04-19T15:09:39.044Z,1650380979.044 [LBLNavigation](INFO): Reset ping filters
2022-04-19T15:09:39.045Z,1650380979.045 [LBLNavigation](INFO): Reset fix filter
2022-04-19T15:09:39.046Z,1650380979.046 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-04-19T15:09:45.494Z,1650380985.494 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:09:45.498Z,1650380985.498 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419150945.237395,06,146,21,0118,0150,134,01,01,00,01,-1,-01,-01,1,3,1,0,150,19.3,0.87,-100,2.13,-01,0.66,58,14500,4000*4F

2022-04-19T15:10:38.853Z,1650381038.853 [Startup:StartupSatComms:A](INFO): Timed out from 2022-04-19T15:09:38.7Z
2022-04-19T15:10:38.853Z,1650381038.853 [Startup:StartupSatComms:A] Stopped
2022-04-19T15:10:38.853Z,1650381038.853 [Startup:StartupSatComms:B] Running Loop=1
2022-04-19T15:10:39.247Z,1650381039.247 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-04-19T15:10:39.624Z,1650381039.624 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-19T15:10:39.625Z,1650381039.625 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-19T15:10:40.023Z,1650381040.023 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:10:40.439Z,1650381040.439 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419151039.230955,06,1316,25,0114,0150,149,01,01,01,02,-1,-01,-01,1,3,5,0,150,65.7,1.03,-100,1.97,-01,-2.80,-12,14500,4000*76

2022-04-19T15:10:51.850Z,1650381051.850 [NAL9602](INFO): SBD MO Status=1, MOMSN=36453, MT Status=0, MTMSN=0
2022-04-19T15:10:51.913Z,1650381051.913 [NAL9602](INFO): Sent 52 bytes from file Logs/20220419T015506/Courier0048.lzma
2022-04-19T15:10:51.913Z,1650381051.913 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:10:59.412Z,1650381059.412 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:10:59.752Z,1650381059.752 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419151059.235689,06,216,23,0093,0150,208,02,02,00,02,-1,-01,-01,1,3,1,0,150,9.5,0.19,-100,2.81,-01,-0.19,60,14500,4000*5C

2022-04-19T15:11:04.151Z,1650381064.151 [NAL9602](INFO): SBD MO Status=1, MOMSN=36454, MT Status=0, MTMSN=0
2022-04-19T15:11:04.201Z,1650381064.201 [NAL9602](INFO): Sent 184 bytes from file Logs/20220419T150803/Courier0000.lzma
2022-04-19T15:11:04.201Z,1650381064.201 [NAL9602](INFO): Packets left to send: 1
2022-04-19T15:11:19.189Z,1650381079.189 [NAL9602](INFO): SBD MO Status=1, MOMSN=36455, MT Status=0, MTMSN=0
2022-04-19T15:11:19.237Z,1650381079.237 [NAL9602](INFO): Sent 80 bytes from file Logs/20220419T150803/Courier0000.lzma
2022-04-19T15:11:19.237Z,1650381079.237 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:11:31.836Z,1650381091.836 [NAL9602](INFO): SBD MO Status=1, MOMSN=36456, MT Status=0, MTMSN=0
2022-04-19T15:11:31.885Z,1650381091.885 [NAL9602](INFO): Sent 119 bytes from file Logs/20220419T015506/Express0046.lzma
2022-04-19T15:11:31.885Z,1650381091.885 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:11:38.980Z,1650381098.980 [Startup:StartupSatComms:B](INFO): Timed out from 2022-04-19T15:10:38.9Z
2022-04-19T15:11:38.980Z,1650381098.980 [Startup:StartupSatComms:B] Stopped
2022-04-19T15:11:38.980Z,1650381098.980 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-04-19T15:11:38.980Z,1650381098.980 [Startup:StartupSatComms] Stopped
2022-04-19T15:11:38.981Z,1650381098.981 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-04-19T15:11:38.981Z,1650381098.981 [Startup](INFO): Completed Startup
2022-04-19T15:11:38.981Z,1650381098.981 [MissionManager](INFO): Startup is completed.
2022-04-19T15:11:38.982Z,1650381098.982 [MissionManager](INFO): Uninitializing Mission Startup
2022-04-19T15:11:38.982Z,1650381098.982 [Startup] Stopped
2022-04-19T15:11:38.982Z,1650381098.982 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-04-19T15:11:38.982Z,1650381098.982 [Startup:A.GoToSurface] Stopped
2022-04-19T15:11:38.982Z,1650381098.982 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-19T15:11:39.393Z,1650381099.393 [MissionManager](IMPORTANT): Started mission Default
2022-04-19T15:11:39.394Z,1650381099.394 [Default] Running Loop=1
2022-04-19T15:11:39.394Z,1650381099.394 [Default](DEBUG): Aggregate::initialize Default
2022-04-19T15:11:39.394Z,1650381099.394 [Default:B.GoToSurface] Running Loop=1
2022-04-19T15:11:39.394Z,1650381099.394 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-19T15:11:39.394Z,1650381099.394 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-04-19T15:11:39.394Z,1650381099.394 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-04-19T15:11:39.395Z,1650381099.395 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-04-19T15:11:39.395Z,1650381099.395 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-19T15:11:39.395Z,1650381099.395 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-19T15:11:39.396Z,1650381099.396 [Default:A.Wait] Running Loop=1
2022-04-19T15:11:39.396Z,1650381099.396 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-04-19T15:11:52.814Z,1650381112.814 [Default:A.Wait](INFO): Done Waiting.
2022-04-19T15:11:52.814Z,1650381112.814 [Default:A.Wait] Stopped
2022-04-19T15:11:52.814Z,1650381112.814 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-04-19T15:11:53.051Z,1650381113.051 [Default:CheckIn] Running Loop=1
2022-04-19T15:11:53.051Z,1650381113.051 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-19T15:11:53.051Z,1650381113.051 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-19T15:11:53.479Z,1650381113.479 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-04-19T15:11:54.648Z,1650381114.648 [NAL9602](INFO): SBD MO Status=1, MOMSN=36457, MT Status=0, MTMSN=0
2022-04-19T15:11:54.698Z,1650381114.698 [NAL9602](INFO): Sent 144 bytes from file Logs/20220419T015506/Express0049.lzma
2022-04-19T15:11:54.698Z,1650381114.698 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:12:18.069Z,1650381138.069 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-19T15:12:18.073Z,1650381138.073 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419151217.227620,06,199,22,0139,0150,208,02,02,00,02,1,-01,-01,2,4,4,0,150,0.2,1.34,01,1.66,-01,-0.07,60,14500,4000*64

2022-04-19T15:13:04.517Z,1650381184.517 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-19T15:13:04.517Z,1650381184.517 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-19T15:13:04.519Z,1650381184.519 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:13:04.930Z,1650381184.930 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419151303.231660,06,167,22,0101,0150,208,02,02,00,03,-1,-01,-01,1,3,6,0,150,84.5,-348.46,-100,-303.90,-01,0.00,-18,14500,4000*6E

2022-04-19T15:13:05.335Z,1650381185.335 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:13:05.730Z,1650381185.730 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419151305.231379,06,507,21,0109,0150,149,01,01,01,01,-1,-01,-01,1,3,1,0,150,21.8,-2.14,-100,5.14,-01,-0.44,51,14500,4000*4F

2022-04-19T15:13:24.326Z,1650381204.326 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-19T15:13:24.327Z,1650381204.327 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-19T15:13:24.331Z,1650381204.331 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:13:24.749Z,1650381204.749 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419151321.230887,06,170,22,0125,0150,194,01,01,00,01,-1,-01,-01,1,3,6,0,150,76.1,-344.88,-100,-307.48,-01,0.00,-6,14500,4000*55

2022-04-19T15:14:01.889Z,1650381241.889 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151403.00,A,4131.95100,N,07047.28652,W,0.194,6.50,190422,,,A*78
2022-04-19T15:14:01.893Z,1650381241.893 [NAL9602](INFO): GPS fix at 20220419T151403: (41.532517, -70.788109)
2022-04-19T15:14:01.939Z,1650381241.939 [Default:CheckIn:Read_GPS] Stopped
2022-04-19T15:14:01.939Z,1650381241.939 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-19T15:14:02.319Z,1650381242.319 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-04-19T15:14:18.964Z,1650381258.964 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-19T15:14:18.966Z,1650381258.966 [NAL9602](INFO): SBD MO Status=1, MOMSN=36458, MT Status=0, MTMSN=0
2022-04-19T15:14:19.013Z,1650381259.013 [NAL9602](INFO): Sent 73 bytes from file Logs/20220419T150803/Courier0004.lzma
2022-04-19T15:14:19.013Z,1650381259.013 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:14:19.373Z,1650381259.373 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419151415.233538,06,166,22,0123,0150,194,03,03,00,03,6,-01,-01,2,3,5,0,150,1.9,-344.26,353,-308.10,-01,0.00,59,14500,4000*76

2022-04-19T15:14:28.022Z,1650381268.022 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-19T15:14:28.422Z,1650381268.422 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419151425.214493,06,1375,25,0107,0150,149,01,01,01,01,1,-01,-01,2,3,2,0,150,1.1,-8.24,-100,11.24,-01,-12.40,60,14500,4000*6A

2022-04-19T15:14:30.437Z,1650381270.437 [NAL9602](INFO): SBD MO Status=1, MOMSN=36459, MT Status=0, MTMSN=0
2022-04-19T15:14:30.493Z,1650381270.493 [NAL9602](INFO): Sent 184 bytes from file Logs/20220419T150803/Express0001.lzma
2022-04-19T15:14:30.493Z,1650381270.493 [NAL9602](INFO): Packets left to send: 5
2022-04-19T15:14:39.415Z,1650381279.415 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-19T15:14:39.815Z,1650381279.815 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419151437.208878,06,753,22,0127,0150,216,02,02,01,02,5,-01,-01,2,3,4,0,150,5.9,-4.75,-100,7.75,-01,-3.85,61,14500,4000*5E

2022-04-19T15:14:41.436Z,1650381281.436 [NAL9602](INFO): SBD MO Status=1, MOMSN=36460, MT Status=0, MTMSN=0
2022-04-19T15:14:41.489Z,1650381281.489 [NAL9602](INFO): Sent 184 bytes from file Logs/20220419T150803/Express0001.lzma
2022-04-19T15:14:41.489Z,1650381281.489 [NAL9602](INFO): Packets left to send: 4
2022-04-19T15:14:52.016Z,1650381292.016 [NAL9602](INFO): SBD MO Status=1, MOMSN=36461, MT Status=0, MTMSN=0
2022-04-19T15:14:52.077Z,1650381292.077 [NAL9602](INFO): Sent 184 bytes from file Logs/20220419T150803/Express0001.lzma
2022-04-19T15:14:52.077Z,1650381292.077 [NAL9602](INFO): Packets left to send: 3
2022-04-19T15:15:03.497Z,1650381303.497 [NAL9602](INFO): SBD MO Status=1, MOMSN=36462, MT Status=0, MTMSN=0
2022-04-19T15:15:03.557Z,1650381303.557 [NAL9602](INFO): Sent 184 bytes from file Logs/20220419T150803/Express0001.lzma
2022-04-19T15:15:03.557Z,1650381303.557 [NAL9602](INFO): Packets left to send: 2
2022-04-19T15:15:12.874Z,1650381312.874 [NAL9602](INFO): SBD MO Status=1, MOMSN=36463, MT Status=0, MTMSN=0
2022-04-19T15:15:12.933Z,1650381312.933 [NAL9602](INFO): Sent 184 bytes from file Logs/20220419T150803/Express0001.lzma
2022-04-19T15:15:12.933Z,1650381312.933 [NAL9602](INFO): Packets left to send: 1
2022-04-19T15:15:21.132Z,1650381321.132 [NAL9602](INFO): SBD MO Status=1, MOMSN=36464, MT Status=0, MTMSN=0
2022-04-19T15:15:21.189Z,1650381321.189 [NAL9602](INFO): Sent 122 bytes from file Logs/20220419T150803/Express0001.lzma
2022-04-19T15:15:21.189Z,1650381321.189 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:15:29.782Z,1650381329.782 [NAL9602](INFO): SBD MO Status=1, MOMSN=36465, MT Status=0, MTMSN=0
2022-04-19T15:15:29.833Z,1650381329.833 [NAL9602](INFO): Sent 94 bytes from file Logs/20220419T150803/Express0005.lzma
2022-04-19T15:15:29.833Z,1650381329.833 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:15:37.800Z,1650381337.800 [NAL9602](INFO): SBD MO Status=0, MOMSN=36466, MT Status=0, MTMSN=0
2022-04-19T15:15:37.912Z,1650381337.912 [Default:CheckIn:Read_Iridium] Stopped
2022-04-19T15:15:37.912Z,1650381337.912 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-19T15:15:37.912Z,1650381337.912 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-19T15:15:42.244Z,1650381342.244 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-04-19T15:15:42.247Z,1650381342.247 [BPC1](INFO): Received data from all battery sticks.
2022-04-19T15:15:45.475Z,1650381345.475 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:15:45.479Z,1650381345.479 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419151545.233484,06,591,21,0096,0150,194,02,02,01,02,-1,-01,-01,1,3,7,0,150,12.5,0.01,-100,2.99,-01,-0.06,59,14500,4000*6D

2022-04-19T15:16:08.507Z,1650381368.507 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-19T15:17:46.983Z,1650381466.983 [DataOverHttps](IMPORTANT): SBD MTMSN=20220419T151749
2022-04-19T15:17:46.987Z,1650381466.987 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004805
2022-04-19T15:18:01.041Z,1650381481.041 [DataOverHttps](INFO): Received command: ! echo i > /dev/loadC3
2022-04-19T15:18:01.091Z,1650381481.091 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC3
2022-04-19T15:18:02.043Z,1650381482.043 [DataOverHttps](IMPORTANT): SBD MTMSN=20220419T151804
2022-04-19T15:18:10.082Z,1650381490.082 [DataOverHttps](INFO): Received command: ! echo i > /dev/loadC2
2022-04-19T15:18:10.154Z,1650381490.154 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC2
2022-04-19T15:18:13.090Z,1650381493.090 [DataOverHttps](IMPORTANT): SBD MTMSN=20220419T151815
2022-04-19T15:18:23.132Z,1650381503.132 [DataOverHttps](INFO): Received command: ! echo i > /dev/loadC1
2022-04-19T15:18:23.190Z,1650381503.190 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC1
2022-04-19T15:18:24.134Z,1650381504.134 [DataOverHttps](IMPORTANT): SBD MTMSN=20220419T151826
2022-04-19T15:18:33.173Z,1650381513.173 [DataOverHttps](INFO): Received command: ! echo i > /dev/loadC0
2022-04-19T15:18:33.206Z,1650381513.206 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC0
2022-04-19T15:18:34.175Z,1650381514.175 [DataOverHttps](IMPORTANT): SBD MTMSN=20220419T151836
2022-04-19T15:18:54.257Z,1650381534.257 [DataOverHttps](INFO): Received command: ! echo i > /dev/loadB5
2022-04-19T15:18:54.278Z,1650381534.278 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB5
2022-04-19T15:18:58.270Z,1650381538.270 [DataOverHttps](IMPORTANT): SBD MTMSN=20220419T151858
2022-04-19T15:19:10.321Z,1650381550.321 [DataOverHttps](INFO): Received command: gfscan
2022-04-19T15:19:10.322Z,1650381550.322 [CommandExec](IMPORTANT): got command gfscan
2022-04-19T15:19:10.363Z,1650381550.363 [CBIT](IMPORTANT): Beginning ground fault scan
2022-04-19T15:19:21.283Z,1650381561.283 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.034534
CHAN A1 (24V): 0.061577
CHAN A2 (12V): 0.017508
CHAN A3 (5V): 0.003840
CHAN B0 (3.3V): 0.003289
CHAN B1 (3.15aV): 0.003716
CHAN B2 (3.15bV): 0.003554
CHAN B3 (GND): -0.000919
OPEN: 0.006044
Full Scale: +/- 1 mA
2022-04-19T15:19:59.595Z,1650381599.595 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-19T15:20:00.005Z,1650381600.005 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419151959.228695,06,545,21,0105,0150,194,01,01,01,01,1,-01,-01,2,4,2,0,150,-29.2,1.25,00,1.75,-01,-1.45,58,14500,4000*76

2022-04-19T15:20:38.393Z,1650381638.393 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-19T15:20:38.393Z,1650381638.393 [Default:CheckIn:C.Wait] Stopped
2022-04-19T15:20:38.393Z,1650381638.393 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-19T15:20:38.393Z,1650381638.393 [Default:CheckIn:D] Running Loop=1
2022-04-19T15:20:38.826Z,1650381638.826 [Default:CheckIn:D] Stopped
2022-04-19T15:20:38.826Z,1650381638.826 [Default:CheckIn:E] Running Loop=1
2022-04-19T15:20:39.211Z,1650381639.211 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.990533 min 
2022-04-19T15:20:39.211Z,1650381639.211 [Default:CheckIn:E] Stopped
2022-04-19T15:20:39.211Z,1650381639.211 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-19T15:20:39.211Z,1650381639.211 [Default:CheckIn] Stopped
2022-04-19T15:20:39.212Z,1650381639.212 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-19T15:20:39.212Z,1650381639.212 [Default:CheckIn](INFO): Running loop #2
2022-04-19T15:20:39.212Z,1650381639.212 [Default:CheckIn] Running Loop=2
2022-04-19T15:20:39.212Z,1650381639.212 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-19T15:20:39.212Z,1650381639.212 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-19T15:20:39.698Z,1650381639.698 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:20:41.205Z,1650381641.205 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152043.00,A,4131.98982,N,07047.25635,W,0.486,52.90,190422,,,A*43
2022-04-19T15:20:41.207Z,1650381641.207 [NAL9602](INFO): GPS fix at 20220419T152043: (41.533164, -70.787606)
2022-04-19T15:20:41.223Z,1650381641.223 [Default:CheckIn:Read_GPS] Stopped
2022-04-19T15:20:41.223Z,1650381641.223 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-19T15:20:52.917Z,1650381652.917 [NAL9602](INFO): SBD MO Status=0, MOMSN=36467, MT Status=0, MTMSN=0
2022-04-19T15:20:52.917Z,1650381652.917 [NAL9602](INFO): No messages in MT queue
2022-04-19T15:20:56.766Z,1650381656.766 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247452
2022-04-19T15:21:16.540Z,1650381676.540 [NAL9602](INFO): SBD MO Status=1, MOMSN=36468, MT Status=0, MTMSN=0
2022-04-19T15:21:16.602Z,1650381676.602 [NAL9602](INFO): Sent 184 bytes from file Logs/20220419T150803/Courier0007.lzma
2022-04-19T15:21:16.602Z,1650381676.602 [NAL9602](INFO): Packets left to send: 1
2022-04-19T15:21:23.125Z,1650381683.125 [NAL9602](INFO): SBD MO Status=1, MOMSN=36469, MT Status=0, MTMSN=0
2022-04-19T15:21:23.185Z,1650381683.185 [NAL9602](INFO): Sent 23 bytes from file Logs/20220419T150803/Courier0007.lzma
2022-04-19T15:21:23.185Z,1650381683.185 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:21:26.474Z,1650381686.474 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-19T15:21:26.474Z,1650381686.474 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-19T15:21:26.851Z,1650381686.851 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:21:27.262Z,1650381687.262 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419152125.234390,06,514,21,0100,0150,208,02,02,01,02,-1,-01,-01,1,3,3,0,150,73.2,0.54,-100,2.46,-01,0.19,-12,14500,4000*6B

2022-04-19T15:21:27.893Z,1650381687.893 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:21:34.124Z,1650381694.124 [NAL9602](INFO): SBD MO Status=1, MOMSN=36470, MT Status=0, MTMSN=0
2022-04-19T15:21:34.173Z,1650381694.173 [NAL9602](INFO): Sent 184 bytes from file Logs/20220419T150803/Express0008.lzma
2022-04-19T15:21:34.173Z,1650381694.173 [NAL9602](INFO): Packets left to send: 2
2022-04-19T15:21:41.116Z,1650381701.116 [NAL9602](INFO): SBD MO Status=1, MOMSN=36471, MT Status=0, MTMSN=0
2022-04-19T15:21:41.173Z,1650381701.173 [NAL9602](INFO): Sent 184 bytes from file Logs/20220419T150803/Express0008.lzma
2022-04-19T15:21:41.173Z,1650381701.173 [NAL9602](INFO): Packets left to send: 1
2022-04-19T15:21:50.513Z,1650381710.513 [NAL9602](INFO): SBD MO Status=1, MOMSN=36472, MT Status=0, MTMSN=0
2022-04-19T15:21:50.566Z,1650381710.566 [NAL9602](INFO): Sent 119 bytes from file Logs/20220419T150803/Express0008.lzma
2022-04-19T15:21:50.567Z,1650381710.567 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:21:58.199Z,1650381718.199 [NAL9602](INFO): SBD MO Status=0, MOMSN=36473, MT Status=0, MTMSN=0
2022-04-19T15:21:58.286Z,1650381718.286 [Default:CheckIn:Read_Iridium] Stopped
2022-04-19T15:21:58.286Z,1650381718.286 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-19T15:21:58.286Z,1650381718.286 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-19T15:22:03.033Z,1650381723.033 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:22:28.897Z,1650381748.897 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-19T15:22:38.173Z,1650381758.173 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:22:43.436Z,1650381763.436 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:22:43.440Z,1650381763.440 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419152243.223775,06,640,22,0090,0150,149,03,03,01,03,-1,-01,-01,1,3,8,0,150,3.8,0.00,-100,3.00,-01,-2.68,61,14500,4000*5B

2022-04-19T15:23:09.300Z,1650381789.300 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:23:09.305Z,1650381789.305 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419152309.224225,06,1000,23,0168,0150,208,02,02,01,02,-1,-01,-01,1,3,4,0,150,11.7,0.05,-100,2.95,-01,0.63,60,14500,4000*7D

2022-04-19T15:23:13.313Z,1650381793.313 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:23:22.669Z,1650381802.669 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-19T15:23:22.669Z,1650381802.669 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-19T15:23:22.671Z,1650381802.671 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:23:23.033Z,1650381803.033 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419152321.220911,06,834,23,0521,0150,156,01,01,01,02,-1,-01,-01,1,3,6,0,150,71.4,3.29,-100,-0.29,-01,-4.18,-12,14500,4000*6F

2022-04-19T15:23:39.597Z,1650381819.597 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:23:39.601Z,1650381819.601 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419152339.225779,06,780,22,0164,0150,141,01,01,01,01,-1,-01,-01,1,3,4,0,150,25.4,-0.05,-100,3.05,-01,-0.24,51,14500,4000*40

2022-04-19T15:23:48.465Z,1650381828.465 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:24:13.533Z,1650381853.533 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-19T15:24:13.534Z,1650381853.534 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-19T15:24:13.535Z,1650381853.535 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:24:13.940Z,1650381853.940 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419152413.223178,06,190,22,0090,0150,14,00,00,00,02,-1,-01,-01,1,3,1,0,150,-100.0,0.43,-100,2.57,-01,-0.38,-2147483648,14500,4000*62

2022-04-19T15:24:23.605Z,1650381863.605 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:24:58.749Z,1650381898.749 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:25:11.300Z,1650381911.300 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-19T15:25:11.301Z,1650381911.301 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-19T15:25:11.302Z,1650381911.302 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:25:11.731Z,1650381911.731 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419152509.222256,06,1195,24,0132,0150,149,01,01,01,01,-1,-01,-01,1,3,4,0,150,66.6,-4.35,-100,7.35,-01,-1.78,-6,14500,4000*66

2022-04-19T15:25:33.889Z,1650381933.889 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:25:59.379Z,1650381959.379 [Micromodem](INFO): Nmea in: $CAMSG,Error accessing coproc,4*51

2022-04-19T15:25:59.384Z,1650381959.384 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419152559.220018,06,1251,24,0093,0150,208,01,01,01,01,-1,-01,-01,4,3,0,0,-999,-99.9,-9.99,-999,-9.99,-01,0.00,-999,14500,4000*67

2022-04-19T15:26:09.037Z,1650381969.037 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:26:41.394Z,1650382001.394 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:26:41.398Z,1650382001.398 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419152641.223270,06,507,21,0129,0150,194,01,01,01,01,-1,-01,-01,1,3,1,0,150,18.6,0.09,-100,2.91,-01,1.98,59,14500,4000*48

2022-04-19T15:26:44.185Z,1650382004.185 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:26:58.867Z,1650382018.867 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-19T15:26:58.867Z,1650382018.867 [Default:CheckIn:C.Wait] Stopped
2022-04-19T15:26:58.867Z,1650382018.867 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-19T15:26:58.867Z,1650382018.867 [Default:CheckIn:D] Running Loop=1
2022-04-19T15:26:59.182Z,1650382019.182 [Default:CheckIn:D] Stopped
2022-04-19T15:26:59.183Z,1650382019.183 [Default:CheckIn:E] Running Loop=1
2022-04-19T15:26:59.594Z,1650382019.594 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.329814 min 
2022-04-19T15:26:59.594Z,1650382019.594 [Default:CheckIn:E] Stopped
2022-04-19T15:26:59.595Z,1650382019.595 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-19T15:26:59.595Z,1650382019.595 [Default:CheckIn] Stopped
2022-04-19T15:26:59.595Z,1650382019.595 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-19T15:26:59.595Z,1650382019.595 [Default:CheckIn](INFO): Running loop #3
2022-04-19T15:26:59.595Z,1650382019.595 [Default:CheckIn] Running Loop=3
2022-04-19T15:26:59.595Z,1650382019.595 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-19T15:26:59.595Z,1650382019.595 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-19T15:27:01.621Z,1650382021.621 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152703.00,A,4132.03789,N,07047.21359,W,0.680,43.04,190422,,,A*46
2022-04-19T15:27:01.624Z,1650382021.624 [NAL9602](INFO): GPS fix at 20220419T152703: (41.533965, -70.786893)
2022-04-19T15:27:01.641Z,1650382021.641 [Default:CheckIn:Read_GPS] Stopped
2022-04-19T15:27:01.641Z,1650382021.641 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-19T15:27:18.277Z,1650382038.277 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=36474, MT Status=1, MTMSN=1420
2022-04-19T15:27:18.322Z,1650382038.322 [NAL9602](INFO): Sent 73 bytes from file Logs/20220419T150803/Courier0010.lzma
2022-04-19T15:27:18.322Z,1650382038.322 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:27:18.777Z,1650382038.777 [NAL9602](INFO): Received command: gfscan
2022-04-19T15:27:18.806Z,1650382038.806 [CommandExec](IMPORTANT): got command gfscan
2022-04-19T15:27:18.825Z,1650382038.825 [CBIT](IMPORTANT): Beginning ground fault scan
2022-04-19T15:27:19.325Z,1650382039.325 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:27:26.956Z,1650382046.956 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-04-19T15:27:31.056Z,1650382051.056 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.026250
CHAN A1 (24V): 0.055856
CHAN A2 (12V): 0.022613
CHAN A3 (5V): 0.003494
CHAN B0 (3.3V): 0.002916
CHAN B1 (3.15aV): 0.002998
CHAN B2 (3.15bV): 0.003003
CHAN B3 (GND): -0.000151
OPEN: 0.006051
Full Scale: +/- 1 mA
2022-04-19T15:27:36.679Z,1650382056.679 [NAL9602](INFO): SBD MO Status=1, MOMSN=36475, MT Status=0, MTMSN=0
2022-04-19T15:27:36.729Z,1650382056.729 [NAL9602](INFO): Sent 120 bytes from file Logs/20220419T150803/Express0012.lzma
2022-04-19T15:27:36.729Z,1650382056.729 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:27:45.531Z,1650382065.531 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-19T15:27:45.531Z,1650382065.531 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-19T15:27:45.935Z,1650382065.935 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:27:46.346Z,1650382066.346 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419152745.218172,06,520,21,0115,0150,208,02,02,01,02,-1,-01,-01,1,3,2,0,150,81.2,2.33,-100,0.67,-01,-0.19,-12,14500,4000*4B

2022-04-19T15:27:46.749Z,1650382066.749 [NAL9602](INFO): SBD MO Status=0, MOMSN=36476, MT Status=0, MTMSN=0
2022-04-19T15:27:54.465Z,1650382074.465 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:28:05.421Z,1650382085.421 [NAL9602](INFO): SBD MO Status=1, MOMSN=36477, MT Status=0, MTMSN=0
2022-04-19T15:28:05.469Z,1650382085.469 [NAL9602](INFO): Sent 52 bytes from file Logs/20220419T150803/Courier0016.lzma
2022-04-19T15:28:05.469Z,1650382085.469 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:28:14.428Z,1650382094.428 [NAL9602](INFO): SBD MO Status=1, MOMSN=36478, MT Status=0, MTMSN=0
2022-04-19T15:28:14.489Z,1650382094.489 [NAL9602](INFO): Sent 184 bytes from file Logs/20220419T150803/Express0017.lzma
2022-04-19T15:28:14.489Z,1650382094.489 [NAL9602](INFO): Packets left to send: 1
2022-04-19T15:28:15.244Z,1650382095.244 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:28:17.392Z,1650382097.392 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419152815.221359,06,229,23,0116,0150,134,01,01,00,02,-1,-01,-01,1,3,7,0,150,21.5,-9.37,-100,12.37,-01,-0.89,50,14500,4000*7C

2022-04-19T15:28:25.038Z,1650382105.038 [NAL9602](INFO): SBD MO Status=1, MOMSN=36479, MT Status=0, MTMSN=0
2022-04-19T15:28:25.089Z,1650382105.089 [NAL9602](INFO): Sent 150 bytes from file Logs/20220419T150803/Express0017.lzma
2022-04-19T15:28:25.089Z,1650382105.089 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:28:29.617Z,1650382109.617 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:28:35.543Z,1650382115.543 [NAL9602](INFO): SBD MO Status=0, MOMSN=36480, MT Status=0, MTMSN=0
2022-04-19T15:28:35.626Z,1650382115.626 [Default:CheckIn:Read_Iridium] Stopped
2022-04-19T15:28:35.626Z,1650382115.626 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-19T15:28:35.626Z,1650382115.626 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-19T15:28:36.797Z,1650382116.797 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-19T15:28:54.969Z,1650382134.969 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2022-04-19T15:29:04.761Z,1650382144.761 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:29:06.251Z,1650382146.251 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-19T15:29:39.909Z,1650382179.909 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:29:41.408Z,1650382181.408 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-19T15:29:41.408Z,1650382181.408 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-19T15:29:41.410Z,1650382181.410 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:29:41.807Z,1650382181.807 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419152941.203630,06,959,23,0105,0150,194,02,02,01,02,-1,-01,-01,1,3,5,0,150,71.6,2.14,-100,0.86,-01,-2.38,-12,14500,4000*4A

2022-04-19T15:30:15.077Z,1650382215.077 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:30:50.217Z,1650382250.217 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:31:25.361Z,1650382285.361 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:32:00.521Z,1650382320.521 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:32:35.674Z,1650382355.674 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:33:10.817Z,1650382390.817 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:33:36.148Z,1650382416.148 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-19T15:33:36.148Z,1650382416.148 [Default:CheckIn:C.Wait] Stopped
2022-04-19T15:33:36.148Z,1650382416.148 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-19T15:33:36.148Z,1650382416.148 [Default:CheckIn:D] Running Loop=1
2022-04-19T15:33:36.542Z,1650382416.542 [Default:CheckIn:D] Stopped
2022-04-19T15:33:36.542Z,1650382416.542 [Default:CheckIn:E] Running Loop=1
2022-04-19T15:33:36.999Z,1650382416.999 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.952476 min 
2022-04-19T15:33:36.999Z,1650382416.999 [Default:CheckIn:E] Stopped
2022-04-19T15:33:36.999Z,1650382416.999 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-19T15:33:36.999Z,1650382416.999 [Default:CheckIn] Stopped
2022-04-19T15:33:36.999Z,1650382416.999 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-19T15:33:36.000Z,1650382417.000 [Default:CheckIn](INFO): Running loop #4
2022-04-19T15:33:36.000Z,1650382417.000 [Default:CheckIn] Running Loop=4
2022-04-19T15:33:36.000Z,1650382417.000 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-19T15:33:36.000Z,1650382417.000 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-19T15:33:38.957Z,1650382418.957 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153341.00,A,4132.08573,N,07047.18098,W,0.972,30.74,190422,,,A*4C
2022-04-19T15:33:38.959Z,1650382418.959 [NAL9602](INFO): GPS fix at 20220419T153341: (41.534762, -70.786350)
2022-04-19T15:33:39.048Z,1650382419.048 [Default:CheckIn:Read_GPS] Stopped
2022-04-19T15:33:39.048Z,1650382419.048 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-19T15:33:39.355Z,1650382419.355 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:33:39.360Z,1650382419.360 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419153339.218513,06,260,24,0098,0150,216,02,02,00,02,-1,-01,-01,1,3,4,0,150,11.4,0.11,-100,2.89,-01,-0.54,61,14500,4000*63

2022-04-19T15:33:45.818Z,1650382425.818 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-19T15:33:45.819Z,1650382425.819 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-19T15:33:45.985Z,1650382425.985 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:33:46.235Z,1650382426.235 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:33:46.661Z,1650382426.661 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419153345.218156,06,284,24,0140,0150,208,02,02,00,02,-1,-01,-01,1,3,1,0,150,73.2,3.62,-100,-0.62,-01,-3.07,-12,14500,4000*6A

2022-04-19T15:33:48.244Z,1650382428.244 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-19T15:33:48.244Z,1650382428.244 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-19T15:33:50.397Z,1650382430.397 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:33:50.770Z,1650382430.770 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419153347.213574,06,699,22,0104,0150,141,01,01,01,02,-1,-01,-01,1,3,4,0,150,66.9,-0.13,-100,3.13,-01,-2.32,-12,14500,4000*6B

2022-04-19T15:33:53.000Z,1650382434.000 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-19T15:33:54.402Z,1650382434.402 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419153353.222742,06,354,25,0168,0150,194,02,02,00,03,1,-01,-01,2,4,4,0,150,2.7,0.63,00,2.37,-01,-0.83,58,14500,4000*65

2022-04-19T15:33:54.813Z,1650382434.813 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=36481, MT Status=1, MTMSN=1421
2022-04-19T15:33:54.865Z,1650382434.865 [NAL9602](INFO): Sent 74 bytes from file Logs/20220419T150803/Courier0019.lzma
2022-04-19T15:33:54.865Z,1650382434.865 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:33:55.389Z,1650382435.389 [NAL9602](INFO): Received command: ! echo i | tee /dev/loadC6 /dev/loadC5 /dev/loadC4 /dev/loadA6 /dev/loadA7
2022-04-19T15:33:55.457Z,1650382435.457 [CommandExec](IMPORTANT): got command ! echo i | tee /dev/loadC6 /dev/loadC5 /dev/loadC4 /dev/loadA6 /dev/loadA7
2022-04-19T15:33:55.561Z,1650382435.561 [CommandExec](IMPORTANT): i
  
2022-04-19T15:34:13.064Z,1650382453.064 [NAL9602](INFO): SBD MO Status=1, MOMSN=36482, MT Status=0, MTMSN=0
2022-04-19T15:34:13.121Z,1650382453.121 [NAL9602](INFO): Sent 120 bytes from file Logs/20220419T150803/Express0020.lzma
2022-04-19T15:34:13.121Z,1650382453.121 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:34:20.749Z,1650382460.749 [NAL9602](INFO): SBD MO Status=0, MOMSN=36483, MT Status=0, MTMSN=0
2022-04-19T15:34:21.125Z,1650382461.125 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:34:25.586Z,1650382465.586 [Micromodem](FAULT): Failed to receive CAREV within timeout
2022-04-19T15:34:25.586Z,1650382465.586 [Micromodem] Hardware Fault, FailCount= 1
2022-04-19T15:34:25.586Z,1650382465.586 [Micromodem](ERROR): Hardware Fault
2022-04-19T15:34:25.743Z,1650382465.743 [CBIT](ERROR): Hardware Fault in component: Micromodem
2022-04-19T15:34:25.990Z,1650382465.990 [Micromodem](INFO): Powering down
2022-04-19T15:34:28.688Z,1650382468.688 [CBIT](INFO): Clearing failed state for component Micromodem
2022-04-19T15:34:28.689Z,1650382468.689 [Micromodem] No Fault, FailCount= 1
2022-04-19T15:34:29.410Z,1650382469.410 [Micromodem](INFO): Powering up
2022-04-19T15:34:29.410Z,1650382469.410 [Micromodem](DEBUG): Initializing Micromodem.
2022-04-19T15:34:34.254Z,1650382474.254 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2022-04-19T15:34:34.740Z,1650382474.740 [Micromodem](INFO): Nmea in: $CATMG,2022-04-19T15:34:33.992226Z,RTC,RTC*59

2022-04-19T15:34:34.740Z,1650382474.740 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2022-04-19T15:34:33.992226Z,RTC,RTC*59

2022-04-19T15:34:35.108Z,1650382475.108 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2022-04-19T15:34:35.110Z,1650382475.110 [Micromodem](INFO): Nmea out: $CCCFG,POW,20*08

2022-04-19T15:34:35.470Z,1650382475.470 [Micromodem](INFO): Nmea in: $CACFG,POW,20*0A

2022-04-19T15:34:35.471Z,1650382475.471 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2022-04-19T15:34:35.874Z,1650382475.874 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2022-04-19T15:34:35.875Z,1650382475.875 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2022-04-19T15:34:36.276Z,1650382476.276 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2022-04-19T15:34:36.277Z,1650382476.277 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2022-04-19T15:34:36.684Z,1650382476.684 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2022-04-19T15:34:36.684Z,1650382476.684 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2022-04-19T15:34:37.086Z,1650382477.086 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2022-04-19T15:34:37.087Z,1650382477.087 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47

2022-04-19T15:34:37.494Z,1650382477.494 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45

2022-04-19T15:34:37.495Z,1650382477.495 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2022-04-19T15:34:37.891Z,1650382477.891 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2022-04-19T15:34:37.891Z,1650382477.891 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2022-04-19T15:34:38.299Z,1650382478.299 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2022-04-19T15:34:38.300Z,1650382478.300 [Micromodem](INFO): Nmea out: $CCCLK,2022,04,19,15,34,39*43

2022-04-19T15:34:38.310Z,1650382478.310 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=36484, MT Status=1, MTMSN=1422
2022-04-19T15:34:38.363Z,1650382478.363 [NAL9602](INFO): Sent 52 bytes from file Logs/20220419T150803/Courier0022.lzma
2022-04-19T15:34:38.363Z,1650382478.363 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:34:38.721Z,1650382478.721 [Micromodem](INFO): Nmea in: $CACLK,2022,4,19,15,34,39*71

2022-04-19T15:34:38.723Z,1650382478.723 [Micromodem](INFO): Nmea in: $CATMS,0,2022-04-19T15:34:40Z*7F

2022-04-19T15:34:38.813Z,1650382478.813 [NAL9602](INFO): Received command: gfscan
2022-04-19T15:34:38.834Z,1650382478.834 [CommandExec](IMPORTANT): got command gfscan
2022-04-19T15:34:38.898Z,1650382478.898 [CBIT](IMPORTANT): Beginning ground fault scan
2022-04-19T15:34:39.107Z,1650382479.107 [Micromodem](INFO): Nmea in: $CATMG,2022-04-19T15:34:40.027047Z,USER_CMD,RTC*1E

2022-04-19T15:34:49.396Z,1650382489.396 [NAL9602](INFO): SBD MO Status=1, MOMSN=36485, MT Status=0, MTMSN=0
2022-04-19T15:34:49.449Z,1650382489.449 [NAL9602](INFO): Sent 173 bytes from file Logs/20220419T150803/Express0023.lzma
2022-04-19T15:34:49.449Z,1650382489.449 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:34:51.062Z,1650382491.062 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.025522
CHAN A1 (24V): 0.054145
CHAN A2 (12V): 0.022613
CHAN A3 (5V): 0.003419
CHAN B0 (3.3V): 0.003557
CHAN B1 (3.15aV): 0.003164
CHAN B2 (3.15bV): 0.002983
CHAN B3 (GND): -0.000709
OPEN: 0.006001
Full Scale: +/- 1 mA
2022-04-19T15:34:56.265Z,1650382496.265 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:34:58.714Z,1650382498.714 [NAL9602](INFO): SBD MO Status=0, MOMSN=36486, MT Status=0, MTMSN=0
2022-04-19T15:35:16.188Z,1650382516.188 [NAL9602](INFO): SBD MO Status=1, MOMSN=36487, MT Status=0, MTMSN=0
2022-04-19T15:35:16.237Z,1650382516.237 [NAL9602](INFO): Sent 52 bytes from file Logs/20220419T150803/Courier0025.lzma
2022-04-19T15:35:16.237Z,1650382516.237 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:35:25.558Z,1650382525.558 [NAL9602](INFO): SBD MO Status=1, MOMSN=36488, MT Status=0, MTMSN=0
2022-04-19T15:35:25.615Z,1650382525.615 [NAL9602](INFO): Sent 184 bytes from file Logs/20220419T150803/Express0026.lzma
2022-04-19T15:35:25.615Z,1650382525.615 [NAL9602](INFO): Packets left to send: 2
2022-04-19T15:35:31.409Z,1650382531.409 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:35:41.813Z,1650382541.813 [NAL9602](INFO): SBD MO Status=1, MOMSN=36489, MT Status=0, MTMSN=0
2022-04-19T15:35:41.867Z,1650382541.867 [NAL9602](INFO): Sent 184 bytes from file Logs/20220419T150803/Express0026.lzma
2022-04-19T15:35:41.867Z,1650382541.867 [NAL9602](INFO): Packets left to send: 1
2022-04-19T15:36:03.806Z,1650382563.806 [NAL9602](INFO): SBD MO Status=2, MOMSN=36490, MT Status=2, MTMSN=0
2022-04-19T15:36:03.807Z,1650382563.807 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-19T15:36:06.549Z,1650382566.549 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:36:22.911Z,1650382582.911 [NAL9602](INFO): SBD MO Status=2, MOMSN=36490, MT Status=2, MTMSN=0
2022-04-19T15:36:22.912Z,1650382582.912 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-19T15:36:41.694Z,1650382601.694 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:36:50.030Z,1650382610.030 [NAL9602](INFO): SBD MO Status=1, MOMSN=36490, MT Status=0, MTMSN=0
2022-04-19T15:36:50.089Z,1650382610.089 [NAL9602](INFO): Sent 6 bytes from file Logs/20220419T150803/Express0026.lzma
2022-04-19T15:36:50.089Z,1650382610.089 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:36:58.109Z,1650382618.109 [NAL9602](INFO): SBD MO Status=0, MOMSN=36491, MT Status=0, MTMSN=0
2022-04-19T15:36:58.187Z,1650382618.187 [Default:CheckIn:Read_Iridium] Stopped
2022-04-19T15:36:58.187Z,1650382618.187 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-19T15:36:58.187Z,1650382618.187 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-19T15:37:16.833Z,1650382636.833 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:37:23.963Z,1650382643.963 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-19T15:37:23.968Z,1650382643.968 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419153724.203291,06,1657,26,0147,0150,216,02,02,01,02,1,-01,-01,2,4,3,0,150,2.7,-1.53,-3,4.53,-01,-0.62,61,14500,4000*6E

2022-04-19T15:37:28.815Z,1650382648.815 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-19T15:37:51.989Z,1650382671.989 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:38:27.137Z,1650382707.137 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:38:57.299Z,1650382737.299 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-19T15:38:57.303Z,1650382737.303 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419153858.215996,06,248,23,0090,0150,208,02,02,00,03,-1,-01,-01,1,3,1,0,150,4.8,0.96,-100,2.04,-01,0.94,61,14500,4000*7E

2022-04-19T15:39:02.285Z,1650382742.285 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:39:37.425Z,1650382777.425 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:40:11.237Z,1650382811.237 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-19T15:40:11.242Z,1650382811.242 [Micromodem](INFO): Nmea in: $CACST,6,1,20220419154010.201281,06,255,24,0096,0150,208,02,02,00,02,5,-01,-01,2,3,4,0,150,3.9,1.24,-100,1.76,-01,-8.26,61,14500,4000*72

2022-04-19T15:40:12.565Z,1650382812.565 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:40:47.705Z,1650382847.705 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:41:17.505Z,1650382877.505 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2022-04-19T15:41:22.845Z,1650382882.845 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:41:57.991Z,1650382917.991 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-04-19T15:41:58.736Z,1650382918.736 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-19T15:41:58.736Z,1650382918.736 [Default:CheckIn:C.Wait] Stopped
2022-04-19T15:41:58.736Z,1650382918.736 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-19T15:41:58.736Z,1650382918.736 [Default:CheckIn:D] Running Loop=1
2022-04-19T15:41:59.135Z,1650382919.135 [Default:CheckIn:D] Stopped
2022-04-19T15:41:59.135Z,1650382919.135 [Default:CheckIn:E] Running Loop=1
2022-04-19T15:41:59.519Z,1650382919.519 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.329026 min 
2022-04-19T15:41:59.519Z,1650382919.519 [Default:CheckIn:E] Stopped
2022-04-19T15:41:59.519Z,1650382919.519 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-19T15:41:59.519Z,1650382919.519 [Default:CheckIn] Stopped
2022-04-19T15:41:59.519Z,1650382919.519 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-19T15:41:59.519Z,1650382919.519 [Default:CheckIn](INFO): Running loop #5
2022-04-19T15:41:59.520Z,1650382919.520 [Default:CheckIn] Running Loop=5
2022-04-19T15:41:59.520Z,1650382919.520 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-19T15:41:59.520Z,1650382919.520 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-19T15:42:01.531Z,1650382921.531 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154203.00,A,4132.13341,N,07047.13521,W,0.467,5.32,190422,,,A*70
2022-04-19T15:42:01.533Z,1650382921.533 [NAL9602](INFO): GPS fix at 20220419T154203: (41.535557, -70.785587)
2022-04-19T15:42:01.556Z,1650382921.556 [Default:CheckIn:Read_GPS] Stopped
2022-04-19T15:42:01.556Z,1650382921.556 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-19T15:42:09.762Z,1650382929.762 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=36492, MT Status=1, MTMSN=1423
2022-04-19T15:42:09.813Z,1650382929.813 [NAL9602](INFO): Sent 80 bytes from file Logs/20220419T150803/Courier0028.lzma
2022-04-19T15:42:09.813Z,1650382929.813 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:42:10.309Z,1650382930.309 [NAL9602](INFO): Received command: configSet Micromodem.loadAtStartup 0 bool persist
2022-04-19T15:42:10.684Z,1650382930.684 [CommandExec](IMPORTANT): got command configSet Micromodem.loadAtStartup 0 bool persist
2022-04-19T15:42:10.689Z,1650382930.689 [CommandExec](IMPORTANT): configSet Micromodem.loadAtStartup requires a restart to take effect.
2022-04-19T15:42:20.360Z,1650382940.360 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=36493, MT Status=1, MTMSN=1424
2022-04-19T15:42:20.417Z,1650382940.417 [NAL9602](INFO): Sent 118 bytes from file Logs/20220419T150803/Express0029.lzma
2022-04-19T15:42:20.417Z,1650382940.417 [NAL9602](INFO): Packets left to send: 0
2022-04-19T15:42:20.853Z,1650382940.853 [NAL9602](INFO): Received command: restart app
2022-04-19T15:42:20.894Z,1650382940.894 [CommandExec](IMPORTANT): got command restart application
2022-04-19T15:42:21.897Z,1650382941.897 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-04-19T15:42:21.897Z,1650382941.897 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-19T15:42:21.897Z,1650382941.897 [CommandExec](INFO): Uninitializing the command executive.
2022-04-19T15:42:21.897Z,1650382941.897 [CommandExec](INFO): Uninitializing the command scheduler.
2022-04-19T15:42:21.898Z,1650382941.898 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:22.093Z,1650382942.093 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-04-19T15:42:22.093Z,1650382942.093 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-04-19T15:42:22.093Z,1650382942.093 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:22.094Z,1650382942.094 [NavChartDb](INFO): Join timeout helper Thread ID is 4942
2022-04-19T15:42:22.229Z,1650382942.229 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-19T15:42:22.229Z,1650382942.229 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:22.233Z,1650382942.233 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2022-04-19T15:42:22.233Z,1650382942.233 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:22.233Z,1650382942.233 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 4943
2022-04-19T15:42:22.265Z,1650382942.265 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-19T15:42:22.265Z,1650382942.265 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:22.273Z,1650382942.273 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-04-19T15:42:22.273Z,1650382942.273 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:22.274Z,1650382942.274 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4944
2022-04-19T15:42:23.177Z,1650382943.177 [CTD_Seabird](INFO): Powering down
2022-04-19T15:42:23.189Z,1650382943.189 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-19T15:42:23.189Z,1650382943.189 [CTD_Seabird](INFO): Powering down
2022-04-19T15:42:23.201Z,1650382943.201 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:23.217Z,1650382943.217 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-04-19T15:42:23.217Z,1650382943.217 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:23.217Z,1650382943.217 [Radio_Surface](INFO): Join timeout helper Thread ID is 4945
2022-04-19T15:42:23.481Z,1650382943.481 [Radio_Surface](INFO): Powering down
2022-04-19T15:42:23.482Z,1650382943.482 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-19T15:42:23.482Z,1650382943.482 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:23.485Z,1650382943.485 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-04-19T15:42:23.485Z,1650382943.485 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:23.485Z,1650382943.485 [Onboard](INFO): Join timeout helper Thread ID is 4946
2022-04-19T15:42:27.341Z,1650382947.341 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-19T15:42:27.341Z,1650382947.341 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:27.362Z,1650382947.362 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-04-19T15:42:27.362Z,1650382947.362 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:27.362Z,1650382947.362 [DataOverHttps](INFO): Join timeout helper Thread ID is 4947
2022-04-19T15:42:27.624Z,1650382947.624 [NAL9602](INFO): SBD MO Status=0, MOMSN=36494, MT Status=0, MTMSN=0
2022-04-19T15:42:28.129Z,1650382948.129 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-19T15:42:28.129Z,1650382948.129 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.149Z,1650382948.149 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-04-19T15:42:28.149Z,1650382948.149 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.150Z,1650382948.150 [BackseatComponent](INFO): Join timeout helper Thread ID is 4948
2022-04-19T15:42:28.325Z,1650382948.325 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-19T15:42:28.325Z,1650382948.325 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.329Z,1650382948.329 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-04-19T15:42:28.329Z,1650382948.329 [logger ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.330Z,1650382948.330 [logger](INFO): Join timeout helper Thread ID is 4949
2022-04-19T15:42:28.369Z,1650382948.369 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-19T15:42:28.369Z,1650382948.369 [logger ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.389Z,1650382948.389 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-04-19T15:42:28.389Z,1650382948.389 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.390Z,1650382948.390 [CommandLine](INFO): Join timeout helper Thread ID is 4950
2022-04-19T15:42:28.425Z,1650382948.425 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-19T15:42:28.425Z,1650382948.425 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.429Z,1650382948.429 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-04-19T15:42:28.430Z,1650382948.430 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.430Z,1650382948.430 [CommandExec](INFO): Join timeout helper Thread ID is 4951
2022-04-19T15:42:28.434Z,1650382948.434 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-04-19T15:42:28.434Z,1650382948.434 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.434Z,1650382948.434 [controlThread](INFO): Join timeout helper Thread ID is 4952
2022-04-19T15:42:28.489Z,1650382948.489 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-19T15:42:28.489Z,1650382948.489 [controlThread](DEBUG): Uninitializing ControlThread
2022-04-19T15:42:28.490Z,1650382948.490 [AHRS_M2](INFO): Powering down
2022-04-19T15:42:28.562Z,1650382948.562 [Micromodem](INFO): Powering down
2022-04-19T15:42:28.658Z,1650382948.658 [NAL9602](INFO): Powering down
2022-04-19T15:42:28.733Z,1650382948.733 [RDI_Pathfinder](INFO): Powering down
2022-04-19T15:42:28.805Z,1650382948.805 [RDI_PathfinderUp](INFO): Powering down
2022-04-19T15:42:28.806Z,1650382948.806 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-04-19T15:42:28.807Z,1650382948.807 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-04-19T15:42:28.808Z,1650382948.808 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-04-19T15:42:28.809Z,1650382948.809 [MissionManager](INFO): Uninitializing Mission Default
2022-04-19T15:42:28.809Z,1650382948.809 [Default] Stopped
2022-04-19T15:42:28.809Z,1650382948.809 [Default](DEBUG): Aggregate::uninitialize Default
2022-04-19T15:42:28.809Z,1650382948.809 [Default:B.GoToSurface] Stopped
2022-04-19T15:42:28.809Z,1650382948.809 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-19T15:42:28.809Z,1650382948.809 [Default:CheckIn] Stopped
2022-04-19T15:42:28.809Z,1650382948.809 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-19T15:42:28.810Z,1650382948.810 [Default:CheckIn:Read_Iridium] Stopped
2022-04-19T15:42:28.812Z,1650382948.812 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-04-19T15:42:28.812Z,1650382948.812 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-04-19T15:42:28.813Z,1650382948.813 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-04-19T15:42:28.813Z,1650382948.813 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-04-19T15:42:28.813Z,1650382948.813 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-04-19T15:42:28.813Z,1650382948.813 [BuoyancyServo](INFO): Powering down
2022-04-19T15:42:28.825Z,1650382948.825 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-04-19T15:42:28.825Z,1650382948.825 [ElevatorServo](INFO): Powering down
2022-04-19T15:42:28.826Z,1650382948.826 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-04-19T15:42:28.826Z,1650382948.826 [MassServo](INFO): Powering down
2022-04-19T15:42:28.827Z,1650382948.827 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-04-19T15:42:28.827Z,1650382948.827 [RudderServo](INFO): Powering down
2022-04-19T15:42:28.827Z,1650382948.827 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-04-19T15:42:28.828Z,1650382948.828 [ThrusterHE](INFO): Powering down
2022-04-19T15:42:28.829Z,1650382948.829 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-04-19T15:42:28.829Z,1650382948.829 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-04-19T15:42:28.829Z,1650382948.829 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-04-19T15:42:28.829Z,1650382948.829 [CBIT](DEBUG): Powering off loads.
2022-04-19T15:42:28.840Z,1650382948.840 [CBIT](DEBUG): Disabling WDT.
2022-04-19T15:42:28.852Z,1650382948.852 [CBIT](DEBUG): Opening all GF detection circuits.
2022-04-19T15:42:28.854Z,1650382948.854 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.862Z,1650382948.862 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.866Z,1650382948.866 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.875Z,1650382948.875 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.919Z,1650382948.919 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.969Z,1650382948.969 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:28.972Z,1650382948.972 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:29.035Z,1650382949.035 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-04-19T15:42:29.107Z,1650382949.107 [logger ThreadHandler](INFO): Thread cancelled.