2023-06-26T12:27:07.526Z,1687782427.526 [Supervisor](DEBUG): Initializing supervisor.
2023-06-26T12:27:07.536Z,1687782427.536 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-06-26T12:27:07.537Z,1687782427.537 [SyncHandler](INFO): Protected caller Thread ID is 4455
2023-06-26T12:27:07.537Z,1687782427.537 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-06-26T12:27:07.538Z,1687782427.538 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-06-26T12:27:07.539Z,1687782427.539 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4456
2023-06-26T12:27:07.543Z,1687782427.543 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-06-26T12:27:07.569Z,1687782427.569 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-06-26T12:27:07.570Z,1687782427.570 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-06-26T12:27:07.570Z,1687782427.570 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 4457
2023-06-26T12:27:07.574Z,1687782427.574 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-06-26T12:27:07.575Z,1687782427.575 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-06-26T12:27:07.576Z,1687782427.576 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4458
2023-06-26T12:27:07.586Z,1687782427.586 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-06-26T12:27:07.587Z,1687782427.587 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-06-26T12:27:07.587Z,1687782427.587 [logger ThreadHandler](INFO): Protected caller Thread ID is 4459
2023-06-26T12:27:07.591Z,1687782427.591 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-06-26T12:27:07.591Z,1687782427.591 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-06-26T12:27:07.593Z,1687782427.593 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-06-26T12:27:08.331Z,1687782428.331 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-06-26T12:27:08.331Z,1687782428.331 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-06-26T12:27:08.647Z,1687782428.647 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-06-26T12:27:08.648Z,1687782428.648 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-06-26T12:27:08.765Z,1687782428.765 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-06-26T12:27:09.098Z,1687782429.098 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-06-26T12:27:09.099Z,1687782429.099 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-06-26T12:27:09.208Z,1687782429.208 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-06-26T12:27:09.363Z,1687782429.363 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-06-26T12:27:09.363Z,1687782429.363 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-06-26T12:27:10.018Z,1687782430.018 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-06-26T12:27:10.019Z,1687782430.019 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-06-26T12:27:10.274Z,1687782430.274 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-06-26T12:27:10.275Z,1687782430.275 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-06-26T12:27:11.292Z,1687782431.292 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-06-26T12:27:11.293Z,1687782431.293 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-06-26T12:27:11.579Z,1687782431.579 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-06-26T12:27:11.580Z,1687782431.580 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-06-26T12:27:12.200Z,1687782432.200 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-06-26T12:27:12.201Z,1687782432.201 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-06-26T12:27:12.650Z,1687782432.650 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-06-26T12:27:12.651Z,1687782432.651 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-06-26T12:27:12.818Z,1687782432.818 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-06-26T12:27:12.819Z,1687782432.819 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-06-26T12:27:14.048Z,1687782434.048 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-06-26T12:27:14.049Z,1687782434.049 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-06-26T12:27:14.566Z,1687782434.566 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-06-26T12:27:14.567Z,1687782434.567 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-06-26T12:27:15.010Z,1687782435.010 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-06-26T12:27:15.016Z,1687782435.016 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2023-06-26T12:27:15.017Z,1687782435.017 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2023-06-26T12:27:15.348Z,1687782435.348 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2023-06-26T12:27:15.473Z,1687782435.473 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2023-06-26T12:27:15.815Z,1687782435.815 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2023-06-26T12:27:15.941Z,1687782435.941 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2023-06-26T12:27:16.216Z,1687782436.216 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-06-26T12:27:16.216Z,1687782436.216 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2023-06-26T12:27:16.324Z,1687782436.324 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2023-06-26T12:27:16.434Z,1687782436.434 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2023-06-26T12:27:16.464Z,1687782436.464 [Config/Navigation](ERROR): Unterminated quote: "US2MI01M,US2MI80M,US4MI57M,US4MI56M,US4MI90M,US4MI89M,
2023-06-26T12:27:16.551Z,1687782436.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2023-06-26T12:27:16.706Z,1687782436.706 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2023-06-26T12:27:16.807Z,1687782436.807 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2023-06-26T12:27:16.908Z,1687782436.908 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2023-06-26T12:27:16.908Z,1687782436.908 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-06-26T12:27:16.919Z,1687782436.919 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-06-26T12:27:16.929Z,1687782436.929 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-06-26T12:27:16.930Z,1687782436.930 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-06-26T12:27:17.028Z,1687782437.028 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-06-26T12:27:17.029Z,1687782437.029 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-06-26T12:27:17.079Z,1687782437.079 [VerticalControl](DEBUG): Construct VerticalControl.
2023-06-26T12:27:17.140Z,1687782437.140 [VerticalControl] Loaded
2023-06-26T12:27:17.140Z,1687782437.140 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-06-26T12:27:17.143Z,1687782437.143 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-06-26T12:27:17.185Z,1687782437.185 [HorizontalControl] Loaded
2023-06-26T12:27:17.185Z,1687782437.185 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-06-26T12:27:17.188Z,1687782437.188 [SpeedControl](DEBUG): Construct SpeedControl.
2023-06-26T12:27:17.191Z,1687782437.191 [SpeedControl] Loaded
2023-06-26T12:27:17.191Z,1687782437.191 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-06-26T12:27:17.194Z,1687782437.194 [LoopControl](DEBUG): Construct LoopControl.
2023-06-26T12:27:17.194Z,1687782437.194 [LoopControl] Loaded
2023-06-26T12:27:17.195Z,1687782437.195 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-06-26T12:27:17.195Z,1687782437.195 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-06-26T12:27:17.196Z,1687782437.196 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-06-26T12:27:17.348Z,1687782437.348 [BuoyancyServo] Loaded
2023-06-26T12:27:17.348Z,1687782437.348 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-06-26T12:27:17.368Z,1687782437.368 [ElevatorServo] Loaded
2023-06-26T12:27:17.368Z,1687782437.368 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-06-26T12:27:17.388Z,1687782437.388 [MassServo] Loaded
2023-06-26T12:27:17.388Z,1687782437.388 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-06-26T12:27:17.406Z,1687782437.406 [RudderServo] Loaded
2023-06-26T12:27:17.406Z,1687782437.406 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-06-26T12:27:17.421Z,1687782437.421 [ThrusterHE] Loaded
2023-06-26T12:27:17.421Z,1687782437.421 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-06-26T12:27:17.422Z,1687782437.422 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-06-26T12:27:17.422Z,1687782437.422 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-06-26T12:27:17.471Z,1687782437.471 [DepthRateCalculator] Loaded
2023-06-26T12:27:17.471Z,1687782437.471 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-06-26T12:27:17.476Z,1687782437.476 [PitchRateCalculator] Loaded
2023-06-26T12:27:17.476Z,1687782437.476 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-06-26T12:27:17.486Z,1687782437.486 [SpeedCalculator] Loaded
2023-06-26T12:27:17.486Z,1687782437.486 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-06-26T12:27:17.491Z,1687782437.491 [YawRateCalculator] Loaded
2023-06-26T12:27:17.491Z,1687782437.491 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-06-26T12:27:17.509Z,1687782437.509 [ElevatorOffsetCalculator] Loaded
2023-06-26T12:27:17.510Z,1687782437.510 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-06-26T12:27:17.510Z,1687782437.510 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-06-26T12:27:17.511Z,1687782437.511 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-06-26T12:27:17.624Z,1687782437.624 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-06-26T12:27:17.624Z,1687782437.624 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-06-26T12:27:17.638Z,1687782437.638 [NavChart] Loaded
2023-06-26T12:27:17.638Z,1687782437.638 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-06-26T12:27:17.644Z,1687782437.644 [UniversalFixResidualReporter] Loaded
2023-06-26T12:27:17.644Z,1687782437.644 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-06-26T12:27:17.645Z,1687782437.645 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-06-26T12:27:17.645Z,1687782437.645 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-06-26T12:27:18.060Z,1687782438.060 [AHRS_M2] Loaded
2023-06-26T12:27:18.061Z,1687782438.061 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-06-26T12:27:18.096Z,1687782438.096 [BackseatComponent] Loaded
2023-06-26T12:27:18.096Z,1687782438.096 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-06-26T12:27:18.097Z,1687782438.097 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408E54E0
2023-06-26T12:27:18.097Z,1687782438.097 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 4541
2023-06-26T12:27:18.100Z,1687782438.100 [LcmUniversalReporter] Loaded
2023-06-26T12:27:18.101Z,1687782438.101 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-06-26T12:27:18.107Z,1687782438.107 [BioacousticsDataBridge] Loaded
2023-06-26T12:27:18.107Z,1687782438.107 [ComponentRegistry](DEBUG): SyncComponent "BioacousticsDataBridge" handled in the control thread.
2023-06-26T12:27:18.943Z,1687782438.943 [BPC1] Loaded
2023-06-26T12:27:18.944Z,1687782438.944 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-06-26T12:27:19.021Z,1687782439.021 [DataOverHttps] Loaded
2023-06-26T12:27:19.021Z,1687782439.021 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-06-26T12:27:19.022Z,1687782439.022 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409154E0
2023-06-26T12:27:19.023Z,1687782439.023 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4542
2023-06-26T12:27:19.044Z,1687782439.044 [Depth_Keller] Loaded
2023-06-26T12:27:19.044Z,1687782439.044 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-06-26T12:27:19.049Z,1687782439.049 [DropWeight] Loaded
2023-06-26T12:27:19.049Z,1687782439.049 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-06-26T12:27:19.112Z,1687782439.112 [NAL9602] Loaded
2023-06-26T12:27:19.112Z,1687782439.112 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-06-26T12:27:19.142Z,1687782439.142 [Onboard] Loaded
2023-06-26T12:27:19.142Z,1687782439.142 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-06-26T12:27:19.143Z,1687782439.143 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409454E0
2023-06-26T12:27:19.143Z,1687782439.143 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 4543
2023-06-26T12:27:19.155Z,1687782439.155 [Power24vConverter] Loaded
2023-06-26T12:27:19.156Z,1687782439.156 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-06-26T12:27:19.169Z,1687782439.169 [Radio_Surface] Loaded
2023-06-26T12:27:19.169Z,1687782439.169 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-06-26T12:27:19.171Z,1687782439.171 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409754E0
2023-06-26T12:27:19.171Z,1687782439.171 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4544
2023-06-26T12:27:19.185Z,1687782439.185 [Sonardyne_Nano] Loaded
2023-06-26T12:27:19.185Z,1687782439.185 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2023-06-26T12:27:19.186Z,1687782439.186 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-06-26T12:27:19.186Z,1687782439.186 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-06-26T12:27:19.241Z,1687782439.241 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-06-26T12:27:19.241Z,1687782439.241 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-06-26T12:27:19.388Z,1687782439.388 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-06-26T12:27:19.389Z,1687782439.389 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-06-26T12:27:19.415Z,1687782439.415 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-06-26T12:27:19.415Z,1687782439.415 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-06-26T12:27:19.583Z,1687782439.583 [CTD_Seabird] Loaded
2023-06-26T12:27:19.583Z,1687782439.583 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-06-26T12:27:19.584Z,1687782439.584 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AA94E0
2023-06-26T12:27:19.584Z,1687782439.584 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4545
2023-06-26T12:27:19.605Z,1687782439.605 [PAR_Licor] Loaded
2023-06-26T12:27:19.605Z,1687782439.605 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-06-26T12:27:19.636Z,1687782439.636 [WetLabsBB2FL] Loaded
2023-06-26T12:27:19.637Z,1687782439.637 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-06-26T12:27:19.638Z,1687782439.638 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AD94E0
2023-06-26T12:27:19.638Z,1687782439.638 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4546
2023-06-26T12:27:19.639Z,1687782439.639 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-06-26T12:27:19.639Z,1687782439.639 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-06-26T12:27:20.175Z,1687782440.175 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-06-26T12:27:20.175Z,1687782440.175 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-06-26T12:27:20.578Z,1687782440.578 [SBIT](DEBUG): Construct Startup Built In Test.
2023-06-26T12:27:20.602Z,1687782440.602 [SBIT] Loaded
2023-06-26T12:27:20.603Z,1687782440.603 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-06-26T12:27:20.606Z,1687782440.606 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-06-26T12:27:20.659Z,1687782440.659 [IBIT] Loaded
2023-06-26T12:27:20.659Z,1687782440.659 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-06-26T12:27:20.673Z,1687782440.673 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-06-26T12:27:21.215Z,1687782441.215 [CBIT] Loaded
2023-06-26T12:27:21.215Z,1687782441.215 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-06-26T12:27:21.215Z,1687782441.215 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-06-26T12:27:21.351Z,1687782441.351 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-06-26T12:27:21.356Z,1687782441.356 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-06-26T12:27:21.367Z,1687782441.367 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-06-26T12:27:21.368Z,1687782441.368 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BC44E0
2023-06-26T12:27:21.368Z,1687782441.368 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4547
2023-06-26T12:27:21.373Z,1687782441.373 [Supervisor](INFO): Main Thread ID is 829
2023-06-26T12:27:21.373Z,1687782441.373 [Supervisor](DEBUG): Running supervisor.
2023-06-26T12:27:21.373Z,1687782441.373 [CommandExec ThreadHandler](INFO): Handler Thread ID is 4548
2023-06-26T12:27:21.374Z,1687782441.374 [CommandExec](INFO): Initializing the command executive.
2023-06-26T12:27:21.375Z,1687782441.375 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4549
2023-06-26T12:27:21.378Z,1687782441.378 [controlThread ThreadHandler](INFO): Handler Thread ID is 4550
2023-06-26T12:27:21.379Z,1687782441.379 [controlThread](DEBUG): Initializing ControlThread
2023-06-26T12:27:21.380Z,1687782441.380 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-06-26T12:27:21.382Z,1687782441.382 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-06-26T12:27:21.382Z,1687782441.382 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-06-26T12:27:21.383Z,1687782441.383 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-06-26T12:27:21.384Z,1687782441.384 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-06-26T12:27:21.384Z,1687782441.384 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-06-26T12:27:21.385Z,1687782441.385 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-06-26T12:27:21.385Z,1687782441.385 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-06-26T12:27:21.386Z,1687782441.386 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-06-26T12:27:21.387Z,1687782441.387 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-06-26T12:27:21.387Z,1687782441.387 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-06-26T12:27:21.396Z,1687782441.396 [SBIT](INFO): Initialize SBIT Component.
2023-06-26T12:27:21.397Z,1687782441.397 [SBIT](IMPORTANT): git: 2023-06-24
2023-06-26T12:27:21.397Z,1687782441.397 [SBIT](INFO): git hash: 9cf9c5a962def38bb65ca45eab8460e9f59ac63f
2023-06-26T12:27:21.397Z,1687782441.397 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-06-26T12:27:21.398Z,1687782441.398 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-06-26T12:27:21.399Z,1687782441.399 [SBIT](INFO): Beginning SBIT in 90.000000 seconds.
2023-06-26T12:27:21.400Z,1687782441.400 [IBIT](INFO): Initialize IBIT Component.
2023-06-26T12:27:21.401Z,1687782441.401 [CBIT](DEBUG): Initialize CBIT Component.
2023-06-26T12:27:21.402Z,1687782441.402 [logger ThreadHandler](INFO): Handler Thread ID is 4551
2023-06-26T12:27:21.412Z,1687782441.412 [CBIT](DEBUG): Initialized mux pins.
2023-06-26T12:27:21.412Z,1687782441.412 [CBIT](DEBUG): Initializing the watchdog timer.
2023-06-26T12:27:21.420Z,1687782441.420 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 4552
2023-06-26T12:27:21.432Z,1687782441.432 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4553
2023-06-26T12:27:21.433Z,1687782441.433 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-06-26T12:27:21.436Z,1687782441.436 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-06-26T12:27:21.436Z,1687782441.436 [CBIT](DEBUG): Initializing heartbeat.
2023-06-26T12:27:21.444Z,1687782441.444 [Onboard ThreadHandler](INFO): Handler Thread ID is 4554
2023-06-26T12:27:21.474Z,1687782441.474 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4555
2023-06-26T12:27:21.484Z,1687782441.484 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4556
2023-06-26T12:27:21.485Z,1687782441.485 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-06-26T12:27:21.489Z,1687782441.489 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4558
2023-06-26T12:27:21.492Z,1687782441.492 [WetLabsBB2FL](INFO): Powering up
2023-06-26T12:27:21.493Z,1687782441.493 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4560
2023-06-26T12:27:21.496Z,1687782441.496 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-06-26T12:27:21.496Z,1687782441.496 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-06-26T12:27:21.496Z,1687782441.496 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-06-26T12:27:21.496Z,1687782441.496 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-06-26T12:27:21.497Z,1687782441.497 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-06-26T12:27:21.497Z,1687782441.497 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-06-26T12:27:21.497Z,1687782441.497 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-06-26T12:27:21.497Z,1687782441.497 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-06-26T12:27:21.508Z,1687782441.508 [CBIT](DEBUG): Deactivating GF circuits.
2023-06-26T12:27:21.508Z,1687782441.508 [CBIT](DEBUG): Deactivating emergency mode.
2023-06-26T12:27:21.548Z,1687782441.548 [CBIT](DEBUG): Backplane powered.
2023-06-26T12:27:21.549Z,1687782441.549 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-06-26T12:27:21.561Z,1687782441.561 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-26T12:27:21.588Z,1687782441.588 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2023-06-26T12:27:21.589Z,1687782441.589 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-06-26T12:27:21.667Z,1687782441.667 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-06-26T12:27:21.668Z,1687782441.668 [Default:A.Wait](DEBUG): Construct Wait.
2023-06-26T12:27:21.670Z,1687782441.670 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-26T12:27:21.719Z,1687782441.719 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-06-26T12:27:21.721Z,1687782441.721 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-06-26T12:27:21.743Z,1687782441.743 [Default:E.Execute](DEBUG): Construct Execute.
2023-06-26T12:27:21.746Z,1687782441.746 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2023-06-26T12:27:21.764Z,1687782441.764 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BioacousticsDataBridge,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-06-26T12:27:21.770Z,1687782441.770 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-06-26T12:27:21.861Z,1687782441.861 [Power24vConverter](INFO): Powering up.
2023-06-26T12:27:21.861Z,1687782441.861 [Sonardyne_Nano](INFO): Initializing.
2023-06-26T12:27:21.876Z,1687782441.876 [Radio_Surface](INFO): Powering up
2023-06-26T12:27:21.926Z,1687782441.926 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-06-26T12:27:21.932Z,1687782441.932 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-06-26T12:27:21.933Z,1687782441.933 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-06-26T12:27:21.948Z,1687782441.948 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-06-26T12:27:21.949Z,1687782441.949 [MassServo](DEBUG): Initializing EZServoServo.
2023-06-26T12:27:21.964Z,1687782441.964 [MassServo](DEBUG): Initializing MassServo.
2023-06-26T12:27:21.965Z,1687782441.965 [RudderServo](DEBUG): Initializing EZServoServo.
2023-06-26T12:27:21.972Z,1687782441.972 [RudderServo](DEBUG): Initializing RudderServo.
2023-06-26T12:27:21.973Z,1687782441.973 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-06-26T12:27:21.980Z,1687782441.980 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-06-26T12:27:23.600Z,1687782443.600 [WetLabsBB2FL](INFO): Powering down
2023-06-26T12:27:23.794Z,1687782443.794 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2023-06-26T12:27:27.677Z,1687782447.677 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-06-26T12:27:28.517Z,1687782448.517 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2023-06-26T12:27:49.249Z,1687782469.249 [NAL9602](INFO): Powering up NAL9602
2023-06-26T12:28:00.161Z,1687782480.161 [NAL9602](INFO): NAL9602 initialized
2023-06-26T12:28:51.887Z,1687782531.887 [SBIT](IMPORTANT): Beginning Startup BIT
2023-06-26T12:28:51.891Z,1687782531.891 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-26T12:29:02.819Z,1687782542.819 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.554049
CHAN A1 (24V): 0.689071
CHAN A2 (12V): 0.408990
CHAN A3 (5V): 0.162167
CHAN B0 (3.3V): 0.110643
CHAN B1 (3.15aV): 0.114973
CHAN B2 (3.15bV): 0.115304
CHAN B3 (GND): -0.001648
OPEN: 0.018657
Full Scale: +/- 1 mA
2023-06-26T12:29:46.022Z,1687782586.022 [SBIT](IMPORTANT): SBIT PASSED
2023-06-26T12:29:46.023Z,1687782586.023 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-06-26T12:29:46.023Z,1687782586.023 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2023-06-26T12:29:46.024Z,1687782586.024 [SBIT](IMPORTANT): CBIT.gfScanTimeout=90 minute;

2023-06-26T12:29:46.024Z,1687782586.024 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2023-06-26T12:29:46.024Z,1687782586.024 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 50.000000 meter;

2023-06-26T12:29:46.024Z,1687782586.024 [SBIT](IMPORTANT): Express none platform_roll_angle;

2023-06-26T12:29:46.024Z,1687782586.024 [SBIT](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2023-06-26T12:29:46.024Z,1687782586.024 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;

2023-06-26T12:29:46.024Z,1687782586.024 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=516.055981 cubic_centimeter;

2023-06-26T12:29:46.025Z,1687782586.025 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.1 angular_degree;

2023-06-26T12:29:46.025Z,1687782586.025 [SBIT](IMPORTANT): VerticalControl.massDefault=1.75 centimeter;

2023-06-26T12:29:46.432Z,1687782586.432 [MissionManager](IMPORTANT): Started mission Startup
2023-06-26T12:29:46.433Z,1687782586.433 [Startup] Running Loop=1
2023-06-26T12:29:46.433Z,1687782586.433 [Startup](DEBUG): Aggregate::initialize Startup
2023-06-26T12:29:46.433Z,1687782586.433 [Startup:A.GoToSurface] Running Loop=1
2023-06-26T12:29:46.433Z,1687782586.433 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-26T12:29:46.434Z,1687782586.434 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-26T12:29:46.434Z,1687782586.434 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-26T12:29:46.434Z,1687782586.434 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-26T12:29:46.435Z,1687782586.435 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-26T12:29:46.435Z,1687782586.435 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-26T12:29:46.437Z,1687782586.437 [Startup:StartupSatComms] Running Loop=1
2023-06-26T12:29:46.437Z,1687782586.437 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-06-26T12:29:46.437Z,1687782586.437 [Startup:StartupSatComms:A] Running Loop=1
2023-06-26T12:29:46.831Z,1687782586.831 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-06-26T12:30:21.569Z,1687782621.569 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-06-26T12:30:21.569Z,1687782621.569 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-06-26T12:30:21.582Z,1687782621.582 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-06-26T12:30:22.045Z,1687782622.045 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-06-26T12:30:22.046Z,1687782622.046 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-06-26T12:30:46.707Z,1687782646.707 [Startup:StartupSatComms:A](INFO): Timed out from 2023-06-26T12:29:46.4Z
2023-06-26T12:30:46.707Z,1687782646.707 [Startup:StartupSatComms:A] Stopped
2023-06-26T12:30:46.707Z,1687782646.707 [Startup:StartupSatComms:B] Running Loop=1
2023-06-26T12:30:47.094Z,1687782647.094 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-26T12:30:48.165Z,1687782648.165 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004020
2023-06-26T12:30:55.359Z,1687782655.359 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230626T002936/Courier0394.lzma
2023-06-26T12:30:56.362Z,1687782656.362 [DataOverHttps](INFO): Moved sent file to Logs/20230626T002936/Courier0394.lzma.bak
2023-06-26T12:30:56.362Z,1687782656.362 [DataOverHttps](INFO): SBD MOMSN=18430955
2023-06-26T12:31:17.804Z,1687782677.804 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230626T122707/Courier0000.lzma
2023-06-26T12:31:18.806Z,1687782678.806 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0000.lzma.bak
2023-06-26T12:31:18.806Z,1687782678.806 [DataOverHttps](INFO): SBD MOMSN=18430957
2023-06-26T12:31:35.865Z,1687782695.865 [DataOverHttps](INFO): Sending 109 bytes from file Logs/20230626T002936/Express0395.lzma
2023-06-26T12:31:36.390Z,1687782696.390 [DataOverHttps](INFO): Moved sent file to Logs/20230626T002936/Express0395.lzma.bak
2023-06-26T12:31:36.390Z,1687782696.390 [DataOverHttps](INFO): SBD MOMSN=18430961
2023-06-26T12:31:47.014Z,1687782707.014 [Startup:StartupSatComms:B](INFO): Timed out from 2023-06-26T12:30:46.7Z
2023-06-26T12:31:47.014Z,1687782707.014 [Startup:StartupSatComms:B] Stopped
2023-06-26T12:31:47.014Z,1687782707.014 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-06-26T12:31:47.014Z,1687782707.014 [Startup:StartupSatComms] Stopped
2023-06-26T12:31:47.014Z,1687782707.014 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-06-26T12:31:47.015Z,1687782707.015 [Startup](INFO): Completed Startup
2023-06-26T12:31:47.015Z,1687782707.015 [MissionManager](INFO): Startup is completed.
2023-06-26T12:31:47.015Z,1687782707.015 [MissionManager](INFO): Uninitializing Mission Startup
2023-06-26T12:31:47.015Z,1687782707.015 [Startup] Stopped
2023-06-26T12:31:47.015Z,1687782707.015 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-06-26T12:31:47.015Z,1687782707.015 [Startup:A.GoToSurface] Stopped
2023-06-26T12:31:47.015Z,1687782707.015 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-26T12:31:47.418Z,1687782707.418 [MissionManager](IMPORTANT): Started mission Default
2023-06-26T12:31:47.418Z,1687782707.418 [Default] Running Loop=1
2023-06-26T12:31:47.418Z,1687782707.418 [Default](DEBUG): Aggregate::initialize Default
2023-06-26T12:31:47.418Z,1687782707.418 [Default:B.GoToSurface] Running Loop=1
2023-06-26T12:31:47.418Z,1687782707.418 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-26T12:31:47.419Z,1687782707.419 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-26T12:31:47.419Z,1687782707.419 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-26T12:31:47.419Z,1687782707.419 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-26T12:31:47.419Z,1687782707.419 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-26T12:31:47.420Z,1687782707.420 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-26T12:31:47.420Z,1687782707.420 [Default:A.Wait] Running Loop=1
2023-06-26T12:31:47.420Z,1687782707.420 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-06-26T12:31:52.105Z,1687782712.105 [DataOverHttps](INFO): Sending 867 bytes from file Logs/20230626T122707/Express0001.lzma
2023-06-26T12:31:53.105Z,1687782713.105 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0001.lzma.bak
2023-06-26T12:31:53.106Z,1687782713.106 [DataOverHttps](INFO): SBD MOMSN=18430964
2023-06-26T12:32:00.747Z,1687782720.747 [Default:A.Wait](INFO): Done Waiting.
2023-06-26T12:32:00.747Z,1687782720.747 [Default:A.Wait] Stopped
2023-06-26T12:32:00.747Z,1687782720.747 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T12:32:01.160Z,1687782721.160 [Default:CheckIn] Running Loop=1
2023-06-26T12:32:01.161Z,1687782721.161 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T12:32:01.161Z,1687782721.161 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T12:32:01.554Z,1687782721.554 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-06-26T12:32:17.697Z,1687782737.697 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T12:32:24.570Z,1687782744.570 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T12:32:39.514Z,1687782759.514 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T12:32:54.461Z,1687782774.461 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T12:33:03.881Z,1687782783.881 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T12:33:09.428Z,1687782789.428 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T12:33:10.291Z,1687782790.291 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,123309.00,A,4313.48077,N,08620.06795,W,0.039,290.62,260623,,,A*78
2023-06-26T12:33:10.295Z,1687782790.295 [NAL9602](INFO): GPS fix at 20230626T123309: (43.224680, -86.334466)
2023-06-26T12:33:10.365Z,1687782790.365 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T12:33:10.365Z,1687782790.365 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T12:33:10.743Z,1687782790.743 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-26T12:33:13.823Z,1687782793.823 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20230626T122707/Courier0004.lzma
2023-06-26T12:33:14.338Z,1687782794.338 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0004.lzma.bak
2023-06-26T12:33:14.338Z,1687782794.338 [DataOverHttps](INFO): SBD MOMSN=18430985
2023-06-26T12:33:24.354Z,1687782804.354 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T12:33:31.372Z,1687782811.372 [DataOverHttps](INFO): Sending 311 bytes from file Logs/20230626T122707/Express0005.lzma
2023-06-26T12:33:32.374Z,1687782812.374 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0005.lzma.bak
2023-06-26T12:33:32.374Z,1687782812.374 [DataOverHttps](INFO): SBD MOMSN=18430988
2023-06-26T12:33:34.071Z,1687782814.071 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T12:33:34.071Z,1687782814.071 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T12:33:34.071Z,1687782814.071 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T12:33:39.706Z,1687782819.706 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T12:33:42.541Z,1687782822.541 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T12:33:55.058Z,1687782835.058 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T12:34:10.445Z,1687782850.445 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T12:34:25.398Z,1687782865.398 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T12:34:39.942Z,1687782879.942 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2023-06-26T12:34:44.396Z,1687782884.396 [BPC1](INFO): Calculating totals. Valid battery stick count: 50. Valid reserve battery stick count: 6.
2023-06-26T12:34:44.399Z,1687782884.399 [BPC1](INFO): Received data from all battery sticks.
2023-06-26T12:37:22.785Z,1687783042.785 [Power24vConverter](INFO): Powering down.
2023-06-26T12:38:34.710Z,1687783114.710 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T12:38:34.710Z,1687783114.710 [Default:CheckIn:C.Wait] Stopped
2023-06-26T12:38:34.710Z,1687783114.710 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T12:38:34.710Z,1687783114.710 [Default:CheckIn:D] Running Loop=1
2023-06-26T12:38:35.110Z,1687783115.110 [Default:CheckIn:D] Stopped
2023-06-26T12:38:35.111Z,1687783115.111 [Default:CheckIn:E] Running Loop=1
2023-06-26T12:38:35.522Z,1687783115.522 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.794873 min 
2023-06-26T12:38:35.522Z,1687783115.522 [Default:CheckIn:E] Stopped
2023-06-26T12:38:35.522Z,1687783115.522 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T12:38:35.522Z,1687783115.522 [Default:CheckIn] Stopped
2023-06-26T12:38:35.522Z,1687783115.522 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T12:38:35.523Z,1687783115.523 [Default:CheckIn](INFO): Running loop #2
2023-06-26T12:38:35.523Z,1687783115.523 [Default:CheckIn] Running Loop=2
2023-06-26T12:38:35.523Z,1687783115.523 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T12:38:35.523Z,1687783115.523 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T12:38:37.531Z,1687783117.531 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,123837.00,A,4313.48549,N,08620.06724,W,0.603,321.39,260623,,,A*76
2023-06-26T12:38:37.533Z,1687783117.533 [NAL9602](INFO): GPS fix at 20230626T123837: (43.224758, -86.334454)
2023-06-26T12:38:37.564Z,1687783117.564 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T12:38:37.564Z,1687783117.564 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T12:38:45.319Z,1687783125.319 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20230626T122707/Courier0007.lzma
2023-06-26T12:38:46.322Z,1687783126.322 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0007.lzma.bak
2023-06-26T12:38:46.322Z,1687783126.322 [DataOverHttps](INFO): SBD MOMSN=18431002
2023-06-26T12:39:01.840Z,1687783141.840 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20230626T122707/Express0008.lzma
2023-06-26T12:39:02.842Z,1687783142.842 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0008.lzma.bak
2023-06-26T12:39:02.842Z,1687783142.842 [DataOverHttps](INFO): SBD MOMSN=18431005
2023-06-26T12:39:06.261Z,1687783146.261 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T12:39:06.261Z,1687783146.261 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T12:39:06.261Z,1687783146.261 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T12:39:08.293Z,1687783148.293 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T12:39:08.372Z,1687783148.372 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T12:41:34.604Z,1687783294.604 [CommandExec](IMPORTANT): got command burn
2023-06-26T12:41:34.604Z,1687783294.604 [CommandExec](FAULT): Incomplete syntax. Try: help burn
2023-06-26T12:41:43.132Z,1687783303.132 [CommandExec](IMPORTANT): got command ibit
2023-06-26T12:41:43.218Z,1687783303.218 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-06-26T12:41:43.218Z,1687783303.218 [IBIT](IMPORTANT): Beginning control surface checks.
2023-06-26T12:41:43.226Z,1687783303.226 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-26T12:41:46.054Z,1687783306.054 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-06-26T12:41:54.063Z,1687783314.063 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.546237
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.376153
CHAN A3 (5V): 0.142536
CHAN B0 (3.3V): 0.098055
CHAN B1 (3.15aV): 0.098864
CHAN B2 (3.15bV): 0.106193
CHAN B3 (GND): -0.002851
OPEN: 0.018446
Full Scale: +/- 1 mA
2023-06-26T12:43:34.304Z,1687783414.304 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2023-06-26T12:43:34.691Z,1687783414.691 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.413000
2023-06-26T12:43:34.692Z,1687783414.692 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-06-26T12:43:34.692Z,1687783414.692 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-06-26T12:43:35.101Z,1687783415.101 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-06-26T12:43:35.101Z,1687783415.101 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-06-26T12:43:35.101Z,1687783415.101 [IBIT](IMPORTANT): Pressure:9.586246 PSI
2023-06-26T12:43:35.102Z,1687783415.102 [IBIT](IMPORTANT): Humidity:3.693078 %
2023-06-26T12:43:35.520Z,1687783415.520 [IBIT](IMPORTANT): Vehicle Pitch:-1.381992 degrees
2023-06-26T12:43:35.521Z,1687783415.521 [IBIT](IMPORTANT): Vehicle  Roll:-5.342038 degrees
2023-06-26T12:43:35.521Z,1687783415.521 [IBIT](IMPORTANT): Vehicle  Heading:60.738235 degrees
2023-06-26T12:43:35.933Z,1687783415.933 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-06-26T12:43:35.934Z,1687783415.934 [IBIT](IMPORTANT): buoyancyNeutral: 516.055969 cc
2023-06-26T12:43:35.934Z,1687783415.934 [IBIT](IMPORTANT): massDefault: 1.750000 cm
2023-06-26T12:43:35.934Z,1687783415.934 [IBIT](IMPORTANT): stopDepth: 100.000000 m
2023-06-26T12:43:35.934Z,1687783415.934 [IBIT](IMPORTANT): abortDepth: 120.000000 m
2023-06-26T12:43:35.935Z,1687783415.935 [IBIT](IMPORTANT): IBIT FAILED
2023-06-26T12:43:39.942Z,1687783419.942 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T12:44:07.005Z,1687783447.005 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T12:44:07.005Z,1687783447.005 [Default:CheckIn:C.Wait] Stopped
2023-06-26T12:44:07.005Z,1687783447.005 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T12:44:07.006Z,1687783447.006 [Default:CheckIn:D] Running Loop=1
2023-06-26T12:44:07.418Z,1687783447.418 [Default:CheckIn:D] Stopped
2023-06-26T12:44:07.418Z,1687783447.418 [Default:CheckIn:E] Running Loop=1
2023-06-26T12:44:07.824Z,1687783447.824 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.333338 min 
2023-06-26T12:44:07.824Z,1687783447.824 [Default:CheckIn:E] Stopped
2023-06-26T12:44:07.824Z,1687783447.824 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T12:44:07.825Z,1687783447.825 [Default:CheckIn] Stopped
2023-06-26T12:44:07.825Z,1687783447.825 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T12:44:07.825Z,1687783447.825 [Default:CheckIn](INFO): Running loop #3
2023-06-26T12:44:07.825Z,1687783447.825 [Default:CheckIn] Running Loop=3
2023-06-26T12:44:07.825Z,1687783447.825 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T12:44:07.825Z,1687783447.825 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T12:44:09.831Z,1687783449.831 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124409.00,A,4313.47989,N,08620.06416,W,0.758,59.19,260623,,,A*4C
2023-06-26T12:44:09.841Z,1687783449.841 [NAL9602](INFO): GPS fix at 20230626T124409: (43.224665, -86.334403)
2023-06-26T12:44:09.852Z,1687783449.852 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T12:44:09.852Z,1687783449.852 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T12:44:17.383Z,1687783457.383 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T122707/Courier0010.lzma
2023-06-26T12:44:18.387Z,1687783458.387 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0010.lzma.bak
2023-06-26T12:44:18.387Z,1687783458.387 [DataOverHttps](IMPORTANT): SBD MOMSN=18431009, MTMSN=20230626T124418
2023-06-26T12:44:25.676Z,1687783465.676 [DataOverHttps](INFO): Received command: sched 20230625T1615 "configSet NAL9602.iridiumMTQueueTimeout 1 minute persist"
2023-06-26T12:44:25.691Z,1687783465.691 [CommandExec](IMPORTANT): got command schedule 20230625T161500 "configSet NAL9602.iridiumMTQueueTimeout 1 minute persist"
2023-06-26T12:44:25.702Z,1687783465.702 [CommandExec](IMPORTANT): Scheduled #1: "configSet NAL9602.iridiumMTQueueTimeout 1 minute persist", AT TIME: 2023-06-25T16:15:00Z
2023-06-26T12:44:26.127Z,1687783466.127 [CommandExec](IMPORTANT): got command configSet NAL9602.iridiumMTQueueTimeout 1 minute persist
2023-06-26T12:44:33.956Z,1687783473.956 [DataOverHttps](INFO): Sending 864 bytes from file Logs/20230626T122707/Express0011.lzma
2023-06-26T12:44:34.958Z,1687783474.958 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0011.lzma.bak
2023-06-26T12:44:34.958Z,1687783474.958 [DataOverHttps](INFO): SBD MOMSN=18431013
2023-06-26T12:44:41.749Z,1687783481.749 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T12:44:50.889Z,1687783490.889 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230626T122707/Courier0013.lzma
2023-06-26T12:44:51.646Z,1687783491.646 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0013.lzma.bak
2023-06-26T12:44:51.646Z,1687783491.646 [DataOverHttps](INFO): SBD MOMSN=18431041
2023-06-26T12:45:13.420Z,1687783513.420 [DataOverHttps](INFO): Sending 286 bytes from file Logs/20230626T122707/Express0014.lzma
2023-06-26T12:45:14.422Z,1687783514.422 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0014.lzma.bak
2023-06-26T12:45:14.422Z,1687783514.422 [DataOverHttps](INFO): SBD MOMSN=18431043
2023-06-26T12:45:16.238Z,1687783516.238 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T12:45:16.238Z,1687783516.238 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T12:45:16.238Z,1687783516.238 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T12:45:22.777Z,1687783522.777 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T124522
2023-06-26T12:45:30.323Z,1687783530.323 [DataOverHttps](INFO): Received command: configSet NAL9602.iridiumMTQueueTimeout 1 minute persist
2023-06-26T12:45:30.687Z,1687783530.687 [CommandExec](IMPORTANT): got command configSet NAL9602.iridiumMTQueueTimeout 1 minute persist
2023-06-26T12:46:06.781Z,1687783566.781 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T124606
2023-06-26T12:46:14.067Z,1687783574.067 [DataOverHttps](INFO): Received command: schedule clear;schedule resume
2023-06-26T12:46:14.143Z,1687783574.143 [CommandExec](IMPORTANT): got command schedule clear
2023-06-26T12:46:14.143Z,1687783574.143 [CommandExec](IMPORTANT): Cleared 0 scheduled commands.
2023-06-26T12:46:14.143Z,1687783574.143 [CommandExec](IMPORTANT): got command schedule resume
2023-06-26T12:50:16.858Z,1687783816.858 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T12:50:16.858Z,1687783816.858 [Default:CheckIn:C.Wait] Stopped
2023-06-26T12:50:16.858Z,1687783816.858 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T12:50:16.858Z,1687783816.858 [Default:CheckIn:D] Running Loop=1
2023-06-26T12:50:17.254Z,1687783817.254 [Default:CheckIn:D] Stopped
2023-06-26T12:50:17.254Z,1687783817.254 [Default:CheckIn:E] Running Loop=1
2023-06-26T12:50:17.713Z,1687783817.713 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.497260 min 
2023-06-26T12:50:17.713Z,1687783817.713 [Default:CheckIn:E] Stopped
2023-06-26T12:50:17.716Z,1687783817.716 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T12:50:17.716Z,1687783817.716 [Default:CheckIn] Stopped
2023-06-26T12:50:17.717Z,1687783817.717 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T12:50:17.719Z,1687783817.719 [Default:CheckIn](INFO): Running loop #4
2023-06-26T12:50:17.719Z,1687783817.719 [Default:CheckIn] Running Loop=4
2023-06-26T12:50:17.732Z,1687783817.732 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T12:50:17.732Z,1687783817.732 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T12:50:19.675Z,1687783819.675 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,125019.00,A,4313.47960,N,08620.06170,W,0.019,150.02,260623,,,A*7A
2023-06-26T12:50:19.677Z,1687783819.677 [NAL9602](INFO): GPS fix at 20230626T125019: (43.224660, -86.334362)
2023-06-26T12:50:19.695Z,1687783819.695 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T12:50:19.695Z,1687783819.695 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T12:50:21.451Z,1687783821.451 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T122707/Courier0016.lzma
2023-06-26T12:50:21.905Z,1687783821.905 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0016.lzma.bak
2023-06-26T12:50:21.906Z,1687783821.906 [DataOverHttps](INFO): SBD MOMSN=18431053
2023-06-26T12:50:37.612Z,1687783837.612 [DataOverHttps](INFO): Sending 280 bytes from file Logs/20230626T122707/Express0017.lzma
2023-06-26T12:50:38.614Z,1687783838.614 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0017.lzma.bak
2023-06-26T12:50:38.614Z,1687783838.614 [DataOverHttps](INFO): SBD MOMSN=18431056
2023-06-26T12:50:50.433Z,1687783850.433 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T12:50:50.512Z,1687783850.512 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T12:50:54.363Z,1687783854.363 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230626T122707/Express0020.lzma
2023-06-26T12:50:58.378Z,1687783858.378 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0020.lzma.bak
2023-06-26T12:50:58.378Z,1687783858.378 [DataOverHttps](INFO): SBD MOMSN=18431065
2023-06-26T12:51:00.605Z,1687783860.605 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T12:51:00.605Z,1687783860.605 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T12:51:00.605Z,1687783860.605 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T12:51:21.669Z,1687783881.669 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T12:51:52.373Z,1687783912.373 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T12:56:01.291Z,1687784161.291 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T12:56:01.291Z,1687784161.291 [Default:CheckIn:C.Wait] Stopped
2023-06-26T12:56:01.291Z,1687784161.291 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T12:56:01.291Z,1687784161.291 [Default:CheckIn:D] Running Loop=1
2023-06-26T12:56:01.685Z,1687784161.685 [Default:CheckIn:D] Stopped
2023-06-26T12:56:01.685Z,1687784161.685 [Default:CheckIn:E] Running Loop=1
2023-06-26T12:56:02.094Z,1687784162.094 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.237789 min 
2023-06-26T12:56:02.095Z,1687784162.095 [Default:CheckIn:E] Stopped
2023-06-26T12:56:02.095Z,1687784162.095 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T12:56:02.095Z,1687784162.095 [Default:CheckIn] Stopped
2023-06-26T12:56:02.095Z,1687784162.095 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T12:56:02.095Z,1687784162.095 [Default:CheckIn](INFO): Running loop #5
2023-06-26T12:56:02.095Z,1687784162.095 [Default:CheckIn] Running Loop=5
2023-06-26T12:56:02.095Z,1687784162.095 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T12:56:02.095Z,1687784162.095 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T12:56:04.107Z,1687784164.107 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,125604.00,A,4313.47980,N,08620.06066,W,0.583,178.70,260623,,,A*71
2023-06-26T12:56:04.110Z,1687784164.110 [NAL9602](INFO): GPS fix at 20230626T125604: (43.224663, -86.334344)
2023-06-26T12:56:04.121Z,1687784164.121 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T12:56:04.121Z,1687784164.121 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T12:56:11.115Z,1687784171.115 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230626T122707/Courier0022.lzma
2023-06-26T12:56:12.118Z,1687784172.118 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0022.lzma.bak
2023-06-26T12:56:12.118Z,1687784172.118 [DataOverHttps](INFO): SBD MOMSN=18431067
2023-06-26T12:56:27.684Z,1687784187.684 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230626T122707/Express0023.lzma
2023-06-26T12:56:28.686Z,1687784188.686 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0023.lzma.bak
2023-06-26T12:56:28.686Z,1687784188.686 [DataOverHttps](INFO): SBD MOMSN=18431070
2023-06-26T12:56:30.376Z,1687784190.376 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T12:56:30.376Z,1687784190.376 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T12:56:30.376Z,1687784190.376 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T12:56:34.806Z,1687784194.806 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T12:56:34.884Z,1687784194.884 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T12:57:06.721Z,1687784226.721 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T12:57:37.452Z,1687784257.452 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T13:01:31.091Z,1687784491.091 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T13:01:31.091Z,1687784491.091 [Default:CheckIn:C.Wait] Stopped
2023-06-26T13:01:31.091Z,1687784491.091 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T13:01:31.091Z,1687784491.091 [Default:CheckIn:D] Running Loop=1
2023-06-26T13:01:31.495Z,1687784491.495 [Default:CheckIn:D] Stopped
2023-06-26T13:01:31.495Z,1687784491.495 [Default:CheckIn:E] Running Loop=1
2023-06-26T13:01:31.894Z,1687784491.894 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.734609 min 
2023-06-26T13:01:31.895Z,1687784491.895 [Default:CheckIn:E] Stopped
2023-06-26T13:01:31.895Z,1687784491.895 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T13:01:31.895Z,1687784491.895 [Default:CheckIn] Stopped
2023-06-26T13:01:31.895Z,1687784491.895 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T13:01:31.895Z,1687784491.895 [Default:CheckIn](INFO): Running loop #6
2023-06-26T13:01:31.895Z,1687784491.895 [Default:CheckIn] Running Loop=6
2023-06-26T13:01:31.895Z,1687784491.895 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T13:01:31.895Z,1687784491.895 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T13:01:33.902Z,1687784493.902 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,130133.00,A,4313.48279,N,08620.06944,W,0.136,178.70,260623,,,A*77
2023-06-26T13:01:33.905Z,1687784493.905 [NAL9602](INFO): GPS fix at 20230626T130133: (43.224713, -86.334491)
2023-06-26T13:01:33.915Z,1687784493.915 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T13:01:33.915Z,1687784493.915 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T13:01:41.523Z,1687784501.523 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T122707/Courier0025.lzma
2023-06-26T13:01:42.526Z,1687784502.526 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0025.lzma.bak
2023-06-26T13:01:42.526Z,1687784502.526 [DataOverHttps](INFO): SBD MOMSN=18431074
2023-06-26T13:01:58.095Z,1687784518.095 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230626T122707/Express0026.lzma
2023-06-26T13:01:59.098Z,1687784519.098 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0026.lzma.bak
2023-06-26T13:01:59.098Z,1687784519.098 [DataOverHttps](INFO): SBD MOMSN=18431077
2023-06-26T13:02:00.987Z,1687784520.987 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T13:02:00.987Z,1687784520.987 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T13:02:00.987Z,1687784520.987 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T13:02:35.717Z,1687784555.717 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T13:03:06.473Z,1687784586.473 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T13:07:01.698Z,1687784821.698 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T13:07:01.699Z,1687784821.699 [Default:CheckIn:C.Wait] Stopped
2023-06-26T13:07:01.699Z,1687784821.699 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T13:07:01.699Z,1687784821.699 [Default:CheckIn:D] Running Loop=1
2023-06-26T13:07:02.109Z,1687784822.109 [Default:CheckIn:D] Stopped
2023-06-26T13:07:02.109Z,1687784822.109 [Default:CheckIn:E] Running Loop=1
2023-06-26T13:07:02.494Z,1687784822.494 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.244849 min 
2023-06-26T13:07:02.494Z,1687784822.494 [Default:CheckIn:E] Stopped
2023-06-26T13:07:02.494Z,1687784822.494 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T13:07:02.494Z,1687784822.494 [Default:CheckIn] Stopped
2023-06-26T13:07:02.494Z,1687784822.494 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T13:07:02.495Z,1687784822.495 [Default:CheckIn](INFO): Running loop #7
2023-06-26T13:07:02.495Z,1687784822.495 [Default:CheckIn] Running Loop=7
2023-06-26T13:07:02.495Z,1687784822.495 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T13:07:02.495Z,1687784822.495 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T13:07:04.513Z,1687784824.513 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,130704.00,A,4313.47878,N,08620.06905,W,0.467,172.99,260623,,,D*7D
2023-06-26T13:07:04.515Z,1687784824.515 [NAL9602](INFO): GPS fix at 20230626T130704: (43.224646, -86.334484)
2023-06-26T13:07:04.525Z,1687784824.525 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T13:07:04.525Z,1687784824.525 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T13:07:14.195Z,1687784834.195 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230626T122707/Courier0028.lzma
2023-06-26T13:07:15.198Z,1687784835.198 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0028.lzma.bak
2023-06-26T13:07:15.198Z,1687784835.198 [DataOverHttps](INFO): SBD MOMSN=18431084
2023-06-26T13:07:30.880Z,1687784850.880 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230626T122707/Express0029.lzma
2023-06-26T13:07:31.882Z,1687784851.882 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0029.lzma.bak
2023-06-26T13:07:31.882Z,1687784851.882 [DataOverHttps](INFO): SBD MOMSN=18431087
2023-06-26T13:07:33.830Z,1687784853.830 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T13:07:33.830Z,1687784853.830 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T13:07:33.830Z,1687784853.830 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T13:07:35.029Z,1687784855.029 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T13:07:35.104Z,1687784855.104 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T13:08:06.543Z,1687784886.543 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T13:08:37.242Z,1687784917.242 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T13:12:34.498Z,1687785154.498 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T13:12:34.498Z,1687785154.498 [Default:CheckIn:C.Wait] Stopped
2023-06-26T13:12:34.498Z,1687785154.498 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T13:12:34.498Z,1687785154.498 [Default:CheckIn:D] Running Loop=1
2023-06-26T13:12:34.896Z,1687785154.896 [Default:CheckIn:D] Stopped
2023-06-26T13:12:34.896Z,1687785154.896 [Default:CheckIn:E] Running Loop=1
2023-06-26T13:12:35.299Z,1687785155.299 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.791292 min 
2023-06-26T13:12:35.299Z,1687785155.299 [Default:CheckIn:E] Stopped
2023-06-26T13:12:35.299Z,1687785155.299 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T13:12:35.299Z,1687785155.299 [Default:CheckIn] Stopped
2023-06-26T13:12:35.299Z,1687785155.299 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T13:12:35.299Z,1687785155.299 [Default:CheckIn](INFO): Running loop #8
2023-06-26T13:12:35.299Z,1687785155.299 [Default:CheckIn] Running Loop=8
2023-06-26T13:12:35.299Z,1687785155.299 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T13:12:35.300Z,1687785155.300 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T13:12:37.315Z,1687785157.315 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,131237.00,A,4313.48008,N,08620.06693,W,0.019,172.99,260623,,,D*74
2023-06-26T13:12:37.318Z,1687785157.318 [NAL9602](INFO): GPS fix at 20230626T131237: (43.224668, -86.334449)
2023-06-26T13:12:37.327Z,1687785157.327 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T13:12:37.327Z,1687785157.327 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T13:12:48.267Z,1687785168.267 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T122707/Courier0031.lzma
2023-06-26T13:12:49.270Z,1687785169.270 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0031.lzma.bak
2023-06-26T13:12:49.270Z,1687785169.270 [DataOverHttps](INFO): SBD MOMSN=18431096
2023-06-26T13:13:06.493Z,1687785186.493 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230626T122707/Express0032.lzma
2023-06-26T13:13:07.494Z,1687785187.494 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0032.lzma.bak
2023-06-26T13:13:07.494Z,1687785187.494 [DataOverHttps](INFO): SBD MOMSN=18431101
2023-06-26T13:13:08.080Z,1687785188.080 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T13:13:08.160Z,1687785188.160 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T13:13:09.751Z,1687785189.751 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T13:13:09.751Z,1687785189.751 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T13:13:09.751Z,1687785189.751 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T13:13:39.611Z,1687785219.611 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T13:14:10.308Z,1687785250.308 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T13:18:10.321Z,1687785490.321 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T13:18:10.322Z,1687785490.322 [Default:CheckIn:C.Wait] Stopped
2023-06-26T13:18:10.322Z,1687785490.322 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T13:18:10.322Z,1687785490.322 [Default:CheckIn:D] Running Loop=1
2023-06-26T13:18:10.730Z,1687785490.730 [Default:CheckIn:D] Stopped
2023-06-26T13:18:10.730Z,1687785490.730 [Default:CheckIn:E] Running Loop=1
2023-06-26T13:18:11.137Z,1687785491.137 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.388538 min 
2023-06-26T13:18:11.137Z,1687785491.137 [Default:CheckIn:E] Stopped
2023-06-26T13:18:11.137Z,1687785491.137 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T13:18:11.138Z,1687785491.138 [Default:CheckIn] Stopped
2023-06-26T13:18:11.138Z,1687785491.138 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T13:18:11.138Z,1687785491.138 [Default:CheckIn](INFO): Running loop #9
2023-06-26T13:18:11.138Z,1687785491.138 [Default:CheckIn] Running Loop=9
2023-06-26T13:18:11.138Z,1687785491.138 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T13:18:11.138Z,1687785491.138 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T13:18:13.141Z,1687785493.141 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,131813.00,A,4313.48031,N,08620.06784,W,0.039,172.99,260623,,,D*77
2023-06-26T13:18:13.144Z,1687785493.144 [NAL9602](INFO): GPS fix at 20230626T131813: (43.224672, -86.334464)
2023-06-26T13:18:13.153Z,1687785493.153 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T13:18:13.153Z,1687785493.153 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T13:18:20.391Z,1687785500.391 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T122707/Courier0034.lzma
2023-06-26T13:18:21.394Z,1687785501.394 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0034.lzma.bak
2023-06-26T13:18:21.394Z,1687785501.394 [DataOverHttps](INFO): SBD MOMSN=18431124
2023-06-26T13:18:41.156Z,1687785521.156 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230626T122707/Express0035.lzma
2023-06-26T13:18:42.158Z,1687785522.158 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0035.lzma.bak
2023-06-26T13:18:42.158Z,1687785522.158 [DataOverHttps](INFO): SBD MOMSN=18431128
2023-06-26T13:18:43.914Z,1687785523.914 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T13:18:43.996Z,1687785523.996 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T13:18:44.348Z,1687785524.348 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T13:18:44.348Z,1687785524.348 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T13:18:44.349Z,1687785524.349 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T13:19:15.845Z,1687785555.845 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T13:19:46.549Z,1687785586.549 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T13:23:44.977Z,1687785824.977 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T13:23:44.977Z,1687785824.977 [Default:CheckIn:C.Wait] Stopped
2023-06-26T13:23:44.977Z,1687785824.977 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T13:23:44.978Z,1687785824.978 [Default:CheckIn:D] Running Loop=1
2023-06-26T13:23:45.371Z,1687785825.371 [Default:CheckIn:D] Stopped
2023-06-26T13:23:45.371Z,1687785825.371 [Default:CheckIn:E] Running Loop=1
2023-06-26T13:23:45.779Z,1687785825.779 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.965873 min 
2023-06-26T13:23:45.779Z,1687785825.779 [Default:CheckIn:E] Stopped
2023-06-26T13:23:45.779Z,1687785825.779 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T13:23:45.779Z,1687785825.779 [Default:CheckIn] Stopped
2023-06-26T13:23:45.779Z,1687785825.779 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T13:23:45.779Z,1687785825.779 [Default:CheckIn](INFO): Running loop #10
2023-06-26T13:23:45.780Z,1687785825.780 [Default:CheckIn] Running Loop=10
2023-06-26T13:23:45.780Z,1687785825.780 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T13:23:45.780Z,1687785825.780 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T13:23:47.791Z,1687785827.791 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132347.00,A,4313.48014,N,08620.07056,W,0.078,172.99,260623,,,D*75
2023-06-26T13:23:47.793Z,1687785827.793 [NAL9602](INFO): GPS fix at 20230626T132347: (43.224669, -86.334509)
2023-06-26T13:23:47.803Z,1687785827.803 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T13:23:47.803Z,1687785827.803 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T13:23:55.384Z,1687785835.384 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T122707/Courier0037.lzma
2023-06-26T13:23:56.386Z,1687785836.386 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0037.lzma.bak
2023-06-26T13:23:56.386Z,1687785836.386 [DataOverHttps](INFO): SBD MOMSN=18431139
2023-06-26T13:24:12.143Z,1687785852.143 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230626T122707/Express0038.lzma
2023-06-26T13:24:13.146Z,1687785853.146 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0038.lzma.bak
2023-06-26T13:24:13.146Z,1687785853.146 [DataOverHttps](INFO): SBD MOMSN=18431142
2023-06-26T13:24:14.877Z,1687785854.877 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T13:24:14.877Z,1687785854.877 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T13:24:14.877Z,1687785854.877 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T13:24:49.604Z,1687785889.604 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T13:25:20.352Z,1687785920.352 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T13:26:07.304Z,1687785967.304 [CommandExec](IMPORTANT): got command ibit
2023-06-26T13:26:07.602Z,1687785967.602 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-06-26T13:26:07.602Z,1687785967.602 [IBIT](IMPORTANT): Beginning control surface checks.
2023-06-26T13:26:07.606Z,1687785967.606 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-26T13:26:09.186Z,1687785969.186 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132609.00,A,4313.47959,N,08620.06939,W,0.058,172.99,260623,,,D*76
2023-06-26T13:26:09.188Z,1687785969.188 [NAL9602](INFO): GPS fix at 20230626T132609: (43.224660, -86.334490)
2023-06-26T13:26:10.485Z,1687785970.485 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-06-26T13:26:18.498Z,1687785978.498 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.684044
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.452863
CHAN A3 (5V): 0.176821
CHAN B0 (3.3V): 0.118496
CHAN B1 (3.15aV): 0.124038
CHAN B2 (3.15bV): 0.132390
CHAN B3 (GND): -0.002236
OPEN: 0.018239
Full Scale: +/- 1 mA
2023-06-26T13:26:39.889Z,1687785999.889 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T13:26:39.968Z,1687785999.968 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T13:27:11.804Z,1687786031.804 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T13:27:13.020Z,1687786033.020 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132713.00,A,4313.47965,N,08620.06899,W,0.214,0.00,260623,,,D*76
2023-06-26T13:27:13.022Z,1687786033.022 [NAL9602](INFO): GPS fix at 20230626T132713: (43.224661, -86.334483)
2023-06-26T13:27:16.251Z,1687786036.251 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132716.00,A,4313.47970,N,08620.06878,W,0.233,0.00,260623,,,D*7D
2023-06-26T13:27:16.253Z,1687786036.253 [NAL9602](INFO): GPS fix at 20230626T132716: (43.224662, -86.334480)
2023-06-26T13:27:19.083Z,1687786039.083 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132719.00,A,4313.47965,N,08620.06860,W,0.136,0.00,260623,,,D*79
2023-06-26T13:27:19.085Z,1687786039.085 [NAL9602](INFO): GPS fix at 20230626T132719: (43.224661, -86.334477)
2023-06-26T13:27:22.314Z,1687786042.314 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132722.00,A,4313.47962,N,08620.06861,W,0.136,0.00,260623,,,D*77
2023-06-26T13:27:22.316Z,1687786042.316 [NAL9602](INFO): GPS fix at 20230626T132722: (43.224660, -86.334477)
2023-06-26T13:27:25.144Z,1687786045.144 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132725.00,A,4313.47963,N,08620.06845,W,0.233,0.00,260623,,,D*71
2023-06-26T13:27:25.146Z,1687786045.146 [NAL9602](INFO): GPS fix at 20230626T132725: (43.224660, -86.334474)
2023-06-26T13:27:28.375Z,1687786048.375 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132728.00,A,4313.47958,N,08620.06837,W,0.097,0.00,260623,,,D*7D
2023-06-26T13:27:28.377Z,1687786048.377 [NAL9602](INFO): GPS fix at 20230626T132728: (43.224660, -86.334473)
2023-06-26T13:27:31.199Z,1687786051.199 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132731.00,A,4313.47968,N,08620.06828,W,0.175,0.00,260623,,,D*75
2023-06-26T13:27:31.201Z,1687786051.201 [NAL9602](INFO): GPS fix at 20230626T132731: (43.224661, -86.334471)
2023-06-26T13:27:34.435Z,1687786054.435 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132734.00,A,4313.47977,N,08620.06804,W,0.194,0.00,260623,,,D*7F
2023-06-26T13:27:34.437Z,1687786054.437 [NAL9602](INFO): GPS fix at 20230626T132734: (43.224663, -86.334467)
2023-06-26T13:27:37.259Z,1687786057.259 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132737.00,A,4313.47983,N,08620.06786,W,0.097,0.00,260623,,,D*70
2023-06-26T13:27:37.261Z,1687786057.261 [NAL9602](INFO): GPS fix at 20230626T132737: (43.224664, -86.334464)
2023-06-26T13:27:40.096Z,1687786060.096 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132740.00,A,4313.47977,N,08620.06788,W,0.039,0.00,260623,,,D*71
2023-06-26T13:27:40.098Z,1687786060.098 [NAL9602](INFO): GPS fix at 20230626T132740: (43.224663, -86.334465)
2023-06-26T13:27:43.328Z,1687786063.328 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132743.00,A,4313.47956,N,08620.06792,W,0.039,0.00,260623,,,D*7A
2023-06-26T13:27:43.330Z,1687786063.330 [NAL9602](INFO): GPS fix at 20230626T132743: (43.224659, -86.334465)
2023-06-26T13:27:46.151Z,1687786066.151 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132746.00,A,4313.47943,N,08620.06801,W,0.078,0.00,260623,,,D*7B
2023-06-26T13:27:46.153Z,1687786066.153 [NAL9602](INFO): GPS fix at 20230626T132746: (43.224657, -86.334467)
2023-06-26T13:27:49.385Z,1687786069.385 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132749.00,A,4313.47937,N,08620.06819,W,0.097,0.00,260623,,,D*7F
2023-06-26T13:27:49.390Z,1687786069.390 [NAL9602](INFO): GPS fix at 20230626T132749: (43.224656, -86.334470)
2023-06-26T13:27:52.207Z,1687786072.207 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132752.00,A,4313.47930,N,08620.06836,W,0.078,0.00,260623,,,D*7E
2023-06-26T13:27:52.217Z,1687786072.217 [NAL9602](INFO): GPS fix at 20230626T132752: (43.224655, -86.334473)
2023-06-26T13:27:55.447Z,1687786075.447 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132755.00,A,4313.47930,N,08620.06839,W,0.097,0.00,260623,,,D*77
2023-06-26T13:27:55.449Z,1687786075.449 [NAL9602](INFO): GPS fix at 20230626T132755: (43.224655, -86.334473)
2023-06-26T13:27:58.266Z,1687786078.266 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132758.00,A,4313.47925,N,08620.06837,W,0.058,0.00,260623,,,D*73
2023-06-26T13:27:58.268Z,1687786078.268 [NAL9602](INFO): GPS fix at 20230626T132758: (43.224654, -86.334473)
2023-06-26T13:27:58.702Z,1687786078.702 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2023-06-26T13:27:59.103Z,1687786079.103 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.372999
2023-06-26T13:27:59.103Z,1687786079.103 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-06-26T13:27:59.108Z,1687786079.108 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-06-26T13:27:59.497Z,1687786079.497 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-06-26T13:27:59.498Z,1687786079.498 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-06-26T13:27:59.498Z,1687786079.498 [IBIT](IMPORTANT): Pressure:9.532964 PSI
2023-06-26T13:27:59.498Z,1687786079.498 [IBIT](IMPORTANT): Humidity:3.644244 %
2023-06-26T13:27:59.907Z,1687786079.907 [IBIT](IMPORTANT): Vehicle Pitch:-1.166871 degrees
2023-06-26T13:27:59.907Z,1687786079.907 [IBIT](IMPORTANT): Vehicle  Roll:-3.392196 degrees
2023-06-26T13:27:59.907Z,1687786079.907 [IBIT](IMPORTANT): Vehicle  Heading:122.937340 degrees
2023-06-26T13:28:00.307Z,1687786080.307 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-06-26T13:28:00.307Z,1687786080.307 [IBIT](IMPORTANT): buoyancyNeutral: 516.055969 cc
2023-06-26T13:28:00.307Z,1687786080.307 [IBIT](IMPORTANT): massDefault: 1.750000 cm
2023-06-26T13:28:00.312Z,1687786080.312 [IBIT](IMPORTANT): stopDepth: 100.000000 m
2023-06-26T13:28:00.312Z,1687786080.312 [IBIT](IMPORTANT): abortDepth: 120.000000 m
2023-06-26T13:28:00.312Z,1687786080.312 [IBIT](IMPORTANT): IBIT FAILED
2023-06-26T13:28:01.095Z,1687786081.095 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132801.00,A,4313.47925,N,08620.06838,W,0.136,0.00,260623,,,D*76
2023-06-26T13:28:01.097Z,1687786081.097 [NAL9602](INFO): GPS fix at 20230626T132801: (43.224654, -86.334473)
2023-06-26T13:28:33.849Z,1687786113.849 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T13:29:15.478Z,1687786155.478 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T13:29:15.479Z,1687786155.479 [Default:CheckIn:C.Wait] Stopped
2023-06-26T13:29:15.479Z,1687786155.479 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T13:29:15.479Z,1687786155.479 [Default:CheckIn:D] Running Loop=1
2023-06-26T13:29:15.878Z,1687786155.878 [Default:CheckIn:D] Stopped
2023-06-26T13:29:15.878Z,1687786155.878 [Default:CheckIn:E] Running Loop=1
2023-06-26T13:29:16.287Z,1687786156.287 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.474325 min 
2023-06-26T13:29:16.287Z,1687786156.287 [Default:CheckIn:E] Stopped
2023-06-26T13:29:16.287Z,1687786156.287 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T13:29:16.287Z,1687786156.287 [Default:CheckIn] Stopped
2023-06-26T13:29:16.287Z,1687786156.287 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T13:29:16.287Z,1687786156.287 [Default:CheckIn](INFO): Running loop #11
2023-06-26T13:29:16.287Z,1687786156.287 [Default:CheckIn] Running Loop=11
2023-06-26T13:29:16.287Z,1687786156.287 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T13:29:16.287Z,1687786156.287 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T13:29:18.299Z,1687786158.299 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132918.00,A,4313.47997,N,08620.06843,W,0.039,0.00,260623,,,D*74
2023-06-26T13:29:18.310Z,1687786158.310 [NAL9602](INFO): GPS fix at 20230626T132918: (43.224666, -86.334474)
2023-06-26T13:29:18.320Z,1687786158.320 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T13:29:18.320Z,1687786158.320 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T13:29:25.435Z,1687786165.435 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T122707/Courier0040.lzma
2023-06-26T13:29:26.438Z,1687786166.438 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0040.lzma.bak
2023-06-26T13:29:26.438Z,1687786166.438 [DataOverHttps](INFO): SBD MOMSN=18431153
2023-06-26T13:29:42.948Z,1687786182.948 [DataOverHttps](INFO): Sending 806 bytes from file Logs/20230626T122707/Express0041.lzma
2023-06-26T13:29:43.950Z,1687786183.950 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0041.lzma.bak
2023-06-26T13:29:43.950Z,1687786183.950 [DataOverHttps](INFO): SBD MOMSN=18431157
2023-06-26T13:29:45.783Z,1687786185.783 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T13:29:45.783Z,1687786185.783 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T13:29:45.783Z,1687786185.783 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T13:30:20.537Z,1687786220.537 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T13:30:51.243Z,1687786251.243 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T13:34:46.523Z,1687786486.523 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T13:34:46.523Z,1687786486.523 [Default:CheckIn:C.Wait] Stopped
2023-06-26T13:34:46.523Z,1687786486.523 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T13:34:46.523Z,1687786486.523 [Default:CheckIn:D] Running Loop=1
2023-06-26T13:34:46.926Z,1687786486.926 [Default:CheckIn:D] Stopped
2023-06-26T13:34:46.926Z,1687786486.926 [Default:CheckIn:E] Running Loop=1
2023-06-26T13:34:47.331Z,1687786487.331 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.991797 min 
2023-06-26T13:34:47.331Z,1687786487.331 [Default:CheckIn:E] Stopped
2023-06-26T13:34:47.331Z,1687786487.331 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T13:34:47.331Z,1687786487.331 [Default:CheckIn] Stopped
2023-06-26T13:34:47.331Z,1687786487.331 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T13:34:47.331Z,1687786487.331 [Default:CheckIn](INFO): Running loop #12
2023-06-26T13:34:47.332Z,1687786487.332 [Default:CheckIn] Running Loop=12
2023-06-26T13:34:47.332Z,1687786487.332 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T13:34:47.332Z,1687786487.332 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T13:34:49.343Z,1687786489.343 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,133449.00,A,4313.48021,N,08620.07121,W,0.175,0.00,260623,,,D*72
2023-06-26T13:34:49.353Z,1687786489.353 [NAL9602](INFO): GPS fix at 20230626T133449: (43.224670, -86.334520)
2023-06-26T13:34:49.362Z,1687786489.362 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T13:34:49.363Z,1687786489.363 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T13:34:56.328Z,1687786496.328 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230626T122707/Courier0043.lzma
2023-06-26T13:34:57.330Z,1687786497.330 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0043.lzma.bak
2023-06-26T13:34:57.330Z,1687786497.330 [DataOverHttps](INFO): SBD MOMSN=18431193
2023-06-26T13:35:12.919Z,1687786512.919 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230626T122707/Express0044.lzma
2023-06-26T13:35:13.922Z,1687786513.922 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0044.lzma.bak
2023-06-26T13:35:13.922Z,1687786513.922 [DataOverHttps](INFO): SBD MOMSN=18431196
2023-06-26T13:35:15.624Z,1687786515.624 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T13:35:15.624Z,1687786515.624 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T13:35:15.624Z,1687786515.624 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T13:35:20.041Z,1687786520.041 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T13:35:20.120Z,1687786520.120 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T13:35:51.569Z,1687786551.569 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T13:36:22.256Z,1687786582.256 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T13:39:39.916Z,1687786779.916 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-06-26T13:39:46.723Z,1687786786.723 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T13:40:02.075Z,1687786802.075 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T13:40:16.230Z,1687786816.230 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T13:40:16.230Z,1687786816.230 [Default:CheckIn:C.Wait] Stopped
2023-06-26T13:40:16.230Z,1687786816.230 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T13:40:16.230Z,1687786816.230 [Default:CheckIn:D] Running Loop=1
2023-06-26T13:40:16.678Z,1687786816.678 [Default:CheckIn:D] Stopped
2023-06-26T13:40:16.678Z,1687786816.678 [Default:CheckIn:E] Running Loop=1
2023-06-26T13:40:17.023Z,1687786817.023 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T13:40:17.043Z,1687786817.043 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.487671 min 
2023-06-26T13:40:17.043Z,1687786817.043 [Default:CheckIn:E] Stopped
2023-06-26T13:40:17.043Z,1687786817.043 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T13:40:17.043Z,1687786817.043 [Default:CheckIn] Stopped
2023-06-26T13:40:17.044Z,1687786817.044 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T13:40:17.044Z,1687786817.044 [Default:CheckIn](INFO): Running loop #13
2023-06-26T13:40:17.044Z,1687786817.044 [Default:CheckIn] Running Loop=13
2023-06-26T13:40:17.044Z,1687786817.044 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T13:40:17.044Z,1687786817.044 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T13:40:19.046Z,1687786819.046 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,134019.00,A,4313.47820,N,08620.06657,W,0.097,346.56,260623,,,D*7A
2023-06-26T13:40:19.058Z,1687786819.058 [NAL9602](INFO): GPS fix at 20230626T134019: (43.224637, -86.334443)
2023-06-26T13:40:19.068Z,1687786819.068 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T13:40:19.068Z,1687786819.068 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T13:40:25.947Z,1687786825.947 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T122707/Courier0046.lzma
2023-06-26T13:40:26.950Z,1687786826.950 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0046.lzma.bak
2023-06-26T13:40:26.950Z,1687786826.950 [DataOverHttps](INFO): SBD MOMSN=18431204
2023-06-26T13:40:32.380Z,1687786832.380 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T13:40:46.435Z,1687786846.435 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230626T122707/Express0047.lzma
2023-06-26T13:40:47.438Z,1687786847.438 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0047.lzma.bak
2023-06-26T13:40:47.438Z,1687786847.438 [DataOverHttps](INFO): SBD MOMSN=18431207
2023-06-26T13:40:48.570Z,1687786848.570 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T13:40:49.410Z,1687786849.410 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T13:40:49.410Z,1687786849.410 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T13:40:49.411Z,1687786849.411 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T13:40:49.785Z,1687786849.785 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T13:40:49.864Z,1687786849.864 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T13:41:03.519Z,1687786863.519 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T13:41:18.065Z,1687786878.065 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T13:41:21.716Z,1687786881.716 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T13:41:33.414Z,1687786893.414 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T13:41:48.767Z,1687786908.767 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-26T13:41:52.409Z,1687786912.409 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T13:42:04.121Z,1687786924.121 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2023-06-26T13:42:10.592Z,1687786930.592 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6.
2023-06-26T13:42:10.594Z,1687786930.594 [BPC1](INFO): Received data from all battery sticks.
2023-06-26T13:45:50.020Z,1687787150.020 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T13:45:50.020Z,1687787150.020 [Default:CheckIn:C.Wait] Stopped
2023-06-26T13:45:50.020Z,1687787150.020 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T13:45:50.020Z,1687787150.020 [Default:CheckIn:D] Running Loop=1
2023-06-26T13:45:50.422Z,1687787150.422 [Default:CheckIn:D] Stopped
2023-06-26T13:45:50.422Z,1687787150.422 [Default:CheckIn:E] Running Loop=1
2023-06-26T13:45:50.824Z,1687787150.824 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.050065 min 
2023-06-26T13:45:50.824Z,1687787150.824 [Default:CheckIn:E] Stopped
2023-06-26T13:45:50.824Z,1687787150.824 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T13:45:50.824Z,1687787150.824 [Default:CheckIn] Stopped
2023-06-26T13:45:50.824Z,1687787150.824 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T13:45:50.825Z,1687787150.825 [Default:CheckIn](INFO): Running loop #14
2023-06-26T13:45:50.825Z,1687787150.825 [Default:CheckIn] Running Loop=14
2023-06-26T13:45:50.825Z,1687787150.825 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T13:45:50.825Z,1687787150.825 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T13:45:52.839Z,1687787152.839 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,134552.00,A,4313.47839,N,08620.06780,W,0.175,346.56,260623,,,D*7E
2023-06-26T13:45:52.842Z,1687787152.842 [NAL9602](INFO): GPS fix at 20230626T134552: (43.224640, -86.334463)
2023-06-26T13:45:52.851Z,1687787152.851 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T13:45:52.852Z,1687787152.852 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T13:46:00.215Z,1687787160.215 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20230626T122707/Courier0049.lzma
2023-06-26T13:46:01.218Z,1687787161.218 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0049.lzma.bak
2023-06-26T13:46:01.218Z,1687787161.218 [DataOverHttps](INFO): SBD MOMSN=18431227
2023-06-26T13:46:17.771Z,1687787177.771 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230626T122707/Express0050.lzma
2023-06-26T13:46:18.774Z,1687787178.774 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0050.lzma.bak
2023-06-26T13:46:18.774Z,1687787178.774 [DataOverHttps](INFO): SBD MOMSN=18431231
2023-06-26T13:46:20.751Z,1687787180.751 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T13:46:20.751Z,1687787180.751 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T13:46:20.751Z,1687787180.751 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T13:46:54.686Z,1687787214.686 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T13:47:25.381Z,1687787245.381 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T13:50:00.546Z,1687787400.546 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T135000
2023-06-26T13:50:07.832Z,1687787407.832 [DataOverHttps](INFO): Received command: sched asap "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m" 1s12r 1 2
2023-06-26T13:50:07.848Z,1687787407.848 [CommandExec](IMPORTANT): got command schedule asap "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m" 1s12r 1 2.000000
2023-06-26T13:50:07.849Z,1687787407.849 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=1s12r
2023-06-26T13:50:07.850Z,1687787407.850 [CommandExec](IMPORTANT): Scheduled #2 (#1 of 2 with id='1s12r'): "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m", ASAP
2023-06-26T13:50:08.833Z,1687787408.833 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T135008
2023-06-26T13:50:16.039Z,1687787416.039 [DataOverHttps](INFO): Received command: sched asap "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run" 1s12r 2 2
2023-06-26T13:50:16.071Z,1687787416.071 [CommandExec](IMPORTANT): got command schedule asap "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run" 1s12r 2 2.000000
2023-06-26T13:50:16.071Z,1687787416.071 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=1s12r
2023-06-26T13:50:16.073Z,1687787416.073 [CommandExec](IMPORTANT): Scheduled #3 (#2 of 2 with id='1s12r'): "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run", ASAP
2023-06-26T13:50:16.186Z,1687787416.186 [CommandExec](IMPORTANT): got command load ./Missions/Transport/transit.tl
2023-06-26T13:50:16.187Z,1687787416.187 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/transit.tl
2023-06-26T13:50:16.187Z,1687787416.187 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file ./Missions/Transport/transit.tx
2023-06-26T13:50:16.288Z,1687787416.288 [MissionManager](INFO): DefineArg transit.MissionTimeout = 60.000000 min
2023-06-26T13:50:16.291Z,1687787416.291 [MissionManager](INFO): DefineArg transit.NeedCommsTime = 30.000000 min
2023-06-26T13:50:16.294Z,1687787416.294 [MissionManager](INFO): DefineArg transit.Latitude = nan arcdeg
2023-06-26T13:50:16.301Z,1687787416.301 [MissionManager](INFO): DefineArg transit.Longitude = nan arcdeg
2023-06-26T13:50:16.303Z,1687787416.303 [MissionManager](INFO): DefineArg transit.Northings = 0.000000 m
2023-06-26T13:50:16.306Z,1687787416.306 [MissionManager](INFO): DefineArg transit.Eastings = 0.000000 m
2023-06-26T13:50:16.309Z,1687787416.309 [MissionManager](INFO): DefineArg transit.Depth = 10.000000 m
2023-06-26T13:50:16.311Z,1687787416.311 [MissionManager](INFO): DefineArg transit.Speed = 1.000000 m/s
2023-06-26T13:50:16.350Z,1687787416.350 [MissionManager](INFO): DefineArg transit.MaxDepth = 20.000000 m
2023-06-26T13:50:16.372Z,1687787416.372 [MissionManager](INFO): DefineArg transit.MinOffshore = 1.000000 km
2023-06-26T13:50:16.375Z,1687787416.375 [MissionManager](INFO): DefineArg transit.MinAltitude = 7.000000 m
2023-06-26T13:50:16.378Z,1687787416.378 [MissionManager](INFO): DefineArg transit.MassHold = 1 bool
2023-06-26T13:50:16.394Z,1687787416.394 [MissionManager](INFO): DefineArg transit.BuoyancyHold = 1 bool
2023-06-26T13:50:16.394Z,1687787416.394 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.xml
2023-06-26T13:50:16.502Z,1687787416.502 [MissionManager](INFO): DefineArg transit:NeedComms.DiveInterval = 3.000000 h
2023-06-26T13:50:16.506Z,1687787416.506 [MissionManager](INFO): DefineArg transit:NeedComms.WaitForPitchUp = 10.000000 min
2023-06-26T13:50:16.521Z,1687787416.521 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacePitch = 20.000000 arcdeg
2023-06-26T13:50:16.532Z,1687787416.532 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceDepthRate = nan m/s
2023-06-26T13:50:16.535Z,1687787416.535 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceSpeed = 1.000000 m/s
2023-06-26T13:50:16.538Z,1687787416.538 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacingTimeout = 1000.000000 s
2023-06-26T13:50:16.548Z,1687787416.548 [MissionManager](INFO): DefineArg transit:NeedComms.GPSTimeout = 7.000000 min
2023-06-26T13:50:16.551Z,1687787416.551 [MissionManager](INFO): DefineArg transit:NeedComms.CommsTimeout = 30.000000 min
2023-06-26T13:50:16.566Z,1687787416.566 [transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-26T13:50:16.615Z,1687787416.615 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.xml
2023-06-26T13:50:16.658Z,1687787416.658 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinAltitude = 5.000000 m
2023-06-26T13:50:16.680Z,1687787416.680 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepthIgnore = 0.000000 m
2023-06-26T13:50:16.683Z,1687787416.683 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepth = 200.000000 m
2023-06-26T13:50:16.690Z,1687787416.690 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinOffshore = 2000.000000 m
2023-06-26T13:50:16.691Z,1687787416.691 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2023-06-26T13:50:16.715Z,1687787416.715 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2023-06-26T13:50:16.759Z,1687787416.759 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2023-06-26T13:50:16.788Z,1687787416.788 [transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2023-06-26T13:50:16.795Z,1687787416.795 [transit:MassHold.Pitch](DEBUG): Construct.
2023-06-26T13:50:16.806Z,1687787416.806 [transit:Transit:A.Pitch](DEBUG): Construct.
2023-06-26T13:50:16.821Z,1687787416.821 [transit:Transit:B.SetSpeed](DEBUG): Construct.
2023-06-26T13:50:16.828Z,1687787416.828 [transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2023-06-26T13:50:16.868Z,1687787416.868 [MissionManager](DEBUG): 
mission transit {
  """
  Vehicle transits to desired waypoint and can be commanded to use/hold
  mass or buoyancy.
  """

  arguments {
    MissionTimeout = 60 minute
      """
      Maximum duration of mission
      """

    NeedCommsTime = 30 minute
      """
      How often to surface for commumications
      """

    Latitude = NaN degree
      """
      Latitude of waypoint to seek. If set to NaN, uses latitude at mission
      initialization.
      """

    Longitude = NaN degree
      """
      Longitude of waypoint to seek. If set to NaN, uses longitude at mission
      initialization.
      """

    Northings = 0 meter
      """
      Northward distance of the waypoint to seek. If combined with Latitude
      and/or Longitude, this is an offset from the specified Latitude and/or
      Longitude.
      """

    Eastings = 0 meter
      """
      Eastward distance of the waypoint to seek. If combined with Latitude
      and/or Longitude, this is an offset from the specified Latitude and/or
      Longitude.
      """

    Depth = 10 meter
      """
      Depth of flat and level flight during the mission.
      """

    Speed = 1 meter_per_second
      """
      Speed of vehicle (relative to water) during the mission.
      """

    MaxDepth = 20 meter
      """
      Maximum depth for the entire mission.
      """

    MinOffshore = 1 kilometer
      """
      Minimum distance offshore for the entire mission.
      """

    MinAltitude = 7 meter
      """
      Minimum height above the sea floor for the entire mission.
      """

    MassHold = true
      """
      Set to True in order to hold mass at default position, False to allow
      mass to run on its own.
      """

    BuoyancyHold = true
      """
      Set to True in order to hold buoyancy at neutral position, False to
      allow buoyancy to run on its own.
      """
  }

  timeout duration=MissionTimeout

  insert id="NeedComms" Insert/NeedComms.xml

  assign in sequence NeedComms:DiveInterval = NeedCommsTime

  assign in sequence NeedComms:WaitForPitchUp = 1 second

  insert Insert/StandardEnvelopes.xml

  assign in sequence StandardEnvelopes:MinAltitude = MinAltitude

  assign in sequence StandardEnvelopes:MaxDepth = MaxDepth

  assign in sequence StandardEnvelopes:MinOffshore = MinOffshore

  behavior Guidance:Buoyancy id="BuoyancyHold" {
    run while ( BuoyancyHold )

    set position = Control:VerticalControl.buoyancyNeutral
  }

  behavior Guidance:Pitch id="MassHold" {
    run while ( MassHold )

    set massPosition = Control:VerticalControl.massDefault
  }

  aggregate Transit {
    run in sequence

    behavior Guidance:Pitch {
      run in parallel

      set depth = Depth
    }

    behavior Guidance:SetSpeed {
      run in parallel

      set speed = Speed
    }

    behavior Guidance:Waypoint id="Wpt1" {
      run in sequence

      set latitude = Latitude
      set longitude = Longitude
      set northingsDelta = Northings
      set eastingsDelta = Eastings
    }

    call id="PhoneHome" refId="NeedComms"
  }
}


2023-06-26T13:50:16.871Z,1687787416.871 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/transit.tl
2023-06-26T13:50:24.652Z,1687787424.652 [CommandExec](IMPORTANT): got command set transit.MissionTimeout 30 minute
2023-06-26T13:50:24.653Z,1687787424.653 [CommandExec](IMPORTANT): got command set transit.NeedCommsTime 12 minute
2023-06-26T13:50:24.653Z,1687787424.653 [CommandExec](IMPORTANT): got command set transit.Latitude 43.20017 degree
2023-06-26T13:50:24.654Z,1687787424.654 [CommandExec](IMPORTANT): got command set transit.Longitude -86.3649 degree
2023-06-26T13:50:24.655Z,1687787424.655 [CommandExec](IMPORTANT): got command set transit.Depth 1 meter
2023-06-26T13:50:24.655Z,1687787424.655 [CommandExec](IMPORTANT): got command set transit.MaxDepth 2 meter
2023-06-26T13:50:27.461Z,1687787427.461 [CommandExec](IMPORTANT): got command set transit.MinOffshore 0.00001 kilometer
2023-06-26T13:50:27.461Z,1687787427.461 [CommandExec](IMPORTANT): got command set transit.MinAltitude 2 meter
2023-06-26T13:50:27.462Z,1687787427.462 [CommandExec](IMPORTANT): got command run
2023-06-26T13:50:27.464Z,1687787427.464 [CommandExec](IMPORTANT): Running 
2023-06-26T13:50:27.603Z,1687787427.603 [Default] Stopped
2023-06-26T13:50:27.603Z,1687787427.603 [Default](DEBUG): Aggregate::uninitialize Default
2023-06-26T13:50:27.603Z,1687787427.603 [Default:B.GoToSurface] Stopped
2023-06-26T13:50:27.603Z,1687787427.603 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-26T13:50:27.603Z,1687787427.603 [Default:CheckIn] Stopped
2023-06-26T13:50:27.603Z,1687787427.603 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T13:50:27.603Z,1687787427.603 [Default:CheckIn:C.Wait] Stopped
2023-06-26T13:50:27.603Z,1687787427.603 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T13:50:27.604Z,1687787427.604 [MissionManager](IMPORTANT): Started mission transit
2023-06-26T13:50:27.604Z,1687787427.604 [transit] Running Loop=1
2023-06-26T13:50:27.604Z,1687787427.604 [transit](DEBUG): Aggregate::initialize transit
2023-06-26T13:50:27.604Z,1687787427.604 [transit:StandardEnvelopes] Running Loop=1
2023-06-26T13:50:27.604Z,1687787427.604 [transit:StandardEnvelopes](DEBUG): Aggregate::initialize transit:StandardEnvelopes
2023-06-26T13:50:27.604Z,1687787427.604 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2023-06-26T13:50:27.604Z,1687787427.604 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2023-06-26T13:50:27.605Z,1687787427.605 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2023-06-26T13:50:27.605Z,1687787427.605 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2023-06-26T13:50:27.605Z,1687787427.605 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2023-06-26T13:50:27.605Z,1687787427.605 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2023-06-26T13:50:27.605Z,1687787427.605 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2023-06-26T13:50:27.605Z,1687787427.605 [transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2023-06-26T13:50:27.605Z,1687787427.605 [transit:MassHold.Pitch] Running Loop=1
2023-06-26T13:50:27.605Z,1687787427.605 [transit:MassHold.Pitch](DEBUG): Initialize.
2023-06-26T13:50:27.606Z,1687787427.606 [transit:B] Running Loop=1
2023-06-26T13:50:27.606Z,1687787427.606 [transit:MassHold.Pitch] Running Loop=1
2023-06-26T13:50:27.607Z,1687787427.607 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2023-06-26T13:50:27.607Z,1687787427.607 [transit:StandardEnvelopes] Running Loop=1
2023-06-26T13:50:27.607Z,1687787427.607 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2023-06-26T13:50:27.607Z,1687787427.607 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2023-06-26T13:50:27.608Z,1687787427.608 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2023-06-26T13:50:27.609Z,1687787427.609 [transit:B] Stopped
2023-06-26T13:50:27.609Z,1687787427.609 [transit:C] Running Loop=1
2023-06-26T13:50:28.022Z,1687787428.022 [transit:C] Stopped
2023-06-26T13:50:28.022Z,1687787428.022 [transit:E] Running Loop=1
2023-06-26T13:50:28.403Z,1687787428.403 [transit:E] Stopped
2023-06-26T13:50:28.403Z,1687787428.403 [transit:F] Running Loop=1
2023-06-26T13:50:28.811Z,1687787428.811 [transit:F] Stopped
2023-06-26T13:50:28.811Z,1687787428.811 [transit:G] Running Loop=1
2023-06-26T13:50:29.220Z,1687787429.220 [transit:G] Stopped
2023-06-26T13:50:29.220Z,1687787429.220 [transit:Transit] Running Loop=1
2023-06-26T13:50:29.220Z,1687787429.220 [transit:Transit](DEBUG): Aggregate::initialize transit:Transit
2023-06-26T13:50:29.220Z,1687787429.220 [transit:Transit:A.Pitch] Running Loop=1
2023-06-26T13:50:29.220Z,1687787429.220 [transit:Transit:A.Pitch](DEBUG): Initialize.
2023-06-26T13:50:29.220Z,1687787429.220 [transit:Transit:B.SetSpeed] Running Loop=1
2023-06-26T13:50:29.220Z,1687787429.220 [transit:Transit:B.SetSpeed](DEBUG): Initialize.
2023-06-26T13:50:29.221Z,1687787429.221 [transit:Transit:Wpt1.Waypoint] Running Loop=1
2023-06-26T13:50:29.221Z,1687787429.221 [transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2023-06-26T13:50:29.320Z,1687787429.320 [transit:Transit:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 43.200169,-86.364899
2023-06-26T13:50:29.321Z,1687787429.321 [transit:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2023-06-26T13:50:29.613Z,1687787429.613 [transit:Transit:B.SetSpeed] Running Loop=1
2023-06-26T13:50:29.614Z,1687787429.614 [transit:Transit:A.Pitch] Running Loop=1
2023-06-26T13:50:52.725Z,1687787452.725 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T135052
2023-06-26T13:51:00.414Z,1687787460.414 [DataOverHttps](INFO): Received command: stop
2023-06-26T13:51:00.477Z,1687787460.477 [CommandExec](IMPORTANT): got command stop
2023-06-26T13:51:00.477Z,1687787460.477 [CommandExec](IMPORTANT): Scheduling is paused
2023-06-26T13:51:00.477Z,1687787460.477 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2023-06-26T13:51:00.813Z,1687787460.813 [MissionManager](INFO): MissionManager is completed.
2023-06-26T13:51:00.813Z,1687787460.813 [MissionManager](INFO): Uninitializing Mission transit
2023-06-26T13:51:00.813Z,1687787460.813 [transit] Stopped
2023-06-26T13:51:00.814Z,1687787460.814 [transit](DEBUG): Aggregate::uninitialize transit
2023-06-26T13:51:00.814Z,1687787460.814 [transit:StandardEnvelopes] Stopped
2023-06-26T13:51:00.814Z,1687787460.814 [transit:StandardEnvelopes](DEBUG): Aggregate::uninitialize transit:StandardEnvelopes
2023-06-26T13:51:00.814Z,1687787460.814 [transit:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2023-06-26T13:51:00.814Z,1687787460.814 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2023-06-26T13:51:00.814Z,1687787460.814 [transit:StandardEnvelopes:B.DepthEnvelope] Stopped
2023-06-26T13:51:00.814Z,1687787460.814 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2023-06-26T13:51:00.814Z,1687787460.814 [transit:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2023-06-26T13:51:00.814Z,1687787460.814 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2023-06-26T13:51:00.814Z,1687787460.814 [transit:BuoyancyHold.Buoyancy] Stopped
2023-06-26T13:51:00.814Z,1687787460.814 [transit:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2023-06-26T13:51:00.814Z,1687787460.814 [transit:MassHold.Pitch] Stopped
2023-06-26T13:51:00.814Z,1687787460.814 [transit:Transit] Stopped
2023-06-26T13:51:00.815Z,1687787460.815 [transit:Transit](DEBUG): Aggregate::uninitialize transit:Transit
2023-06-26T13:51:00.815Z,1687787460.815 [transit:Transit:A.Pitch] Stopped
2023-06-26T13:51:00.815Z,1687787460.815 [transit:Transit:B.SetSpeed] Stopped
2023-06-26T13:51:00.815Z,1687787460.815 [transit:Transit:B.SetSpeed](DEBUG): Uninitialize.
2023-06-26T13:51:00.815Z,1687787460.815 [transit:Transit:Wpt1.Waypoint] Stopped
2023-06-26T13:51:00.815Z,1687787460.815 [transit:Transit:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2023-06-26T13:51:01.233Z,1687787461.233 [MissionManager](IMPORTANT): Started mission Default
2023-06-26T13:51:01.233Z,1687787461.233 [Default] Running Loop=1
2023-06-26T13:51:01.233Z,1687787461.233 [Default](DEBUG): Aggregate::initialize Default
2023-06-26T13:51:01.233Z,1687787461.233 [Default:B.GoToSurface] Running Loop=1
2023-06-26T13:51:01.233Z,1687787461.233 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-26T13:51:01.233Z,1687787461.233 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-26T13:51:01.234Z,1687787461.234 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-26T13:51:01.234Z,1687787461.234 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-26T13:51:01.234Z,1687787461.234 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-26T13:51:01.235Z,1687787461.235 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-26T13:51:01.235Z,1687787461.235 [Default:A.Wait] Running Loop=1
2023-06-26T13:51:01.235Z,1687787461.235 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-06-26T13:51:14.550Z,1687787474.550 [Default:A.Wait](INFO): Done Waiting.
2023-06-26T13:51:14.551Z,1687787474.551 [Default:A.Wait] Stopped
2023-06-26T13:51:14.551Z,1687787474.551 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T13:51:14.942Z,1687787474.942 [Default:CheckIn] Running Loop=1
2023-06-26T13:51:14.942Z,1687787474.942 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T13:51:14.942Z,1687787474.942 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T13:51:16.955Z,1687787476.955 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,135116.00,A,4313.47992,N,08620.06804,W,0.272,346.56,260623,,,D*7C
2023-06-26T13:51:16.966Z,1687787476.966 [NAL9602](INFO): GPS fix at 20230626T135116: (43.224665, -86.334467)
2023-06-26T13:51:16.976Z,1687787476.976 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T13:51:16.976Z,1687787476.976 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T13:51:23.995Z,1687787483.995 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230626T122707/Courier0052.lzma
2023-06-26T13:51:24.998Z,1687787484.998 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0052.lzma.bak
2023-06-26T13:51:24.998Z,1687787484.998 [DataOverHttps](INFO): SBD MOMSN=18431316
2023-06-26T13:51:40.665Z,1687787500.665 [DataOverHttps](INFO): Sending 774 bytes from file Logs/20230626T122707/Express0053.lzma
2023-06-26T13:51:41.674Z,1687787501.674 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0053.lzma.bak
2023-06-26T13:51:41.674Z,1687787501.674 [DataOverHttps](INFO): SBD MOMSN=18431319
2023-06-26T13:51:43.635Z,1687787503.635 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T13:51:43.636Z,1687787503.636 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T13:51:43.636Z,1687787503.636 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T13:51:47.661Z,1687787507.661 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T13:51:47.736Z,1687787507.736 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T13:52:19.581Z,1687787539.581 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T13:52:50.292Z,1687787570.292 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T13:56:44.219Z,1687787804.219 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T13:56:44.219Z,1687787804.219 [Default:CheckIn:C.Wait] Stopped
2023-06-26T13:56:44.219Z,1687787804.219 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T13:56:44.219Z,1687787804.219 [Default:CheckIn:D] Running Loop=1
2023-06-26T13:56:44.633Z,1687787804.633 [Default:CheckIn:D] Stopped
2023-06-26T13:56:44.633Z,1687787804.633 [Default:CheckIn:E] Running Loop=1
2023-06-26T13:56:45.030Z,1687787805.030 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.723339 min 
2023-06-26T13:56:45.030Z,1687787805.030 [Default:CheckIn:E] Stopped
2023-06-26T13:56:45.030Z,1687787805.030 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T13:56:45.030Z,1687787805.030 [Default:CheckIn] Stopped
2023-06-26T13:56:45.030Z,1687787805.030 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T13:56:45.031Z,1687787805.031 [Default:CheckIn](INFO): Running loop #2
2023-06-26T13:56:45.031Z,1687787805.031 [Default:CheckIn] Running Loop=2
2023-06-26T13:56:45.031Z,1687787805.031 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T13:56:45.031Z,1687787805.031 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T13:56:47.038Z,1687787807.038 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,135647.00,A,4313.48003,N,08620.10080,W,1.516,217.00,260623,,,D*70
2023-06-26T13:56:47.040Z,1687787807.040 [NAL9602](INFO): GPS fix at 20230626T135647: (43.224667, -86.335013)
2023-06-26T13:56:47.050Z,1687787807.050 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T13:56:47.051Z,1687787807.051 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T13:56:53.979Z,1687787813.979 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T122707/Courier0055.lzma
2023-06-26T13:56:54.982Z,1687787814.982 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0055.lzma.bak
2023-06-26T13:56:54.982Z,1687787814.982 [DataOverHttps](INFO): SBD MOMSN=18431349
2023-06-26T13:57:13.763Z,1687787833.763 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20230626T122707/Express0057.lzma
2023-06-26T13:57:14.766Z,1687787834.766 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0057.lzma.bak
2023-06-26T13:57:14.766Z,1687787834.766 [DataOverHttps](INFO): SBD MOMSN=18431352
2023-06-26T13:57:16.575Z,1687787836.575 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T13:57:16.575Z,1687787836.575 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T13:57:16.576Z,1687787836.576 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T13:57:49.679Z,1687787869.679 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T13:58:20.389Z,1687787900.389 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T14:02:17.214Z,1687788137.214 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-26T14:02:17.214Z,1687788137.214 [Default:CheckIn:C.Wait] Stopped
2023-06-26T14:02:17.214Z,1687788137.214 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T14:02:17.214Z,1687788137.214 [Default:CheckIn:D] Running Loop=1
2023-06-26T14:02:17.618Z,1687788137.618 [Default:CheckIn:D] Stopped
2023-06-26T14:02:17.618Z,1687788137.618 [Default:CheckIn:E] Running Loop=1
2023-06-26T14:02:18.019Z,1687788138.019 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.273089 min 
2023-06-26T14:02:18.019Z,1687788138.019 [Default:CheckIn:E] Stopped
2023-06-26T14:02:18.019Z,1687788138.019 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-26T14:02:18.019Z,1687788138.019 [Default:CheckIn] Stopped
2023-06-26T14:02:18.019Z,1687788138.019 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T14:02:18.020Z,1687788138.020 [Default:CheckIn](INFO): Running loop #3
2023-06-26T14:02:18.020Z,1687788138.020 [Default:CheckIn] Running Loop=3
2023-06-26T14:02:18.020Z,1687788138.020 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T14:02:18.020Z,1687788138.020 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T14:02:20.033Z,1687788140.033 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140220.00,A,4313.34505,N,08620.15625,W,0.078,265.29,260623,,,D*71
2023-06-26T14:02:20.035Z,1687788140.035 [NAL9602](INFO): GPS fix at 20230626T140220: (43.222417, -86.335938)
2023-06-26T14:02:20.045Z,1687788140.045 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T14:02:20.045Z,1687788140.045 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T14:02:27.659Z,1687788147.659 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230626T122707/Courier0061.lzma
2023-06-26T14:02:28.662Z,1687788148.662 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0061.lzma.bak
2023-06-26T14:02:28.662Z,1687788148.662 [DataOverHttps](INFO): SBD MOMSN=18431356
2023-06-26T14:02:48.720Z,1687788168.720 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20230626T122707/Express0062.lzma
2023-06-26T14:02:49.722Z,1687788169.722 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0062.lzma.bak
2023-06-26T14:02:49.722Z,1687788169.722 [DataOverHttps](INFO): SBD MOMSN=18431359
2023-06-26T14:02:51.587Z,1687788171.587 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T14:02:51.587Z,1687788171.587 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T14:02:51.587Z,1687788171.587 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T14:03:22.685Z,1687788202.685 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T14:03:53.389Z,1687788233.389 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T14:05:56.257Z,1687788356.257 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T140556
2023-06-26T14:06:03.543Z,1687788363.543 [DataOverHttps](INFO): Received command: ibit
2023-06-26T14:06:03.637Z,1687788363.637 [CommandExec](IMPORTANT): got command ibit
2023-06-26T14:06:03.896Z,1687788363.896 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-06-26T14:06:03.896Z,1687788363.896 [IBIT](IMPORTANT): Beginning control surface checks.
2023-06-26T14:06:03.899Z,1687788363.899 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-26T14:06:05.499Z,1687788365.499 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140605.00,A,4313.33870,N,08620.16107,W,0.019,213.47,260623,,,A*75
2023-06-26T14:06:05.501Z,1687788365.501 [NAL9602](INFO): GPS fix at 20230626T140605: (43.222312, -86.336018)
2023-06-26T14:06:06.773Z,1687788366.773 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-06-26T14:06:14.820Z,1687788374.820 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.697961
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.467554
CHAN A3 (5V): 0.186990
CHAN B0 (3.3V): 0.128572
CHAN B1 (3.15aV): 0.136104
CHAN B2 (3.15bV): 0.136442
CHAN B3 (GND): -0.000689
OPEN: 0.017557
Full Scale: +/- 1 mA
2023-06-26T14:06:36.237Z,1687788396.237 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T14:06:36.320Z,1687788396.320 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T14:06:43.850Z,1687788403.850 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T140642
2023-06-26T14:06:51.160Z,1687788411.160 [DataOverHttps](INFO): Received command: sched asap "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m" 1s1ua 1 2
2023-06-26T14:06:51.201Z,1687788411.201 [CommandExec](IMPORTANT): got command schedule asap "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m" 1s1ua 1 2.000000
2023-06-26T14:06:51.201Z,1687788411.201 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=1s1ua
2023-06-26T14:06:51.202Z,1687788411.202 [CommandExec](IMPORTANT): Scheduled #4 (#1 of 2 with id='1s1ua'): "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m", ASAP
2023-06-26T14:06:52.161Z,1687788412.161 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T140652
2023-06-26T14:06:59.440Z,1687788419.440 [DataOverHttps](INFO): Received command: sched asap "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run" 1s1ua 2 2
2023-06-26T14:06:59.519Z,1687788419.519 [CommandExec](IMPORTANT): got command schedule asap "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run" 1s1ua 2 2.000000
2023-06-26T14:06:59.519Z,1687788419.519 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=1s1ua
2023-06-26T14:06:59.520Z,1687788419.520 [CommandExec](IMPORTANT): Scheduled #5 (#2 of 2 with id='1s1ua'): "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run", ASAP
2023-06-26T14:06:59.632Z,1687788419.632 [CommandExec](IMPORTANT): got command load ./Missions/Transport/transit.tl
2023-06-26T14:06:59.632Z,1687788419.632 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/transit.tl
2023-06-26T14:06:59.632Z,1687788419.632 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file ./Missions/Transport/transit.tx
2023-06-26T14:06:59.760Z,1687788419.760 [MissionManager](INFO): DefineArg transit.MissionTimeout = 60.000000 min
2023-06-26T14:06:59.762Z,1687788419.762 [MissionManager](INFO): DefineArg transit.NeedCommsTime = 30.000000 min
2023-06-26T14:06:59.764Z,1687788419.764 [MissionManager](INFO): DefineArg transit.Latitude = nan arcdeg
2023-06-26T14:06:59.766Z,1687788419.766 [MissionManager](INFO): DefineArg transit.Longitude = nan arcdeg
2023-06-26T14:06:59.768Z,1687788419.768 [MissionManager](INFO): DefineArg transit.Northings = 0.000000 m
2023-06-26T14:06:59.770Z,1687788419.770 [MissionManager](INFO): DefineArg transit.Eastings = 0.000000 m
2023-06-26T14:06:59.772Z,1687788419.772 [MissionManager](INFO): DefineArg transit.Depth = 10.000000 m
2023-06-26T14:06:59.774Z,1687788419.774 [MissionManager](INFO): DefineArg transit.Speed = 1.000000 m/s
2023-06-26T14:06:59.776Z,1687788419.776 [MissionManager](INFO): DefineArg transit.MaxDepth = 20.000000 m
2023-06-26T14:06:59.778Z,1687788419.778 [MissionManager](INFO): DefineArg transit.MinOffshore = 1.000000 km
2023-06-26T14:06:59.781Z,1687788419.781 [MissionManager](INFO): DefineArg transit.MinAltitude = 7.000000 m
2023-06-26T14:06:59.782Z,1687788419.782 [MissionManager](INFO): DefineArg transit.MassHold = 1 bool
2023-06-26T14:06:59.784Z,1687788419.784 [MissionManager](INFO): DefineArg transit.BuoyancyHold = 1 bool
2023-06-26T14:06:59.785Z,1687788419.785 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.xml
2023-06-26T14:06:59.893Z,1687788419.893 [MissionManager](INFO): DefineArg transit:NeedComms.DiveInterval = 3.000000 h
2023-06-26T14:06:59.895Z,1687788419.895 [MissionManager](INFO): DefineArg transit:NeedComms.WaitForPitchUp = 10.000000 min
2023-06-26T14:06:59.913Z,1687788419.913 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacePitch = 20.000000 arcdeg
2023-06-26T14:06:59.915Z,1687788419.915 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceDepthRate = nan m/s
2023-06-26T14:06:59.917Z,1687788419.917 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceSpeed = 1.000000 m/s
2023-06-26T14:06:59.919Z,1687788419.919 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacingTimeout = 1000.000000 s
2023-06-26T14:06:59.936Z,1687788419.936 [MissionManager](INFO): DefineArg transit:NeedComms.GPSTimeout = 7.000000 min
2023-06-26T14:06:59.938Z,1687788419.938 [MissionManager](INFO): DefineArg transit:NeedComms.CommsTimeout = 30.000000 min
2023-06-26T14:06:59.943Z,1687788419.943 [transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-26T14:06:59.981Z,1687788419.981 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.xml
2023-06-26T14:06:59.999Z,1687788419.999 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinAltitude = 5.000000 m
2023-06-26T14:07:00.002Z,1687788420.002 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepthIgnore = 0.000000 m
2023-06-26T14:07:00.003Z,1687788420.003 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepth = 200.000000 m
2023-06-26T14:07:00.006Z,1687788420.006 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinOffshore = 2000.000000 m
2023-06-26T14:07:00.006Z,1687788420.006 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2023-06-26T14:07:00.016Z,1687788420.016 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2023-06-26T14:07:00.121Z,1687788420.121 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2023-06-26T14:07:00.154Z,1687788420.154 [transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2023-06-26T14:07:00.165Z,1687788420.165 [transit:MassHold.Pitch](DEBUG): Construct.
2023-06-26T14:07:00.186Z,1687788420.186 [transit:Transit:A.Pitch](DEBUG): Construct.
2023-06-26T14:07:00.206Z,1687788420.206 [transit:Transit:B.SetSpeed](DEBUG): Construct.
2023-06-26T14:07:00.245Z,1687788420.245 [transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2023-06-26T14:07:00.295Z,1687788420.295 [MissionManager](DEBUG): 
mission transit {
  """
  Vehicle transits to desired waypoint and can be commanded to use/hold
  mass or buoyancy.
  """

  arguments {
    MissionTimeout = 60 minute
      """
      Maximum duration of mission
      """

    NeedCommsTime = 30 minute
      """
      How often to surface for commumications
      """

    Latitude = NaN degree
      """
      Latitude of waypoint to seek. If set to NaN, uses latitude at mission
      initialization.
      """

    Longitude = NaN degree
      """
      Longitude of waypoint to seek. If set to NaN, uses longitude at mission
      initialization.
      """

    Northings = 0 meter
      """
      Northward distance of the waypoint to seek. If combined with Latitude
      and/or Longitude, this is an offset from the specified Latitude and/or
      Longitude.
      """

    Eastings = 0 meter
      """
      Eastward distance of the waypoint to seek. If combined with Latitude
      and/or Longitude, this is an offset from the specified Latitude and/or
      Longitude.
      """

    Depth = 10 meter
      """
      Depth of flat and level flight during the mission.
      """

    Speed = 1 meter_per_second
      """
      Speed of vehicle (relative to water) during the mission.
      """

    MaxDepth = 20 meter
      """
      Maximum depth for the entire mission.
      """

    MinOffshore = 1 kilometer
      """
      Minimum distance offshore for the entire mission.
      """

    MinAltitude = 7 meter
      """
      Minimum height above the sea floor for the entire mission.
      """

    MassHold = true
      """
      Set to True in order to hold mass at default position, False to allow
      mass to run on its own.
      """

    BuoyancyHold = true
      """
      Set to True in order to hold buoyancy at neutral position, False to
      allow buoyancy to run on its own.
      """
  }

  timeout duration=MissionTimeout

  insert id="NeedComms" Insert/NeedComms.xml

  assign in sequence NeedComms:DiveInterval = NeedCommsTime

  assign in sequence NeedComms:WaitForPitchUp = 1 second

  insert Insert/StandardEnvelopes.xml

  assign in sequence StandardEnvelopes:MinAltitude = MinAltitude

  assign in sequence StandardEnvelopes:MaxDepth = MaxDepth

  assign in sequence StandardEnvelopes:MinOffshore = MinOffshore

  behavior Guidance:Buoyancy id="BuoyancyHold" {
    run while ( BuoyancyHold )

    set position = Control:VerticalControl.buoyancyNeutral
  }

  behavior Guidance:Pitch id="MassHold" {
    run while ( MassHold )

    set massPosition = Control:VerticalControl.massDefault
  }

  aggregate Transit {
    run in sequence

    behavior Guidance:Pitch {
      run in parallel

      set depth = Depth
    }

    behavior Guidance:SetSpeed {
      run in parallel

      set speed = Speed
    }

    behavior Guidance:Waypoint id="Wpt1" {
      run in sequence

      set latitude = Latitude
      set longitude = Longitude
      set northingsDelta = Northings
      set eastingsDelta = Eastings
    }

    call id="PhoneHome" refId="NeedComms"
  }
}


2023-06-26T14:07:00.304Z,1687788420.304 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/transit.tl
2023-06-26T14:07:07.834Z,1687788427.834 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T14:07:09.055Z,1687788429.055 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140709.00,A,4313.33895,N,08620.16100,W,0.019,213.47,260623,,,D*71
2023-06-26T14:07:09.058Z,1687788429.058 [NAL9602](INFO): GPS fix at 20230626T140709: (43.222316, -86.336017)
2023-06-26T14:07:12.319Z,1687788432.319 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140712.00,A,4313.33891,N,08620.16091,W,0.039,213.47,260623,,,D*74
2023-06-26T14:07:12.321Z,1687788432.321 [NAL9602](INFO): GPS fix at 20230626T140712: (43.222315, -86.336015)
2023-06-26T14:07:14.669Z,1687788434.669 [CommandExec](IMPORTANT): got command set transit.MissionTimeout 30 minute
2023-06-26T14:07:14.670Z,1687788434.670 [CommandExec](IMPORTANT): got command set transit.NeedCommsTime 12 minute
2023-06-26T14:07:14.671Z,1687788434.671 [CommandExec](IMPORTANT): got command set transit.Latitude 43.20017 degree
2023-06-26T14:07:14.671Z,1687788434.671 [CommandExec](IMPORTANT): got command set transit.Longitude -86.3649 degree
2023-06-26T14:07:14.680Z,1687788434.680 [CommandExec](IMPORTANT): got command set transit.Depth 1 meter
2023-06-26T14:07:14.681Z,1687788434.681 [CommandExec](IMPORTANT): got command set transit.MaxDepth 2 meter
2023-06-26T14:07:15.171Z,1687788435.171 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140715.00,A,4313.33889,N,08620.16093,W,0.039,213.47,260623,,,D*78
2023-06-26T14:07:15.173Z,1687788435.173 [NAL9602](INFO): GPS fix at 20230626T140715: (43.222315, -86.336016)
2023-06-26T14:07:18.411Z,1687788438.411 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140718.00,A,4313.33885,N,08620.16093,W,0.058,213.47,260623,,,D*7E
2023-06-26T14:07:18.413Z,1687788438.413 [NAL9602](INFO): GPS fix at 20230626T140718: (43.222314, -86.336016)
2023-06-26T14:07:19.555Z,1687788439.555 [CommandExec](IMPORTANT): got command set transit.MinOffshore 0.00001 kilometer
2023-06-26T14:07:19.555Z,1687788439.555 [CommandExec](IMPORTANT): got command set transit.MinAltitude 2 meter
2023-06-26T14:07:19.556Z,1687788439.556 [CommandExec](IMPORTANT): got command run
2023-06-26T14:07:19.558Z,1687788439.558 [CommandExec](IMPORTANT): Running 
2023-06-26T14:07:21.238Z,1687788441.238 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140721.00,A,4313.33885,N,08620.16089,W,0.058,213.47,260623,,,D*7F
2023-06-26T14:07:21.240Z,1687788441.240 [NAL9602](INFO): GPS fix at 20230626T140721: (43.222314, -86.336015)
2023-06-26T14:07:24.075Z,1687788444.075 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140724.00,A,4313.33887,N,08620.16091,W,0.039,213.47,260623,,,D*76
2023-06-26T14:07:24.077Z,1687788444.077 [NAL9602](INFO): GPS fix at 20230626T140724: (43.222315, -86.336015)
2023-06-26T14:07:27.300Z,1687788447.300 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140727.00,A,4313.33886,N,08620.16097,W,0.019,213.47,260623,,,D*70
2023-06-26T14:07:27.302Z,1687788447.302 [NAL9602](INFO): GPS fix at 20230626T140727: (43.222314, -86.336016)
2023-06-26T14:07:30.131Z,1687788450.131 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140730.00,A,4313.33884,N,08620.16091,W,0.039,213.47,260623,,,D*70
2023-06-26T14:07:30.133Z,1687788450.133 [NAL9602](INFO): GPS fix at 20230626T140730: (43.222314, -86.336015)
2023-06-26T14:07:33.359Z,1687788453.359 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140733.00,A,4313.33886,N,08620.16086,W,0.039,213.47,260623,,,D*77
2023-06-26T14:07:33.361Z,1687788453.361 [NAL9602](INFO): GPS fix at 20230626T140733: (43.222314, -86.336014)
2023-06-26T14:07:36.191Z,1687788456.191 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140736.00,A,4313.33883,N,08620.16084,W,0.039,213.47,260623,,,D*75
2023-06-26T14:07:36.194Z,1687788456.194 [NAL9602](INFO): GPS fix at 20230626T140736: (43.222314, -86.336014)
2023-06-26T14:07:39.418Z,1687788459.418 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140739.00,A,4313.33886,N,08620.16089,W,0.058,213.47,260623,,,D*75
2023-06-26T14:07:39.420Z,1687788459.420 [NAL9602](INFO): GPS fix at 20230626T140739: (43.222314, -86.336015)
2023-06-26T14:07:42.251Z,1687788462.251 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140742.00,A,4313.33890,N,08620.16091,W,0.019,213.47,260623,,,D*72
2023-06-26T14:07:42.261Z,1687788462.261 [NAL9602](INFO): GPS fix at 20230626T140742: (43.222315, -86.336015)
2023-06-26T14:07:45.152Z,1687788465.152 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140745.00,A,4313.33890,N,08620.16093,W,0.019,213.47,260623,,,D*77
2023-06-26T14:07:45.154Z,1687788465.154 [NAL9602](INFO): GPS fix at 20230626T140745: (43.222315, -86.336016)
2023-06-26T14:07:48.311Z,1687788468.311 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140748.00,A,4313.33891,N,08620.16095,W,0.058,213.47,260623,,,D*78
2023-06-26T14:07:48.313Z,1687788468.313 [NAL9602](INFO): GPS fix at 20230626T140748: (43.222315, -86.336016)
2023-06-26T14:07:51.139Z,1687788471.139 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140751.00,A,4313.33886,N,08620.16091,W,0.039,213.47,260623,,,D*75
2023-06-26T14:07:51.141Z,1687788471.141 [NAL9602](INFO): GPS fix at 20230626T140751: (43.222314, -86.336015)
2023-06-26T14:07:54.371Z,1687788474.371 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140754.00,A,4313.33882,N,08620.16086,W,0.019,213.47,260623,,,D*70
2023-06-26T14:07:54.374Z,1687788474.374 [NAL9602](INFO): GPS fix at 20230626T140754: (43.222314, -86.336014)
2023-06-26T14:07:54.798Z,1687788474.798 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2023-06-26T14:07:55.193Z,1687788475.193 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.334000
2023-06-26T14:07:55.193Z,1687788475.193 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-06-26T14:07:55.194Z,1687788475.194 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-06-26T14:07:55.601Z,1687788475.601 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-06-26T14:07:55.602Z,1687788475.602 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-06-26T14:07:55.602Z,1687788475.602 [IBIT](IMPORTANT): Pressure:9.557750 PSI
2023-06-26T14:07:55.602Z,1687788475.602 [IBIT](IMPORTANT): Humidity:3.558784 %
2023-06-26T14:07:56.021Z,1687788476.021 [IBIT](IMPORTANT): Vehicle Pitch:-15.041125 degrees
2023-06-26T14:07:56.021Z,1687788476.021 [IBIT](IMPORTANT): Vehicle  Roll:-3.022426 degrees
2023-06-26T14:07:56.022Z,1687788476.022 [IBIT](IMPORTANT): Vehicle  Heading:212.564087 degrees
2023-06-26T14:07:56.399Z,1687788476.399 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-06-26T14:07:56.399Z,1687788476.399 [IBIT](IMPORTANT): buoyancyNeutral: 516.055969 cc
2023-06-26T14:07:56.399Z,1687788476.399 [IBIT](IMPORTANT): massDefault: 1.750000 cm
2023-06-26T14:07:56.399Z,1687788476.399 [IBIT](IMPORTANT): stopDepth: 100.000000 m
2023-06-26T14:07:56.400Z,1687788476.400 [IBIT](IMPORTANT): abortDepth: 120.000000 m
2023-06-26T14:07:56.400Z,1687788476.400 [IBIT](IMPORTANT): IBIT FAILED
2023-06-26T14:07:56.815Z,1687788476.815 [Default] Stopped
2023-06-26T14:07:56.815Z,1687788476.815 [Default](DEBUG): Aggregate::uninitialize Default
2023-06-26T14:07:56.816Z,1687788476.816 [Default:B.GoToSurface] Stopped
2023-06-26T14:07:56.816Z,1687788476.816 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-26T14:07:56.816Z,1687788476.816 [Default:CheckIn] Stopped
2023-06-26T14:07:56.816Z,1687788476.816 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T14:07:56.816Z,1687788476.816 [Default:CheckIn:C.Wait] Stopped
2023-06-26T14:07:56.816Z,1687788476.816 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T14:07:56.816Z,1687788476.816 [MissionManager](IMPORTANT): Started mission transit
2023-06-26T14:07:56.817Z,1687788476.817 [transit] Running Loop=1
2023-06-26T14:07:56.817Z,1687788476.817 [transit](DEBUG): Aggregate::initialize transit
2023-06-26T14:07:56.817Z,1687788476.817 [transit:StandardEnvelopes] Running Loop=1
2023-06-26T14:07:56.817Z,1687788476.817 [transit:StandardEnvelopes](DEBUG): Aggregate::initialize transit:StandardEnvelopes
2023-06-26T14:07:56.817Z,1687788476.817 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2023-06-26T14:07:56.817Z,1687788476.817 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2023-06-26T14:07:56.817Z,1687788476.817 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2023-06-26T14:07:56.817Z,1687788476.817 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2023-06-26T14:07:56.817Z,1687788476.817 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2023-06-26T14:07:56.817Z,1687788476.817 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2023-06-26T14:07:56.818Z,1687788476.818 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2023-06-26T14:07:56.818Z,1687788476.818 [transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2023-06-26T14:07:56.818Z,1687788476.818 [transit:MassHold.Pitch] Running Loop=1
2023-06-26T14:07:56.818Z,1687788476.818 [transit:MassHold.Pitch](DEBUG): Initialize.
2023-06-26T14:07:56.818Z,1687788476.818 [transit:B] Running Loop=1
2023-06-26T14:07:56.819Z,1687788476.819 [transit:MassHold.Pitch] Running Loop=1
2023-06-26T14:07:56.819Z,1687788476.819 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2023-06-26T14:07:56.819Z,1687788476.819 [transit:StandardEnvelopes] Running Loop=1
2023-06-26T14:07:56.819Z,1687788476.819 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2023-06-26T14:07:56.820Z,1687788476.820 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2023-06-26T14:07:56.821Z,1687788476.821 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2023-06-26T14:07:56.821Z,1687788476.821 [transit:B] Stopped
2023-06-26T14:07:56.821Z,1687788476.821 [transit:C] Running Loop=1
2023-06-26T14:07:57.195Z,1687788477.195 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140757.00,A,4313.33880,N,08620.16080,W,0.039,213.47,260623,,,D*75
2023-06-26T14:07:57.197Z,1687788477.197 [NAL9602](INFO): GPS fix at 20230626T140757: (43.222313, -86.336013)
2023-06-26T14:07:57.218Z,1687788477.218 [transit:C] Stopped
2023-06-26T14:07:57.218Z,1687788477.218 [transit:E] Running Loop=1
2023-06-26T14:07:57.639Z,1687788477.639 [transit:E] Stopped
2023-06-26T14:07:57.639Z,1687788477.639 [transit:F] Running Loop=1
2023-06-26T14:07:58.019Z,1687788478.019 [transit:F] Stopped
2023-06-26T14:07:58.019Z,1687788478.019 [transit:G] Running Loop=1
2023-06-26T14:07:58.417Z,1687788478.417 [transit:G] Stopped
2023-06-26T14:07:58.417Z,1687788478.417 [transit:Transit] Running Loop=1
2023-06-26T14:07:58.417Z,1687788478.417 [transit:Transit](DEBUG): Aggregate::initialize transit:Transit
2023-06-26T14:07:58.418Z,1687788478.418 [transit:Transit:A.Pitch] Running Loop=1
2023-06-26T14:07:58.418Z,1687788478.418 [transit:Transit:A.Pitch](DEBUG): Initialize.
2023-06-26T14:07:58.418Z,1687788478.418 [transit:Transit:B.SetSpeed] Running Loop=1
2023-06-26T14:07:58.418Z,1687788478.418 [transit:Transit:B.SetSpeed](DEBUG): Initialize.
2023-06-26T14:07:58.418Z,1687788478.418 [transit:Transit:Wpt1.Waypoint] Running Loop=1
2023-06-26T14:07:58.418Z,1687788478.418 [transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2023-06-26T14:07:58.419Z,1687788478.419 [transit:Transit:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 43.200169,-86.364899
2023-06-26T14:07:58.420Z,1687788478.420 [transit:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2023-06-26T14:07:58.835Z,1687788478.835 [transit:Transit:B.SetSpeed] Running Loop=1
2023-06-26T14:07:58.835Z,1687788478.835 [transit:Transit:A.Pitch] Running Loop=1
2023-06-26T14:08:29.993Z,1687788509.993 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T14:08:47.641Z,1687788527.641 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T140847
2023-06-26T14:08:55.211Z,1687788535.211 [DataOverHttps](INFO): Received command: stop
2023-06-26T14:08:55.213Z,1687788535.213 [CommandExec](IMPORTANT): got command stop
2023-06-26T14:08:55.213Z,1687788535.213 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2023-06-26T14:08:55.458Z,1687788535.458 [MissionManager](INFO): MissionManager is completed.
2023-06-26T14:08:55.458Z,1687788535.458 [MissionManager](INFO): Uninitializing Mission transit
2023-06-26T14:08:55.459Z,1687788535.459 [transit] Stopped
2023-06-26T14:08:55.459Z,1687788535.459 [transit](DEBUG): Aggregate::uninitialize transit
2023-06-26T14:08:55.459Z,1687788535.459 [transit:StandardEnvelopes] Stopped
2023-06-26T14:08:55.459Z,1687788535.459 [transit:StandardEnvelopes](DEBUG): Aggregate::uninitialize transit:StandardEnvelopes
2023-06-26T14:08:55.459Z,1687788535.459 [transit:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2023-06-26T14:08:55.459Z,1687788535.459 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2023-06-26T14:08:55.459Z,1687788535.459 [transit:StandardEnvelopes:B.DepthEnvelope] Stopped
2023-06-26T14:08:55.459Z,1687788535.459 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2023-06-26T14:08:55.459Z,1687788535.459 [transit:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2023-06-26T14:08:55.459Z,1687788535.459 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2023-06-26T14:08:55.459Z,1687788535.459 [transit:BuoyancyHold.Buoyancy] Stopped
2023-06-26T14:08:55.459Z,1687788535.459 [transit:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2023-06-26T14:08:55.459Z,1687788535.459 [transit:MassHold.Pitch] Stopped
2023-06-26T14:08:55.460Z,1687788535.460 [transit:Transit] Stopped
2023-06-26T14:08:55.460Z,1687788535.460 [transit:Transit](DEBUG): Aggregate::uninitialize transit:Transit
2023-06-26T14:08:55.460Z,1687788535.460 [transit:Transit:A.Pitch] Stopped
2023-06-26T14:08:55.460Z,1687788535.460 [transit:Transit:B.SetSpeed] Stopped
2023-06-26T14:08:55.460Z,1687788535.460 [transit:Transit:B.SetSpeed](DEBUG): Uninitialize.
2023-06-26T14:08:55.460Z,1687788535.460 [transit:Transit:Wpt1.Waypoint] Stopped
2023-06-26T14:08:55.460Z,1687788535.460 [transit:Transit:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2023-06-26T14:08:55.873Z,1687788535.873 [MissionManager](IMPORTANT): Started mission Default
2023-06-26T14:08:55.873Z,1687788535.873 [Default] Running Loop=1
2023-06-26T14:08:55.873Z,1687788535.873 [Default](DEBUG): Aggregate::initialize Default
2023-06-26T14:08:55.873Z,1687788535.873 [Default:B.GoToSurface] Running Loop=1
2023-06-26T14:08:55.874Z,1687788535.874 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-26T14:08:55.874Z,1687788535.874 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-26T14:08:55.874Z,1687788535.874 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-26T14:08:55.874Z,1687788535.874 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-26T14:08:55.875Z,1687788535.875 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-26T14:08:55.875Z,1687788535.875 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-26T14:08:55.875Z,1687788535.875 [Default:A.Wait] Running Loop=1
2023-06-26T14:08:55.876Z,1687788535.876 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-06-26T14:09:09.204Z,1687788549.204 [Default:A.Wait](INFO): Done Waiting.
2023-06-26T14:09:09.204Z,1687788549.204 [Default:A.Wait] Stopped
2023-06-26T14:09:09.204Z,1687788549.204 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T14:09:09.605Z,1687788549.605 [Default:CheckIn] Running Loop=1
2023-06-26T14:09:09.605Z,1687788549.605 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-26T14:09:09.605Z,1687788549.605 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-26T14:09:11.611Z,1687788551.611 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140911.00,A,4313.33897,N,08620.16062,W,0.194,213.47,260623,,,D*75
2023-06-26T14:09:11.621Z,1687788551.621 [NAL9602](INFO): GPS fix at 20230626T140911: (43.222316, -86.336010)
2023-06-26T14:09:11.631Z,1687788551.631 [Default:CheckIn:Read_GPS] Stopped
2023-06-26T14:09:11.631Z,1687788551.631 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-26T14:09:18.843Z,1687788558.843 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T122707/Courier0064.lzma
2023-06-26T14:09:19.846Z,1687788559.846 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0064.lzma.bak
2023-06-26T14:09:19.846Z,1687788559.846 [DataOverHttps](INFO): SBD MOMSN=18431373
2023-06-26T14:09:36.099Z,1687788576.099 [DataOverHttps](INFO): Sending 1327 bytes from file Logs/20230626T122707/Express0065.lzma
2023-06-26T14:09:37.602Z,1687788577.602 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0065.lzma.bak
2023-06-26T14:09:37.602Z,1687788577.602 [DataOverHttps](INFO): SBD MOMSN=18431376
2023-06-26T14:09:39.512Z,1687788579.512 [Default:CheckIn:Read_Iridium] Stopped
2023-06-26T14:09:39.512Z,1687788579.512 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-26T14:09:39.512Z,1687788579.512 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-26T14:10:13.416Z,1687788613.416 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T14:10:44.133Z,1687788644.133 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T14:10:56.918Z,1687788656.918 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T141056
2023-06-26T14:11:06.824Z,1687788666.824 [DataOverHttps](INFO): Received command: sched asap "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m" 1s21s 1 2
2023-06-26T14:11:06.836Z,1687788666.836 [CommandExec](IMPORTANT): got command schedule asap "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m" 1s21s 1 2.000000
2023-06-26T14:11:06.837Z,1687788666.837 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=1s21s
2023-06-26T14:11:06.838Z,1687788666.838 [CommandExec](IMPORTANT): Scheduled #6 (#1 of 2 with id='1s21s'): "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m", ASAP
2023-06-26T14:11:07.818Z,1687788667.818 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T141107
2023-06-26T14:11:16.527Z,1687788676.527 [DataOverHttps](INFO): Received command: sched asap "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run" 1s21s 2 2
2023-06-26T14:11:16.591Z,1687788676.591 [CommandExec](IMPORTANT): got command schedule asap "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run" 1s21s 2 2.000000
2023-06-26T14:11:16.591Z,1687788676.591 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=1s21s
2023-06-26T14:11:16.594Z,1687788676.594 [CommandExec](IMPORTANT): Scheduled #7 (#2 of 2 with id='1s21s'): "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run", ASAP
2023-06-26T14:11:16.704Z,1687788676.704 [CommandExec](IMPORTANT): got command load ./Missions/Transport/transit.tl
2023-06-26T14:11:16.704Z,1687788676.704 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/transit.tl
2023-06-26T14:11:16.704Z,1687788676.704 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file ./Missions/Transport/transit.tx
2023-06-26T14:11:16.770Z,1687788676.770 [MissionManager](INFO): DefineArg transit.MissionTimeout = 60.000000 min
2023-06-26T14:11:16.772Z,1687788676.772 [MissionManager](INFO): DefineArg transit.NeedCommsTime = 30.000000 min
2023-06-26T14:11:16.774Z,1687788676.774 [MissionManager](INFO): DefineArg transit.Latitude = nan arcdeg
2023-06-26T14:11:16.776Z,1687788676.776 [MissionManager](INFO): DefineArg transit.Longitude = nan arcdeg
2023-06-26T14:11:16.778Z,1687788676.778 [MissionManager](INFO): DefineArg transit.Northings = 0.000000 m
2023-06-26T14:11:16.796Z,1687788676.796 [MissionManager](INFO): DefineArg transit.Eastings = 0.000000 m
2023-06-26T14:11:16.798Z,1687788676.798 [MissionManager](INFO): DefineArg transit.Depth = 10.000000 m
2023-06-26T14:11:16.801Z,1687788676.801 [MissionManager](INFO): DefineArg transit.Speed = 1.000000 m/s
2023-06-26T14:11:16.803Z,1687788676.803 [MissionManager](INFO): DefineArg transit.MaxDepth = 20.000000 m
2023-06-26T14:11:16.805Z,1687788676.805 [MissionManager](INFO): DefineArg transit.MinOffshore = 1.000000 km
2023-06-26T14:11:16.807Z,1687788676.807 [MissionManager](INFO): DefineArg transit.MinAltitude = 7.000000 m
2023-06-26T14:11:16.832Z,1687788676.832 [MissionManager](INFO): DefineArg transit.MassHold = 1 bool
2023-06-26T14:11:16.834Z,1687788676.834 [MissionManager](INFO): DefineArg transit.BuoyancyHold = 1 bool
2023-06-26T14:11:16.834Z,1687788676.834 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.xml
2023-06-26T14:11:16.967Z,1687788676.967 [MissionManager](INFO): DefineArg transit:NeedComms.DiveInterval = 3.000000 h
2023-06-26T14:11:16.978Z,1687788676.978 [MissionManager](INFO): DefineArg transit:NeedComms.WaitForPitchUp = 10.000000 min
2023-06-26T14:11:16.980Z,1687788676.980 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacePitch = 20.000000 arcdeg
2023-06-26T14:11:16.982Z,1687788676.982 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceDepthRate = nan m/s
2023-06-26T14:11:16.984Z,1687788676.984 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceSpeed = 1.000000 m/s
2023-06-26T14:11:16.986Z,1687788676.986 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacingTimeout = 1000.000000 s
2023-06-26T14:11:16.988Z,1687788676.988 [MissionManager](INFO): DefineArg transit:NeedComms.GPSTimeout = 7.000000 min
2023-06-26T14:11:16.990Z,1687788676.990 [MissionManager](INFO): DefineArg transit:NeedComms.CommsTimeout = 30.000000 min
2023-06-26T14:11:17.026Z,1687788677.026 [transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-26T14:11:17.066Z,1687788677.066 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.xml
2023-06-26T14:11:17.100Z,1687788677.100 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinAltitude = 5.000000 m
2023-06-26T14:11:17.102Z,1687788677.102 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepthIgnore = 0.000000 m
2023-06-26T14:11:17.104Z,1687788677.104 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepth = 200.000000 m
2023-06-26T14:11:17.106Z,1687788677.106 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinOffshore = 2000.000000 m
2023-06-26T14:11:17.107Z,1687788677.107 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2023-06-26T14:11:17.112Z,1687788677.112 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2023-06-26T14:11:17.118Z,1687788677.118 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2023-06-26T14:11:17.126Z,1687788677.126 [transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2023-06-26T14:11:17.129Z,1687788677.129 [transit:MassHold.Pitch](DEBUG): Construct.
2023-06-26T14:11:17.134Z,1687788677.134 [transit:Transit:A.Pitch](DEBUG): Construct.
2023-06-26T14:11:17.138Z,1687788677.138 [transit:Transit:B.SetSpeed](DEBUG): Construct.
2023-06-26T14:11:17.140Z,1687788677.140 [transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2023-06-26T14:11:17.181Z,1687788677.181 [MissionManager](DEBUG): 
mission transit {
  """
  Vehicle transits to desired waypoint and can be commanded to use/hold
  mass or buoyancy.
  """

  arguments {
    MissionTimeout = 60 minute
      """
      Maximum duration of mission
      """

    NeedCommsTime = 30 minute
      """
      How often to surface for commumications
      """

    Latitude = NaN degree
      """
      Latitude of waypoint to seek. If set to NaN, uses latitude at mission
      initialization.
      """

    Longitude = NaN degree
      """
      Longitude of waypoint to seek. If set to NaN, uses longitude at mission
      initialization.
      """

    Northings = 0 meter
      """
      Northward distance of the waypoint to seek. If combined with Latitude
      and/or Longitude, this is an offset from the specified Latitude and/or
      Longitude.
      """

    Eastings = 0 meter
      """
      Eastward distance of the waypoint to seek. If combined with Latitude
      and/or Longitude, this is an offset from the specified Latitude and/or
      Longitude.
      """

    Depth = 10 meter
      """
      Depth of flat and level flight during the mission.
      """

    Speed = 1 meter_per_second
      """
      Speed of vehicle (relative to water) during the mission.
      """

    MaxDepth = 20 meter
      """
      Maximum depth for the entire mission.
      """

    MinOffshore = 1 kilometer
      """
      Minimum distance offshore for the entire mission.
      """

    MinAltitude = 7 meter
      """
      Minimum height above the sea floor for the entire mission.
      """

    MassHold = true
      """
      Set to True in order to hold mass at default position, False to allow
      mass to run on its own.
      """

    BuoyancyHold = true
      """
      Set to True in order to hold buoyancy at neutral position, False to
      allow buoyancy to run on its own.
      """
  }

  timeout duration=MissionTimeout

  insert id="NeedComms" Insert/NeedComms.xml

  assign in sequence NeedComms:DiveInterval = NeedCommsTime

  assign in sequence NeedComms:WaitForPitchUp = 1 second

  insert Insert/StandardEnvelopes.xml

  assign in sequence StandardEnvelopes:MinAltitude = MinAltitude

  assign in sequence StandardEnvelopes:MaxDepth = MaxDepth

  assign in sequence StandardEnvelopes:MinOffshore = MinOffshore

  behavior Guidance:Buoyancy id="BuoyancyHold" {
    run while ( BuoyancyHold )

    set position = Control:VerticalControl.buoyancyNeutral
  }

  behavior Guidance:Pitch id="MassHold" {
    run while ( MassHold )

    set massPosition = Control:VerticalControl.massDefault
  }

  aggregate Transit {
    run in sequence

    behavior Guidance:Pitch {
      run in parallel

      set depth = Depth
    }

    behavior Guidance:SetSpeed {
      run in parallel

      set speed = Speed
    }

    behavior Guidance:Waypoint id="Wpt1" {
      run in sequence

      set latitude = Latitude
      set longitude = Longitude
      set northingsDelta = Northings
      set eastingsDelta = Eastings
    }

    call id="PhoneHome" refId="NeedComms"
  }
}


2023-06-26T14:11:17.181Z,1687788677.181 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/transit.tl
2023-06-26T14:11:24.833Z,1687788684.833 [CommandExec](IMPORTANT): got command set transit.MissionTimeout 30 minute
2023-06-26T14:11:24.834Z,1687788684.834 [CommandExec](IMPORTANT): got command set transit.NeedCommsTime 12 minute
2023-06-26T14:11:24.834Z,1687788684.834 [CommandExec](IMPORTANT): got command set transit.Latitude 43.20017 degree
2023-06-26T14:11:24.835Z,1687788684.835 [CommandExec](IMPORTANT): got command set transit.Longitude -86.3649 degree
2023-06-26T14:11:24.836Z,1687788684.836 [CommandExec](IMPORTANT): got command set transit.Depth 1 meter
2023-06-26T14:11:24.837Z,1687788684.837 [CommandExec](IMPORTANT): got command set transit.MaxDepth 2 meter
2023-06-26T14:11:27.630Z,1687788687.630 [CommandExec](IMPORTANT): got command set transit.MinOffshore 0.00001 kilometer
2023-06-26T14:11:27.631Z,1687788687.631 [CommandExec](IMPORTANT): got command set transit.MinAltitude 2 meter
2023-06-26T14:11:27.631Z,1687788687.631 [CommandExec](IMPORTANT): got command run
2023-06-26T14:11:27.633Z,1687788687.633 [CommandExec](IMPORTANT): Running 
2023-06-26T14:11:27.785Z,1687788687.785 [Default] Stopped
2023-06-26T14:11:27.785Z,1687788687.785 [Default](DEBUG): Aggregate::uninitialize Default
2023-06-26T14:11:27.785Z,1687788687.785 [Default:B.GoToSurface] Stopped
2023-06-26T14:11:27.785Z,1687788687.785 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-26T14:11:27.785Z,1687788687.785 [Default:CheckIn] Stopped
2023-06-26T14:11:27.785Z,1687788687.785 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-26T14:11:27.785Z,1687788687.785 [Default:CheckIn:C.Wait] Stopped
2023-06-26T14:11:27.785Z,1687788687.785 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-26T14:11:27.785Z,1687788687.785 [MissionManager](IMPORTANT): Started mission transit
2023-06-26T14:11:27.786Z,1687788687.786 [transit] Running Loop=1
2023-06-26T14:11:27.786Z,1687788687.786 [transit](DEBUG): Aggregate::initialize transit
2023-06-26T14:11:27.786Z,1687788687.786 [transit:StandardEnvelopes] Running Loop=1
2023-06-26T14:11:27.786Z,1687788687.786 [transit:StandardEnvelopes](DEBUG): Aggregate::initialize transit:StandardEnvelopes
2023-06-26T14:11:27.786Z,1687788687.786 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2023-06-26T14:11:27.786Z,1687788687.786 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2023-06-26T14:11:27.786Z,1687788687.786 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2023-06-26T14:11:27.786Z,1687788687.786 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2023-06-26T14:11:27.787Z,1687788687.787 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2023-06-26T14:11:27.787Z,1687788687.787 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2023-06-26T14:11:27.787Z,1687788687.787 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2023-06-26T14:11:27.787Z,1687788687.787 [transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2023-06-26T14:11:27.787Z,1687788687.787 [transit:MassHold.Pitch] Running Loop=1
2023-06-26T14:11:27.787Z,1687788687.787 [transit:MassHold.Pitch](DEBUG): Initialize.
2023-06-26T14:11:27.787Z,1687788687.787 [transit:B] Running Loop=1
2023-06-26T14:11:27.788Z,1687788687.788 [transit:MassHold.Pitch] Running Loop=1
2023-06-26T14:11:27.788Z,1687788687.788 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2023-06-26T14:11:27.788Z,1687788687.788 [transit:StandardEnvelopes] Running Loop=1
2023-06-26T14:11:27.788Z,1687788687.788 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2023-06-26T14:11:27.789Z,1687788687.789 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2023-06-26T14:11:27.789Z,1687788687.789 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2023-06-26T14:11:27.789Z,1687788687.789 [transit:B] Stopped
2023-06-26T14:11:27.790Z,1687788687.790 [transit:C] Running Loop=1
2023-06-26T14:11:28.212Z,1687788688.212 [transit:C] Stopped
2023-06-26T14:11:28.212Z,1687788688.212 [transit:E] Running Loop=1
2023-06-26T14:11:28.588Z,1687788688.588 [transit:E] Stopped
2023-06-26T14:11:28.588Z,1687788688.588 [transit:F] Running Loop=1
2023-06-26T14:11:28.996Z,1687788688.996 [transit:F] Stopped
2023-06-26T14:11:28.996Z,1687788688.996 [transit:G] Running Loop=1
2023-06-26T14:11:29.407Z,1687788689.407 [transit:G] Stopped
2023-06-26T14:11:29.408Z,1687788689.408 [transit:Transit] Running Loop=1
2023-06-26T14:11:29.408Z,1687788689.408 [transit:Transit](DEBUG): Aggregate::initialize transit:Transit
2023-06-26T14:11:29.408Z,1687788689.408 [transit:Transit:A.Pitch] Running Loop=1
2023-06-26T14:11:29.408Z,1687788689.408 [transit:Transit:A.Pitch](DEBUG): Initialize.
2023-06-26T14:11:29.408Z,1687788689.408 [transit:Transit:B.SetSpeed] Running Loop=1
2023-06-26T14:11:29.408Z,1687788689.408 [transit:Transit:B.SetSpeed](DEBUG): Initialize.
2023-06-26T14:11:29.409Z,1687788689.409 [transit:Transit:Wpt1.Waypoint] Running Loop=1
2023-06-26T14:11:29.409Z,1687788689.409 [transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2023-06-26T14:11:29.410Z,1687788689.410 [transit:Transit:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 43.200169,-86.364899
2023-06-26T14:11:29.411Z,1687788689.411 [transit:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2023-06-26T14:11:29.803Z,1687788689.803 [transit:Transit:B.SetSpeed] Running Loop=1
2023-06-26T14:11:29.803Z,1687788689.803 [transit:Transit:A.Pitch] Running Loop=1
2023-06-26T14:12:17.781Z,1687788737.781 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.251591
2023-06-26T14:12:49.908Z,1687788769.908 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:13:25.050Z,1687788805.050 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:14:00.214Z,1687788840.214 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:14:35.360Z,1687788875.360 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:15:10.510Z,1687788910.510 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:15:43.316Z,1687788943.316 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002924
2023-06-26T14:17:32.996Z,1687789052.996 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:17:38.017Z,1687789058.017 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247669
2023-06-26T14:18:56.044Z,1687789136.044 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002935
2023-06-26T14:19:54.276Z,1687789194.276 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:19:56.284Z,1687789196.284 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.243252
2023-06-26T14:20:29.416Z,1687789229.416 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:21:04.556Z,1687789264.556 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:21:12.831Z,1687789272.831 [transit:NeedComms] Running Loop=1
2023-06-26T14:21:12.831Z,1687789272.831 [transit:NeedComms](DEBUG): Aggregate::initialize transit:NeedComms
2023-06-26T14:21:12.831Z,1687789272.831 [transit:NeedComms:B.GoToSurface] Running Loop=1
2023-06-26T14:21:12.832Z,1687789272.832 [transit:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-26T14:21:12.832Z,1687789272.832 [transit:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2023-06-26T14:21:12.833Z,1687789272.833 [transit:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2023-06-26T14:21:12.833Z,1687789272.833 [transit:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2023-06-26T14:21:12.833Z,1687789272.833 [transit:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2023-06-26T14:21:12.834Z,1687789272.834 [transit:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-26T14:21:12.834Z,1687789272.834 [transit:NeedComms:A] Running Loop=1
2023-06-26T14:21:12.836Z,1687789272.836 [transit:NeedComms:A](INFO): last time_fix was: 1687788551.000000 second since 1970/01/01T00:00:00Z 
2023-06-26T14:21:12.836Z,1687789272.836 [transit:NeedComms:A] Stopped
2023-06-26T14:21:25.363Z,1687789285.363 [transit:NeedComms:C] Running Loop=1
2023-06-26T14:21:25.754Z,1687789285.754 [transit:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-06-26T14:21:39.696Z,1687789299.696 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:21:58.061Z,1687789318.061 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T14:21:58.140Z,1687789318.140 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T14:22:13.352Z,1687789333.352 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002908
2023-06-26T14:22:29.568Z,1687789349.568 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T14:22:30.787Z,1687789350.787 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,142230.00,A,4313.09008,N,08620.45041,W,0.292,116.99,260623,,,A*7A
2023-06-26T14:22:30.790Z,1687789350.790 [NAL9602](INFO): GPS fix at 20230626T142230: (43.218168, -86.340840)
2023-06-26T14:22:30.802Z,1687789350.802 [UniversalFixResidualReporter](INFO): Fix residual: 8.6 %DT, over the last 569.8 m. Residual distance 49.2 m at bearing -0.3 degrees. Fix at (43.2182, -86.3408) with 604.9 m made good.
2023-06-26T14:22:30.805Z,1687789350.805 [transit:NeedComms:C] Stopped
2023-06-26T14:22:30.806Z,1687789350.806 [transit:NeedComms:D] Running Loop=1
2023-06-26T14:22:31.226Z,1687789351.226 [transit:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-26T14:22:42.976Z,1687789362.976 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230626T122707/Courier0069.lzma
2023-06-26T14:22:43.978Z,1687789363.978 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0069.lzma.bak
2023-06-26T14:22:43.978Z,1687789363.978 [DataOverHttps](INFO): SBD MOMSN=18431461
2023-06-26T14:23:02.517Z,1687789382.517 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T14:23:04.169Z,1687789384.169 [DataOverHttps](INFO): Sending 992 bytes from file Logs/20230626T122707/Express0071.lzma
2023-06-26T14:23:05.170Z,1687789385.170 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0071.lzma.bak
2023-06-26T14:23:05.170Z,1687789385.170 [DataOverHttps](INFO): SBD MOMSN=18431464
2023-06-26T14:23:21.243Z,1687789401.243 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230626T122707/Express0074.lzma
2023-06-26T14:23:22.246Z,1687789402.246 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Express0074.lzma.bak
2023-06-26T14:23:22.246Z,1687789402.246 [DataOverHttps](INFO): SBD MOMSN=18431491
2023-06-26T14:23:23.946Z,1687789403.946 [transit:NeedComms:D] Stopped
2023-06-26T14:23:23.947Z,1687789403.947 [transit:NeedComms:E] Running Loop=1
2023-06-26T14:23:24.346Z,1687789404.346 [transit:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-06-26T14:23:25.955Z,1687789405.955 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,142326.00,A,4313.09028,N,08620.45165,W,0.350,42.70,260623,,,A*41
2023-06-26T14:23:25.969Z,1687789405.969 [NAL9602](INFO): GPS fix at 20230626T142326: (43.218171, -86.340861)
2023-06-26T14:23:25.987Z,1687789405.987 [transit:NeedComms:E] Stopped
2023-06-26T14:23:25.987Z,1687789405.987 [transit:NeedComms](INFO): Completed transit:NeedComms
2023-06-26T14:23:25.987Z,1687789405.987 [transit:NeedComms] Stopped
2023-06-26T14:23:25.992Z,1687789405.992 [transit:NeedComms](DEBUG): Aggregate::uninitialize transit:NeedComms
2023-06-26T14:23:25.992Z,1687789405.992 [transit:NeedComms:B.GoToSurface] Stopped
2023-06-26T14:23:25.992Z,1687789405.992 [transit:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-26T14:23:56.654Z,1687789436.654 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T14:23:56.732Z,1687789436.732 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T14:24:28.702Z,1687789468.702 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T14:24:30.735Z,1687789470.735 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 20.00 deg, mass-position 17.50 mm (1 active estimators).
2023-06-26T14:24:59.404Z,1687789499.404 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-26T14:25:04.436Z,1687789504.436 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:25:07.448Z,1687789507.448 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.279236
2023-06-26T14:25:31.296Z,1687789531.296 [Radio_Surface](INFO): Powering down
2023-06-26T14:25:39.576Z,1687789539.576 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:25:40.580Z,1687789540.580 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-06-26T14:25:55.940Z,1687789555.940 [Radio_Surface](INFO): Powering up
2023-06-26T14:26:01.672Z,1687789561.672 [DataOverHttps](INFO): Radio surface powered ON.
2023-06-26T14:26:31.792Z,1687789591.792 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:27:06.936Z,1687789626.936 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:27:42.076Z,1687789662.076 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:28:17.224Z,1687789697.224 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:28:52.364Z,1687789732.364 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:29:27.504Z,1687789767.504 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:30:02.660Z,1687789802.660 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:30:37.816Z,1687789837.816 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:31:06.628Z,1687789866.628 [RudderServo](ERROR): getPosition uart error serial timeout
2023-06-26T14:31:06.628Z,1687789866.628 [RudderServo](FAULT): Rudder uart error - getPosition..serial timeout
2023-06-26T14:31:06.628Z,1687789866.628 [RudderServo] Communications Fault, FailCount= 1
2023-06-26T14:31:06.628Z,1687789866.628 [RudderServo](ERROR): Communications Fault
2023-06-26T14:31:06.643Z,1687789866.643 [CBIT](ERROR): Communications Fault in component: RudderServo
2023-06-26T14:31:06.769Z,1687789866.769 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-06-26T14:31:06.769Z,1687789866.769 [RudderServo](INFO): Powering down
2023-06-26T14:31:07.609Z,1687789867.609 [RudderServo](DEBUG): Initializing EZServoServo.
2023-06-26T14:31:07.729Z,1687789867.729 [RudderServo](DEBUG): Initializing RudderServo.
2023-06-26T14:31:07.808Z,1687789867.808 [CBIT](INFO): Clearing failed state for component RudderServo
2023-06-26T14:31:07.808Z,1687789867.808 [RudderServo] No Fault, FailCount= 1
2023-06-26T14:31:12.972Z,1687789872.972 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:31:48.112Z,1687789908.112 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:32:23.252Z,1687789943.252 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:32:58.392Z,1687789978.392 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:33:33.532Z,1687790013.532 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:34:08.709Z,1687790048.709 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:34:43.848Z,1687790083.848 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:35:18.988Z,1687790118.988 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:35:27.275Z,1687790127.275 [transit:NeedComms] Running Loop=1
2023-06-26T14:35:27.275Z,1687790127.275 [transit:NeedComms](DEBUG): Aggregate::initialize transit:NeedComms
2023-06-26T14:35:27.275Z,1687790127.275 [transit:NeedComms:B.GoToSurface] Running Loop=1
2023-06-26T14:35:27.275Z,1687790127.275 [transit:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-26T14:35:27.275Z,1687790127.275 [transit:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2023-06-26T14:35:27.276Z,1687790127.276 [transit:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2023-06-26T14:35:27.276Z,1687790127.276 [transit:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2023-06-26T14:35:27.277Z,1687790127.277 [transit:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2023-06-26T14:35:27.277Z,1687790127.277 [transit:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-26T14:35:27.277Z,1687790127.277 [transit:NeedComms:A] Running Loop=1
2023-06-26T14:35:27.279Z,1687790127.279 [transit:NeedComms:A](INFO): last time_fix was: 1687789406.000000 second since 1970/01/01T00:00:00Z 
2023-06-26T14:35:27.279Z,1687790127.279 [transit:NeedComms:A] Stopped
2023-06-26T14:35:34.125Z,1687790134.125 [transit:NeedComms:C] Running Loop=1
2023-06-26T14:35:54.132Z,1687790154.132 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-26T14:36:06.842Z,1687790166.842 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-06-26T14:36:06.920Z,1687790166.920 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-06-26T14:36:15.664Z,1687790175.664 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002880
2023-06-26T14:36:38.366Z,1687790198.366 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-26T14:36:39.595Z,1687790199.595 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,143639.00,A,4312.84209,N,08620.84224,W,0.389,279.97,260623,,,A*72
2023-06-26T14:36:39.602Z,1687790199.602 [NAL9602](INFO): GPS fix at 20230626T143639: (43.214035, -86.347371)
2023-06-26T14:36:39.679Z,1687790199.679 [UniversalFixResidualReporter](INFO): Fix residual: 4.6 %DT, over the last 712.8 m. Residual distance 32.8 m at bearing 126.3 degrees. Fix at (43.2140, -86.3474) with 699.9 m made good.
2023-06-26T14:36:39.708Z,1687790199.708 [transit:NeedComms:C] Stopped
2023-06-26T14:36:39.709Z,1687790199.709 [transit:NeedComms:D] Running Loop=1
2023-06-26T14:36:44.366Z,1687790204.366 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20230626T122707/Courier0076.lzma
2023-06-26T14:36:44.870Z,1687790204.870 [DataOverHttps](INFO): Moved sent file to Logs/20230626T122707/Courier0076.lzma.bak
2023-06-26T14:36:44.870Z,1687790204.870 [DataOverHttps](IMPORTANT): SBD MOMSN=18431553, MTMSN=20230626T143645