2022-08-31T11:33:57.345Z,1661945637.345 [Supervisor](DEBUG): Initializing supervisor. 2022-08-31T11:33:57.349Z,1661945637.349 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2022-08-31T11:33:57.349Z,1661945637.349 [SyncHandler](INFO): Protected caller Thread ID is 8273 2022-08-31T11:33:57.350Z,1661945637.350 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2022-08-31T11:33:57.351Z,1661945637.351 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2022-08-31T11:33:57.351Z,1661945637.351 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8274 2022-08-31T11:33:57.355Z,1661945637.355 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2022-08-31T11:33:57.373Z,1661945637.373 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2022-08-31T11:33:57.374Z,1661945637.374 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2022-08-31T11:33:57.375Z,1661945637.375 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 8275 2022-08-31T11:33:57.379Z,1661945637.379 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2022-08-31T11:33:57.380Z,1661945637.380 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2022-08-31T11:33:57.380Z,1661945637.380 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8276 2022-08-31T11:33:57.382Z,1661945637.382 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2022-08-31T11:33:57.383Z,1661945637.383 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2022-08-31T11:33:57.384Z,1661945637.384 [logger ThreadHandler](INFO): Protected caller Thread ID is 8277 2022-08-31T11:33:57.387Z,1661945637.387 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2022-08-31T11:33:57.388Z,1661945637.388 [Supervisor](INFO): Looking for Config files in directory: Config/ 2022-08-31T11:33:57.393Z,1661945637.393 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2022-08-31T11:33:57.868Z,1661945637.868 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2022-08-31T11:33:57.869Z,1661945637.869 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2022-08-31T11:33:57.950Z,1661945637.950 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2022-08-31T11:33:58.275Z,1661945638.275 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2022-08-31T11:33:58.277Z,1661945638.277 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2022-08-31T11:33:58.383Z,1661945638.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2022-08-31T11:33:58.385Z,1661945638.385 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2022-08-31T11:33:58.576Z,1661945638.576 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2022-08-31T11:33:58.577Z,1661945638.577 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2022-08-31T11:33:59.049Z,1661945639.049 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2022-08-31T11:33:59.051Z,1661945639.051 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2022-08-31T11:33:59.315Z,1661945639.315 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2022-08-31T11:33:59.316Z,1661945639.316 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2022-08-31T11:33:59.528Z,1661945639.528 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2022-08-31T11:33:59.529Z,1661945639.529 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2022-08-31T11:33:59.717Z,1661945639.717 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2022-08-31T11:33:59.718Z,1661945639.718 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2022-08-31T11:33:59.815Z,1661945639.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2022-08-31T11:33:59.816Z,1661945639.816 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2022-08-31T11:34:00.035Z,1661945640.035 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2022-08-31T11:34:00.037Z,1661945640.037 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2022-08-31T11:34:00.404Z,1661945640.404 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2022-08-31T11:34:00.405Z,1661945640.405 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2022-08-31T11:34:00.486Z,1661945640.486 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2022-08-31T11:34:00.624Z,1661945640.624 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2022-08-31T11:34:00.625Z,1661945640.625 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2022-08-31T11:34:01.321Z,1661945641.321 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2022-08-31T11:34:01.322Z,1661945641.322 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2022-08-31T11:34:01.695Z,1661945641.695 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2022-08-31T11:34:01.697Z,1661945641.697 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/ 2022-08-31T11:34:01.895Z,1661945641.895 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg 2022-08-31T11:34:02.333Z,1661945642.333 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg 2022-08-31T11:34:02.499Z,1661945642.499 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg 2022-08-31T11:34:02.708Z,1661945642.708 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg 2022-08-31T11:34:02.807Z,1661945642.807 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg 2022-08-31T11:34:03.073Z,1661945643.073 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2022-08-31T11:34:03.074Z,1661945643.074 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg 2022-08-31T11:34:03.182Z,1661945643.182 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg 2022-08-31T11:34:03.285Z,1661945643.285 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg 2022-08-31T11:34:03.406Z,1661945643.406 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg 2022-08-31T11:34:03.517Z,1661945643.517 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg 2022-08-31T11:34:03.602Z,1661945643.602 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg 2022-08-31T11:34:03.687Z,1661945643.687 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg 2022-08-31T11:34:03.796Z,1661945643.796 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg 2022-08-31T11:34:03.902Z,1661945643.902 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg 2022-08-31T11:34:04.099Z,1661945644.099 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg 2022-08-31T11:34:04.253Z,1661945644.253 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2022-08-31T11:34:04.270Z,1661945644.270 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2022-08-31T11:34:04.831Z,1661945644.831 [AHRS_M2] Loaded 2022-08-31T11:34:04.832Z,1661945644.832 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2022-08-31T11:34:05.621Z,1661945645.621 [BPC1] Loaded 2022-08-31T11:34:05.621Z,1661945645.621 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2022-08-31T11:34:05.729Z,1661945645.729 [DataOverHttps] Loaded 2022-08-31T11:34:05.729Z,1661945645.729 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2022-08-31T11:34:05.731Z,1661945645.731 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407E44E0 2022-08-31T11:34:05.731Z,1661945645.731 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 8371 2022-08-31T11:34:05.756Z,1661945645.756 [DDM] Loaded 2022-08-31T11:34:05.756Z,1661945645.756 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread. 2022-08-31T11:34:05.776Z,1661945645.776 [Depth_Keller] Loaded 2022-08-31T11:34:05.776Z,1661945645.776 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2022-08-31T11:34:05.781Z,1661945645.781 [DropWeight] Loaded 2022-08-31T11:34:05.781Z,1661945645.781 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2022-08-31T11:34:05.831Z,1661945645.831 [Micromodem] Loaded 2022-08-31T11:34:05.831Z,1661945645.831 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread. 2022-08-31T11:34:05.894Z,1661945645.894 [NAL9602] Loaded 2022-08-31T11:34:05.894Z,1661945645.894 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2022-08-31T11:34:05.924Z,1661945645.924 [Onboard] Loaded 2022-08-31T11:34:05.924Z,1661945645.924 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2022-08-31T11:34:05.925Z,1661945645.925 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408144E0 2022-08-31T11:34:05.925Z,1661945645.925 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 8372 2022-08-31T11:34:05.931Z,1661945645.931 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1 2022-08-31T11:34:05.942Z,1661945645.942 [PowerOnly] Loaded 2022-08-31T11:34:05.943Z,1661945645.943 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2022-08-31T11:34:05.954Z,1661945645.954 [Power24vConverter] Loaded 2022-08-31T11:34:05.954Z,1661945645.954 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2022-08-31T11:34:05.968Z,1661945645.968 [Radio_Surface] Loaded 2022-08-31T11:34:05.969Z,1661945645.969 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2022-08-31T11:34:05.970Z,1661945645.970 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408444E0 2022-08-31T11:34:05.970Z,1661945645.970 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8373 2022-08-31T11:34:06.014Z,1661945646.014 [RDI_Pathfinder] Loaded 2022-08-31T11:34:06.015Z,1661945646.015 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2022-08-31T11:34:06.042Z,1661945646.042 [RDI_PathfinderUp] Loaded 2022-08-31T11:34:06.042Z,1661945646.042 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread. 2022-08-31T11:34:06.043Z,1661945646.043 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2022-08-31T11:34:06.044Z,1661945646.044 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2022-08-31T11:34:06.059Z,1661945646.059 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2022-08-31T11:34:06.060Z,1661945646.060 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2022-08-31T11:34:06.198Z,1661945646.198 [DeadReckonUsingMultipleVelocitySources] Loaded 2022-08-31T11:34:06.198Z,1661945646.198 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2022-08-31T11:34:06.223Z,1661945646.223 [LBLNavigation] Loaded 2022-08-31T11:34:06.223Z,1661945646.223 [ComponentRegistry](DEBUG): SyncComponent "LBLNavigation" handled in the control thread. 2022-08-31T11:34:06.236Z,1661945646.236 [NavChart] Loaded 2022-08-31T11:34:06.236Z,1661945646.236 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2022-08-31T11:34:06.242Z,1661945646.242 [UniversalFixResidualReporter] Loaded 2022-08-31T11:34:06.242Z,1661945646.242 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2022-08-31T11:34:06.252Z,1661945646.252 [WorkSite] Loaded 2022-08-31T11:34:06.253Z,1661945646.253 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread. 2022-08-31T11:34:06.253Z,1661945646.253 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2022-08-31T11:34:06.254Z,1661945646.254 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2022-08-31T11:34:06.376Z,1661945646.376 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2022-08-31T11:34:06.376Z,1661945646.376 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2022-08-31T11:34:06.531Z,1661945646.531 [BuoyancyServo] Loaded 2022-08-31T11:34:06.531Z,1661945646.531 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2022-08-31T11:34:06.553Z,1661945646.553 [ElevatorServo] Loaded 2022-08-31T11:34:06.554Z,1661945646.554 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2022-08-31T11:34:06.574Z,1661945646.574 [MassServo] Loaded 2022-08-31T11:34:06.575Z,1661945646.575 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2022-08-31T11:34:06.595Z,1661945646.595 [RudderServo] Loaded 2022-08-31T11:34:06.595Z,1661945646.595 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2022-08-31T11:34:06.611Z,1661945646.611 [ThrusterHE] Loaded 2022-08-31T11:34:06.611Z,1661945646.611 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2022-08-31T11:34:06.612Z,1661945646.612 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2022-08-31T11:34:06.612Z,1661945646.612 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2022-08-31T11:34:06.832Z,1661945646.832 [CTD_Seabird] Loaded 2022-08-31T11:34:06.832Z,1661945646.832 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2022-08-31T11:34:06.855Z,1661945646.855 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409824E0 2022-08-31T11:34:06.855Z,1661945646.855 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 8374 2022-08-31T11:34:07.024Z,1661945647.024 [WetLabsSeaOWL_UV_A] Loaded 2022-08-31T11:34:07.024Z,1661945647.024 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2022-08-31T11:34:07.033Z,1661945647.033 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409B24E0 2022-08-31T11:34:07.033Z,1661945647.033 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 8375 2022-08-31T11:34:07.034Z,1661945647.034 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2022-08-31T11:34:07.035Z,1661945647.035 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2022-08-31T11:34:07.745Z,1661945647.745 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2022-08-31T11:34:07.746Z,1661945647.746 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2022-08-31T11:34:07.819Z,1661945647.819 [DepthRateCalculator] Loaded 2022-08-31T11:34:07.819Z,1661945647.819 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2022-08-31T11:34:07.825Z,1661945647.825 [PitchRateCalculator] Loaded 2022-08-31T11:34:07.825Z,1661945647.825 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2022-08-31T11:34:07.834Z,1661945647.834 [SpeedCalculator] Loaded 2022-08-31T11:34:07.834Z,1661945647.834 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2022-08-31T11:34:07.847Z,1661945647.847 [TempGradientCalculator] Loaded 2022-08-31T11:34:07.847Z,1661945647.847 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2022-08-31T11:34:07.863Z,1661945647.863 [VerticalHomogeneityIndexCalculator] Loaded 2022-08-31T11:34:07.863Z,1661945647.863 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread. 2022-08-31T11:34:07.867Z,1661945647.867 [YawRateCalculator] Loaded 2022-08-31T11:34:07.868Z,1661945647.868 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2022-08-31T11:34:07.890Z,1661945647.890 [ElevatorOffsetCalculator] Loaded 2022-08-31T11:34:07.890Z,1661945647.890 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2022-08-31T11:34:07.890Z,1661945647.890 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2022-08-31T11:34:07.891Z,1661945647.891 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2022-08-31T11:34:08.066Z,1661945648.066 [SBIT](DEBUG): Construct Startup Built In Test. 2022-08-31T11:34:08.078Z,1661945648.078 [SBIT] Loaded 2022-08-31T11:34:08.079Z,1661945648.079 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2022-08-31T11:34:08.082Z,1661945648.082 [IBIT](DEBUG): Construct Initiated Built In Test. 2022-08-31T11:34:08.094Z,1661945648.094 [IBIT] Loaded 2022-08-31T11:34:08.094Z,1661945648.094 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2022-08-31T11:34:08.100Z,1661945648.100 [CBIT](DEBUG): Construct Continuous Built In Test. 2022-08-31T11:34:08.207Z,1661945648.207 [CBIT] Loaded 2022-08-31T11:34:08.207Z,1661945648.207 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2022-08-31T11:34:08.207Z,1661945648.207 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2022-08-31T11:34:08.208Z,1661945648.208 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2022-08-31T11:34:08.294Z,1661945648.294 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2022-08-31T11:34:08.294Z,1661945648.294 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2022-08-31T11:34:08.489Z,1661945648.489 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2022-08-31T11:34:08.490Z,1661945648.490 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2022-08-31T11:34:08.559Z,1661945648.559 [VerticalControl](DEBUG): Construct VerticalControl. 2022-08-31T11:34:08.609Z,1661945648.609 [VerticalControl] Loaded 2022-08-31T11:34:08.610Z,1661945648.610 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2022-08-31T11:34:08.613Z,1661945648.613 [HorizontalControl](DEBUG): Construct HorizontalControl. 2022-08-31T11:34:08.650Z,1661945648.650 [HorizontalControl] Loaded 2022-08-31T11:34:08.650Z,1661945648.650 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2022-08-31T11:34:08.653Z,1661945648.653 [SpeedControl](DEBUG): Construct SpeedControl. 2022-08-31T11:34:08.654Z,1661945648.654 [SpeedControl] Loaded 2022-08-31T11:34:08.655Z,1661945648.655 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2022-08-31T11:34:08.658Z,1661945648.658 [LoopControl](DEBUG): Construct LoopControl. 2022-08-31T11:34:08.658Z,1661945648.658 [LoopControl] Loaded 2022-08-31T11:34:08.658Z,1661945648.658 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2022-08-31T11:34:08.659Z,1661945648.659 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2022-08-31T11:34:08.659Z,1661945648.659 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2022-08-31T11:34:08.705Z,1661945648.705 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2022-08-31T11:34:08.711Z,1661945648.711 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2022-08-31T11:34:08.714Z,1661945648.714 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2022-08-31T11:34:08.725Z,1661945648.725 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2022-08-31T11:34:08.732Z,1661945648.732 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B6E4E0 2022-08-31T11:34:08.733Z,1661945648.733 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8376 2022-08-31T11:34:08.737Z,1661945648.737 [Supervisor](INFO): Main Thread ID is 8272 2022-08-31T11:34:08.737Z,1661945648.737 [Supervisor](DEBUG): Running supervisor. 2022-08-31T11:34:08.739Z,1661945648.739 [CommandExec ThreadHandler](INFO): Handler Thread ID is 8377 2022-08-31T11:34:08.740Z,1661945648.740 [CommandExec](INFO): Initializing the command executive. 2022-08-31T11:34:08.742Z,1661945648.742 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8378 2022-08-31T11:34:08.744Z,1661945648.744 [controlThread ThreadHandler](INFO): Handler Thread ID is 8379 2022-08-31T11:34:08.744Z,1661945648.744 [controlThread](DEBUG): Initializing ControlThread 2022-08-31T11:34:08.753Z,1661945648.753 [NavChart](DEBUG): Initialize NavChart Navigation. 2022-08-31T11:34:08.753Z,1661945648.753 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2022-08-31T11:34:08.754Z,1661945648.754 [WorkSite](DEBUG): Initializing WorkSite component. 2022-08-31T11:34:08.755Z,1661945648.755 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2022-08-31T11:34:08.755Z,1661945648.755 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2022-08-31T11:34:08.756Z,1661945648.756 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2022-08-31T11:34:08.756Z,1661945648.756 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2022-08-31T11:34:08.757Z,1661945648.757 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing 2022-08-31T11:34:08.758Z,1661945648.758 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2022-08-31T11:34:08.758Z,1661945648.758 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2022-08-31T11:34:08.759Z,1661945648.759 [SBIT](INFO): Initialize SBIT Component. 2022-08-31T11:34:08.759Z,1661945648.759 [SBIT](IMPORTANT): git: 2022-08-25 2022-08-31T11:34:08.759Z,1661945648.759 [SBIT](INFO): git hash: e1ddd60859d931066d70c4e9618f9367e52a6cfe 2022-08-31T11:34:08.759Z,1661945648.759 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2022-08-31T11:34:08.761Z,1661945648.761 [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-08-31T11:34:08.762Z,1661945648.762 [SBIT](INFO): Beginning SBIT in 42.000000 seconds. 2022-08-31T11:34:08.765Z,1661945648.765 [IBIT](INFO): Initialize IBIT Component. 2022-08-31T11:34:08.766Z,1661945648.766 [CBIT](DEBUG): Initialize CBIT Component. 2022-08-31T11:34:08.767Z,1661945648.767 [logger ThreadHandler](INFO): Handler Thread ID is 8380 2022-08-31T11:34:08.777Z,1661945648.777 [CBIT](DEBUG): Initialized mux pins. 2022-08-31T11:34:08.777Z,1661945648.777 [CBIT](DEBUG): Initializing the watchdog timer. 2022-08-31T11:34:08.786Z,1661945648.786 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 8381 2022-08-31T11:34:08.786Z,1661945648.786 [DataOverHttps](DEBUG): dashIP=128.128.181.226 starts with a digit so assuming it is a numeric IP 2022-08-31T11:34:08.797Z,1661945648.797 [Onboard ThreadHandler](INFO): Handler Thread ID is 8382 2022-08-31T11:34:08.802Z,1661945648.802 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2022-08-31T11:34:08.802Z,1661945648.802 [CBIT](DEBUG): Initializing heartbeat. 2022-08-31T11:34:08.818Z,1661945648.818 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8383 2022-08-31T11:34:08.837Z,1661945648.837 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 8384 2022-08-31T11:34:08.838Z,1661945648.838 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2022-08-31T11:34:08.843Z,1661945648.843 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 8386 2022-08-31T11:34:08.849Z,1661945648.849 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8387 2022-08-31T11:34:08.856Z,1661945648.856 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2022-08-31T11:34:08.857Z,1661945648.857 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2022-08-31T11:34:08.857Z,1661945648.857 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2022-08-31T11:34:08.857Z,1661945648.857 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2022-08-31T11:34:08.857Z,1661945648.857 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2022-08-31T11:34:08.857Z,1661945648.857 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2022-08-31T11:34:08.858Z,1661945648.858 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2022-08-31T11:34:08.858Z,1661945648.858 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2022-08-31T11:34:08.873Z,1661945648.873 [CBIT](DEBUG): Deactivating GF circuits. 2022-08-31T11:34:08.873Z,1661945648.873 [CBIT](DEBUG): Deactivating emergency mode. 2022-08-31T11:34:08.909Z,1661945648.909 [CBIT](DEBUG): Backplane powered. 2022-08-31T11:34:08.909Z,1661945648.909 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2022-08-31T11:34:08.911Z,1661945648.911 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2022-08-31T11:34:08.912Z,1661945648.912 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2022-08-31T11:34:08.912Z,1661945648.912 [LoopControl](DEBUG): Initialize LoopControlComponent. 2022-08-31T11:34:08.913Z,1661945648.913 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2022-08-31T11:34:08.940Z,1661945648.940 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2022-08-31T11:34:08.991Z,1661945648.991 [MissionManager](DEBUG): 2022-08-31T11:34:08.992Z,1661945648.992 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2022-08-31T11:34:09.055Z,1661945649.055 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2022-08-31T11:34:09.056Z,1661945649.056 [Default:A.Wait](DEBUG): Construct Wait. 2022-08-31T11:34:09.074Z,1661945649.074 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2022-08-31T11:34:09.101Z,1661945649.101 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2022-08-31T11:34:09.104Z,1661945649.104 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2022-08-31T11:34:09.126Z,1661945649.126 [Default:E.Execute](DEBUG): Construct Execute. 2022-08-31T11:34:09.142Z,1661945649.142 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2022-08-31T11:34:09.147Z,1661945649.147 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,DDM,Depth_Keller,DropWeight,Micromodem,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,RDI_PathfinderUp,Depth_Keller,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,Reporter,LogSplitter, 2022-08-31T11:34:09.161Z,1661945649.161 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2022-08-31T11:34:09.221Z,1661945649.221 [Radio_Surface](INFO): Powering up 2022-08-31T11:34:09.230Z,1661945649.230 [DDM](INFO): Powering up 2022-08-31T11:34:09.230Z,1661945649.230 [DDM](DEBUG): Initializing DDM. 2022-08-31T11:34:09.250Z,1661945649.250 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar 2022-08-31T11:34:09.252Z,1661945649.252 [Power24vConverter](INFO): Powering up. 2022-08-31T11:34:09.253Z,1661945649.253 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2022-08-31T11:34:09.273Z,1661945649.273 [DepthRateCalculator](ERROR): Depth measurement is not active 2022-08-31T11:34:09.314Z,1661945649.314 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2022-08-31T11:34:09.321Z,1661945649.321 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2022-08-31T11:34:09.322Z,1661945649.322 [ElevatorServo](DEBUG): Initializing EZServoServo. 2022-08-31T11:34:09.329Z,1661945649.329 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2022-08-31T11:34:09.342Z,1661945649.342 [MassServo](DEBUG): Initializing EZServoServo. 2022-08-31T11:34:09.349Z,1661945649.349 [MassServo](DEBUG): Initializing MassServo. 2022-08-31T11:34:09.350Z,1661945649.350 [RudderServo](DEBUG): Initializing EZServoServo. 2022-08-31T11:34:09.358Z,1661945649.358 [RudderServo](DEBUG): Initializing RudderServo. 2022-08-31T11:34:09.359Z,1661945649.359 [ThrusterHE](DEBUG): Initializing EZServoServo. 2022-08-31T11:34:09.365Z,1661945649.365 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2022-08-31T11:34:09.603Z,1661945649.603 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-08-31T11:34:09.603Z,1661945649.603 [DropWeight] Hardware Fault, FailCount= 1 2022-08-31T11:34:09.603Z,1661945649.603 [DropWeight](ERROR): Hardware Fault 2022-08-31T11:34:09.604Z,1661945649.604 [Micromodem](INFO): Powering up 2022-08-31T11:34:09.604Z,1661945649.604 [Micromodem](DEBUG): Initializing Micromodem. 2022-08-31T11:34:09.639Z,1661945649.639 [CommandExec](FAULT): Scheduling is paused 2022-08-31T11:34:09.640Z,1661945649.640 [CBIT](INFO): Critical error at 20220831T113409 2022-08-31T11:34:09.640Z,1661945649.640 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2022-08-31T11:34:09.647Z,1661945649.647 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-08-31T11:34:09.647Z,1661945649.647 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-08-31T11:34:10.277Z,1661945650.277 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2022-08-31T11:34:10.277Z,1661945650.277 [RudderServo](FAULT): Rudder failed to initialize 2022-08-31T11:34:10.277Z,1661945650.277 [RudderServo] Communications Fault, FailCount= 1 2022-08-31T11:34:10.277Z,1661945650.277 [RudderServo](ERROR): Communications Fault 2022-08-31T11:34:10.279Z,1661945650.279 [CBIT](INFO): Critical error at 20220831T113409 2022-08-31T11:34:10.282Z,1661945650.282 [CBIT](ERROR): Communications Fault in component: RudderServo 2022-08-31T11:34:10.502Z,1661945650.502 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-08-31T11:34:10.502Z,1661945650.502 [RudderServo](INFO): Powering down 2022-08-31T11:34:11.185Z,1661945651.185 [RudderServo](DEBUG): Initializing EZServoServo. 2022-08-31T11:34:11.306Z,1661945651.306 [RudderServo](DEBUG): Initializing RudderServo. 2022-08-31T11:34:11.310Z,1661945651.310 [CBIT](INFO): Clearing failed state for component RudderServo 2022-08-31T11:34:11.310Z,1661945651.310 [RudderServo] No Fault, FailCount= 1 2022-08-31T11:34:14.449Z,1661945654.449 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33 2022-08-31T11:34:14.851Z,1661945654.851 [Micromodem](INFO): Nmea in: $CATMG,2022-08-31T11:34:19.819045Z,RTC,RTC*56 2022-08-31T11:34:14.852Z,1661945654.852 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2022-08-31T11:34:19.819045Z,RTC,RTC*56 2022-08-31T11:34:14.943Z,1661945654.943 [ThrusterHE](ERROR): Zero Speed Commanded. 2022-08-31T11:34:15.259Z,1661945655.259 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31 2022-08-31T11:34:15.259Z,1661945655.259 [Micromodem](INFO): Nmea out: $CCCFG,POW,20*08 2022-08-31T11:34:15.659Z,1661945655.659 [Micromodem](INFO): Nmea in: $CACFG,POW,20*0A 2022-08-31T11:34:15.659Z,1661945655.659 [Micromodem](INFO): Nmea out: $CCCFG,SRC,0*30 2022-08-31T11:34:16.063Z,1661945656.063 [Micromodem](INFO): Nmea in: $CACFG,SRC,0*32 2022-08-31T11:34:16.063Z,1661945656.063 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64 2022-08-31T11:34:16.467Z,1661945656.467 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66 2022-08-31T11:34:16.467Z,1661945656.467 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F 2022-08-31T11:34:16.872Z,1661945656.872 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D 2022-08-31T11:34:16.872Z,1661945656.872 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E 2022-08-31T11:34:17.275Z,1661945657.275 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C 2022-08-31T11:34:17.275Z,1661945657.275 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47 2022-08-31T11:34:17.621Z,1661945657.621 [BuoyancyServo](ERROR): getPosition uart error serial timeout 2022-08-31T11:34:17.621Z,1661945657.621 [BuoyancyServo](FAULT): Buoyancy getPosition uart error.serial timeout 2022-08-31T11:34:17.621Z,1661945657.621 [BuoyancyServo] Communications Fault, FailCount= 1 2022-08-31T11:34:17.621Z,1661945657.621 [BuoyancyServo](ERROR): Communications Fault 2022-08-31T11:34:17.650Z,1661945657.650 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2022-08-31T11:34:17.683Z,1661945657.683 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45 2022-08-31T11:34:17.683Z,1661945657.683 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63 2022-08-31T11:34:18.071Z,1661945658.071 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61 2022-08-31T11:34:18.071Z,1661945658.071 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A 2022-08-31T11:34:18.471Z,1661945658.471 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38 2022-08-31T11:34:18.471Z,1661945658.471 [Micromodem](INFO): Nmea out: $CCCLK,2022,08,31,11,34,19*43 2022-08-31T11:34:18.875Z,1661945658.875 [Micromodem](INFO): Nmea in: $CACLK,2022,8,31,11,34,19*71 2022-08-31T11:34:18.876Z,1661945658.876 [Micromodem](INFO): Nmea in: $CATMS,0,2022-08-31T11:34:20Z*7B 2022-08-31T11:34:18.879Z,1661945658.879 [Micromodem](INFO): Nmea in: $CATMG,2022-08-31T11:34:20.027168Z,USER_CMD,RTC*16 2022-08-31T11:34:19.290Z,1661945659.290 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-08-31T11:34:19.290Z,1661945659.290 [BuoyancyServo](INFO): Powering down 2022-08-31T11:34:19.694Z,1661945659.694 [BuoyancyServo](FAULT): LCB fault: Current Limiter Activated. 2022-08-31T11:34:19.695Z,1661945659.695 [BuoyancyServo] Hardware Fault, FailCount= 1 2022-08-31T11:34:19.695Z,1661945659.695 [BuoyancyServo](ERROR): Hardware Fault 2022-08-31T11:34:20.130Z,1661945660.130 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2022-08-31T11:34:20.130Z,1661945660.130 [BuoyancyServo] No Fault, FailCount= 1 2022-08-31T11:34:20.507Z,1661945660.507 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2022-08-31T11:34:20.517Z,1661945660.517 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2022-08-31T11:34:24.931Z,1661945664.931 [DDM](INFO): Latch/Whisker Boards:V1,H_RECOVERY_LATCH !V2,H_RECOVERY_WHISKERS 2022-08-31T11:34:25.033Z,1661945665.033 [DDM](INFO): Dynamic Docking Module:C REMUS Capture Rev 1.1 2022-08-31T11:34:36.247Z,1661945676.247 [NAL9602](INFO): Powering up NAL9602 2022-08-31T11:34:47.159Z,1661945687.159 [NAL9602](INFO): NAL9602 initialized 2022-08-31T11:34:51.240Z,1661945691.240 [SBIT](IMPORTANT): Beginning Startup BIT 2022-08-31T11:34:51.252Z,1661945691.252 [CBIT](IMPORTANT): Beginning ground fault scan 2022-08-31T11:34:52.412Z,1661945692.412 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:34:52.416Z,1661945692.416 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831113452.721663,06,1972,26,0104,0150,208,02,02,01,02,-1,-01,-01,1,3,4,0,150,10.6,0.01,-100,2.99,-01,-0.71,65,14500,4000*51 2022-08-31T11:35:02.158Z,1661945702.158 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.146539 CHAN A1 (24V): 0.072979 CHAN A2 (12V): 0.024008 CHAN A3 (5V): 0.000329 CHAN B0 (3.3V): -0.000205 CHAN B1 (3.15aV): 0.000502 CHAN B2 (3.15bV): 0.000866 CHAN B3 (GND): -0.003422 OPEN: 0.005820 Full Scale: +/- 1 mA 2022-08-31T11:35:06.552Z,1661945706.552 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T11:35:06.564Z,1661945706.564 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831113502.722736,06,1746,26,0102,0150,149,01,01,01,01,6,-01,-01,2,3,6,0,150,3.0,-1.78,04,4.78,-01,-8.09,55,14500,4000*75 2022-08-31T11:35:36.048Z,1661945736.048 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:35:36.463Z,1661945736.463 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831113536.731657,06,1509,25,0092,0150,208,02,02,01,02,-1,-01,-01,1,3,5,0,150,6.5,0.02,-100,2.98,-01,0.12,64,14500,4000*47 2022-08-31T11:35:40.085Z,1661945740.085 [NAL9602](INFO): SBD MO Status=2, MOMSN=44248, MT Status=2, MTMSN=0 2022-08-31T11:35:40.086Z,1661945740.086 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T11:35:45.361Z,1661945745.361 [SBIT](IMPORTANT): SBIT PASSED 2022-08-31T11:35:45.361Z,1661945745.361 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2022-08-31T11:35:45.362Z,1661945745.362 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour; 2022-08-31T11:35:45.362Z,1661945745.362 [SBIT](IMPORTANT): DDM.loadAtStartup=1 bool; 2022-08-31T11:35:45.362Z,1661945745.362 [SBIT](IMPORTANT): DockingServo.loadAtStartup=0 bool; 2022-08-31T11:35:45.363Z,1661945745.363 [SBIT](IMPORTANT): LineCapture.armSpeed=1.2 meter_per_second; 2022-08-31T11:35:45.363Z,1661945745.363 [SBIT](IMPORTANT): LineCapture.midcourseSpeed=1.2 meter_per_second; 2022-08-31T11:35:45.363Z,1661945745.363 [SBIT](IMPORTANT): LineCapture.rolloutTimeout=6 minute; 2022-08-31T11:35:45.363Z,1661945745.363 [SBIT](IMPORTANT): LineCapture.shortFinalRange=-1 meter; 2022-08-31T11:35:45.363Z,1661945745.363 [SBIT](IMPORTANT): LineCapture.terminalRange=300 meter; 2022-08-31T11:35:45.363Z,1661945745.363 [SBIT](IMPORTANT): LineCapture.verbose=1 bool; 2022-08-31T11:35:45.363Z,1661945745.363 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=411.225225 cubic_centimeter; 2022-08-31T11:35:45.363Z,1661945745.363 [SBIT](IMPORTANT): VerticalControl.massDefault=-5.740576 millimeter; 2022-08-31T11:35:45.787Z,1661945745.787 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg 2022-08-31T11:35:45.790Z,1661945745.790 [WorkSite](IMPORTANT): WorkSite fix at 20220826T230524: (41.524428, -70.671366) 2022-08-31T11:35:45.792Z,1661945745.792 [MissionManager](IMPORTANT): Started mission Startup 2022-08-31T11:35:45.792Z,1661945745.792 [Startup] Running Loop=1 2022-08-31T11:35:45.792Z,1661945745.792 [Startup](DEBUG): Aggregate::initialize Startup 2022-08-31T11:35:45.792Z,1661945745.792 [Startup:A.GoToSurface] Running Loop=1 2022-08-31T11:35:45.792Z,1661945745.792 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-08-31T11:35:45.793Z,1661945745.793 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-08-31T11:35:45.794Z,1661945745.794 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-08-31T11:35:45.794Z,1661945745.794 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-08-31T11:35:45.794Z,1661945745.794 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-08-31T11:35:45.795Z,1661945745.795 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-08-31T11:35:45.796Z,1661945745.796 [Startup:StartupSatComms] Running Loop=1 2022-08-31T11:35:45.796Z,1661945745.796 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2022-08-31T11:35:45.796Z,1661945745.796 [Startup:StartupSatComms:A] Running Loop=1 2022-08-31T11:35:46.165Z,1661945746.165 [LBLNavigation](INFO): Reset ping filters 2022-08-31T11:35:46.165Z,1661945746.165 [LBLNavigation](INFO): Reset fix filter 2022-08-31T11:35:46.167Z,1661945746.167 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2022-08-31T11:36:03.956Z,1661945763.956 [NAL9602](INFO): SBD MO Status=2, MOMSN=44248, MT Status=2, MTMSN=0 2022-08-31T11:36:03.956Z,1661945763.956 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T11:36:13.616Z,1661945773.616 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T11:36:13.620Z,1661945773.620 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831113610.719085,06,834,23,0123,0150,223,02,02,01,02,5,-01,-01,2,3,7,0,150,-3.1,3.35,-100,-0.35,-01,-0.36,66,14500,4000*77 2022-08-31T11:36:16.448Z,1661945776.448 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=44248, MT Status=1, MTMSN=1678 2022-08-31T11:36:16.448Z,1661945776.448 [NAL9602](INFO): Data available in MT queue 2022-08-31T11:36:16.973Z,1661945776.973 [NAL9602](INFO): Received command: get platform_battery_voltage 2022-08-31T11:36:17.980Z,1661945777.980 [CommandExec](IMPORTANT): got command get platform_battery_voltage 2022-08-31T11:36:17.982Z,1661945777.982 [CommandExec](IMPORTANT): platform_battery_voltage 16.730000 V 2022-08-31T11:36:18.061Z,1661945778.061 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,113623.00,A,4005.87912,N,07059.91845,W,10.069,308.36,310822,,,A*4C 2022-08-31T11:36:18.064Z,1661945778.064 [NAL9602](INFO): GPS fix at 20220831T113623: (40.097985, -70.998641) 2022-08-31T11:36:18.115Z,1661945778.115 [Startup:StartupSatComms:A] Stopped 2022-08-31T11:36:18.115Z,1661945778.115 [Startup:StartupSatComms:B] Running Loop=1 2022-08-31T11:36:18.504Z,1661945778.504 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2022-08-31T11:36:34.876Z,1661945794.876 [NAL9602](INFO): SBD MO Status=1, MOMSN=44249, MT Status=0, MTMSN=0 2022-08-31T11:36:34.933Z,1661945794.933 [NAL9602](INFO): Sent 159 bytes from file Logs/20220826T220222/Courier0037.lzma 2022-08-31T11:36:34.933Z,1661945794.933 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:36:47.621Z,1661945807.621 [NAL9602](INFO): SBD MO Status=1, MOMSN=44250, MT Status=0, MTMSN=0 2022-08-31T11:36:47.681Z,1661945807.681 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Courier0000.lzma 2022-08-31T11:36:47.681Z,1661945807.681 [NAL9602](INFO): Packets left to send: 1 2022-08-31T11:37:09.142Z,1661945829.142 [NAL9602](INFO): SBD MO Status=1, MOMSN=44251, MT Status=0, MTMSN=0 2022-08-31T11:37:09.197Z,1661945829.197 [NAL9602](INFO): Sent 164 bytes from file Logs/20220831T113357/Courier0000.lzma 2022-08-31T11:37:09.197Z,1661945829.197 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:37:17.317Z,1661945837.317 [NAL9602](INFO): SBD MO Status=1, MOMSN=44252, MT Status=0, MTMSN=0 2022-08-31T11:37:17.377Z,1661945837.377 [NAL9602](INFO): Sent 114 bytes from file Logs/20220826T220222/Express0038.lzma 2022-08-31T11:37:17.377Z,1661945837.377 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:37:18.302Z,1661945838.302 [Startup:StartupSatComms:B](INFO): Timed out from 2022-08-31T11:36:18.1Z 2022-08-31T11:37:18.302Z,1661945838.302 [Startup:StartupSatComms:B] Stopped 2022-08-31T11:37:18.302Z,1661945838.302 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2022-08-31T11:37:18.302Z,1661945838.302 [Startup:StartupSatComms] Stopped 2022-08-31T11:37:18.302Z,1661945838.302 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2022-08-31T11:37:18.303Z,1661945838.303 [Startup](INFO): Completed Startup 2022-08-31T11:37:18.303Z,1661945838.303 [MissionManager](INFO): Startup is completed. 2022-08-31T11:37:18.303Z,1661945838.303 [MissionManager](INFO): Uninitializing Mission Startup 2022-08-31T11:37:18.303Z,1661945838.303 [Startup] Stopped 2022-08-31T11:37:18.303Z,1661945838.303 [Startup](DEBUG): Aggregate::uninitialize Startup 2022-08-31T11:37:18.304Z,1661945838.304 [Startup:A.GoToSurface] Stopped 2022-08-31T11:37:18.304Z,1661945838.304 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-08-31T11:37:20.200Z,1661945840.200 [MissionManager](IMPORTANT): Started mission Default 2022-08-31T11:37:20.201Z,1661945840.201 [Default] Running Loop=1 2022-08-31T11:37:20.201Z,1661945840.201 [Default](DEBUG): Aggregate::initialize Default 2022-08-31T11:37:20.233Z,1661945840.233 [Default:B.GoToSurface] Running Loop=1 2022-08-31T11:37:20.233Z,1661945840.233 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-08-31T11:37:20.233Z,1661945840.233 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-08-31T11:37:20.234Z,1661945840.234 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-08-31T11:37:20.234Z,1661945840.234 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-08-31T11:37:20.234Z,1661945840.234 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-08-31T11:37:20.234Z,1661945840.234 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-08-31T11:37:20.235Z,1661945840.235 [Default:A.Wait] Running Loop=1 2022-08-31T11:37:20.235Z,1661945840.235 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-08-31T11:37:26.490Z,1661945846.490 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T11:37:26.491Z,1661945846.491 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T11:37:26.492Z,1661945846.492 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:37:26.871Z,1661945846.871 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831113726.719907,06,1605,26,0183,0150,194,02,02,01,02,-1,-01,-01,1,3,3,0,150,74.1,0.48,-100,2.52,-01,-2.75,-12,14500,4000*72 2022-08-31T11:37:33.339Z,1661945853.339 [Default:A.Wait](INFO): Done Waiting. 2022-08-31T11:37:33.339Z,1661945853.339 [Default:A.Wait] Stopped 2022-08-31T11:37:33.339Z,1661945853.339 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T11:37:33.805Z,1661945853.805 [Default:CheckIn] Running Loop=1 2022-08-31T11:37:33.805Z,1661945853.805 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T11:37:33.805Z,1661945853.805 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T11:37:34.155Z,1661945854.155 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2022-08-31T11:37:38.184Z,1661945858.184 [NAL9602](INFO): SBD MO Status=1, MOMSN=44253, MT Status=0, MTMSN=0 2022-08-31T11:37:38.237Z,1661945858.237 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Express0001.lzma 2022-08-31T11:37:38.237Z,1661945858.237 [NAL9602](INFO): Packets left to send: 6 2022-08-31T11:37:39.396Z,1661945859.396 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,113745.00,A,4006.02315,N,07100.13532,W,9.641,313.87,310822,,,A*70 2022-08-31T11:37:39.411Z,1661945859.411 [NAL9602](INFO): GPS fix at 20220831T113745: (40.100386, -71.002255) 2022-08-31T11:37:39.429Z,1661945859.429 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T11:37:39.429Z,1661945859.429 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T11:37:39.847Z,1661945859.847 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2022-08-31T11:37:41.880Z,1661945861.880 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2022-08-31T11:38:03.506Z,1661945883.506 [NAL9602](INFO): SBD MO Status=1, MOMSN=44254, MT Status=0, MTMSN=0 2022-08-31T11:38:03.561Z,1661945883.561 [NAL9602](INFO): Sent 52 bytes from file Logs/20220831T113357/Courier0004.lzma 2022-08-31T11:38:03.561Z,1661945883.561 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:38:20.988Z,1661945900.988 [NAL9602](INFO): SBD MO Status=2, MOMSN=44255, MT Status=2, MTMSN=0 2022-08-31T11:38:20.989Z,1661945900.989 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T11:38:40.940Z,1661945920.940 [NAL9602](INFO): SBD MO Status=1, MOMSN=44255, MT Status=0, MTMSN=0 2022-08-31T11:38:40.989Z,1661945920.989 [NAL9602](INFO): Sent 73 bytes from file Logs/20220831T113357/Courier0007.lzma 2022-08-31T11:38:40.989Z,1661945920.989 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:38:50.383Z,1661945930.383 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:38:50.386Z,1661945930.386 [NAL9602](INFO): SBD MO Status=1, MOMSN=44256, MT Status=0, MTMSN=0 2022-08-31T11:38:50.446Z,1661945930.446 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Express0001.lzma 2022-08-31T11:38:50.446Z,1661945930.446 [NAL9602](INFO): Packets left to send: 5 2022-08-31T11:38:50.790Z,1661945930.790 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831113850.734402,06,1322,25,0125,0150,141,01,01,01,01,-1,-01,-01,1,3,3,0,150,23.2,0.08,-100,2.92,-01,-2.89,56,14500,4000*58 2022-08-31T11:39:02.680Z,1661945942.680 [NAL9602](INFO): SBD MO Status=1, MOMSN=44257, MT Status=0, MTMSN=0 2022-08-31T11:39:02.737Z,1661945942.737 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Express0001.lzma 2022-08-31T11:39:02.737Z,1661945942.737 [NAL9602](INFO): Packets left to send: 4 2022-08-31T11:39:11.490Z,1661945951.490 [NAL9602](INFO): SBD MO Status=1, MOMSN=44258, MT Status=0, MTMSN=0 2022-08-31T11:39:11.539Z,1661945951.539 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Express0001.lzma 2022-08-31T11:39:11.539Z,1661945951.539 [NAL9602](INFO): Packets left to send: 3 2022-08-31T11:39:29.944Z,1661945969.944 [NAL9602](INFO): SBD MO Status=1, MOMSN=44259, MT Status=0, MTMSN=0 2022-08-31T11:39:29.993Z,1661945969.993 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Express0001.lzma 2022-08-31T11:39:29.993Z,1661945969.993 [NAL9602](INFO): Packets left to send: 2 2022-08-31T11:39:44.456Z,1661945984.456 [NAL9602](INFO): SBD MO Status=2, MOMSN=44260, MT Status=2, MTMSN=0 2022-08-31T11:39:44.456Z,1661945984.456 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T11:39:54.241Z,1661945994.241 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:39:54.646Z,1661945994.646 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831113954.735707,06,155,21,0091,0150,149,01,01,00,01,-1,-01,-01,1,3,7,0,150,23.9,-0.01,-100,3.01,-01,0.26,55,14500,4000*63 2022-08-31T11:40:25.063Z,1661946025.063 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T11:40:25.063Z,1661946025.063 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T11:40:25.461Z,1661946025.461 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:40:25.830Z,1661946025.830 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831114024.719910,06,1321,25,0093,0150,208,02,02,01,02,-1,-01,-01,1,3,3,0,150,76.4,0.74,-100,2.26,-01,0.85,-12,14500,4000*5B 2022-08-31T11:40:44.112Z,1661946044.112 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:40:44.502Z,1661946044.502 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831114042.738246,06,237,23,0119,0150,223,02,02,00,02,-1,-01,-01,1,3,1,0,150,4.7,1.20,-100,1.80,-01,0.25,66,14500,4000*75 2022-08-31T11:40:49.348Z,1661946049.348 [NAL9602](INFO): SBD MO Status=1, MOMSN=44260, MT Status=0, MTMSN=0 2022-08-31T11:40:49.418Z,1661946049.418 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Express0001.lzma 2022-08-31T11:40:49.418Z,1661946049.418 [NAL9602](INFO): Packets left to send: 1 2022-08-31T11:41:00.262Z,1661946060.262 [NAL9602](INFO): SBD MO Status=1, MOMSN=44261, MT Status=0, MTMSN=0 2022-08-31T11:41:00.311Z,1661946060.311 [NAL9602](INFO): Sent 112 bytes from file Logs/20220831T113357/Express0001.lzma 2022-08-31T11:41:00.311Z,1661946060.311 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:41:10.524Z,1661946070.524 [NAL9602](INFO): SBD MO Status=1, MOMSN=44262, MT Status=0, MTMSN=0 2022-08-31T11:41:10.582Z,1661946070.582 [NAL9602](INFO): Sent 94 bytes from file Logs/20220831T113357/Express0005.lzma 2022-08-31T11:41:10.582Z,1661946070.582 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:41:19.272Z,1661946079.272 [NAL9602](INFO): SBD MO Status=1, MOMSN=44263, MT Status=0, MTMSN=0 2022-08-31T11:41:19.333Z,1661946079.333 [NAL9602](INFO): Sent 62 bytes from file Logs/20220831T113357/Express0008.lzma 2022-08-31T11:41:19.333Z,1661946079.333 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:41:21.150Z,1661946081.150 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T11:41:21.563Z,1661946081.563 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831114118.738022,06,373,25,0090,0150,149,01,01,00,01,5,-01,-01,2,3,5,0,150,3.0,-0.47,-100,3.47,-01,3.41,55,14500,4000*7B 2022-08-31T11:41:22.740Z,1661946082.740 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T11:41:22.740Z,1661946082.740 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T11:41:23.147Z,1661946083.147 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:41:23.550Z,1661946083.550 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831114122.717663,06,1278,25,0106,0150,208,02,02,01,02,-1,-01,-01,1,3,2,0,150,76.5,0.38,-100,2.62,-01,-4.82,-12,14500,4000*7F 2022-08-31T11:41:28.804Z,1661946088.804 [NAL9602](INFO): SBD MO Status=0, MOMSN=44264, MT Status=0, MTMSN=0 2022-08-31T11:41:28.899Z,1661946088.899 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T11:41:28.899Z,1661946088.899 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T11:41:28.899Z,1661946088.899 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T11:41:34.080Z,1661946094.080 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:41:34.493Z,1661946094.493 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831114134.730067,06,279,24,0093,0150,208,02,02,00,02,-1,-01,-01,1,3,1,0,150,6.4,0.15,-100,2.85,-01,-0.99,64,14500,4000*53 2022-08-31T11:41:37.289Z,1661946097.289 [BPC1](ERROR): Battery stick #62 (s/n: 0138) reported TERMINATE_CHARGE_ALARM. Status code: 0x40C0. 2022-08-31T11:41:37.290Z,1661946097.290 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6. 2022-08-31T11:41:37.293Z,1661946097.293 [BPC1](INFO): Received data from all battery sticks. 2022-08-31T11:41:59.507Z,1661946119.507 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T11:42:21.752Z,1661946141.752 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-08-31T11:42:28.191Z,1661946148.191 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:42:28.196Z,1661946148.196 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831114228.723553,06,271,24,0091,0150,223,02,02,00,02,-1,-01,-01,1,3,1,0,150,6.2,0.44,-100,2.56,-01,-1.93,66,14500,4000*5B 2022-08-31T11:42:31.852Z,1661946151.852 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-08-31T11:42:48.388Z,1661946168.388 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:42:48.402Z,1661946168.402 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831114248.731868,06,260,24,0106,0150,194,02,02,00,02,-1,-01,-01,1,3,1,0,150,10.9,0.50,-100,2.50,-01,0.48,62,14500,4000*4A 2022-08-31T11:46:09.179Z,1661946369.179 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T11:46:09.198Z,1661946369.198 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831114608.719946,06,2103,27,0149,0150,186,01,01,01,01,6,-01,-01,2,3,1,0,150,-5.8,3.53,10,-0.53,-01,-2.03,61,14500,4000*53 2022-08-31T11:46:29.467Z,1661946389.467 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T11:46:29.467Z,1661946389.467 [Default:CheckIn:C.Wait] Stopped 2022-08-31T11:46:29.467Z,1661946389.467 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T11:46:29.468Z,1661946389.468 [Default:CheckIn:D] Running Loop=1 2022-08-31T11:46:29.830Z,1661946389.830 [Default:CheckIn:D] Stopped 2022-08-31T11:46:29.831Z,1661946389.831 [Default:CheckIn:E] Running Loop=1 2022-08-31T11:46:30.207Z,1661946390.207 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.160498 min 2022-08-31T11:46:30.207Z,1661946390.207 [Default:CheckIn:E] Stopped 2022-08-31T11:46:30.208Z,1661946390.208 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T11:46:30.208Z,1661946390.208 [Default:CheckIn] Stopped 2022-08-31T11:46:30.208Z,1661946390.208 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T11:46:30.208Z,1661946390.208 [Default:CheckIn](INFO): Running loop #2 2022-08-31T11:46:30.208Z,1661946390.208 [Default:CheckIn] Running Loop=2 2022-08-31T11:46:30.208Z,1661946390.208 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T11:46:30.208Z,1661946390.208 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T11:46:32.205Z,1661946392.205 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,114638.00,A,4006.91536,N,07101.59523,W,9.816,308.62,310822,,,A*73 2022-08-31T11:46:32.207Z,1661946392.207 [NAL9602](INFO): GPS fix at 20220831T114638: (40.115256, -71.026587) 2022-08-31T11:46:32.219Z,1661946392.219 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T11:46:32.219Z,1661946392.219 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T11:46:48.243Z,1661946408.243 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:46:48.654Z,1661946408.654 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831114648.716048,06,1399,25,0096,0150,149,01,01,01,01,-1,-01,-01,1,3,1,0,150,23.9,-0.17,-100,3.17,-01,1.44,55,14500,4000*59 2022-08-31T11:46:55.111Z,1661946415.111 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T11:46:55.518Z,1661946415.518 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831114654.714698,06,1704,26,0097,0150,194,02,02,01,02,5,-01,-01,2,3,2,0,150,-7.3,4.78,-100,-1.78,-01,1.67,61,14500,4000*64 2022-08-31T11:46:59.576Z,1661946419.576 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T11:47:01.176Z,1661946421.176 [NAL9602](INFO): SBD MO Status=2, MOMSN=44265, MT Status=2, MTMSN=0 2022-08-31T11:47:01.176Z,1661946421.176 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T11:47:02.381Z,1661946422.381 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T11:47:02.381Z,1661946422.381 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T11:47:02.789Z,1661946422.789 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:47:03.194Z,1661946423.194 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831114702.719518,06,156,21,0121,0150,208,02,02,00,02,-1,-01,-01,1,3,2,0,150,76.3,0.32,-100,2.68,-01,0.92,-12,14500,4000*6A 2022-08-31T11:47:09.803Z,1661946429.803 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-08-31T11:47:09.808Z,1661946429.808 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T11:47:11.830Z,1661946431.830 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. 2022-08-31T11:47:13.013Z,1661946433.013 [NAL9602](INFO): SBD MO Status=1, MOMSN=44265, MT Status=0, MTMSN=0 2022-08-31T11:47:13.065Z,1661946433.065 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Courier0010.lzma 2022-08-31T11:47:13.065Z,1661946433.065 [NAL9602](INFO): Packets left to send: 1 2022-08-31T11:47:17.686Z,1661946437.686 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2022-08-31T11:47:19.296Z,1661946439.296 [NAL9602](INFO): SBD MO Status=1, MOMSN=44266, MT Status=0, MTMSN=0 2022-08-31T11:47:19.353Z,1661946439.353 [NAL9602](INFO): Sent 18 bytes from file Logs/20220831T113357/Courier0010.lzma 2022-08-31T11:47:19.353Z,1661946439.353 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:47:28.960Z,1661946448.960 [NAL9602](INFO): SBD MO Status=1, MOMSN=44267, MT Status=0, MTMSN=0 2022-08-31T11:47:29.013Z,1661946449.013 [NAL9602](INFO): Sent 166 bytes from file Logs/20220831T113357/Express0011.lzma 2022-08-31T11:47:29.013Z,1661946449.013 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:47:34.628Z,1661946454.628 [RDI_PathfinderUp](ERROR): only read 0 of 4 data items 2022-08-31T11:47:37.044Z,1661946457.044 [NAL9602](INFO): SBD MO Status=0, MOMSN=44268, MT Status=0, MTMSN=0 2022-08-31T11:47:37.127Z,1661946457.127 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T11:47:37.127Z,1661946457.127 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T11:47:37.127Z,1661946457.127 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T11:47:49.592Z,1661946469.592 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-08-31T11:48:07.748Z,1661946487.748 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T11:49:09.663Z,1661946549.663 [CBIT](INFO): Clearing failed state for component DropWeight 2022-08-31T11:49:09.663Z,1661946549.663 [DropWeight] No Fault, FailCount= 1 2022-08-31T11:50:34.399Z,1661946634.399 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T11:50:34.400Z,1661946634.400 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T11:50:34.402Z,1661946634.402 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:50:34.811Z,1661946634.811 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831115034.723344,06,1471,25,0164,0150,134,01,01,01,01,-1,-01,-01,1,3,8,0,150,59.1,2.68,-100,0.32,-01,-0.88,-6,14500,4000*43 2022-08-31T11:51:02.280Z,1661946662.280 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:51:02.284Z,1661946662.284 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831115102.720638,06,1783,26,0090,0150,149,01,01,01,01,-1,-01,-01,1,3,1,0,150,24.2,-0.04,-100,3.04,-01,-0.45,55,14500,4000*7E 2022-08-31T11:51:50.356Z,1661946710.356 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:51:50.361Z,1661946710.361 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831115150.729986,06,217,23,0160,0150,141,01,01,00,01,-1,-01,-01,1,3,1,0,150,25.1,0.99,-100,2.01,-01,1.02,54,14500,4000*40 2022-08-31T11:52:10.152Z,1661946730.152 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:52:10.170Z,1661946730.170 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831115210.734837,06,724,22,0095,0150,194,02,02,01,02,-1,-01,-01,1,3,7,0,150,11.7,0.18,-100,2.82,-01,-1.07,61,14500,4000*6E 2022-08-31T11:52:30.356Z,1661946750.356 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:52:30.360Z,1661946750.360 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831115230.714513,06,880,23,0102,0150,156,01,01,01,02,-1,-01,-01,1,3,8,0,150,13.4,0.03,-100,2.97,-01,0.67,59,14500,4000*45 2022-08-31T11:52:37.668Z,1661946757.668 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T11:52:37.669Z,1661946757.669 [Default:CheckIn:C.Wait] Stopped 2022-08-31T11:52:37.669Z,1661946757.669 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T11:52:37.669Z,1661946757.669 [Default:CheckIn:D] Running Loop=1 2022-08-31T11:52:38.037Z,1661946758.037 [Default:CheckIn:D] Stopped 2022-08-31T11:52:38.038Z,1661946758.038 [Default:CheckIn:E] Running Loop=1 2022-08-31T11:52:38.446Z,1661946758.446 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.297281 min 2022-08-31T11:52:38.446Z,1661946758.446 [Default:CheckIn:E] Stopped 2022-08-31T11:52:38.446Z,1661946758.446 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T11:52:38.446Z,1661946758.446 [Default:CheckIn] Stopped 2022-08-31T11:52:38.447Z,1661946758.447 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T11:52:38.447Z,1661946758.447 [Default:CheckIn](INFO): Running loop #3 2022-08-31T11:52:38.447Z,1661946758.447 [Default:CheckIn] Running Loop=3 2022-08-31T11:52:38.447Z,1661946758.447 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T11:52:38.447Z,1661946758.447 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T11:52:40.449Z,1661946760.449 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,115247.00,A,4007.52224,N,07102.61793,W,9.467,308.19,310822,,,A*73 2022-08-31T11:52:40.451Z,1661946760.451 [NAL9602](INFO): GPS fix at 20220831T115247: (40.125371, -71.043632) 2022-08-31T11:52:40.479Z,1661946760.479 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T11:52:40.479Z,1661946760.479 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T11:52:46.113Z,1661946766.113 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:52:46.527Z,1661946766.527 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831115246.719940,06,1544,25,0098,0150,149,01,01,01,01,-1,-01,-01,1,3,1,0,150,24.5,0.95,-100,2.05,-01,-3.03,55,14500,4000*56 2022-08-31T11:52:56.196Z,1661946776.196 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:52:56.606Z,1661946776.606 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831115256.728414,06,277,24,0098,0150,208,02,02,00,02,-1,-01,-01,1,3,1,0,150,9.0,0.60,-100,2.40,-01,-1.34,64,14500,4000*5F 2022-08-31T11:53:05.091Z,1661946785.091 [NAL9602](INFO): SBD MO Status=1, MOMSN=44269, MT Status=0, MTMSN=0 2022-08-31T11:53:05.141Z,1661946785.141 [NAL9602](INFO): Sent 73 bytes from file Logs/20220831T113357/Courier0013.lzma 2022-08-31T11:53:05.141Z,1661946785.141 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:53:14.861Z,1661946794.861 [NAL9602](INFO): SBD MO Status=1, MOMSN=44270, MT Status=0, MTMSN=0 2022-08-31T11:53:14.917Z,1661946794.917 [NAL9602](INFO): Sent 136 bytes from file Logs/20220831T113357/Express0014.lzma 2022-08-31T11:53:14.917Z,1661946794.917 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:53:22.817Z,1661946802.817 [NAL9602](INFO): SBD MO Status=0, MOMSN=44271, MT Status=0, MTMSN=0 2022-08-31T11:53:22.903Z,1661946802.903 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T11:53:22.903Z,1661946802.903 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T11:53:22.903Z,1661946802.903 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T11:53:24.032Z,1661946804.032 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:53:24.430Z,1661946804.430 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831115324.730612,06,1164,24,0096,0150,141,01,01,01,01,-1,-01,-01,1,3,7,0,150,23.6,-0.05,-100,3.05,-01,-0.85,55,14500,4000*7B 2022-08-31T11:53:52.856Z,1661946832.856 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T11:53:52.856Z,1661946832.856 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T11:53:52.858Z,1661946832.858 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:53:53.254Z,1661946833.254 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831115352.727782,06,313,24,0104,0150,149,01,01,00,01,-1,-01,-01,1,3,6,0,150,61.5,6.07,-100,-3.07,-01,2.55,-6,14500,4000*7F 2022-08-31T11:53:53.255Z,1661946833.255 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T11:54:03.774Z,1661946843.774 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-08-31T11:56:16.273Z,1661946976.273 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T11:56:16.273Z,1661946976.273 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T11:56:16.275Z,1661946976.275 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:56:16.676Z,1661946976.676 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831115616.733524,06,189,22,0125,0150,208,02,02,00,02,-1,-01,-01,1,3,1,0,150,-100.0,-0.02,-100,3.02,-01,-0.72,-2147483648,14500,4000*76 2022-08-31T11:56:38.899Z,1661946998.899 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T11:56:38.900Z,1661946998.900 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T11:56:39.296Z,1661946999.296 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:56:39.300Z,1661946999.300 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831115638.725954,06,251,23,0116,0150,208,02,02,00,02,-1,-01,-01,1,3,2,0,150,76.8,9.02,-100,-6.02,-01,-3.62,-12,14500,4000*6F 2022-08-31T11:58:23.589Z,1661947103.589 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T11:58:23.589Z,1661947103.589 [Default:CheckIn:C.Wait] Stopped 2022-08-31T11:58:23.590Z,1661947103.590 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T11:58:23.590Z,1661947103.590 [Default:CheckIn:D] Running Loop=1 2022-08-31T11:58:23.947Z,1661947103.947 [Default:CheckIn:D] Stopped 2022-08-31T11:58:23.948Z,1661947103.948 [Default:CheckIn:E] Running Loop=1 2022-08-31T11:58:24.361Z,1661947104.361 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.062447 min 2022-08-31T11:58:24.361Z,1661947104.361 [Default:CheckIn:E] Stopped 2022-08-31T11:58:24.361Z,1661947104.361 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T11:58:24.361Z,1661947104.361 [Default:CheckIn] Stopped 2022-08-31T11:58:24.362Z,1661947104.362 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T11:58:24.362Z,1661947104.362 [Default:CheckIn](INFO): Running loop #4 2022-08-31T11:58:24.362Z,1661947104.362 [Default:CheckIn] Running Loop=4 2022-08-31T11:58:24.362Z,1661947104.362 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T11:58:24.362Z,1661947104.362 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T11:58:26.361Z,1661947106.361 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T11:58:26.362Z,1661947106.362 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T11:58:26.363Z,1661947106.363 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T11:58:26.366Z,1661947106.366 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,115833.00,A,4008.09053,N,07103.58027,W,9.525,304.01,310822,,,A*78 2022-08-31T11:58:26.368Z,1661947106.368 [NAL9602](INFO): GPS fix at 20220831T115833: (40.134842, -71.059671) 2022-08-31T11:58:26.412Z,1661947106.412 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T11:58:26.412Z,1661947106.412 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T11:58:26.764Z,1661947106.764 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831115826.709783,06,1276,25,0139,0150,149,01,01,01,01,-1,-01,-01,1,3,1,0,150,-100.0,0.39,-100,2.61,-01,-0.66,-2147483648,14500,4000*65 2022-08-31T11:58:41.491Z,1661947121.491 [NAL9602](INFO): SBD MO Status=1, MOMSN=44272, MT Status=0, MTMSN=0 2022-08-31T11:58:41.541Z,1661947121.541 [NAL9602](INFO): Sent 74 bytes from file Logs/20220831T113357/Courier0016.lzma 2022-08-31T11:58:41.541Z,1661947121.541 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:58:50.310Z,1661947130.310 [NAL9602](INFO): SBD MO Status=1, MOMSN=44273, MT Status=0, MTMSN=0 2022-08-31T11:58:50.369Z,1661947130.369 [NAL9602](INFO): Sent 136 bytes from file Logs/20220831T113357/Express0017.lzma 2022-08-31T11:58:50.369Z,1661947130.369 [NAL9602](INFO): Packets left to send: 0 2022-08-31T11:58:58.600Z,1661947138.600 [NAL9602](INFO): SBD MO Status=0, MOMSN=44274, MT Status=0, MTMSN=0 2022-08-31T11:58:58.681Z,1661947138.681 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T11:58:58.681Z,1661947138.681 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T11:58:58.681Z,1661947138.681 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T11:59:29.299Z,1661947169.299 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T12:00:27.483Z,1661947227.483 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T12:00:27.487Z,1661947227.487 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831120026.719621,06,286,24,0095,0150,194,01,01,00,01,2,-01,-01,2,3,1,0,150,-7.1,3.98,11,-0.98,-01,-2.70,61,14500,4000*67 2022-08-31T12:01:00.201Z,1661947260.201 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:01:00.206Z,1661947260.206 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831120100.711770,06,676,22,0119,0150,208,02,02,01,02,-1,-01,-01,1,3,1,0,150,8.9,1.07,-100,1.93,-01,-1.58,63,14500,4000*50 2022-08-31T12:01:27.679Z,1661947287.679 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2022-08-31T12:01:50.295Z,1661947310.295 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:01:50.299Z,1661947310.299 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831120150.712671,06,1681,26,0130,0150,208,02,02,01,02,-1,-01,-01,1,3,1,0,150,9.1,1.04,-100,1.96,-01,-0.94,64,14500,4000*69 2022-08-31T12:01:55.556Z,1661947315.556 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T12:01:55.561Z,1661947315.561 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831120154.707159,06,926,23,0377,0150,194,02,02,01,02,5,-01,-01,2,3,3,0,150,-10.3,6.38,-100,-3.38,-01,-1.49,61,14500,4000*4D 2022-08-31T12:02:24.240Z,1661947344.240 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:02:24.244Z,1661947344.244 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831120224.723714,06,629,21,0090,0150,134,03,03,01,03,-1,-01,-01,1,3,1,0,150,10.8,1.02,-100,1.98,-01,0.17,56,14500,4000*45 2022-08-31T12:03:08.280Z,1661947388.280 [Micromodem](INFO): Nmea in: $CAMSG,Error accessing coproc,4*51 2022-08-31T12:03:08.284Z,1661947388.284 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831120308.708708,06,1588,25,0117,0150,194,02,02,01,02,-1,-01,-01,4,3,0,0,-999,-99.9,-9.99,-999,-9.99,-01,0.00,-999,14500,4000*65 2022-08-31T12:03:29.715Z,1661947409.715 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T12:03:59.188Z,1661947439.188 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T12:03:59.188Z,1661947439.188 [Default:CheckIn:C.Wait] Stopped 2022-08-31T12:03:59.188Z,1661947439.188 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T12:03:59.189Z,1661947439.189 [Default:CheckIn:D] Running Loop=1 2022-08-31T12:03:59.626Z,1661947439.626 [Default:CheckIn:D] Stopped 2022-08-31T12:03:59.626Z,1661947439.626 [Default:CheckIn:E] Running Loop=1 2022-08-31T12:04:00.012Z,1661947440.012 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.657088 min 2022-08-31T12:04:00.012Z,1661947440.012 [Default:CheckIn:E] Stopped 2022-08-31T12:04:00.012Z,1661947440.012 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T12:04:00.012Z,1661947440.012 [Default:CheckIn] Stopped 2022-08-31T12:04:00.013Z,1661947440.013 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T12:04:00.013Z,1661947440.013 [Default:CheckIn](INFO): Running loop #5 2022-08-31T12:04:00.013Z,1661947440.013 [Default:CheckIn] Running Loop=5 2022-08-31T12:04:00.013Z,1661947440.013 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T12:04:00.013Z,1661947440.013 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T12:04:02.009Z,1661947442.009 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,120408.00,A,4008.65144,N,07104.50709,W,9.544,307.34,310822,,,A*71 2022-08-31T12:04:02.011Z,1661947442.011 [NAL9602](INFO): GPS fix at 20220831T120408: (40.144191, -71.075118) 2022-08-31T12:04:02.022Z,1661947442.022 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T12:04:02.022Z,1661947442.022 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T12:04:30.495Z,1661947470.495 [NAL9602](INFO): SBD MO Status=1, MOMSN=44275, MT Status=0, MTMSN=0 2022-08-31T12:04:30.545Z,1661947470.545 [NAL9602](INFO): Sent 72 bytes from file Logs/20220831T113357/Courier0019.lzma 2022-08-31T12:04:30.545Z,1661947470.545 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:04:40.226Z,1661947480.226 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T12:04:40.227Z,1661947480.227 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T12:04:40.624Z,1661947480.624 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:04:41.038Z,1661947481.038 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831120440.721174,06,161,22,0211,0150,141,01,01,00,01,-1,-01,-01,1,3,2,0,150,65.2,0.29,-100,2.71,-01,-0.67,-6,14500,4000*74 2022-08-31T12:04:41.045Z,1661947481.045 [NAL9602](INFO): SBD MO Status=1, MOMSN=44276, MT Status=0, MTMSN=0 2022-08-31T12:04:41.113Z,1661947481.113 [NAL9602](INFO): Sent 136 bytes from file Logs/20220831T113357/Express0020.lzma 2022-08-31T12:04:41.114Z,1661947481.114 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:04:49.356Z,1661947489.356 [NAL9602](INFO): SBD MO Status=0, MOMSN=44277, MT Status=0, MTMSN=0 2022-08-31T12:04:49.455Z,1661947489.455 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T12:04:49.455Z,1661947489.455 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T12:04:49.455Z,1661947489.455 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T12:05:20.070Z,1661947520.070 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T12:06:15.501Z,1661947575.501 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T12:06:50.558Z,1661947610.558 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T12:06:55.470Z,1661947615.470 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2022-08-31T12:06:58.232Z,1661947618.232 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T12:06:58.236Z,1661947618.236 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831120656.715380,06,1435,25,0249,0150,134,01,01,01,01,5,-01,-01,2,3,4,0,150,3.3,-0.30,-100,3.30,-01,-1.55,53,14500,4000*62 2022-08-31T12:07:35.487Z,1661947655.487 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-08-31T12:07:35.493Z,1661947655.493 [RDI_PathfinderUp](ERROR): only read 1 of 4 data items 2022-08-31T12:08:26.304Z,1661947706.304 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:08:26.308Z,1661947706.308 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831120826.703221,06,1555,25,0100,0150,208,02,02,01,02,-1,-01,-01,1,3,1,0,150,9.8,0.96,-100,2.04,-01,2.75,63,14500,4000*46 2022-08-31T12:08:32.360Z,1661947712.360 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:08:32.364Z,1661947712.364 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831120832.702712,06,1185,24,0126,0150,216,02,02,01,02,-1,-01,-01,1,3,6,0,150,8.8,-0.12,-100,3.12,-01,1.04,64,14500,4000*67 2022-08-31T12:09:06.301Z,1661947746.301 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T12:09:06.301Z,1661947746.301 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T12:09:06.303Z,1661947746.303 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:09:06.703Z,1661947746.703 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831120906.706857,06,1375,25,0101,0150,141,01,01,01,01,-1,-01,-01,1,3,1,0,150,-100.0,0.35,-100,2.65,-01,-5.33,-2147483648,14500,4000*65 2022-08-31T12:09:49.959Z,1661947789.959 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T12:09:49.959Z,1661947789.959 [Default:CheckIn:C.Wait] Stopped 2022-08-31T12:09:49.959Z,1661947789.959 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T12:09:49.959Z,1661947789.959 [Default:CheckIn:D] Running Loop=1 2022-08-31T12:09:50.347Z,1661947790.347 [Default:CheckIn:D] Stopped 2022-08-31T12:09:50.347Z,1661947790.347 [Default:CheckIn:E] Running Loop=1 2022-08-31T12:09:50.750Z,1661947790.750 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.502433 min 2022-08-31T12:09:50.751Z,1661947790.751 [Default:CheckIn:E] Stopped 2022-08-31T12:09:50.751Z,1661947790.751 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T12:09:50.751Z,1661947790.751 [Default:CheckIn] Stopped 2022-08-31T12:09:50.751Z,1661947790.751 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T12:09:50.751Z,1661947790.751 [Default:CheckIn](INFO): Running loop #6 2022-08-31T12:09:50.751Z,1661947790.751 [Default:CheckIn] Running Loop=6 2022-08-31T12:09:50.751Z,1661947790.751 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T12:09:50.751Z,1661947790.751 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T12:09:52.768Z,1661947792.768 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,120959.00,A,4009.24473,N,07105.47265,W,9.719,308.20,310822,,,A*75 2022-08-31T12:09:52.770Z,1661947792.770 [NAL9602](INFO): GPS fix at 20220831T120959: (40.154079, -71.091211) 2022-08-31T12:09:52.792Z,1661947792.792 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T12:09:52.792Z,1661947792.792 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T12:10:17.185Z,1661947817.185 [NAL9602](INFO): SBD MO Status=1, MOMSN=44278, MT Status=0, MTMSN=0 2022-08-31T12:10:17.233Z,1661947817.233 [NAL9602](INFO): Sent 74 bytes from file Logs/20220831T113357/Courier0022.lzma 2022-08-31T12:10:17.233Z,1661947817.233 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:10:27.679Z,1661947827.679 [NAL9602](INFO): SBD MO Status=1, MOMSN=44279, MT Status=0, MTMSN=0 2022-08-31T12:10:27.729Z,1661947827.729 [NAL9602](INFO): Sent 136 bytes from file Logs/20220831T113357/Express0023.lzma 2022-08-31T12:10:27.729Z,1661947827.729 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:10:28.094Z,1661947828.094 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:10:29.642Z,1661947829.642 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831121028.716959,06,1178,24,0119,0150,149,01,01,01,01,-1,-01,-01,1,3,5,0,150,25.0,0.01,-100,2.99,-01,0.97,55,14500,4000*75 2022-08-31T12:10:36.867Z,1661947836.867 [NAL9602](INFO): SBD MO Status=0, MOMSN=44280, MT Status=0, MTMSN=0 2022-08-31T12:10:36.951Z,1661947836.951 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T12:10:36.951Z,1661947836.951 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T12:10:36.951Z,1661947836.951 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T12:11:07.651Z,1661947867.651 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T12:11:28.260Z,1661947888.260 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:11:28.264Z,1661947888.264 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831121128.699849,06,525,21,0280,0150,194,02,02,01,02,-1,-01,-01,1,3,1,0,150,12.3,0.97,-100,2.03,-01,-0.04,61,14500,4000*65 2022-08-31T12:13:52.093Z,1661948032.093 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T12:13:52.093Z,1661948032.093 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T12:13:52.095Z,1661948032.095 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:13:52.491Z,1661948032.491 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831121350.727754,06,880,23,0097,0150,134,01,01,01,01,-1,-01,-01,1,3,4,0,150,63.8,0.11,-100,2.89,-01,-2.10,-6,14500,4000*7D 2022-08-31T12:15:37.588Z,1661948137.588 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T12:15:37.588Z,1661948137.588 [Default:CheckIn:C.Wait] Stopped 2022-08-31T12:15:37.588Z,1661948137.588 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T12:15:37.588Z,1661948137.588 [Default:CheckIn:D] Running Loop=1 2022-08-31T12:15:37.949Z,1661948137.949 [Default:CheckIn:D] Stopped 2022-08-31T12:15:37.950Z,1661948137.950 [Default:CheckIn:E] Running Loop=1 2022-08-31T12:15:38.346Z,1661948138.346 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.295813 min 2022-08-31T12:15:38.346Z,1661948138.346 [Default:CheckIn:E] Stopped 2022-08-31T12:15:38.346Z,1661948138.346 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T12:15:38.347Z,1661948138.347 [Default:CheckIn] Stopped 2022-08-31T12:15:38.347Z,1661948138.347 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T12:15:38.347Z,1661948138.347 [Default:CheckIn](INFO): Running loop #7 2022-08-31T12:15:38.347Z,1661948138.347 [Default:CheckIn] Running Loop=7 2022-08-31T12:15:38.347Z,1661948138.347 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T12:15:38.347Z,1661948138.347 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T12:15:40.352Z,1661948140.352 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,121547.00,A,4009.84794,N,07106.41923,W,9.914,308.59,310822,,,A*76 2022-08-31T12:15:40.355Z,1661948140.355 [NAL9602](INFO): GPS fix at 20220831T121547: (40.164132, -71.106987) 2022-08-31T12:15:40.367Z,1661948140.367 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T12:15:40.367Z,1661948140.367 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T12:15:55.092Z,1661948155.092 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T12:15:55.092Z,1661948155.092 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T12:15:55.460Z,1661948155.460 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:15:55.876Z,1661948155.876 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831121552.716330,06,1582,25,0122,0150,208,02,02,01,02,-1,-01,-01,1,3,3,0,150,76.8,4.65,-100,-1.65,-01,1.09,-12,14500,4000*7E 2022-08-31T12:15:58.688Z,1661948158.688 [NAL9602](INFO): SBD MO Status=1, MOMSN=44281, MT Status=0, MTMSN=0 2022-08-31T12:15:58.737Z,1661948158.737 [NAL9602](INFO): Sent 74 bytes from file Logs/20220831T113357/Courier0025.lzma 2022-08-31T12:15:58.737Z,1661948158.737 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:16:09.266Z,1661948169.266 [NAL9602](INFO): SBD MO Status=1, MOMSN=44282, MT Status=0, MTMSN=0 2022-08-31T12:16:09.313Z,1661948169.313 [NAL9602](INFO): Sent 136 bytes from file Logs/20220831T113357/Express0026.lzma 2022-08-31T12:16:09.314Z,1661948169.314 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:16:15.988Z,1661948175.988 [NAL9602](INFO): SBD MO Status=0, MOMSN=44283, MT Status=0, MTMSN=0 2022-08-31T12:16:16.083Z,1661948176.083 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T12:16:16.084Z,1661948176.084 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T12:16:16.084Z,1661948176.084 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T12:16:46.690Z,1661948206.690 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T12:16:58.818Z,1661948218.818 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T12:16:58.818Z,1661948218.818 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T12:16:58.819Z,1661948218.819 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:16:59.222Z,1661948219.222 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831121658.721380,06,223,23,0091,0150,208,02,02,00,02,-1,-01,-01,1,3,4,0,150,76.7,0.49,-100,2.51,-01,0.30,-12,14500,4000*6B 2022-08-31T12:18:41.444Z,1661948321.444 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T12:18:41.449Z,1661948321.449 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831121840.709305,06,1143,24,0115,0150,149,01,01,01,01,1,-01,-01,2,3,1,0,150,-10.5,10.85,-100,-7.85,-01,-2.09,55,14500,4000*4E 2022-08-31T12:19:10.926Z,1661948350.926 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-08-31T12:19:10.926Z,1661948350.926 [DropWeight] Hardware Fault, FailCount= 1 2022-08-31T12:19:10.926Z,1661948350.926 [DropWeight](ERROR): Hardware Fault 2022-08-31T12:19:10.947Z,1661948350.947 [CBIT](INFO): Critical error at 20220831T121910 2022-08-31T12:19:10.950Z,1661948350.950 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-08-31T12:19:10.950Z,1661948350.950 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-08-31T12:19:11.378Z,1661948351.378 [CBIT](INFO): Critical error at 20220831T121910 2022-08-31T12:19:46.095Z,1661948386.095 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items 2022-08-31T12:20:05.504Z,1661948405.504 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-08-31T12:20:48.295Z,1661948448.295 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:20:48.300Z,1661948448.300 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831122048.703815,06,2205,27,0134,0150,216,02,02,01,02,-1,-01,-01,1,3,2,0,150,9.7,-0.19,-100,3.19,-01,-2.79,64,14500,4000*4F 2022-08-31T12:21:16.599Z,1661948476.599 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T12:21:16.599Z,1661948476.599 [Default:CheckIn:C.Wait] Stopped 2022-08-31T12:21:16.600Z,1661948476.600 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T12:21:16.600Z,1661948476.600 [Default:CheckIn:D] Running Loop=1 2022-08-31T12:21:16.995Z,1661948476.995 [Default:CheckIn:D] Stopped 2022-08-31T12:21:16.995Z,1661948476.995 [Default:CheckIn:E] Running Loop=1 2022-08-31T12:21:17.487Z,1661948477.487 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.946578 min 2022-08-31T12:21:17.487Z,1661948477.487 [Default:CheckIn:E] Stopped 2022-08-31T12:21:17.487Z,1661948477.487 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T12:21:17.487Z,1661948477.487 [Default:CheckIn] Stopped 2022-08-31T12:21:17.488Z,1661948477.488 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T12:21:17.488Z,1661948477.488 [Default:CheckIn](INFO): Running loop #8 2022-08-31T12:21:17.488Z,1661948477.488 [Default:CheckIn] Running Loop=8 2022-08-31T12:21:17.488Z,1661948477.488 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T12:21:17.488Z,1661948477.488 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T12:21:19.444Z,1661948479.444 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,122126.00,A,4010.45690,N,07107.33913,W,9.991,310.00,310822,,,A*79 2022-08-31T12:21:19.446Z,1661948479.446 [NAL9602](INFO): GPS fix at 20220831T122126: (40.174282, -71.122319) 2022-08-31T12:21:19.516Z,1661948479.516 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T12:21:19.517Z,1661948479.517 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T12:21:38.204Z,1661948498.204 [NAL9602](INFO): SBD MO Status=1, MOMSN=44284, MT Status=0, MTMSN=0 2022-08-31T12:21:38.257Z,1661948498.257 [NAL9602](INFO): Sent 149 bytes from file Logs/20220831T113357/Courier0028.lzma 2022-08-31T12:21:38.257Z,1661948498.257 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:21:53.525Z,1661948513.525 [NAL9602](INFO): SBD MO Status=1, MOMSN=44285, MT Status=0, MTMSN=0 2022-08-31T12:21:53.573Z,1661948513.573 [NAL9602](INFO): Sent 136 bytes from file Logs/20220831T113357/Express0029.lzma 2022-08-31T12:21:53.574Z,1661948513.574 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:22:09.039Z,1661948529.039 [NAL9602](INFO): SBD MO Status=2, MOMSN=44286, MT Status=2, MTMSN=0 2022-08-31T12:22:09.040Z,1661948529.040 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T12:22:10.670Z,1661948530.670 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T12:22:11.066Z,1661948531.066 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831122208.703426,06,1236,24,0902,0150,216,02,02,01,02,2,-01,-01,2,3,2,0,150,-36.5,1.38,07,1.62,-01,-5.64,67,14500,4000*44 2022-08-31T12:22:15.211Z,1661948535.211 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2022-08-31T12:22:18.704Z,1661948538.704 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2022-08-31T12:22:21.910Z,1661948541.910 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2022-08-31T12:22:35.308Z,1661948555.308 [NAL9602](INFO): SBD MO Status=0, MOMSN=44286, MT Status=0, MTMSN=0 2022-08-31T12:22:35.427Z,1661948555.427 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T12:22:35.427Z,1661948555.427 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T12:22:35.427Z,1661948555.427 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T12:22:36.111Z,1661948556.111 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:22:36.116Z,1661948556.116 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831122236.710747,06,921,23,0101,0150,208,02,02,01,02,-1,-01,-01,1,3,4,0,150,9.7,-0.17,-100,3.17,-01,-2.24,63,14500,4000*75 2022-08-31T12:22:52.276Z,1661948572.276 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T12:22:52.290Z,1661948572.290 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T12:22:52.292Z,1661948572.292 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:22:52.682Z,1661948572.682 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831122252.698448,06,949,23,0126,0150,194,02,02,01,02,-1,-01,-01,1,3,1,0,150,-100.0,0.14,-100,2.86,-01,0.60,-2147483648,14500,4000*75 2022-08-31T12:23:06.011Z,1661948586.011 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T12:23:58.127Z,1661948638.127 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:23:58.132Z,1661948638.132 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831122358.701645,06,458,26,0097,0150,149,01,01,00,01,-1,-01,-01,1,3,7,0,150,25.0,0.08,-100,2.92,-01,2.03,54,14500,4000*4A 2022-08-31T12:26:31.677Z,1661948791.677 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout 2022-08-31T12:26:31.678Z,1661948791.678 [RDI_Pathfinder] Communications Fault, FailCount= 1 2022-08-31T12:26:31.678Z,1661948791.678 [RDI_Pathfinder](ERROR): Communications Fault 2022-08-31T12:26:31.743Z,1661948791.743 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2022-08-31T12:26:32.117Z,1661948792.117 [RDI_Pathfinder](INFO): Powering down 2022-08-31T12:26:32.878Z,1661948792.878 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2022-08-31T12:26:32.878Z,1661948792.878 [RDI_Pathfinder] No Fault, FailCount= 1 2022-08-31T12:26:33.266Z,1661948793.266 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2022-08-31T12:26:54.272Z,1661948814.272 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:26:54.276Z,1661948814.276 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831122654.627548,06,249,23,0093,0150,208,02,02,00,02,-1,-01,-01,1,3,4,0,150,10.6,-0.04,-100,3.04,-01,-0.49,63,14500,4000*43 2022-08-31T12:27:01.576Z,1661948821.576 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T12:27:11.702Z,1661948831.702 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items 2022-08-31T12:27:35.893Z,1661948855.893 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T12:27:35.893Z,1661948855.893 [Default:CheckIn:C.Wait] Stopped 2022-08-31T12:27:35.893Z,1661948855.893 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T12:27:35.894Z,1661948855.894 [Default:CheckIn:D] Running Loop=1 2022-08-31T12:27:36.303Z,1661948856.303 [Default:CheckIn:D] Stopped 2022-08-31T12:27:36.303Z,1661948856.303 [Default:CheckIn:E] Running Loop=1 2022-08-31T12:27:36.725Z,1661948856.725 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.268372 min 2022-08-31T12:27:36.725Z,1661948856.725 [Default:CheckIn:E] Stopped 2022-08-31T12:27:36.725Z,1661948856.725 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T12:27:36.725Z,1661948856.725 [Default:CheckIn] Stopped 2022-08-31T12:27:36.725Z,1661948856.725 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T12:27:36.726Z,1661948856.726 [Default:CheckIn](INFO): Running loop #9 2022-08-31T12:27:36.726Z,1661948856.726 [Default:CheckIn] Running Loop=9 2022-08-31T12:27:36.726Z,1661948856.726 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T12:27:36.726Z,1661948856.726 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T12:27:38.713Z,1661948858.713 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,122745.00,A,4011.13725,N,07108.35781,W,9.505,311.95,310822,,,A*77 2022-08-31T12:27:38.715Z,1661948858.715 [NAL9602](INFO): GPS fix at 20220831T122745: (40.185621, -71.139297) 2022-08-31T12:27:38.760Z,1661948858.760 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T12:27:38.761Z,1661948858.761 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T12:27:53.048Z,1661948873.048 [NAL9602](INFO): SBD MO Status=1, MOMSN=44287, MT Status=0, MTMSN=0 2022-08-31T12:27:53.097Z,1661948873.097 [NAL9602](INFO): Sent 73 bytes from file Logs/20220831T113357/Courier0031.lzma 2022-08-31T12:27:53.097Z,1661948873.097 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:28:01.931Z,1661948881.931 [NAL9602](INFO): SBD MO Status=1, MOMSN=44288, MT Status=0, MTMSN=0 2022-08-31T12:28:01.993Z,1661948881.993 [NAL9602](INFO): Sent 170 bytes from file Logs/20220831T113357/Express0032.lzma 2022-08-31T12:28:01.993Z,1661948881.993 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:28:09.901Z,1661948889.901 [NAL9602](INFO): SBD MO Status=0, MOMSN=44289, MT Status=0, MTMSN=0 2022-08-31T12:28:09.985Z,1661948889.985 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T12:28:09.986Z,1661948889.986 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T12:28:09.986Z,1661948889.986 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T12:28:40.327Z,1661948920.327 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T12:29:07.800Z,1661948947.800 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T12:29:08.200Z,1661948948.200 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831122904.628522,06,672,22,0137,0150,141,01,01,01,01,2,-01,-01,2,3,3,0,150,2.4,-1.52,05,4.52,-01,-3.82,53,14500,4000*47 2022-08-31T12:30:33.852Z,1661949033.852 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:30:34.253Z,1661949034.253 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831123034.604343,06,1252,24,0091,0150,194,02,02,01,02,-1,-01,-01,1,3,1,0,150,12.4,0.99,-100,2.01,-01,-1.01,61,14500,4000*50 2022-08-31T12:33:10.617Z,1661949190.617 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T12:33:10.617Z,1661949190.617 [Default:CheckIn:C.Wait] Stopped 2022-08-31T12:33:10.617Z,1661949190.617 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T12:33:10.617Z,1661949190.617 [Default:CheckIn:D] Running Loop=1 2022-08-31T12:33:11.019Z,1661949191.019 [Default:CheckIn:D] Stopped 2022-08-31T12:33:11.019Z,1661949191.019 [Default:CheckIn:E] Running Loop=1 2022-08-31T12:33:11.495Z,1661949191.495 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.846969 min 2022-08-31T12:33:11.495Z,1661949191.495 [Default:CheckIn:E] Stopped 2022-08-31T12:33:11.495Z,1661949191.495 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T12:33:11.495Z,1661949191.495 [Default:CheckIn] Stopped 2022-08-31T12:33:11.495Z,1661949191.495 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T12:33:11.495Z,1661949191.495 [Default:CheckIn](INFO): Running loop #10 2022-08-31T12:33:11.495Z,1661949191.495 [Default:CheckIn] Running Loop=10 2022-08-31T12:33:11.495Z,1661949191.495 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T12:33:11.495Z,1661949191.495 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T12:33:13.433Z,1661949193.433 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,123320.00,A,4011.73581,N,07109.25539,W,9.583,310.19,310822,,,A*71 2022-08-31T12:33:13.435Z,1661949193.435 [NAL9602](INFO): GPS fix at 20220831T123320: (40.195597, -71.154257) 2022-08-31T12:33:13.493Z,1661949193.493 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T12:33:13.493Z,1661949193.493 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T12:33:25.974Z,1661949205.974 [CommandExec](IMPORTANT): got command burn on 2022-08-31T12:33:25.974Z,1661949205.974 [CommandExec](IMPORTANT): Activating dropweight wire 2022-08-31T12:33:33.008Z,1661949213.008 [NAL9602](INFO): SBD MO Status=1, MOMSN=44290, MT Status=0, MTMSN=0 2022-08-31T12:33:33.073Z,1661949213.073 [NAL9602](INFO): Sent 72 bytes from file Logs/20220831T113357/Courier0034.lzma 2022-08-31T12:33:33.073Z,1661949213.073 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:33:41.134Z,1661949221.134 [NAL9602](INFO): SBD MO Status=1, MOMSN=44291, MT Status=0, MTMSN=0 2022-08-31T12:33:41.185Z,1661949221.185 [NAL9602](INFO): Sent 136 bytes from file Logs/20220831T113357/Express0035.lzma 2022-08-31T12:33:41.192Z,1661949221.192 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:33:47.430Z,1661949227.430 [CommandExec](IMPORTANT): got command burn off 2022-08-31T12:33:47.430Z,1661949227.430 [CommandExec](IMPORTANT): Deactivating dropweight wire 2022-08-31T12:33:49.010Z,1661949229.010 [NAL9602](INFO): SBD MO Status=0, MOMSN=44292, MT Status=0, MTMSN=0 2022-08-31T12:33:49.083Z,1661949229.083 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T12:33:49.083Z,1661949229.083 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T12:33:49.083Z,1661949229.083 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T12:34:01.946Z,1661949241.946 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T12:34:01.946Z,1661949241.946 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T12:34:01.948Z,1661949241.948 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:34:02.344Z,1661949242.344 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831123402.629712,06,691,22,0165,0150,216,02,02,01,02,-1,-01,-01,1,3,1,0,150,-100.0,0.12,-100,2.88,-01,0.53,-2147483648,14500,4000*7C 2022-08-31T12:34:03.966Z,1661949243.966 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:34:03.972Z,1661949243.972 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831123404.617710,06,1478,25,0172,0150,194,02,02,01,02,-1,-01,-01,1,3,7,0,150,13.1,0.04,-100,2.96,-01,1.62,61,14500,4000*74 2022-08-31T12:34:11.300Z,1661949251.300 [CBIT](INFO): Clearing failed state for component DropWeight 2022-08-31T12:34:11.300Z,1661949251.300 [DropWeight] No Fault, FailCount= 1 2022-08-31T12:34:19.715Z,1661949259.715 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T12:34:45.979Z,1661949285.979 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:34:45.987Z,1661949285.987 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831123446.610123,06,926,23,0124,0150,208,02,02,01,02,-1,-01,-01,1,3,5,0,150,10.5,-0.01,-100,3.01,-01,-1.96,63,14500,4000*41 2022-08-31T12:36:20.103Z,1661949380.103 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:36:20.107Z,1661949380.107 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831123620.625643,06,669,22,0101,0150,208,02,02,01,02,-1,-01,-01,1,3,2,0,150,10.4,0.01,-100,2.99,-01,2.17,63,14500,4000*4A 2022-08-31T12:36:28.184Z,1661949388.184 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:36:28.188Z,1661949388.188 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831123628.601171,06,1450,25,0096,0150,149,01,01,01,01,-1,-01,-01,1,3,3,0,150,25.8,-0.05,-100,3.05,-01,-4.90,54,14500,4000*70 2022-08-31T12:36:56.068Z,1661949416.068 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:36:56.072Z,1661949416.072 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831123656.605596,06,1376,25,0096,0150,141,01,01,01,01,-1,-01,-01,1,3,5,0,150,26.6,0.02,-100,2.98,-01,0.53,53,14500,4000*7E 2022-08-31T12:38:49.634Z,1661949529.634 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T12:38:49.634Z,1661949529.634 [Default:CheckIn:C.Wait] Stopped 2022-08-31T12:38:49.634Z,1661949529.634 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T12:38:49.634Z,1661949529.634 [Default:CheckIn:D] Running Loop=1 2022-08-31T12:38:50.020Z,1661949530.020 [Default:CheckIn:D] Stopped 2022-08-31T12:38:50.020Z,1661949530.020 [Default:CheckIn:E] Running Loop=1 2022-08-31T12:38:50.402Z,1661949530.402 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.496997 min 2022-08-31T12:38:50.402Z,1661949530.402 [Default:CheckIn:E] Stopped 2022-08-31T12:38:50.402Z,1661949530.402 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T12:38:50.402Z,1661949530.402 [Default:CheckIn] Stopped 2022-08-31T12:38:50.402Z,1661949530.402 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T12:38:50.403Z,1661949530.403 [Default:CheckIn](INFO): Running loop #11 2022-08-31T12:38:50.403Z,1661949530.403 [Default:CheckIn] Running Loop=11 2022-08-31T12:38:50.403Z,1661949530.403 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T12:38:50.403Z,1661949530.403 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T12:38:52.421Z,1661949532.421 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,123859.00,A,4012.33215,N,07110.18556,W,9.933,310.98,310822,,,A*78 2022-08-31T12:38:52.423Z,1661949532.423 [NAL9602](INFO): GPS fix at 20220831T123859: (40.205536, -71.169759) 2022-08-31T12:38:52.434Z,1661949532.434 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T12:38:52.434Z,1661949532.434 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T12:39:18.844Z,1661949558.844 [NAL9602](INFO): SBD MO Status=2, MOMSN=44293, MT Status=2, MTMSN=0 2022-08-31T12:39:18.845Z,1661949558.845 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T12:39:41.583Z,1661949581.583 [NAL9602](INFO): SBD MO Status=2, MOMSN=44293, MT Status=2, MTMSN=0 2022-08-31T12:39:41.583Z,1661949581.583 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T12:40:02.864Z,1661949602.864 [NAL9602](INFO): SBD MO Status=1, MOMSN=44293, MT Status=0, MTMSN=0 2022-08-31T12:40:02.921Z,1661949602.921 [NAL9602](INFO): Sent 73 bytes from file Logs/20220831T113357/Courier0037.lzma 2022-08-31T12:40:02.921Z,1661949602.921 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:40:28.780Z,1661949628.780 [NAL9602](INFO): SBD MO Status=1, MOMSN=44294, MT Status=0, MTMSN=0 2022-08-31T12:40:28.837Z,1661949628.837 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Express0038.lzma 2022-08-31T12:40:28.837Z,1661949628.837 [NAL9602](INFO): Packets left to send: 1 2022-08-31T12:40:45.592Z,1661949645.592 [NAL9602](INFO): SBD MO Status=2, MOMSN=44295, MT Status=2, MTMSN=0 2022-08-31T12:40:45.593Z,1661949645.593 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T12:40:56.187Z,1661949656.187 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T12:40:56.187Z,1661949656.187 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T12:40:56.584Z,1661949656.584 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:40:56.990Z,1661949656.990 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831124056.601526,06,2564,28,0104,0150,149,01,01,01,01,-1,-01,-01,1,3,3,0,150,60.8,1.03,-100,1.97,-01,-1.07,-6,14500,4000*4F 2022-08-31T12:41:05.484Z,1661949665.484 [NAL9602](INFO): SBD MO Status=1, MOMSN=44295, MT Status=0, MTMSN=0 2022-08-31T12:41:05.533Z,1661949665.533 [NAL9602](INFO): Sent 23 bytes from file Logs/20220831T113357/Express0038.lzma 2022-08-31T12:41:05.533Z,1661949665.533 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:41:10.987Z,1661949670.987 [NAL9602](INFO): SBD MO Status=0, MOMSN=44296, MT Status=0, MTMSN=0 2022-08-31T12:41:11.074Z,1661949671.074 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T12:41:11.074Z,1661949671.074 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T12:41:11.074Z,1661949671.074 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T12:41:41.687Z,1661949701.687 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T12:43:29.976Z,1661949809.976 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:43:29.982Z,1661949809.982 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831124330.626890,06,760,22,0102,0150,134,02,02,01,02,-1,-01,-01,1,3,1,0,150,21.7,0.65,-100,2.35,-01,0.91,52,14500,4000*45 2022-08-31T12:43:47.339Z,1661949827.339 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2022-08-31T12:43:57.443Z,1661949837.443 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2022-08-31T12:44:37.459Z,1661949877.459 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-08-31T12:45:23.370Z,1661949923.370 [CommandExec](IMPORTANT): got command ibit 2022-08-31T12:45:23.564Z,1661949923.564 [IBIT](IMPORTANT): Beginning Initiated BIT 2022-08-31T12:45:23.564Z,1661949923.564 [IBIT](IMPORTANT): Beginning control surface checks. 2022-08-31T12:45:23.572Z,1661949923.572 [CBIT](IMPORTANT): Beginning ground fault scan 2022-08-31T12:45:25.113Z,1661949925.113 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124531.00,A,4012.97834,N,07111.25876,W,9.641,308.53,310822,,,A*7F 2022-08-31T12:45:25.115Z,1661949925.115 [NAL9602](INFO): GPS fix at 20220831T124531: (40.216306, -71.187646) 2022-08-31T12:45:31.972Z,1661949931.972 [Micromodem](INFO): Nmea in: $CAMSG,Error accessing coproc,4*51 2022-08-31T12:45:31.976Z,1661949931.976 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831124532.599871,06,1339,25,0097,0150,208,02,02,01,02,-1,-01,-01,4,3,0,0,-999,-99.9,-9.99,-999,-9.99,-01,0.00,-999,14500,4000*66 2022-08-31T12:45:34.455Z,1661949934.455 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.038990 CHAN A1 (24V): 0.056220 CHAN A2 (12V): 0.011458 CHAN A3 (5V): 0.001813 CHAN B0 (3.3V): 0.000634 CHAN B1 (3.15aV): 0.000545 CHAN B2 (3.15bV): 0.000631 CHAN B3 (GND): -0.002728 OPEN: 0.006088 Full Scale: +/- 1 mA 2022-08-31T12:45:39.299Z,1661949939.299 [NAL9602](INFO): SBD MO Status=0, MOMSN=44297, MT Status=0, MTMSN=0 2022-08-31T12:45:39.299Z,1661949939.299 [NAL9602](INFO): No messages in MT queue 2022-08-31T12:45:40.461Z,1661949940.461 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124547.00,A,4013.00484,N,07111.30192,W,9.564,309.97,310822,,,A*7C 2022-08-31T12:45:40.463Z,1661949940.463 [NAL9602](INFO): GPS fix at 20220831T124547: (40.216747, -71.188365) 2022-08-31T12:45:43.689Z,1661949943.689 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124550.00,A,4013.00967,N,07111.31027,W,9.778,305.58,310822,,,A*74 2022-08-31T12:45:43.691Z,1661949943.691 [NAL9602](INFO): GPS fix at 20220831T124550: (40.216828, -71.188504) 2022-08-31T12:45:46.510Z,1661949946.510 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124553.00,A,4013.01470,N,07111.31851,W,9.836,310.49,310822,,,A*75 2022-08-31T12:45:46.512Z,1661949946.512 [NAL9602](INFO): GPS fix at 20220831T124553: (40.216912, -71.188642) 2022-08-31T12:45:49.745Z,1661949949.745 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124556.00,A,4013.01987,N,07111.32658,W,9.389,308.03,310822,,,A*79 2022-08-31T12:45:49.748Z,1661949949.748 [NAL9602](INFO): GPS fix at 20220831T124556: (40.216998, -71.188776) 2022-08-31T12:45:52.606Z,1661949952.606 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124559.00,A,4013.02472,N,07111.33489,W,9.330,307.27,310822,,,A*76 2022-08-31T12:45:52.608Z,1661949952.608 [NAL9602](INFO): GPS fix at 20220831T124559: (40.217079, -71.188915) 2022-08-31T12:45:55.401Z,1661949955.401 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124602.00,A,4013.02965,N,07111.34312,W,9.622,308.13,310822,,,A*7C 2022-08-31T12:45:55.416Z,1661949955.416 [NAL9602](INFO): GPS fix at 20220831T124602: (40.217161, -71.189052) 2022-08-31T12:45:58.629Z,1661949958.629 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124605.00,A,4013.03467,N,07111.35150,W,9.855,307.84,310822,,,A*7F 2022-08-31T12:45:58.631Z,1661949958.631 [NAL9602](INFO): GPS fix at 20220831T124605: (40.217244, -71.189192) 2022-08-31T12:46:01.458Z,1661949961.458 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124608.00,A,4013.03931,N,07111.35992,W,9.564,306.96,310822,,,A*77 2022-08-31T12:46:01.460Z,1661949961.460 [NAL9602](INFO): GPS fix at 20220831T124608: (40.217322, -71.189332) 2022-08-31T12:46:04.691Z,1661949964.691 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124611.00,A,4013.04426,N,07111.36815,W,9.622,307.87,310822,,,A*7E 2022-08-31T12:46:04.693Z,1661949964.693 [NAL9602](INFO): GPS fix at 20220831T124611: (40.217404, -71.189469) 2022-08-31T12:46:07.533Z,1661949967.533 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124614.00,A,4013.04926,N,07111.37635,W,9.661,308.21,310822,,,A*7F 2022-08-31T12:46:07.535Z,1661949967.535 [NAL9602](INFO): GPS fix at 20220831T124614: (40.217488, -71.189606) 2022-08-31T12:46:09.230Z,1661949969.230 [CommandExec](IMPORTANT): got command failComponent 2022-08-31T12:46:09.230Z,1661949969.230 [CommandExec](IMPORTANT): Failed components: 2022-08-31T12:46:09.230Z,1661949969.230 [CommandExec](IMPORTANT): No failed Components. 2022-08-31T12:46:09.972Z,1661949969.972 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 40.217487 Longitude: -71.189606 2022-08-31T12:46:10.430Z,1661949970.430 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 345.548981 Voltage: 16.611000 2022-08-31T12:46:10.430Z,1661949970.430 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2022-08-31T12:46:10.431Z,1661949970.431 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2022-08-31T12:46:10.757Z,1661949970.757 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124617.00,A,4013.05405,N,07111.38461,W,9.467,307.15,310822,,,A*71 2022-08-31T12:46:10.759Z,1661949970.759 [NAL9602](INFO): GPS fix at 20220831T124617: (40.217568, -71.189744) 2022-08-31T12:46:10.786Z,1661949970.786 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2022-08-31T12:46:10.786Z,1661949970.786 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2022-08-31T12:46:10.787Z,1661949970.787 [IBIT](IMPORTANT): Pressure:7.495161 PSI 2022-08-31T12:46:10.787Z,1661949970.787 [IBIT](IMPORTANT): Humidity:24.349895 % 2022-08-31T12:46:11.191Z,1661949971.191 [IBIT](IMPORTANT): Vehicle Pitch:1.580008 degrees 2022-08-31T12:46:11.191Z,1661949971.191 [IBIT](IMPORTANT): Vehicle Roll:3.271384 degrees 2022-08-31T12:46:11.192Z,1661949971.192 [IBIT](IMPORTANT): Vehicle Heading:124.732574 degrees 2022-08-31T12:46:11.632Z,1661949971.632 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2022-08-31T12:46:11.632Z,1661949971.632 [IBIT](IMPORTANT): buoyancyNeutral: 411.225220 cc 2022-08-31T12:46:11.632Z,1661949971.632 [IBIT](IMPORTANT): massDefault: -0.574058 cm 2022-08-31T12:46:11.633Z,1661949971.633 [IBIT](IMPORTANT): stopDepth: 35.000000 m 2022-08-31T12:46:11.637Z,1661949971.637 [IBIT](IMPORTANT): abortDepth: 50.000000 m 2022-08-31T12:46:11.637Z,1661949971.637 [IBIT](IMPORTANT): IBIT PASSED 2022-08-31T12:46:11.981Z,1661949971.981 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T12:46:11.982Z,1661949971.982 [Default:CheckIn:C.Wait] Stopped 2022-08-31T12:46:11.982Z,1661949971.982 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T12:46:11.982Z,1661949971.982 [Default:CheckIn:D] Running Loop=1 2022-08-31T12:46:12.409Z,1661949972.409 [Default:CheckIn:D] Stopped 2022-08-31T12:46:12.409Z,1661949972.409 [Default:CheckIn:E] Running Loop=1 2022-08-31T12:46:12.818Z,1661949972.818 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.870142 min 2022-08-31T12:46:12.818Z,1661949972.818 [Default:CheckIn:E] Stopped 2022-08-31T12:46:12.818Z,1661949972.818 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T12:46:12.818Z,1661949972.818 [Default:CheckIn] Stopped 2022-08-31T12:46:12.818Z,1661949972.818 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T12:46:12.818Z,1661949972.818 [Default:CheckIn](INFO): Running loop #12 2022-08-31T12:46:12.818Z,1661949972.818 [Default:CheckIn] Running Loop=12 2022-08-31T12:46:12.818Z,1661949972.818 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T12:46:12.818Z,1661949972.818 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T12:46:14.792Z,1661949974.792 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124621.00,A,4013.06048,N,07111.39572,W,9.816,307.60,310822,,,A*70 2022-08-31T12:46:14.794Z,1661949974.794 [NAL9602](INFO): GPS fix at 20220831T124621: (40.217675, -71.189929) 2022-08-31T12:46:14.805Z,1661949974.805 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T12:46:14.805Z,1661949974.805 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T12:46:28.160Z,1661949988.160 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T12:46:40.470Z,1661950000.470 [NAL9602](INFO): SBD MO Status=1, MOMSN=44298, MT Status=0, MTMSN=0 2022-08-31T12:46:40.527Z,1661950000.527 [NAL9602](INFO): Sent 73 bytes from file Logs/20220831T113357/Courier0040.lzma 2022-08-31T12:46:40.527Z,1661950000.527 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:47:04.908Z,1661950024.908 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T12:47:05.323Z,1661950025.323 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831124702.624260,06,132,21,0094,0150,141,01,01,00,01,2,-01,-01,2,3,2,0,150,2.1,-1.31,02,4.31,-01,-3.32,53,14500,4000*45 2022-08-31T12:47:06.528Z,1661950026.528 [NAL9602](INFO): SBD MO Status=1, MOMSN=44299, MT Status=0, MTMSN=0 2022-08-31T12:47:06.577Z,1661950026.577 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Express0041.lzma 2022-08-31T12:47:06.577Z,1661950026.577 [NAL9602](INFO): Packets left to send: 4 2022-08-31T12:47:12.656Z,1661950032.656 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items 2022-08-31T12:47:15.106Z,1661950035.106 [NAL9602](INFO): SBD MO Status=1, MOMSN=44300, MT Status=0, MTMSN=0 2022-08-31T12:47:15.161Z,1661950035.161 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Express0041.lzma 2022-08-31T12:47:15.161Z,1661950035.161 [NAL9602](INFO): Packets left to send: 3 2022-08-31T12:47:23.652Z,1661950043.652 [NAL9602](INFO): SBD MO Status=1, MOMSN=44301, MT Status=0, MTMSN=0 2022-08-31T12:47:23.718Z,1661950043.718 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Express0041.lzma 2022-08-31T12:47:23.718Z,1661950043.718 [NAL9602](INFO): Packets left to send: 2 2022-08-31T12:47:32.240Z,1661950052.240 [NAL9602](INFO): SBD MO Status=1, MOMSN=44302, MT Status=0, MTMSN=0 2022-08-31T12:47:32.297Z,1661950052.297 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T113357/Express0041.lzma 2022-08-31T12:47:32.297Z,1661950052.297 [NAL9602](INFO): Packets left to send: 1 2022-08-31T12:47:40.619Z,1661950060.619 [NAL9602](INFO): SBD MO Status=1, MOMSN=44303, MT Status=0, MTMSN=0 2022-08-31T12:47:40.670Z,1661950060.670 [NAL9602](INFO): Sent 106 bytes from file Logs/20220831T113357/Express0041.lzma 2022-08-31T12:47:40.670Z,1661950060.670 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:47:49.345Z,1661950069.345 [NAL9602](INFO): SBD MO Status=0, MOMSN=44304, MT Status=0, MTMSN=0 2022-08-31T12:47:49.518Z,1661950069.518 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T12:47:49.518Z,1661950069.518 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T12:47:49.518Z,1661950069.518 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T12:48:20.087Z,1661950100.087 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T12:48:49.694Z,1661950129.694 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2022-08-31T12:49:42.106Z,1661950182.106 [RDI_PathfinderUp](ERROR): only read 1 of 4 data items 2022-08-31T12:50:42.720Z,1661950242.720 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T12:51:12.200Z,1661950272.200 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:51:12.204Z,1661950272.204 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831125112.607788,06,1119,24,0094,0150,194,02,02,01,02,-1,-01,-01,1,3,6,0,150,13.2,0.08,-100,2.92,-01,-0.92,61,14500,4000*53 2022-08-31T12:52:49.987Z,1661950369.987 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T12:52:49.988Z,1661950369.988 [Default:CheckIn:C.Wait] Stopped 2022-08-31T12:52:49.988Z,1661950369.988 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T12:52:49.988Z,1661950369.988 [Default:CheckIn:D] Running Loop=1 2022-08-31T12:52:50.378Z,1661950370.378 [Default:CheckIn:D] Stopped 2022-08-31T12:52:50.379Z,1661950370.379 [Default:CheckIn:E] Running Loop=1 2022-08-31T12:52:50.792Z,1661950370.792 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.502962 min 2022-08-31T12:52:50.793Z,1661950370.793 [Default:CheckIn:E] Stopped 2022-08-31T12:52:50.793Z,1661950370.793 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T12:52:50.793Z,1661950370.793 [Default:CheckIn] Stopped 2022-08-31T12:52:50.793Z,1661950370.793 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T12:52:50.793Z,1661950370.793 [Default:CheckIn](INFO): Running loop #13 2022-08-31T12:52:50.793Z,1661950370.793 [Default:CheckIn] Running Loop=13 2022-08-31T12:52:50.793Z,1661950370.793 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T12:52:50.793Z,1661950370.793 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T12:52:52.797Z,1661950372.797 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,125259.00,A,4013.71386,N,07112.50003,W,9.292,308.07,310822,,,A*7C 2022-08-31T12:52:52.799Z,1661950372.799 [NAL9602](INFO): GPS fix at 20220831T125259: (40.228564, -71.208334) 2022-08-31T12:52:52.828Z,1661950372.828 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T12:52:52.828Z,1661950372.828 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T12:53:30.553Z,1661950410.553 [NAL9602](INFO): SBD MO Status=2, MOMSN=44305, MT Status=2, MTMSN=0 2022-08-31T12:53:30.554Z,1661950410.554 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T12:53:35.459Z,1661950415.459 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2022-08-31T12:53:43.959Z,1661950423.959 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:53:44.363Z,1661950424.363 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831125344.611777,06,412,26,0095,0150,149,01,01,00,01,-1,-01,-01,1,3,2,0,150,25.8,0.08,-100,2.92,-01,-1.20,54,14500,4000*6E 2022-08-31T12:54:07.197Z,1661950447.197 [NAL9602](INFO): SBD MO Status=2, MOMSN=44305, MT Status=2, MTMSN=0 2022-08-31T12:54:07.197Z,1661950447.197 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T12:54:23.760Z,1661950463.760 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2022-08-31T12:54:27.740Z,1661950467.740 [NAL9602](INFO): SBD MO Status=1, MOMSN=44305, MT Status=0, MTMSN=0 2022-08-31T12:54:27.798Z,1661950467.798 [NAL9602](INFO): Sent 73 bytes from file Logs/20220831T113357/Courier0043.lzma 2022-08-31T12:54:27.799Z,1661950467.799 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:54:30.111Z,1661950470.111 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:54:32.275Z,1661950472.275 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831125430.606678,06,1204,24,0178,0150,216,02,02,01,02,-1,-01,-01,1,3,1,0,150,9.8,0.29,-100,2.71,-01,-0.98,64,14500,4000*6B 2022-08-31T12:54:37.106Z,1661950477.106 [NAL9602](INFO): SBD MO Status=1, MOMSN=44306, MT Status=0, MTMSN=0 2022-08-31T12:54:37.153Z,1661950477.153 [NAL9602](INFO): Sent 136 bytes from file Logs/20220831T113357/Express0044.lzma 2022-08-31T12:54:37.154Z,1661950477.154 [NAL9602](INFO): Packets left to send: 0 2022-08-31T12:54:44.176Z,1661950484.176 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:54:44.582Z,1661950484.582 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831125444.609809,06,756,22,0090,0150,208,02,02,01,02,-1,-01,-01,1,3,1,0,150,10.6,0.91,-100,2.09,-01,0.78,63,14500,4000*4C 2022-08-31T12:54:45.435Z,1661950485.435 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2022-08-31T12:54:45.448Z,1661950485.448 [NAL9602](INFO): SBD MO Status=0, MOMSN=44307, MT Status=0, MTMSN=0 2022-08-31T12:54:45.600Z,1661950485.600 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T12:54:45.600Z,1661950485.600 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T12:54:45.601Z,1661950485.601 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T12:55:16.112Z,1661950516.112 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T12:55:23.819Z,1661950523.819 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2022-08-31T12:55:35.902Z,1661950535.902 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T12:55:35.903Z,1661950535.903 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T12:55:35.904Z,1661950535.904 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T12:55:36.302Z,1661950536.302 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831125536.596526,06,2054,27,0095,0150,208,02,02,01,02,-1,-01,-01,1,3,1,0,150,-100.0,0.02,-100,2.98,-01,0.67,-2147483648,14500,4000*40 2022-08-31T12:56:52.299Z,1661950612.299 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2022-08-31T12:57:21.791Z,1661950641.791 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2022-08-31T12:57:29.876Z,1661950649.876 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2022-08-31T12:58:19.554Z,1661950699.554 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2022-08-31T12:58:42.177Z,1661950722.177 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2022-08-31T12:58:53.080Z,1661950733.080 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2022-08-31T12:59:46.160Z,1661950786.160 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2022-08-31T12:59:46.175Z,1661950786.175 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T12:59:46.175Z,1661950786.175 [Default:CheckIn:C.Wait] Stopped 2022-08-31T12:59:46.175Z,1661950786.175 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T12:59:46.176Z,1661950786.176 [Default:CheckIn:D] Running Loop=1 2022-08-31T12:59:46.578Z,1661950786.578 [Default:CheckIn:D] Stopped 2022-08-31T12:59:46.578Z,1661950786.578 [Default:CheckIn:E] Running Loop=1 2022-08-31T12:59:46.959Z,1661950786.959 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.439632 min 2022-08-31T12:59:46.959Z,1661950786.959 [Default:CheckIn:E] Stopped 2022-08-31T12:59:46.960Z,1661950786.960 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T12:59:46.960Z,1661950786.960 [Default:CheckIn] Stopped 2022-08-31T12:59:46.960Z,1661950786.960 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T12:59:46.960Z,1661950786.960 [Default:CheckIn](INFO): Running loop #14 2022-08-31T12:59:46.960Z,1661950786.960 [Default:CheckIn] Running Loop=14 2022-08-31T12:59:46.960Z,1661950786.960 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T12:59:46.960Z,1661950786.960 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T12:59:48.961Z,1661950788.961 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,125955.00,A,4014.39108,N,07113.64072,W,9.661,306.87,310822,,,A*7A 2022-08-31T12:59:48.964Z,1661950788.964 [NAL9602](INFO): GPS fix at 20220831T125955: (40.239851, -71.227345) 2022-08-31T12:59:48.974Z,1661950788.974 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T12:59:48.974Z,1661950788.974 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T13:00:00.291Z,1661950800.291 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2022-08-31T13:00:13.824Z,1661950813.824 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error 2022-08-31T13:00:13.825Z,1661950813.825 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error expected 41 2022-08-31T13:00:14.062Z,1661950814.062 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T13:00:14.430Z,1661950814.430 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831130012.617435,06,700,22,0101,0150,208,02,02,01,02,-1,-01,-01,1,3,4,0,150,79.4,1.53,-100,1.47,-01,-2.22,-12,14500,4000*4C 2022-08-31T13:00:21.687Z,1661950821.687 [NAL9602](INFO): SBD MO Status=2, MOMSN=44308, MT Status=2, MTMSN=0 2022-08-31T13:00:21.687Z,1661950821.687 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T13:00:38.856Z,1661950838.856 [NAL9602](INFO): SBD MO Status=1, MOMSN=44308, MT Status=0, MTMSN=0 2022-08-31T13:00:38.909Z,1661950838.909 [NAL9602](INFO): Sent 73 bytes from file Logs/20220831T113357/Courier0046.lzma 2022-08-31T13:00:38.909Z,1661950838.909 [NAL9602](INFO): Packets left to send: 0 2022-08-31T13:00:43.550Z,1661950843.550 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2022-08-31T13:00:46.796Z,1661950846.796 [NAL9602](INFO): SBD MO Status=1, MOMSN=44309, MT Status=0, MTMSN=0 2022-08-31T13:00:46.844Z,1661950846.844 [NAL9602](INFO): Sent 135 bytes from file Logs/20220831T113357/Express0047.lzma 2022-08-31T13:00:46.845Z,1661950846.845 [NAL9602](INFO): Packets left to send: 0 2022-08-31T13:01:05.464Z,1661950865.464 [NAL9602](INFO): SBD MO Status=2, MOMSN=44310, MT Status=2, MTMSN=0 2022-08-31T13:01:05.464Z,1661950865.464 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T13:01:09.148Z,1661950869.148 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2022-08-31T13:01:11.737Z,1661950871.737 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T13:01:28.790Z,1661950888.790 [NAL9602](INFO): SBD MO Status=2, MOMSN=44310, MT Status=2, MTMSN=0 2022-08-31T13:01:28.790Z,1661950888.790 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T13:01:34.971Z,1661950894.971 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2022-08-31T13:01:38.142Z,1661950898.142 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2022-08-31T13:02:04.743Z,1661950924.743 [NAL9602](INFO): SBD MO Status=2, MOMSN=44310, MT Status=2, MTMSN=0 2022-08-31T13:02:04.743Z,1661950924.743 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T13:02:21.564Z,1661950941.564 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=44310, MT Status=1, MTMSN=1679 2022-08-31T13:02:22.036Z,1661950942.036 [NAL9602](INFO): Received command: restart app 2022-08-31T13:02:22.077Z,1661950942.077 [CommandExec](IMPORTANT): got command restart application 2022-08-31T13:02:23.080Z,1661950943.080 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T13:02:23.080Z,1661950943.080 [CommandExec](INFO): Uninitializing the command executive. 2022-08-31T13:02:23.080Z,1661950943.080 [CommandExec](INFO): Uninitializing the command scheduler. 2022-08-31T13:02:23.080Z,1661950943.080 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:23.131Z,1661950943.131 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-08-31T13:02:23.131Z,1661950943.131 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-08-31T13:02:23.132Z,1661950943.132 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:23.132Z,1661950943.132 [NavChartDb](INFO): Join timeout helper Thread ID is 8483 2022-08-31T13:02:23.424Z,1661950943.424 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T13:02:23.425Z,1661950943.425 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:23.439Z,1661950943.439 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2022-08-31T13:02:23.439Z,1661950943.439 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:23.440Z,1661950943.440 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 8484 2022-08-31T13:02:23.480Z,1661950943.480 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T13:02:23.480Z,1661950943.480 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:23.481Z,1661950943.481 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-08-31T13:02:23.481Z,1661950943.481 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:23.481Z,1661950943.481 [CTD_Seabird](INFO): Join timeout helper Thread ID is 8485 2022-08-31T13:02:23.860Z,1661950943.860 [CTD_Seabird](INFO): Powering down 2022-08-31T13:02:23.875Z,1661950943.875 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T13:02:23.876Z,1661950943.876 [CTD_Seabird](INFO): Powering down 2022-08-31T13:02:23.887Z,1661950943.887 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:23.900Z,1661950943.900 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-08-31T13:02:23.900Z,1661950943.900 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:23.900Z,1661950943.900 [Radio_Surface](INFO): Join timeout helper Thread ID is 8486 2022-08-31T13:02:24.208Z,1661950944.208 [Radio_Surface](INFO): Powering down 2022-08-31T13:02:24.208Z,1661950944.208 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T13:02:24.209Z,1661950944.209 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:24.211Z,1661950944.211 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-08-31T13:02:24.211Z,1661950944.211 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:24.212Z,1661950944.212 [Onboard](INFO): Join timeout helper Thread ID is 8487 2022-08-31T13:02:28.311Z,1661950948.311 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T13:02:28.312Z,1661950948.312 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:28.320Z,1661950948.320 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-08-31T13:02:28.321Z,1661950948.321 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:28.321Z,1661950948.321 [DataOverHttps](INFO): Join timeout helper Thread ID is 8488 2022-08-31T13:02:28.780Z,1661950948.780 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T13:02:28.780Z,1661950948.780 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:28.781Z,1661950948.781 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-08-31T13:02:28.782Z,1661950948.782 [logger ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:28.782Z,1661950948.782 [logger](INFO): Join timeout helper Thread ID is 8489 2022-08-31T13:02:28.805Z,1661950948.805 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T13:02:28.805Z,1661950948.805 [logger ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:28.808Z,1661950948.808 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-08-31T13:02:28.808Z,1661950948.808 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:28.809Z,1661950948.809 [CommandLine](INFO): Join timeout helper Thread ID is 8490 2022-08-31T13:02:28.896Z,1661950948.896 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T13:02:28.896Z,1661950948.896 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:28.900Z,1661950948.900 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-08-31T13:02:28.900Z,1661950948.900 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:28.901Z,1661950948.901 [CommandExec](INFO): Join timeout helper Thread ID is 8491 2022-08-31T13:02:28.902Z,1661950948.902 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-08-31T13:02:28.902Z,1661950948.902 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:28.902Z,1661950948.902 [controlThread](INFO): Join timeout helper Thread ID is 8492 2022-08-31T13:02:29.088Z,1661950949.088 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T13:02:29.088Z,1661950949.088 [controlThread](DEBUG): Uninitializing ControlThread 2022-08-31T13:02:29.088Z,1661950949.088 [AHRS_M2](INFO): Powering down 2022-08-31T13:02:29.160Z,1661950949.160 [DDM](INFO): Powering down 2022-08-31T13:02:29.232Z,1661950949.232 [Micromodem](INFO): Powering down 2022-08-31T13:02:29.328Z,1661950949.328 [NAL9602](INFO): Powering down 2022-08-31T13:02:29.400Z,1661950949.400 [RDI_Pathfinder](INFO): Powering down 2022-08-31T13:02:29.471Z,1661950949.471 [RDI_PathfinderUp](INFO): Powering down 2022-08-31T13:02:29.473Z,1661950949.473 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-08-31T13:02:29.474Z,1661950949.474 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-08-31T13:02:29.474Z,1661950949.474 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-08-31T13:02:29.475Z,1661950949.475 [MissionManager](INFO): Uninitializing Mission Default 2022-08-31T13:02:29.475Z,1661950949.475 [Default] Stopped 2022-08-31T13:02:29.475Z,1661950949.475 [Default](DEBUG): Aggregate::uninitialize Default 2022-08-31T13:02:29.475Z,1661950949.475 [Default:B.GoToSurface] Stopped 2022-08-31T13:02:29.476Z,1661950949.476 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-08-31T13:02:29.476Z,1661950949.476 [Default:CheckIn] Stopped 2022-08-31T13:02:29.476Z,1661950949.476 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T13:02:29.476Z,1661950949.476 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T13:02:29.478Z,1661950949.478 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-08-31T13:02:29.479Z,1661950949.479 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-08-31T13:02:29.479Z,1661950949.479 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-08-31T13:02:29.480Z,1661950949.480 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-08-31T13:02:29.480Z,1661950949.480 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-08-31T13:02:29.480Z,1661950949.480 [BuoyancyServo](INFO): Powering down 2022-08-31T13:02:29.491Z,1661950949.491 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-08-31T13:02:29.492Z,1661950949.492 [ElevatorServo](INFO): Powering down 2022-08-31T13:02:29.492Z,1661950949.492 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-08-31T13:02:29.493Z,1661950949.493 [MassServo](INFO): Powering down 2022-08-31T13:02:29.493Z,1661950949.493 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-08-31T13:02:29.493Z,1661950949.493 [RudderServo](INFO): Powering down 2022-08-31T13:02:29.494Z,1661950949.494 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2022-08-31T13:02:29.494Z,1661950949.494 [ThrusterHE](INFO): Powering down 2022-08-31T13:02:29.495Z,1661950949.495 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-08-31T13:02:29.496Z,1661950949.496 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-08-31T13:02:29.496Z,1661950949.496 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-08-31T13:02:29.496Z,1661950949.496 [CBIT](DEBUG): Powering off loads. 2022-08-31T13:02:29.507Z,1661950949.507 [CBIT](DEBUG): Disabling WDT. 2022-08-31T13:02:29.519Z,1661950949.519 [CBIT](DEBUG): Opening all GF detection circuits. 2022-08-31T13:02:29.520Z,1661950949.520 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:29.544Z,1661950949.544 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:29.547Z,1661950949.547 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:29.557Z,1661950949.557 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:29.646Z,1661950949.646 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:29.649Z,1661950949.649 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:29.708Z,1661950949.708 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-31T13:02:29.785Z,1661950949.785 [logger ThreadHandler](INFO): Thread cancelled.