2023-02-16T21:34:13.251Z,1676583253.251 [Supervisor](DEBUG): Initializing supervisor.
2023-02-16T21:34:13.256Z,1676583253.256 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-02-16T21:34:13.256Z,1676583253.256 [SyncHandler](INFO): Protected caller Thread ID is 315
2023-02-16T21:34:13.257Z,1676583253.257 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-02-16T21:34:13.258Z,1676583253.258 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-02-16T21:34:13.258Z,1676583253.258 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 316
2023-02-16T21:34:13.262Z,1676583253.262 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-02-16T21:34:13.279Z,1676583253.279 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-02-16T21:34:13.280Z,1676583253.280 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-02-16T21:34:13.281Z,1676583253.281 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 317
2023-02-16T21:34:13.285Z,1676583253.285 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-02-16T21:34:13.286Z,1676583253.286 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-02-16T21:34:13.286Z,1676583253.286 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 318
2023-02-16T21:34:13.288Z,1676583253.288 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-02-16T21:34:13.289Z,1676583253.289 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-02-16T21:34:13.290Z,1676583253.290 [logger ThreadHandler](INFO): Protected caller Thread ID is 319
2023-02-16T21:34:13.293Z,1676583253.293 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-02-16T21:34:13.294Z,1676583253.294 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-02-16T21:34:13.295Z,1676583253.295 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-02-16T21:34:13.818Z,1676583253.818 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-02-16T21:34:13.819Z,1676583253.819 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-02-16T21:34:14.032Z,1676583254.032 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-02-16T21:34:14.033Z,1676583254.033 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-02-16T21:34:14.115Z,1676583254.115 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-02-16T21:34:14.341Z,1676583254.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-02-16T21:34:14.342Z,1676583254.342 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-02-16T21:34:14.422Z,1676583254.422 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-02-16T21:34:14.519Z,1676583254.519 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-02-16T21:34:14.520Z,1676583254.520 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-02-16T21:34:14.862Z,1676583254.862 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-02-16T21:34:14.863Z,1676583254.863 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-02-16T21:34:14.996Z,1676583254.996 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-02-16T21:34:14.997Z,1676583254.997 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-02-16T21:34:15.497Z,1676583255.497 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-02-16T21:34:15.497Z,1676583255.497 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-02-16T21:34:15.689Z,1676583255.689 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-02-16T21:34:15.690Z,1676583255.690 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-02-16T21:34:16.097Z,1676583256.097 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-02-16T21:34:16.098Z,1676583256.098 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-02-16T21:34:16.385Z,1676583256.385 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-02-16T21:34:16.386Z,1676583256.386 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-02-16T21:34:16.532Z,1676583256.532 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-02-16T21:34:16.533Z,1676583256.533 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-02-16T21:34:18.289Z,1676583258.289 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-02-16T21:34:18.290Z,1676583258.290 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-02-16T21:34:18.633Z,1676583258.633 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-02-16T21:34:18.633Z,1676583258.633 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-02-16T21:34:18.857Z,1676583258.857 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-02-16T21:34:18.859Z,1676583258.859 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2023-02-16T21:34:18.860Z,1676583258.860 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2023-02-16T21:34:19.052Z,1676583259.052 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2023-02-16T21:34:19.137Z,1676583259.137 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2023-02-16T21:34:19.276Z,1676583259.276 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2023-02-16T21:34:19.363Z,1676583259.363 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2023-02-16T21:34:19.627Z,1676583259.627 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-02-16T21:34:19.627Z,1676583259.627 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2023-02-16T21:34:19.734Z,1676583259.734 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2023-02-16T21:34:19.847Z,1676583259.847 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2023-02-16T21:34:19.962Z,1676583259.962 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2023-02-16T21:34:20.109Z,1676583260.109 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2023-02-16T21:34:20.209Z,1676583260.209 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2023-02-16T21:34:20.305Z,1676583260.305 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-02-16T21:34:20.316Z,1676583260.316 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-02-16T21:34:20.327Z,1676583260.327 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-02-16T21:34:20.327Z,1676583260.327 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-02-16T21:34:20.427Z,1676583260.427 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-02-16T21:34:20.428Z,1676583260.428 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-02-16T21:34:20.481Z,1676583260.481 [VerticalControl](DEBUG): Construct VerticalControl.
2023-02-16T21:34:20.539Z,1676583260.539 [VerticalControl] Loaded
2023-02-16T21:34:20.540Z,1676583260.540 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-02-16T21:34:20.543Z,1676583260.543 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-02-16T21:34:20.583Z,1676583260.583 [HorizontalControl] Loaded
2023-02-16T21:34:20.583Z,1676583260.583 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-02-16T21:34:20.586Z,1676583260.586 [SpeedControl](DEBUG): Construct SpeedControl.
2023-02-16T21:34:20.589Z,1676583260.589 [SpeedControl] Loaded
2023-02-16T21:34:20.589Z,1676583260.589 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-02-16T21:34:20.591Z,1676583260.591 [LoopControl](DEBUG): Construct LoopControl.
2023-02-16T21:34:20.592Z,1676583260.592 [LoopControl] Loaded
2023-02-16T21:34:20.592Z,1676583260.592 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-02-16T21:34:20.592Z,1676583260.592 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-02-16T21:34:20.593Z,1676583260.593 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-02-16T21:34:20.752Z,1676583260.752 [BuoyancyServo] Loaded
2023-02-16T21:34:20.752Z,1676583260.752 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-02-16T21:34:20.772Z,1676583260.772 [ElevatorServo] Loaded
2023-02-16T21:34:20.772Z,1676583260.772 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-02-16T21:34:20.791Z,1676583260.791 [MassServo] Loaded
2023-02-16T21:34:20.791Z,1676583260.791 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-02-16T21:34:20.809Z,1676583260.809 [RudderServo] Loaded
2023-02-16T21:34:20.809Z,1676583260.809 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-02-16T21:34:20.824Z,1676583260.824 [ThrusterHE] Loaded
2023-02-16T21:34:20.824Z,1676583260.824 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-02-16T21:34:20.824Z,1676583260.824 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-02-16T21:34:20.825Z,1676583260.825 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-02-16T21:34:20.878Z,1676583260.878 [DepthRateCalculator] Loaded
2023-02-16T21:34:20.878Z,1676583260.878 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-02-16T21:34:20.883Z,1676583260.883 [PitchRateCalculator] Loaded
2023-02-16T21:34:20.883Z,1676583260.883 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-02-16T21:34:20.893Z,1676583260.893 [SpeedCalculator] Loaded
2023-02-16T21:34:20.893Z,1676583260.893 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-02-16T21:34:20.897Z,1676583260.897 [YawRateCalculator] Loaded
2023-02-16T21:34:20.897Z,1676583260.897 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-02-16T21:34:20.915Z,1676583260.915 [ElevatorOffsetCalculator] Loaded
2023-02-16T21:34:20.915Z,1676583260.915 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-02-16T21:34:20.916Z,1676583260.916 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-02-16T21:34:20.916Z,1676583260.916 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-02-16T21:34:21.031Z,1676583261.031 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-02-16T21:34:21.031Z,1676583261.031 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-02-16T21:34:21.045Z,1676583261.045 [NavChart] Loaded
2023-02-16T21:34:21.045Z,1676583261.045 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-02-16T21:34:21.051Z,1676583261.051 [UniversalFixResidualReporter] Loaded
2023-02-16T21:34:21.051Z,1676583261.051 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-02-16T21:34:21.051Z,1676583261.051 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-02-16T21:34:21.052Z,1676583261.052 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-02-16T21:34:21.480Z,1676583261.480 [AHRS_M2] Loaded
2023-02-16T21:34:21.481Z,1676583261.481 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-02-16T21:34:21.515Z,1676583261.515 [BackseatComponent] Loaded
2023-02-16T21:34:21.515Z,1676583261.515 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-02-16T21:34:21.517Z,1676583261.517 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408E04E0
2023-02-16T21:34:21.517Z,1676583261.517 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 403
2023-02-16T21:34:21.520Z,1676583261.520 [LcmUniversalReporter] Loaded
2023-02-16T21:34:21.520Z,1676583261.520 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-02-16T21:34:22.342Z,1676583262.342 [BPC1] Loaded
2023-02-16T21:34:22.342Z,1676583262.342 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-02-16T21:34:22.413Z,1676583262.413 [DataOverHttps] Loaded
2023-02-16T21:34:22.413Z,1676583262.413 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-02-16T21:34:22.414Z,1676583262.414 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409104E0
2023-02-16T21:34:22.415Z,1676583262.415 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 404
2023-02-16T21:34:22.435Z,1676583262.435 [Depth_Keller] Loaded
2023-02-16T21:34:22.435Z,1676583262.435 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-02-16T21:34:22.440Z,1676583262.440 [DropWeight] Loaded
2023-02-16T21:34:22.441Z,1676583262.441 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-02-16T21:34:22.459Z,1676583262.459 [MultiRay] Loaded
2023-02-16T21:34:22.459Z,1676583262.459 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread.
2023-02-16T21:34:22.520Z,1676583262.520 [NAL9602] Loaded
2023-02-16T21:34:22.520Z,1676583262.520 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-02-16T21:34:22.550Z,1676583262.550 [Onboard] Loaded
2023-02-16T21:34:22.550Z,1676583262.550 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-02-16T21:34:22.551Z,1676583262.551 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409404E0
2023-02-16T21:34:22.551Z,1676583262.551 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 405
2023-02-16T21:34:22.563Z,1676583262.563 [Power24vConverter] Loaded
2023-02-16T21:34:22.564Z,1676583262.564 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-02-16T21:34:22.577Z,1676583262.577 [Radio_Surface] Loaded
2023-02-16T21:34:22.577Z,1676583262.577 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-02-16T21:34:22.578Z,1676583262.578 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409704E0
2023-02-16T21:34:22.578Z,1676583262.578 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 406
2023-02-16T21:34:22.670Z,1676583262.670 [DAT] Loaded
2023-02-16T21:34:22.670Z,1676583262.670 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-02-16T21:34:22.671Z,1676583262.671 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 409A04E0
2023-02-16T21:34:22.671Z,1676583262.671 [DAT ThreadHandler](INFO): Protected caller Thread ID is 407
2023-02-16T21:34:22.672Z,1676583262.672 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-02-16T21:34:22.672Z,1676583262.672 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-02-16T21:34:23.179Z,1676583263.179 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-02-16T21:34:23.180Z,1676583263.180 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-02-16T21:34:23.526Z,1676583263.526 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-02-16T21:34:23.527Z,1676583263.527 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-02-16T21:34:23.553Z,1676583263.553 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-02-16T21:34:23.554Z,1676583263.554 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-02-16T21:34:23.722Z,1676583263.722 [CTD_Seabird] Loaded
2023-02-16T21:34:23.722Z,1676583263.722 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-02-16T21:34:23.723Z,1676583263.723 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40ACB4E0
2023-02-16T21:34:23.723Z,1676583263.723 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 408
2023-02-16T21:34:23.756Z,1676583263.756 [ESPComponent] Loaded
2023-02-16T21:34:23.756Z,1676583263.756 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-02-16T21:34:23.776Z,1676583263.776 [PAR_Licor] Loaded
2023-02-16T21:34:23.776Z,1676583263.776 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-02-16T21:34:23.806Z,1676583263.806 [WetLabsBB2FL] Loaded
2023-02-16T21:34:23.807Z,1676583263.807 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-02-16T21:34:23.808Z,1676583263.808 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AFB4E0
2023-02-16T21:34:23.808Z,1676583263.808 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 409
2023-02-16T21:34:23.809Z,1676583263.809 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-02-16T21:34:23.809Z,1676583263.809 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-02-16T21:34:24.120Z,1676583264.120 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-02-16T21:34:24.120Z,1676583264.120 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-02-16T21:34:24.258Z,1676583264.258 [SBIT](DEBUG): Construct Startup Built In Test.
2023-02-16T21:34:24.268Z,1676583264.268 [SBIT] Loaded
2023-02-16T21:34:24.268Z,1676583264.268 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-02-16T21:34:24.271Z,1676583264.271 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-02-16T21:34:24.283Z,1676583264.283 [IBIT] Loaded
2023-02-16T21:34:24.284Z,1676583264.284 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-02-16T21:34:24.290Z,1676583264.290 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-02-16T21:34:24.393Z,1676583264.393 [CBIT] Loaded
2023-02-16T21:34:24.393Z,1676583264.393 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-02-16T21:34:24.394Z,1676583264.394 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-02-16T21:34:24.400Z,1676583264.400 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-02-16T21:34:24.403Z,1676583264.403 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-02-16T21:34:24.414Z,1676583264.414 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-02-16T21:34:24.415Z,1676583264.415 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BDE4E0
2023-02-16T21:34:24.415Z,1676583264.415 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 410
2023-02-16T21:34:24.420Z,1676583264.420 [Supervisor](INFO): Main Thread ID is 2769
2023-02-16T21:34:24.420Z,1676583264.420 [Supervisor](DEBUG): Running supervisor.
2023-02-16T21:34:24.420Z,1676583264.420 [CommandExec ThreadHandler](INFO): Handler Thread ID is 411
2023-02-16T21:34:24.421Z,1676583264.421 [CommandExec](INFO): Initializing the command executive.
2023-02-16T21:34:24.422Z,1676583264.422 [CommandLine ThreadHandler](INFO): Handler Thread ID is 412
2023-02-16T21:34:24.424Z,1676583264.424 [controlThread ThreadHandler](INFO): Handler Thread ID is 413
2023-02-16T21:34:24.425Z,1676583264.425 [controlThread](DEBUG): Initializing ControlThread
2023-02-16T21:34:24.426Z,1676583264.426 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-02-16T21:34:24.427Z,1676583264.427 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-02-16T21:34:24.428Z,1676583264.428 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-02-16T21:34:24.429Z,1676583264.429 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-02-16T21:34:24.430Z,1676583264.430 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-02-16T21:34:24.430Z,1676583264.430 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-02-16T21:34:24.431Z,1676583264.431 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-02-16T21:34:24.431Z,1676583264.431 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-02-16T21:34:24.431Z,1676583264.431 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-02-16T21:34:24.433Z,1676583264.433 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-02-16T21:34:24.433Z,1676583264.433 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-02-16T21:34:24.440Z,1676583264.440 [SBIT](INFO): Initialize SBIT Component.
2023-02-16T21:34:24.441Z,1676583264.441 [SBIT](IMPORTANT): git: 2023-02-10
2023-02-16T21:34:24.441Z,1676583264.441 [SBIT](INFO): git hash: c406eb0a7e3d06ad2f4805df3abb847da8df30bc
2023-02-16T21:34:24.441Z,1676583264.441 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-02-16T21:34:24.442Z,1676583264.442 [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-02-16T21:34:24.443Z,1676583264.443 [SBIT](INFO): Beginning SBIT in 58.000000 seconds.
2023-02-16T21:34:24.444Z,1676583264.444 [IBIT](INFO): Initialize IBIT Component.
2023-02-16T21:34:24.445Z,1676583264.445 [CBIT](DEBUG): Initialize CBIT Component.
2023-02-16T21:34:24.446Z,1676583264.446 [logger ThreadHandler](INFO): Handler Thread ID is 414
2023-02-16T21:34:24.456Z,1676583264.456 [CBIT](DEBUG): Initialized mux pins.
2023-02-16T21:34:24.456Z,1676583264.456 [CBIT](DEBUG): Initializing the watchdog timer.
2023-02-16T21:34:24.465Z,1676583264.465 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 416
2023-02-16T21:34:24.476Z,1676583264.476 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 417
2023-02-16T21:34:24.477Z,1676583264.477 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-02-16T21:34:24.480Z,1676583264.480 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-02-16T21:34:24.481Z,1676583264.481 [CBIT](DEBUG): Initializing heartbeat.
2023-02-16T21:34:24.488Z,1676583264.488 [Onboard ThreadHandler](INFO): Handler Thread ID is 418
2023-02-16T21:34:24.506Z,1676583264.506 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 419
2023-02-16T21:34:24.525Z,1676583264.525 [DAT ThreadHandler](INFO): Handler Thread ID is 420
2023-02-16T21:34:24.526Z,1676583264.526 [DAT](INFO): Powering up
2023-02-16T21:34:24.526Z,1676583264.526 [DAT](DEBUG): Initializing DAT.
2023-02-16T21:34:24.529Z,1676583264.529 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 422
2023-02-16T21:34:24.530Z,1676583264.530 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-02-16T21:34:24.533Z,1676583264.533 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 424
2023-02-16T21:34:24.537Z,1676583264.537 [WetLabsBB2FL](INFO): Powering up
2023-02-16T21:34:24.538Z,1676583264.538 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 426
2023-02-16T21:34:24.542Z,1676583264.542 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-02-16T21:34:24.542Z,1676583264.542 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-02-16T21:34:24.542Z,1676583264.542 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-02-16T21:34:24.542Z,1676583264.542 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-02-16T21:34:24.543Z,1676583264.543 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-02-16T21:34:24.543Z,1676583264.543 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-02-16T21:34:24.543Z,1676583264.543 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-02-16T21:34:24.543Z,1676583264.543 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-02-16T21:34:24.553Z,1676583264.553 [CBIT](DEBUG): Deactivating GF circuits.
2023-02-16T21:34:24.553Z,1676583264.553 [CBIT](DEBUG): Deactivating emergency mode.
2023-02-16T21:34:24.588Z,1676583264.588 [CBIT](DEBUG): Backplane powered.
2023-02-16T21:34:24.589Z,1676583264.589 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-02-16T21:34:24.604Z,1676583264.604 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-02-16T21:34:24.628Z,1676583264.628 [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-02-16T21:34:24.652Z,1676583264.652 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-02-16T21:34:24.731Z,1676583264.731 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-02-16T21:34:24.748Z,1676583264.748 [Default:A.Wait](DEBUG): Construct Wait.
2023-02-16T21:34:24.751Z,1676583264.751 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-02-16T21:34:24.774Z,1676583264.774 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-02-16T21:34:24.805Z,1676583264.805 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-02-16T21:34:24.811Z,1676583264.811 [Default:E.Execute](DEBUG): Construct Execute.
2023-02-16T21:34:24.830Z,1676583264.830 [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-02-16T21:34:24.835Z,1676583264.835 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,Power24vConverter,ESPComponent,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-02-16T21:34:24.860Z,1676583264.860 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-02-16T21:34:24.912Z,1676583264.912 [Radio_Surface](INFO): Powering up
2023-02-16T21:34:24.934Z,1676583264.934 [MultiRay](INFO): Powering up MultiRay Lights
2023-02-16T21:34:24.977Z,1676583264.977 [Power24vConverter](INFO): Powering up.
2023-02-16T21:34:25.049Z,1676583265.049 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-02-16T21:34:25.056Z,1676583265.056 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-02-16T21:34:25.057Z,1676583265.057 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-02-16T21:34:25.064Z,1676583265.064 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-02-16T21:34:25.065Z,1676583265.065 [MassServo](DEBUG): Initializing EZServoServo.
2023-02-16T21:34:25.072Z,1676583265.072 [MassServo](DEBUG): Initializing MassServo.
2023-02-16T21:34:25.073Z,1676583265.073 [RudderServo](DEBUG): Initializing EZServoServo.
2023-02-16T21:34:25.080Z,1676583265.080 [RudderServo](DEBUG): Initializing RudderServo.
2023-02-16T21:34:25.081Z,1676583265.081 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-02-16T21:34:25.088Z,1676583265.088 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-02-16T21:34:25.980Z,1676583265.980 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2023-02-16T21:34:25.980Z,1676583265.980 [RudderServo](FAULT): Rudder failed to initialize
2023-02-16T21:34:25.980Z,1676583265.980 [RudderServo] Communications Fault, FailCount= 1
2023-02-16T21:34:25.980Z,1676583265.980 [RudderServo](ERROR): Communications Fault
2023-02-16T21:34:25.984Z,1676583265.984 [CBIT](ERROR): Communications Fault in component: RudderServo
2023-02-16T21:34:26.441Z,1676583266.441 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-02-16T21:34:26.441Z,1676583266.441 [RudderServo](INFO): Powering down
2023-02-16T21:34:26.644Z,1676583266.644 [WetLabsBB2FL](INFO): Powering down
2023-02-16T21:34:26.884Z,1676583266.884 [RudderServo](DEBUG): Initializing EZServoServo.
2023-02-16T21:34:27.005Z,1676583267.005 [RudderServo](DEBUG): Initializing RudderServo.
2023-02-16T21:34:27.009Z,1676583267.009 [CBIT](INFO): Clearing failed state for component RudderServo
2023-02-16T21:34:27.009Z,1676583267.009 [RudderServo] No Fault, FailCount= 1
2023-02-16T21:34:30.665Z,1676583270.665 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-02-16T21:34:31.561Z,1676583271.561 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2023-02-16T21:34:39.410Z,1676583279.410 [DAT](INFO): commRate: 800
2023-02-16T21:34:41.476Z,1676583281.476 [DAT](INFO): entering command mode
2023-02-16T21:34:41.677Z,1676583281.677 [DAT](INFO): setting verbose to 3
2023-02-16T21:34:41.930Z,1676583281.930 [DAT](INFO): set verbose to 3
2023-02-16T21:34:41.930Z,1676583281.930 [DAT](INFO): setting DatVerbose to 27440
2023-02-16T21:34:42.181Z,1676583282.181 [DAT](INFO): set DatVerbose to 27440
2023-02-16T21:34:42.182Z,1676583282.182 [DAT](INFO): setting transmit power to 8
2023-02-16T21:34:42.435Z,1676583282.435 [DAT](INFO): set transmit power to 8
2023-02-16T21:34:42.435Z,1676583282.435 [DAT](INFO): setting local address to 5
2023-02-16T21:34:42.685Z,1676583282.685 [DAT](INFO): set local address to 5
2023-02-16T21:34:42.687Z,1676583282.687 [DAT](INFO): Setting time to: 21:34:42 And date to:2/16/2023
2023-02-16T21:34:42.938Z,1676583282.938 [DAT](INFO): Local DAT time set to Thu Feb 16, 2023  21:34:42  

2023-02-16T21:34:52.834Z,1676583292.834 [NAL9602](INFO): Powering up NAL9602
2023-02-16T21:35:03.746Z,1676583303.746 [NAL9602](INFO): NAL9602 initialized
2023-02-16T21:35:23.162Z,1676583323.162 [SBIT](IMPORTANT): Beginning Startup BIT
2023-02-16T21:35:23.166Z,1676583323.166 [CBIT](IMPORTANT): Beginning ground fault scan
2023-02-16T21:35:23.947Z,1676583323.947 [NAL9602](INFO): SBD MO Status=0, MOMSN=11840, MT Status=0, MTMSN=0
2023-02-16T21:35:23.948Z,1676583323.948 [NAL9602](INFO): No messages in MT queue
2023-02-16T21:35:34.093Z,1676583334.093 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006138
CHAN A1 (24V): -0.007668
CHAN A2 (12V): -0.004661
CHAN A3 (5V): -0.003364
CHAN B0 (3.3V): -0.001055
CHAN B1 (3.15aV): -0.001156
CHAN B2 (3.15bV): -0.001652
CHAN B3 (GND): -0.000541
OPEN: 0.004911
Full Scale: +/- 1 mA
2023-02-16T21:35:57.884Z,1676583357.884 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213556.00,A,3648.17468,N,12147.28178,W,0.175,0.00,160223,,,A*7D
2023-02-16T21:35:57.887Z,1676583357.887 [NAL9602](INFO): GPS fix at 20230216T213556: (36.802911, -121.788030)
2023-02-16T21:36:17.298Z,1676583377.298 [SBIT](IMPORTANT): SBIT PASSED
2023-02-16T21:36:17.298Z,1676583377.298 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-02-16T21:36:17.299Z,1676583377.299 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2023-02-16T21:36:17.299Z,1676583377.299 [SBIT](IMPORTANT): BackseatComponent.alwaysOn=0 bool;

2023-02-16T21:36:17.300Z,1676583377.300 [SBIT](IMPORTANT): DAT.verbosity=1 count;

2023-02-16T21:36:17.300Z,1676583377.300 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2023-02-16T21:36:17.302Z,1676583377.302 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2023-02-16T21:36:17.302Z,1676583377.302 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2023-02-16T21:36:17.302Z,1676583377.302 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2023-02-16T21:36:17.302Z,1676583377.302 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;

2023-02-16T21:36:17.302Z,1676583377.302 [SBIT](IMPORTANT): Express linearApproximation platform_roll_angle 5.000000 degree;

2023-02-16T21:36:17.303Z,1676583377.303 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=292.336296 cubic_centimeter;

2023-02-16T21:36:17.303Z,1676583377.303 [SBIT](IMPORTANT): VerticalControl.massDefault=9.520437 millimeter;

2023-02-16T21:36:17.709Z,1676583377.709 [MissionManager](IMPORTANT): Started mission Startup
2023-02-16T21:36:17.709Z,1676583377.709 [Startup] Running Loop=1
2023-02-16T21:36:17.710Z,1676583377.710 [Startup](DEBUG): Aggregate::initialize Startup
2023-02-16T21:36:17.710Z,1676583377.710 [Startup:A.GoToSurface] Running Loop=1
2023-02-16T21:36:17.710Z,1676583377.710 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-02-16T21:36:17.710Z,1676583377.710 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-02-16T21:36:17.711Z,1676583377.711 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-02-16T21:36:17.711Z,1676583377.711 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-02-16T21:36:17.711Z,1676583377.711 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-02-16T21:36:17.712Z,1676583377.712 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-02-16T21:36:17.713Z,1676583377.713 [Startup:StartupSatComms] Running Loop=1
2023-02-16T21:36:17.713Z,1676583377.713 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-02-16T21:36:17.714Z,1676583377.714 [Startup:StartupSatComms:A] Running Loop=1
2023-02-16T21:36:18.096Z,1676583378.096 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-02-16T21:36:19.707Z,1676583379.707 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213618.00,A,3648.17494,N,12147.28100,W,0.778,0.00,160223,,,A*73
2023-02-16T21:36:19.710Z,1676583379.710 [NAL9602](INFO): GPS fix at 20230216T213618: (36.802916, -121.788017)
2023-02-16T21:36:19.721Z,1676583379.721 [Startup:StartupSatComms:A] Stopped
2023-02-16T21:36:19.721Z,1676583379.721 [Startup:StartupSatComms:B] Running Loop=1
2023-02-16T21:36:20.138Z,1676583380.138 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-02-16T21:36:54.068Z,1676583414.068 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-02-16T21:37:07.779Z,1676583427.779 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-02-16T21:37:19.912Z,1676583439.912 [Startup:StartupSatComms:B](INFO): Timed out from 2023-02-16T21:36:19.7Z
2023-02-16T21:37:19.912Z,1676583439.912 [Startup:StartupSatComms:B] Stopped
2023-02-16T21:37:19.912Z,1676583439.912 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-02-16T21:37:19.912Z,1676583439.912 [Startup:StartupSatComms] Stopped
2023-02-16T21:37:19.912Z,1676583439.912 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-02-16T21:37:19.913Z,1676583439.913 [Startup](INFO): Completed Startup
2023-02-16T21:37:19.913Z,1676583439.913 [MissionManager](INFO): Startup is completed.
2023-02-16T21:37:19.914Z,1676583439.914 [MissionManager](INFO): Uninitializing Mission Startup
2023-02-16T21:37:19.914Z,1676583439.914 [Startup] Stopped
2023-02-16T21:37:19.914Z,1676583439.914 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-02-16T21:37:19.914Z,1676583439.914 [Startup:A.GoToSurface] Stopped
2023-02-16T21:37:19.914Z,1676583439.914 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-02-16T21:37:20.353Z,1676583440.353 [MissionManager](IMPORTANT): Started mission Default
2023-02-16T21:37:20.353Z,1676583440.353 [Default] Running Loop=1
2023-02-16T21:37:20.353Z,1676583440.353 [Default](DEBUG): Aggregate::initialize Default
2023-02-16T21:37:20.353Z,1676583440.353 [Default:B.GoToSurface] Running Loop=1
2023-02-16T21:37:20.353Z,1676583440.353 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-02-16T21:37:20.354Z,1676583440.354 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-02-16T21:37:20.354Z,1676583440.354 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-02-16T21:37:20.354Z,1676583440.354 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-02-16T21:37:20.354Z,1676583440.354 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-02-16T21:37:20.355Z,1676583440.355 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-02-16T21:37:20.355Z,1676583440.355 [Default:A.Wait] Running Loop=1
2023-02-16T21:37:20.355Z,1676583440.355 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-02-16T21:37:21.172Z,1676583441.172 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-02-16T21:37:33.640Z,1676583453.640 [Default:A.Wait](INFO): Done Waiting.
2023-02-16T21:37:33.640Z,1676583453.640 [Default:A.Wait] Stopped
2023-02-16T21:37:33.640Z,1676583453.640 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-02-16T21:37:34.048Z,1676583454.048 [Default:CheckIn] Running Loop=1
2023-02-16T21:37:34.048Z,1676583454.048 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-02-16T21:37:34.048Z,1676583454.048 [Default:CheckIn:Read_GPS] Running Loop=1
2023-02-16T21:37:34.568Z,1676583454.568 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-02-16T21:37:34.847Z,1676583454.847 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-02-16T21:37:36.055Z,1676583456.055 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213734.00,A,3648.17575,N,12147.28074,W,0.447,342.12,160223,,,A*79
2023-02-16T21:37:36.067Z,1676583456.067 [NAL9602](INFO): GPS fix at 20230216T213734: (36.802929, -121.788012)
2023-02-16T21:37:36.078Z,1676583456.078 [Default:CheckIn:Read_GPS] Stopped
2023-02-16T21:37:36.078Z,1676583456.078 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-02-16T21:37:36.494Z,1676583456.494 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-02-16T21:37:47.828Z,1676583467.828 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-02-16T21:37:49.130Z,1676583469.130 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004346
2023-02-16T21:37:56.691Z,1676583476.691 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230216T210838/Courier0014.lzma
2023-02-16T21:37:57.694Z,1676583477.694 [DataOverHttps](INFO): Moved sent file to Logs/20230216T210838/Courier0014.lzma.bak
2023-02-16T21:37:57.694Z,1676583477.694 [DataOverHttps](INFO): SBD MOMSN=17479092
2023-02-16T21:38:01.261Z,1676583481.261 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-02-16T21:38:13.653Z,1676583493.653 [DataOverHttps](INFO): Sending 266 bytes from file Logs/20230216T213413/Courier0000.lzma
2023-02-16T21:38:14.493Z,1676583494.493 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-02-16T21:38:14.654Z,1676583494.654 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Courier0000.lzma.bak
2023-02-16T21:38:14.654Z,1676583494.654 [DataOverHttps](INFO): SBD MOMSN=17479094
2023-02-16T21:38:20.557Z,1676583500.557 [NAL9602](INFO): Not Powering down - fast GPS
2023-02-16T21:38:27.824Z,1676583507.824 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-02-16T21:38:30.939Z,1676583510.939 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230216T213413/Courier0004.lzma
2023-02-16T21:38:31.942Z,1676583511.942 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Courier0004.lzma.bak
2023-02-16T21:38:31.942Z,1676583511.942 [DataOverHttps](INFO): SBD MOMSN=17479098
2023-02-16T21:38:41.716Z,1676583521.716 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-02-16T21:38:50.498Z,1676583530.498 [DataOverHttps](INFO): Sending 579 bytes from file Logs/20230216T210838/Express0016.lzma
2023-02-16T21:38:51.498Z,1676583531.498 [DataOverHttps](INFO): Moved sent file to Logs/20230216T210838/Express0016.lzma.bak
2023-02-16T21:38:51.498Z,1676583531.498 [DataOverHttps](INFO): SBD MOMSN=17479101
2023-02-16T21:38:55.352Z,1676583535.352 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-02-16T21:39:09.320Z,1676583549.320 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-02-16T21:39:11.307Z,1676583551.307 [DataOverHttps](INFO): Sending 1058 bytes from file Logs/20230216T213413/Express0001.lzma
2023-02-16T21:39:12.307Z,1676583552.307 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Express0001.lzma.bak
2023-02-16T21:39:12.307Z,1676583552.307 [DataOverHttps](INFO): SBD MOMSN=17479120
2023-02-16T21:39:28.128Z,1676583568.128 [DataOverHttps](INFO): Sending 117 bytes from file Logs/20230216T213413/Express0005.lzma
2023-02-16T21:39:29.130Z,1676583569.130 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Express0005.lzma.bak
2023-02-16T21:39:29.130Z,1676583569.130 [DataOverHttps](INFO): SBD MOMSN=17479143
2023-02-16T21:39:30.981Z,1676583570.981 [Default:CheckIn:Read_Iridium] Stopped
2023-02-16T21:39:30.981Z,1676583570.981 [Default:CheckIn:C.Wait] Running Loop=1
2023-02-16T21:39:30.981Z,1676583570.981 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-02-16T21:41:50.361Z,1676583710.361 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2023-02-16T21:41:50.364Z,1676583710.364 [BPC1](INFO): Received data from all battery sticks.
2023-02-16T21:44:31.635Z,1676583871.635 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-02-16T21:44:31.635Z,1676583871.635 [Default:CheckIn:C.Wait] Stopped
2023-02-16T21:44:31.635Z,1676583871.635 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-02-16T21:44:31.635Z,1676583871.635 [Default:CheckIn:D] Running Loop=1
2023-02-16T21:44:32.035Z,1676583872.035 [Default:CheckIn:D] Stopped
2023-02-16T21:44:32.035Z,1676583872.035 [Default:CheckIn:E] Running Loop=1
2023-02-16T21:44:32.460Z,1676583872.460 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.194695 min 
2023-02-16T21:44:32.461Z,1676583872.461 [Default:CheckIn:E] Stopped
2023-02-16T21:44:32.461Z,1676583872.461 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-02-16T21:44:32.461Z,1676583872.461 [Default:CheckIn] Stopped
2023-02-16T21:44:32.461Z,1676583872.461 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-02-16T21:44:32.461Z,1676583872.461 [Default:CheckIn](INFO): Running loop #2
2023-02-16T21:44:32.461Z,1676583872.461 [Default:CheckIn] Running Loop=2
2023-02-16T21:44:32.461Z,1676583872.461 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-02-16T21:44:32.461Z,1676583872.461 [Default:CheckIn:Read_GPS] Running Loop=1
2023-02-16T21:44:34.451Z,1676583874.451 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214433.00,A,3648.17723,N,12147.27839,W,0.194,358.46,160223,,,A*74
2023-02-16T21:44:34.454Z,1676583874.454 [NAL9602](INFO): GPS fix at 20230216T214433: (36.802954, -121.787973)
2023-02-16T21:44:34.493Z,1676583874.493 [Default:CheckIn:Read_GPS] Stopped
2023-02-16T21:44:34.493Z,1676583874.493 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-02-16T21:44:44.284Z,1676583884.284 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230216T213413/Courier0007.lzma
2023-02-16T21:44:45.286Z,1676583885.286 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Courier0007.lzma.bak
2023-02-16T21:44:45.286Z,1676583885.286 [DataOverHttps](INFO): SBD MOMSN=17479154
2023-02-16T21:44:56.243Z,1676583896.243 [NAL9602](INFO): SBD MO Status=0, MOMSN=11841, MT Status=0, MTMSN=0
2023-02-16T21:44:56.243Z,1676583896.243 [NAL9602](INFO): No messages in MT queue
2023-02-16T21:45:00.988Z,1676583900.988 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20230216T213413/Express0008.lzma
2023-02-16T21:45:01.990Z,1676583901.990 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Express0008.lzma.bak
2023-02-16T21:45:01.990Z,1676583901.990 [DataOverHttps](INFO): SBD MOMSN=17479157
2023-02-16T21:45:03.949Z,1676583903.949 [Default:CheckIn:Read_Iridium] Stopped
2023-02-16T21:45:03.949Z,1676583903.949 [Default:CheckIn:C.Wait] Running Loop=1
2023-02-16T21:45:03.949Z,1676583903.949 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-02-16T21:45:27.018Z,1676583927.018 [NAL9602](INFO): Not Powering down - fast GPS
2023-02-16T21:50:04.583Z,1676584204.583 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-02-16T21:50:04.583Z,1676584204.583 [Default:CheckIn:C.Wait] Stopped
2023-02-16T21:50:04.583Z,1676584204.583 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-02-16T21:50:04.584Z,1676584204.584 [Default:CheckIn:D] Running Loop=1
2023-02-16T21:50:04.994Z,1676584204.994 [Default:CheckIn:D] Stopped
2023-02-16T21:50:04.994Z,1676584204.994 [Default:CheckIn:E] Running Loop=1
2023-02-16T21:50:05.404Z,1676584205.404 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.744017 min 
2023-02-16T21:50:05.405Z,1676584205.405 [Default:CheckIn:E] Stopped
2023-02-16T21:50:05.405Z,1676584205.405 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-02-16T21:50:05.405Z,1676584205.405 [Default:CheckIn] Stopped
2023-02-16T21:50:05.405Z,1676584205.405 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-02-16T21:50:05.405Z,1676584205.405 [Default:CheckIn](INFO): Running loop #3
2023-02-16T21:50:05.405Z,1676584205.405 [Default:CheckIn] Running Loop=3
2023-02-16T21:50:05.405Z,1676584205.405 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-02-16T21:50:05.405Z,1676584205.405 [Default:CheckIn:Read_GPS] Running Loop=1
2023-02-16T21:50:07.403Z,1676584207.403 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215006.00,A,3648.17405,N,12147.28100,W,0.369,306.12,160223,,,A*76
2023-02-16T21:50:07.405Z,1676584207.405 [NAL9602](INFO): GPS fix at 20230216T215006: (36.802901, -121.788017)
2023-02-16T21:50:07.415Z,1676584207.415 [Default:CheckIn:Read_GPS] Stopped
2023-02-16T21:50:07.415Z,1676584207.415 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-02-16T21:50:15.108Z,1676584215.108 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230216T213413/Courier0010.lzma
2023-02-16T21:50:16.110Z,1676584216.110 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Courier0010.lzma.bak
2023-02-16T21:50:16.110Z,1676584216.110 [DataOverHttps](INFO): SBD MOMSN=17479161
2023-02-16T21:50:31.988Z,1676584231.988 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20230216T213413/Express0011.lzma
2023-02-16T21:50:32.990Z,1676584232.990 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Express0011.lzma.bak
2023-02-16T21:50:32.990Z,1676584232.990 [DataOverHttps](INFO): SBD MOMSN=17479164
2023-02-16T21:50:33.259Z,1676584233.259 [NAL9602](INFO): SBD MO Status=0, MOMSN=11842, MT Status=0, MTMSN=0
2023-02-16T21:50:33.259Z,1676584233.259 [NAL9602](INFO): No messages in MT queue
2023-02-16T21:50:34.900Z,1676584234.900 [Default:CheckIn:Read_Iridium] Stopped
2023-02-16T21:50:34.900Z,1676584234.900 [Default:CheckIn:C.Wait] Running Loop=1
2023-02-16T21:50:34.901Z,1676584234.901 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-02-16T21:51:04.012Z,1676584264.012 [NAL9602](INFO): Not Powering down - fast GPS
2023-02-16T21:54:22.186Z,1676584462.186 [CommandExec](IMPORTANT): got command get VerticalControl.buoyancyNeutral
2023-02-16T21:54:22.186Z,1676584462.186 [CommandExec](IMPORTANT): VerticalControl.buoyancyNeutral 292.336304 cc
2023-02-16T21:54:27.089Z,1676584467.089 [CommandExec](IMPORTANT): got command failComponent 
2023-02-16T21:54:27.089Z,1676584467.089 [CommandExec](IMPORTANT): Failed components:
2023-02-16T21:54:27.089Z,1676584467.089 [CommandExec](IMPORTANT): No failed Components.
2023-02-16T21:55:35.607Z,1676584535.607 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-02-16T21:55:35.607Z,1676584535.607 [Default:CheckIn:C.Wait] Stopped
2023-02-16T21:55:35.607Z,1676584535.607 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-02-16T21:55:35.607Z,1676584535.607 [Default:CheckIn:D] Running Loop=1
2023-02-16T21:55:35.996Z,1676584535.996 [Default:CheckIn:D] Stopped
2023-02-16T21:55:35.996Z,1676584535.996 [Default:CheckIn:E] Running Loop=1
2023-02-16T21:55:36.395Z,1676584536.395 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.260710 min 
2023-02-16T21:55:36.396Z,1676584536.396 [Default:CheckIn:E] Stopped
2023-02-16T21:55:36.396Z,1676584536.396 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-02-16T21:55:36.420Z,1676584536.420 [Default:CheckIn] Stopped
2023-02-16T21:55:36.420Z,1676584536.420 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-02-16T21:55:36.420Z,1676584536.420 [Default:CheckIn](INFO): Running loop #4
2023-02-16T21:55:36.420Z,1676584536.420 [Default:CheckIn] Running Loop=4
2023-02-16T21:55:36.420Z,1676584536.420 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-02-16T21:55:36.420Z,1676584536.420 [Default:CheckIn:Read_GPS] Running Loop=1
2023-02-16T21:55:38.403Z,1676584538.403 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215537.00,A,3648.17087,N,12147.28527,W,0.544,306.12,160223,,,A*77
2023-02-16T21:55:38.406Z,1676584538.406 [NAL9602](INFO): GPS fix at 20230216T215537: (36.802848, -121.788088)
2023-02-16T21:55:38.416Z,1676584538.416 [Default:CheckIn:Read_GPS] Stopped
2023-02-16T21:55:38.416Z,1676584538.416 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-02-16T21:55:46.283Z,1676584546.283 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230216T213413/Courier0013.lzma
2023-02-16T21:55:47.286Z,1676584547.286 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Courier0013.lzma.bak
2023-02-16T21:55:47.286Z,1676584547.286 [DataOverHttps](INFO): SBD MOMSN=17479177
2023-02-16T21:56:03.564Z,1676584563.564 [DataOverHttps](INFO): Sending 275 bytes from file Logs/20230216T213413/Express0014.lzma
2023-02-16T21:56:04.566Z,1676584564.566 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Express0014.lzma.bak
2023-02-16T21:56:04.566Z,1676584564.566 [DataOverHttps](INFO): SBD MOMSN=17479180
2023-02-16T21:56:06.294Z,1676584566.294 [Default:CheckIn:Read_Iridium] Stopped
2023-02-16T21:56:06.294Z,1676584566.294 [Default:CheckIn:C.Wait] Running Loop=1
2023-02-16T21:56:06.294Z,1676584566.294 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-02-16T21:58:17.188Z,1676584697.188 [NAL9602](INFO): SBD MO Status=2, MOMSN=11843, MT Status=2, MTMSN=0
2023-02-16T21:58:17.188Z,1676584697.188 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-02-16T21:59:06.931Z,1676584746.931 [NAL9602](INFO): SBD MO Status=2, MOMSN=11843, MT Status=2, MTMSN=0
2023-02-16T21:59:06.931Z,1676584746.931 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-02-16T21:59:28.776Z,1676584768.776 [NAL9602](INFO): SBD MO Status=0, MOMSN=11843, MT Status=0, MTMSN=0
2023-02-16T21:59:28.777Z,1676584768.777 [NAL9602](INFO): No messages in MT queue
2023-02-16T21:59:59.477Z,1676584799.477 [NAL9602](INFO): Not Powering down - fast GPS
2023-02-16T22:01:06.966Z,1676584866.966 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-02-16T22:01:06.967Z,1676584866.967 [Default:CheckIn:C.Wait] Stopped
2023-02-16T22:01:06.967Z,1676584866.967 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-02-16T22:01:06.967Z,1676584866.967 [Default:CheckIn:D] Running Loop=1
2023-02-16T22:01:07.355Z,1676584867.355 [Default:CheckIn:D] Stopped
2023-02-16T22:01:07.355Z,1676584867.355 [Default:CheckIn:E] Running Loop=1
2023-02-16T22:01:07.768Z,1676584867.768 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.783366 min 
2023-02-16T22:01:07.769Z,1676584867.769 [Default:CheckIn:E] Stopped
2023-02-16T22:01:07.769Z,1676584867.769 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-02-16T22:01:07.769Z,1676584867.769 [Default:CheckIn] Stopped
2023-02-16T22:01:07.769Z,1676584867.769 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-02-16T22:01:07.769Z,1676584867.769 [Default:CheckIn](INFO): Running loop #5
2023-02-16T22:01:07.769Z,1676584867.769 [Default:CheckIn] Running Loop=5
2023-02-16T22:01:07.769Z,1676584867.769 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-02-16T22:01:07.769Z,1676584867.769 [Default:CheckIn:Read_GPS] Running Loop=1
2023-02-16T22:01:09.771Z,1676584869.771 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220109.00,A,3648.17536,N,12147.28128,W,0.136,306.12,160223,,,A*7D
2023-02-16T22:01:09.774Z,1676584869.774 [NAL9602](INFO): GPS fix at 20230216T220109: (36.802923, -121.788021)
2023-02-16T22:01:09.805Z,1676584869.805 [Default:CheckIn:Read_GPS] Stopped
2023-02-16T22:01:09.805Z,1676584869.805 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-02-16T22:01:16.687Z,1676584876.687 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230216T213413/Courier0016.lzma
2023-02-16T22:01:17.690Z,1676584877.690 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Courier0016.lzma.bak
2023-02-16T22:01:17.690Z,1676584877.690 [DataOverHttps](INFO): SBD MOMSN=17479196
2023-02-16T22:01:20.759Z,1676584880.759 [NAL9602](INFO): SBD MO Status=0, MOMSN=11844, MT Status=0, MTMSN=0
2023-02-16T22:01:20.759Z,1676584880.759 [NAL9602](INFO): No messages in MT queue
2023-02-16T22:01:33.548Z,1676584893.548 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20230216T213413/Express0017.lzma
2023-02-16T22:01:34.550Z,1676584894.550 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Express0017.lzma.bak
2023-02-16T22:01:34.550Z,1676584894.550 [DataOverHttps](INFO): SBD MOMSN=17479200
2023-02-16T22:01:36.103Z,1676584896.103 [Default:CheckIn:Read_Iridium] Stopped
2023-02-16T22:01:36.104Z,1676584896.104 [Default:CheckIn:C.Wait] Running Loop=1
2023-02-16T22:01:36.104Z,1676584896.104 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-02-16T22:01:51.434Z,1676584911.434 [NAL9602](INFO): Not Powering down - fast GPS
2023-02-16T22:06:36.774Z,1676585196.774 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-02-16T22:06:36.774Z,1676585196.774 [Default:CheckIn:C.Wait] Stopped
2023-02-16T22:06:36.774Z,1676585196.774 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-02-16T22:06:36.774Z,1676585196.774 [Default:CheckIn:D] Running Loop=1
2023-02-16T22:06:37.194Z,1676585197.194 [Default:CheckIn:D] Stopped
2023-02-16T22:06:37.208Z,1676585197.208 [Default:CheckIn:E] Running Loop=1
2023-02-16T22:06:37.552Z,1676585197.552 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.280678 min 
2023-02-16T22:06:37.552Z,1676585197.552 [Default:CheckIn:E] Stopped
2023-02-16T22:06:37.552Z,1676585197.552 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-02-16T22:06:37.552Z,1676585197.552 [Default:CheckIn] Stopped
2023-02-16T22:06:37.553Z,1676585197.553 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-02-16T22:06:37.553Z,1676585197.553 [Default:CheckIn](INFO): Running loop #6
2023-02-16T22:06:37.553Z,1676585197.553 [Default:CheckIn] Running Loop=6
2023-02-16T22:06:37.553Z,1676585197.553 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-02-16T22:06:37.553Z,1676585197.553 [Default:CheckIn:Read_GPS] Running Loop=1
2023-02-16T22:06:39.567Z,1676585199.567 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220639.00,A,3648.17614,N,12147.27871,W,0.175,0.00,160223,,,A*71
2023-02-16T22:06:39.570Z,1676585199.570 [NAL9602](INFO): GPS fix at 20230216T220639: (36.802936, -121.787978)
2023-02-16T22:06:39.599Z,1676585199.599 [Default:CheckIn:Read_GPS] Stopped
2023-02-16T22:06:39.599Z,1676585199.599 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-02-16T22:06:47.399Z,1676585207.399 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230216T213413/Courier0019.lzma
2023-02-16T22:06:48.402Z,1676585208.402 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Courier0019.lzma.bak
2023-02-16T22:06:48.402Z,1676585208.402 [DataOverHttps](INFO): SBD MOMSN=17479213
2023-02-16T22:07:02.210Z,1676585222.210 [NAL9602](INFO): SBD MO Status=2, MOMSN=11845, MT Status=2, MTMSN=0
2023-02-16T22:07:02.211Z,1676585222.211 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-02-16T22:07:05.424Z,1676585225.424 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20230216T213413/Express0020.lzma
2023-02-16T22:07:06.426Z,1676585226.426 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Express0020.lzma.bak
2023-02-16T22:07:06.426Z,1676585226.426 [DataOverHttps](INFO): SBD MOMSN=17479216
2023-02-16T22:07:08.709Z,1676585228.709 [Default:CheckIn:Read_Iridium] Stopped
2023-02-16T22:07:08.709Z,1676585228.709 [Default:CheckIn:C.Wait] Running Loop=1
2023-02-16T22:07:08.709Z,1676585228.709 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-02-16T22:07:47.870Z,1676585267.870 [NAL9602](INFO): SBD MO Status=2, MOMSN=11845, MT Status=2, MTMSN=0
2023-02-16T22:07:47.870Z,1676585267.870 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-02-16T22:09:28.539Z,1676585368.539 [NAL9602](INFO): SBD MO Status=0, MOMSN=11845, MT Status=0, MTMSN=0
2023-02-16T22:09:28.539Z,1676585368.539 [NAL9602](INFO): No messages in MT queue
2023-02-16T22:09:59.241Z,1676585399.241 [NAL9602](INFO): Not Powering down - fast GPS
2023-02-16T22:12:09.416Z,1676585529.416 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-02-16T22:12:09.416Z,1676585529.416 [Default:CheckIn:C.Wait] Stopped
2023-02-16T22:12:09.416Z,1676585529.416 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-02-16T22:12:09.416Z,1676585529.416 [Default:CheckIn:D] Running Loop=1
2023-02-16T22:12:09.811Z,1676585529.811 [Default:CheckIn:D] Stopped
2023-02-16T22:12:09.811Z,1676585529.811 [Default:CheckIn:E] Running Loop=1
2023-02-16T22:12:10.221Z,1676585530.221 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.824296 min 
2023-02-16T22:12:10.221Z,1676585530.221 [Default:CheckIn:E] Stopped
2023-02-16T22:12:10.221Z,1676585530.221 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-02-16T22:12:10.221Z,1676585530.221 [Default:CheckIn] Stopped
2023-02-16T22:12:10.222Z,1676585530.222 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-02-16T22:12:10.222Z,1676585530.222 [Default:CheckIn](INFO): Running loop #7
2023-02-16T22:12:10.222Z,1676585530.222 [Default:CheckIn] Running Loop=7
2023-02-16T22:12:10.222Z,1676585530.222 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-02-16T22:12:10.222Z,1676585530.222 [Default:CheckIn:Read_GPS] Running Loop=1
2023-02-16T22:12:12.227Z,1676585532.227 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221211.00,A,3648.14907,N,12147.22390,W,0.136,105.60,160223,,,A*74
2023-02-16T22:12:12.230Z,1676585532.230 [NAL9602](INFO): GPS fix at 20230216T221211: (36.802484, -121.787065)
2023-02-16T22:12:12.241Z,1676585532.241 [Default:CheckIn:Read_GPS] Stopped
2023-02-16T22:12:12.241Z,1676585532.241 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-02-16T22:12:20.896Z,1676585540.896 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230216T213413/Courier0022.lzma
2023-02-16T22:12:21.898Z,1676585541.898 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Courier0022.lzma.bak
2023-02-16T22:12:21.898Z,1676585541.898 [DataOverHttps](INFO): SBD MOMSN=17479220
2023-02-16T22:12:25.166Z,1676585545.166 [NAL9602](INFO): SBD MO Status=0, MOMSN=11846, MT Status=0, MTMSN=0
2023-02-16T22:12:25.166Z,1676585545.166 [NAL9602](INFO): No messages in MT queue
2023-02-16T22:12:40.848Z,1676585560.848 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20230216T213413/Express0023.lzma
2023-02-16T22:12:41.850Z,1676585561.850 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Express0023.lzma.bak
2023-02-16T22:12:41.850Z,1676585561.850 [DataOverHttps](INFO): SBD MOMSN=17479223
2023-02-16T22:12:43.367Z,1676585563.367 [Default:CheckIn:Read_Iridium] Stopped
2023-02-16T22:12:43.367Z,1676585563.367 [Default:CheckIn:C.Wait] Running Loop=1
2023-02-16T22:12:43.368Z,1676585563.368 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-02-16T22:12:55.871Z,1676585575.871 [NAL9602](INFO): Not Powering down - fast GPS
2023-02-16T22:17:44.116Z,1676585864.116 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-02-16T22:17:44.116Z,1676585864.116 [Default:CheckIn:C.Wait] Stopped
2023-02-16T22:17:44.116Z,1676585864.116 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-02-16T22:17:44.116Z,1676585864.116 [Default:CheckIn:D] Running Loop=1
2023-02-16T22:17:44.507Z,1676585864.507 [Default:CheckIn:D] Stopped
2023-02-16T22:17:44.507Z,1676585864.507 [Default:CheckIn:E] Running Loop=1
2023-02-16T22:17:44.912Z,1676585864.912 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.402568 min 
2023-02-16T22:17:44.912Z,1676585864.912 [Default:CheckIn:E] Stopped
2023-02-16T22:17:44.912Z,1676585864.912 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-02-16T22:17:44.912Z,1676585864.912 [Default:CheckIn] Stopped
2023-02-16T22:17:44.912Z,1676585864.912 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-02-16T22:17:44.912Z,1676585864.912 [Default:CheckIn](INFO): Running loop #8
2023-02-16T22:17:44.912Z,1676585864.912 [Default:CheckIn] Running Loop=8
2023-02-16T22:17:44.913Z,1676585864.913 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-02-16T22:17:44.913Z,1676585864.913 [Default:CheckIn:Read_GPS] Running Loop=1
2023-02-16T22:17:46.924Z,1676585866.924 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221746.00,A,3648.15300,N,12147.21521,W,0.758,331.01,160223,,,A*7C
2023-02-16T22:17:46.926Z,1676585866.926 [NAL9602](INFO): GPS fix at 20230216T221746: (36.802550, -121.786920)
2023-02-16T22:17:46.937Z,1676585866.937 [Default:CheckIn:Read_GPS] Stopped
2023-02-16T22:17:46.937Z,1676585866.937 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-02-16T22:17:53.940Z,1676585873.940 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230216T213413/Courier0025.lzma
2023-02-16T22:17:54.942Z,1676585874.942 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Courier0025.lzma.bak
2023-02-16T22:17:54.942Z,1676585874.942 [DataOverHttps](INFO): SBD MOMSN=17479236
2023-02-16T22:18:10.688Z,1676585890.688 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20230216T213413/Express0026.lzma
2023-02-16T22:18:11.690Z,1676585891.690 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Express0026.lzma.bak
2023-02-16T22:18:11.690Z,1676585891.690 [DataOverHttps](INFO): SBD MOMSN=17479239
2023-02-16T22:18:13.203Z,1676585893.203 [Default:CheckIn:Read_Iridium] Stopped
2023-02-16T22:18:13.203Z,1676585893.203 [Default:CheckIn:C.Wait] Running Loop=1
2023-02-16T22:18:13.203Z,1676585893.203 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-02-16T22:18:32.570Z,1676585912.570 [NAL9602](INFO): SBD MO Status=0, MOMSN=11847, MT Status=0, MTMSN=0
2023-02-16T22:18:32.570Z,1676585912.570 [NAL9602](INFO): No messages in MT queue
2023-02-16T22:19:03.272Z,1676585943.272 [NAL9602](INFO): Not Powering down - fast GPS
2023-02-16T22:21:18.389Z,1676586078.389 [DataOverHttps](IMPORTANT): SBD MTMSN=20230216T222117
2023-02-16T22:21:25.796Z,1676586085.796 [DataOverHttps](INFO): Received command: ibit
2023-02-16T22:21:25.889Z,1676586085.889 [CommandExec](IMPORTANT): got command ibit
2023-02-16T22:21:25.906Z,1676586085.906 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-02-16T22:21:25.907Z,1676586085.907 [IBIT](IMPORTANT): Beginning control surface checks.
2023-02-16T22:21:25.910Z,1676586085.910 [CBIT](IMPORTANT): Beginning ground fault scan
2023-02-16T22:21:27.503Z,1676586087.503 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222126.00,A,3648.43130,N,12147.11481,W,5.151,0.81,160223,,,D*73
2023-02-16T22:21:27.505Z,1676586087.505 [NAL9602](INFO): GPS fix at 20230216T222126: (36.807188, -121.785247)
2023-02-16T22:21:36.847Z,1676586096.847 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006272
CHAN A1 (24V): -0.007908
CHAN A2 (12V): -0.004869
CHAN A3 (5V): -0.002698
CHAN B0 (3.3V): -0.000427
CHAN B1 (3.15aV): -0.001067
CHAN B2 (3.15bV): -0.000955
CHAN B3 (GND): -0.000092
OPEN: 0.004920
Full Scale: +/- 1 mA
2023-02-16T22:21:42.854Z,1676586102.854 [NAL9602](INFO): SBD MO Status=0, MOMSN=11848, MT Status=0, MTMSN=0
2023-02-16T22:21:42.854Z,1676586102.854 [NAL9602](INFO): No messages in MT queue
2023-02-16T22:21:44.066Z,1676586104.066 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222143.00,A,3648.45635,N,12147.11437,W,5.365,359.42,160223,,,D*7C
2023-02-16T22:21:44.069Z,1676586104.069 [NAL9602](INFO): GPS fix at 20230216T222143: (36.807606, -121.785240)
2023-02-16T22:21:46.895Z,1676586106.895 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222146.00,A,3648.46087,N,12147.11451,W,5.423,358.47,160223,,,D*74
2023-02-16T22:21:46.901Z,1676586106.901 [NAL9602](INFO): GPS fix at 20230216T222146: (36.807681, -121.785242)
2023-02-16T22:21:49.727Z,1676586109.727 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222149.00,A,3648.46531,N,12147.11471,W,5.229,357.50,160223,,,D*74
2023-02-16T22:21:49.730Z,1676586109.730 [NAL9602](INFO): GPS fix at 20230216T222149: (36.807755, -121.785245)
2023-02-16T22:21:52.964Z,1676586112.964 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222152.00,A,3648.46975,N,12147.11511,W,5.365,355.13,160223,,,D*79
2023-02-16T22:21:52.966Z,1676586112.966 [NAL9602](INFO): GPS fix at 20230216T222152: (36.807829, -121.785252)
2023-02-16T22:21:55.787Z,1676586115.787 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222155.00,A,3648.47418,N,12147.11576,W,5.346,352.61,160223,,,D*7B
2023-02-16T22:21:55.790Z,1676586115.790 [NAL9602](INFO): GPS fix at 20230216T222155: (36.807903, -121.785263)
2023-02-16T22:21:59.015Z,1676586119.015 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222158.00,A,3648.47856,N,12147.11666,W,5.248,349.95,160223,,,D*7C
2023-02-16T22:21:59.018Z,1676586119.018 [NAL9602](INFO): GPS fix at 20230216T222158: (36.807976, -121.785278)
2023-02-16T22:22:01.842Z,1676586121.842 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222201.00,A,3648.48293,N,12147.11784,W,5.248,347.04,160223,,,D*74
2023-02-16T22:22:01.844Z,1676586121.844 [NAL9602](INFO): GPS fix at 20230216T222201: (36.808049, -121.785297)
2023-02-16T22:22:04.681Z,1676586124.681 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222204.00,A,3648.48723,N,12147.11925,W,5.248,344.33,160223,,,D*7D
2023-02-16T22:22:04.683Z,1676586124.683 [NAL9602](INFO): GPS fix at 20230216T222204: (36.808121, -121.785321)
2023-02-16T22:22:07.907Z,1676586127.907 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222207.00,A,3648.49145,N,12147.12094,W,5.287,341.70,160223,,,D*78
2023-02-16T22:22:07.910Z,1676586127.910 [NAL9602](INFO): GPS fix at 20230216T222207: (36.808191, -121.785349)
2023-02-16T22:22:10.735Z,1676586130.735 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222210.00,A,3648.49567,N,12147.12288,W,5.346,338.44,160223,,,D*70
2023-02-16T22:22:10.738Z,1676586130.738 [NAL9602](INFO): GPS fix at 20230216T222210: (36.808261, -121.785381)
2023-02-16T22:22:12.367Z,1676586132.367 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.808262 Longitude: -121.785385
2023-02-16T22:22:12.777Z,1676586132.777 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 15.779000
2023-02-16T22:22:12.778Z,1676586132.778 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-02-16T22:22:12.778Z,1676586132.778 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-02-16T22:22:13.180Z,1676586133.180 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-02-16T22:22:13.181Z,1676586133.181 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-02-16T22:22:13.181Z,1676586133.181 [IBIT](IMPORTANT): Pressure:10.702171 PSI
2023-02-16T22:22:13.181Z,1676586133.181 [IBIT](IMPORTANT): Humidity:9.730191 %
2023-02-16T22:22:13.571Z,1676586133.571 [IBIT](IMPORTANT): Vehicle Pitch:0.015871 degrees
2023-02-16T22:22:13.572Z,1676586133.572 [IBIT](IMPORTANT): Vehicle  Roll:-2.357627 degrees
2023-02-16T22:22:13.572Z,1676586133.572 [IBIT](IMPORTANT): Vehicle  Heading:326.722595 degrees
2023-02-16T22:22:13.980Z,1676586133.980 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-02-16T22:22:13.981Z,1676586133.981 [IBIT](IMPORTANT): buoyancyNeutral: 292.336304 cc
2023-02-16T22:22:13.981Z,1676586133.981 [IBIT](IMPORTANT): massDefault: 0.952044 cm
2023-02-16T22:22:13.981Z,1676586133.981 [IBIT](IMPORTANT): stopDepth: 275.000000 m
2023-02-16T22:22:13.982Z,1676586133.982 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2023-02-16T22:22:13.982Z,1676586133.982 [IBIT](IMPORTANT): IBIT PASSED
2023-02-16T22:22:43.457Z,1676586163.457 [NAL9602](INFO): Not Powering down - fast GPS
2023-02-16T22:23:13.771Z,1676586193.771 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-02-16T22:23:13.771Z,1676586193.771 [Default:CheckIn:C.Wait] Stopped
2023-02-16T22:23:13.771Z,1676586193.771 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-02-16T22:23:13.771Z,1676586193.771 [Default:CheckIn:D] Running Loop=1
2023-02-16T22:23:14.167Z,1676586194.167 [Default:CheckIn:D] Stopped
2023-02-16T22:23:14.167Z,1676586194.167 [Default:CheckIn:E] Running Loop=1
2023-02-16T22:23:14.582Z,1676586194.582 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.896899 min 
2023-02-16T22:23:14.582Z,1676586194.582 [Default:CheckIn:E] Stopped
2023-02-16T22:23:14.582Z,1676586194.582 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-02-16T22:23:14.582Z,1676586194.582 [Default:CheckIn] Stopped
2023-02-16T22:23:14.582Z,1676586194.582 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-02-16T22:23:14.583Z,1676586194.583 [Default:CheckIn](INFO): Running loop #9
2023-02-16T22:23:14.583Z,1676586194.583 [Default:CheckIn] Running Loop=9
2023-02-16T22:23:14.583Z,1676586194.583 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-02-16T22:23:14.583Z,1676586194.583 [Default:CheckIn:Read_GPS] Running Loop=1
2023-02-16T22:23:16.584Z,1676586196.584 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222316.00,A,3648.51616,N,12147.22477,W,5.404,238.29,160223,,,D*75
2023-02-16T22:23:16.586Z,1676586196.586 [NAL9602](INFO): GPS fix at 20230216T222316: (36.808603, -121.787080)
2023-02-16T22:23:16.613Z,1676586196.613 [Default:CheckIn:Read_GPS] Stopped
2023-02-16T22:23:16.613Z,1676586196.613 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-02-16T22:23:24.539Z,1676586204.539 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230216T213413/Courier0028.lzma
2023-02-16T22:23:25.542Z,1676586205.542 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Courier0028.lzma.bak
2023-02-16T22:23:25.542Z,1676586205.542 [DataOverHttps](INFO): SBD MOMSN=17479245
2023-02-16T22:23:42.071Z,1676586222.071 [DataOverHttps](INFO): Sending 885 bytes from file Logs/20230216T213413/Express0029.lzma
2023-02-16T22:23:43.070Z,1676586223.070 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Express0029.lzma.bak
2023-02-16T22:23:43.070Z,1676586223.070 [DataOverHttps](INFO): SBD MOMSN=17479248
2023-02-16T22:23:44.867Z,1676586224.867 [NAL9602](INFO): SBD MO Status=2, MOMSN=11849, MT Status=2, MTMSN=0
2023-02-16T22:23:44.867Z,1676586224.867 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-02-16T22:23:53.755Z,1676586233.755 [NAL9602](INFO): SBD MO Status=0, MOMSN=11849, MT Status=0, MTMSN=0
2023-02-16T22:23:53.755Z,1676586233.755 [NAL9602](INFO): No messages in MT queue
2023-02-16T22:23:58.975Z,1676586238.975 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230216T213413/Express0032.lzma
2023-02-16T22:23:59.978Z,1676586239.978 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Express0032.lzma.bak
2023-02-16T22:23:59.978Z,1676586239.978 [DataOverHttps](INFO): SBD MOMSN=17479274
2023-02-16T22:24:01.873Z,1676586241.873 [Default:CheckIn:Read_Iridium] Stopped
2023-02-16T22:24:01.873Z,1676586241.873 [Default:CheckIn:C.Wait] Running Loop=1
2023-02-16T22:24:01.873Z,1676586241.873 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-02-16T22:24:24.477Z,1676586264.477 [NAL9602](INFO): Not Powering down - fast GPS
2023-02-16T22:29:02.476Z,1676586542.476 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-02-16T22:29:02.476Z,1676586542.476 [Default:CheckIn:C.Wait] Stopped
2023-02-16T22:29:02.477Z,1676586542.477 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-02-16T22:29:02.477Z,1676586542.477 [Default:CheckIn:D] Running Loop=1
2023-02-16T22:29:02.880Z,1676586542.880 [Default:CheckIn:D] Stopped
2023-02-16T22:29:02.880Z,1676586542.880 [Default:CheckIn:E] Running Loop=1
2023-02-16T22:29:03.271Z,1676586543.271 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.708777 min 
2023-02-16T22:29:03.271Z,1676586543.271 [Default:CheckIn:E] Stopped
2023-02-16T22:29:03.271Z,1676586543.271 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-02-16T22:29:03.271Z,1676586543.271 [Default:CheckIn] Stopped
2023-02-16T22:29:03.272Z,1676586543.272 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-02-16T22:29:03.272Z,1676586543.272 [Default:CheckIn](INFO): Running loop #10
2023-02-16T22:29:03.272Z,1676586543.272 [Default:CheckIn] Running Loop=10
2023-02-16T22:29:03.272Z,1676586543.272 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-02-16T22:29:03.272Z,1676586543.272 [Default:CheckIn:Read_GPS] Running Loop=1
2023-02-16T22:29:05.284Z,1676586545.284 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222904.00,A,3648.11282,N,12148.69553,W,26.261,257.32,160223,,,A*44
2023-02-16T22:29:05.286Z,1676586545.286 [NAL9602](INFO): GPS fix at 20230216T222904: (36.801880, -121.811592)
2023-02-16T22:29:05.304Z,1676586545.304 [Default:CheckIn:Read_GPS] Stopped
2023-02-16T22:29:05.304Z,1676586545.304 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-02-16T22:29:15.904Z,1676586555.904 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230216T213413/Courier0034.lzma
2023-02-16T22:29:16.906Z,1676586556.906 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Courier0034.lzma.bak
2023-02-16T22:29:16.906Z,1676586556.906 [DataOverHttps](INFO): SBD MOMSN=17479285
2023-02-16T22:29:32.720Z,1676586572.720 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20230216T213413/Express0035.lzma
2023-02-16T22:29:33.722Z,1676586573.722 [DataOverHttps](INFO): Moved sent file to Logs/20230216T213413/Express0035.lzma.bak
2023-02-16T22:29:33.722Z,1676586573.722 [DataOverHttps](INFO): SBD MOMSN=17479289
2023-02-16T22:29:35.245Z,1676586575.245 [Default:CheckIn:Read_Iridium] Stopped
2023-02-16T22:29:35.245Z,1676586575.245 [Default:CheckIn:C.Wait] Running Loop=1
2023-02-16T22:29:35.245Z,1676586575.245 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-02-16T22:29:47.755Z,1676586587.755 [NAL9602](INFO): SBD MO Status=2, MOMSN=11850, MT Status=2, MTMSN=0
2023-02-16T22:29:47.755Z,1676586587.755 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-02-16T22:30:15.235Z,1676586615.235 [NAL9602](INFO): SBD MO Status=0, MOMSN=11850, MT Status=0, MTMSN=0
2023-02-16T22:30:15.235Z,1676586615.235 [NAL9602](INFO): No messages in MT queue
2023-02-16T22:30:45.929Z,1676586645.929 [NAL9602](INFO): Not Powering down - fast GPS
2023-02-16T22:34:13.516Z,1676586853.516 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:34:16.528Z,1676586856.528 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239212
2023-02-16T22:34:35.866Z,1676586875.866 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-02-16T22:34:35.866Z,1676586875.866 [Default:CheckIn:C.Wait] Stopped
2023-02-16T22:34:35.867Z,1676586875.867 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-02-16T22:34:35.867Z,1676586875.867 [Default:CheckIn:D] Running Loop=1
2023-02-16T22:34:36.271Z,1676586876.271 [Default:CheckIn:D] Stopped
2023-02-16T22:34:36.271Z,1676586876.271 [Default:CheckIn:E] Running Loop=1
2023-02-16T22:34:36.683Z,1676586876.683 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.265299 min 
2023-02-16T22:34:36.683Z,1676586876.683 [Default:CheckIn:E] Stopped
2023-02-16T22:34:36.683Z,1676586876.683 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-02-16T22:34:36.683Z,1676586876.683 [Default:CheckIn] Stopped
2023-02-16T22:34:36.683Z,1676586876.683 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-02-16T22:34:36.683Z,1676586876.683 [Default:CheckIn](INFO): Running loop #11
2023-02-16T22:34:36.683Z,1676586876.683 [Default:CheckIn] Running Loop=11
2023-02-16T22:34:36.683Z,1676586876.683 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-02-16T22:34:36.684Z,1676586876.684 [Default:CheckIn:Read_GPS] Running Loop=1
2023-02-16T22:34:38.691Z,1676586878.691 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223438.00,A,3647.84432,N,12150.74717,W,0.447,67.46,160223,,,D*4F
2023-02-16T22:34:38.693Z,1676586878.693 [NAL9602](INFO): GPS fix at 20230216T223438: (36.797405, -121.845786)
2023-02-16T22:34:38.719Z,1676586878.719 [Default:CheckIn:Read_GPS] Stopped
2023-02-16T22:34:38.719Z,1676586878.719 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-02-16T22:34:48.656Z,1676586888.656 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:35:02.193Z,1676586902.193 [NAL9602](INFO): SBD MO Status=1, MOMSN=11851, MT Status=0, MTMSN=0
2023-02-16T22:35:02.242Z,1676586902.242 [NAL9602](INFO): Sent 73 bytes from file Logs/20230216T213413/Courier0037.lzma
2023-02-16T22:35:02.242Z,1676586902.242 [NAL9602](INFO): Packets left to send: 0
2023-02-16T22:35:20.559Z,1676586920.559 [NAL9602](INFO): SBD MO Status=2, MOMSN=11852, MT Status=2, MTMSN=0
2023-02-16T22:35:20.559Z,1676586920.559 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-02-16T22:35:23.816Z,1676586923.816 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:35:48.612Z,1676586948.612 [NAL9602](INFO): SBD MO Status=2, MOMSN=11852, MT Status=2, MTMSN=0
2023-02-16T22:35:48.613Z,1676586948.613 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-02-16T22:35:58.980Z,1676586958.980 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:36:23.984Z,1676586983.984 [NAL9602](INFO): SBD MO Status=1, MOMSN=11852, MT Status=0, MTMSN=0
2023-02-16T22:36:24.034Z,1676586984.034 [NAL9602](INFO): Sent 274 bytes from file Logs/20230216T213413/Express0038.lzma
2023-02-16T22:36:24.034Z,1676586984.034 [NAL9602](INFO): Packets left to send: 0
2023-02-16T22:36:34.129Z,1676586994.129 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:36:37.351Z,1676586997.351 [NAL9602](INFO): SBD MO Status=0, MOMSN=11853, MT Status=0, MTMSN=0
2023-02-16T22:36:37.445Z,1676586997.445 [Default:CheckIn:Read_Iridium] Stopped
2023-02-16T22:36:37.445Z,1676586997.445 [Default:CheckIn:C.Wait] Running Loop=1
2023-02-16T22:36:37.445Z,1676586997.445 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-02-16T22:37:08.048Z,1676587028.048 [NAL9602](INFO): Not Powering down - fast GPS
2023-02-16T22:37:09.268Z,1676587029.268 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:37:44.428Z,1676587064.428 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:38:19.580Z,1676587099.580 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:38:54.720Z,1676587134.720 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:39:29.860Z,1676587169.860 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:40:05.000Z,1676587205.000 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:40:40.140Z,1676587240.140 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:41:15.288Z,1676587275.288 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:41:37.981Z,1676587297.981 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-02-16T22:41:37.981Z,1676587297.981 [Default:CheckIn:C.Wait] Stopped
2023-02-16T22:41:37.981Z,1676587297.981 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-02-16T22:41:37.981Z,1676587297.981 [Default:CheckIn:D] Running Loop=1
2023-02-16T22:41:38.346Z,1676587298.346 [Default:CheckIn:D] Stopped
2023-02-16T22:41:38.346Z,1676587298.346 [Default:CheckIn:E] Running Loop=1
2023-02-16T22:41:38.744Z,1676587298.744 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.299878 min 
2023-02-16T22:41:38.744Z,1676587298.744 [Default:CheckIn:E] Stopped
2023-02-16T22:41:38.760Z,1676587298.760 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-02-16T22:41:38.760Z,1676587298.760 [Default:CheckIn] Stopped
2023-02-16T22:41:38.760Z,1676587298.760 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-02-16T22:41:38.760Z,1676587298.760 [Default:CheckIn](INFO): Running loop #12
2023-02-16T22:41:38.760Z,1676587298.760 [Default:CheckIn] Running Loop=12
2023-02-16T22:41:38.761Z,1676587298.761 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-02-16T22:41:38.761Z,1676587298.761 [Default:CheckIn:Read_GPS] Running Loop=1
2023-02-16T22:41:40.755Z,1676587300.755 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224140.00,A,3647.86135,N,12150.69965,W,0.039,80.49,160223,,,D*4E
2023-02-16T22:41:40.758Z,1676587300.758 [NAL9602](INFO): GPS fix at 20230216T224140: (36.797689, -121.844994)
2023-02-16T22:41:40.769Z,1676587300.769 [Default:CheckIn:Read_GPS] Stopped
2023-02-16T22:41:40.769Z,1676587300.769 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-02-16T22:41:50.432Z,1676587310.432 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-02-16T22:41:54.942Z,1676587314.942 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=11854, MT Status=1, MTMSN=782
2023-02-16T22:41:54.992Z,1676587314.992 [NAL9602](INFO): Sent 72 bytes from file Logs/20230216T213413/Courier0040.lzma
2023-02-16T22:41:54.992Z,1676587314.992 [NAL9602](INFO): Packets left to send: 0
2023-02-16T22:41:55.449Z,1676587315.449 [NAL9602](INFO): Received command: restart logs