2020-12-08T22:38:57.336Z,1607467137.336 [Supervisor](DEBUG): Initializing supervisor.
2020-12-08T22:38:57.340Z,1607467137.340 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-12-08T22:38:57.341Z,1607467137.341 [SyncHandler](INFO): Protected caller Thread ID is 835
2020-12-08T22:38:57.341Z,1607467137.341 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-12-08T22:38:57.342Z,1607467137.342 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-12-08T22:38:57.343Z,1607467137.343 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 836
2020-12-08T22:38:57.347Z,1607467137.347 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-12-08T22:38:57.366Z,1607467137.366 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-12-08T22:38:57.367Z,1607467137.367 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-12-08T22:38:57.367Z,1607467137.367 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 837
2020-12-08T22:38:57.369Z,1607467137.369 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-12-08T22:38:57.370Z,1607467137.370 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-12-08T22:38:57.371Z,1607467137.371 [logger ThreadHandler](INFO): Protected caller Thread ID is 838
2020-12-08T22:38:57.374Z,1607467137.374 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-12-08T22:38:57.375Z,1607467137.375 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-12-08T22:38:57.379Z,1607467137.379 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-12-08T22:38:57.475Z,1607467137.475 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-12-08T22:38:57.477Z,1607467137.477 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-12-08T22:38:58.019Z,1607467138.019 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-12-08T22:38:58.021Z,1607467138.021 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-12-08T22:38:58.222Z,1607467138.222 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-12-08T22:38:58.224Z,1607467138.224 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-12-08T22:38:58.304Z,1607467138.304 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-12-08T22:38:58.408Z,1607467138.408 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-12-08T22:38:58.410Z,1607467138.410 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-12-08T22:38:58.490Z,1607467138.490 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-12-08T22:38:58.589Z,1607467138.589 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-12-08T22:38:58.590Z,1607467138.590 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-12-08T22:38:58.880Z,1607467138.880 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-12-08T22:38:58.881Z,1607467138.881 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-12-08T22:38:59.378Z,1607467139.378 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-12-08T22:38:59.380Z,1607467139.380 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-12-08T22:38:59.521Z,1607467139.521 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-12-08T22:38:59.522Z,1607467139.522 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-12-08T22:38:59.702Z,1607467139.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-12-08T22:38:59.703Z,1607467139.703 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-12-08T22:39:00.111Z,1607467140.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-12-08T22:39:00.112Z,1607467140.112 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-12-08T22:39:00.324Z,1607467140.324 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-12-08T22:39:00.326Z,1607467140.326 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-12-08T22:39:00.522Z,1607467140.522 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-12-08T22:39:00.524Z,1607467140.524 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-12-08T22:39:00.933Z,1607467140.933 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-12-08T22:39:01.546Z,1607467141.546 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-12-08T22:39:01.913Z,1607467141.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-12-08T22:39:01.915Z,1607467141.915 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2020-12-08T22:39:01.917Z,1607467141.917 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2020-12-08T22:39:02.001Z,1607467142.001 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2020-12-08T22:39:02.158Z,1607467142.158 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2020-12-08T22:39:02.267Z,1607467142.267 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2020-12-08T22:39:02.353Z,1607467142.353 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2020-12-08T22:39:02.448Z,1607467142.448 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2020-12-08T22:39:02.639Z,1607467142.639 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2020-12-08T22:39:02.893Z,1607467142.893 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-12-08T22:39:02.895Z,1607467142.895 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2020-12-08T22:39:02.989Z,1607467142.989 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2020-12-08T22:39:03.087Z,1607467143.087 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2020-12-08T22:39:03.224Z,1607467143.224 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2020-12-08T22:39:03.322Z,1607467143.322 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-12-08T22:39:03.340Z,1607467143.340 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-12-08T22:39:03.450Z,1607467143.450 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-12-08T22:39:03.451Z,1607467143.451 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-12-08T22:39:03.516Z,1607467143.516 [VerticalControl](DEBUG): Construct VerticalControl.
2020-12-08T22:39:03.575Z,1607467143.575 [VerticalControl] Loaded
2020-12-08T22:39:03.575Z,1607467143.575 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-12-08T22:39:03.578Z,1607467143.578 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-12-08T22:39:03.615Z,1607467143.615 [HorizontalControl] Loaded
2020-12-08T22:39:03.615Z,1607467143.615 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-12-08T22:39:03.618Z,1607467143.618 [SpeedControl](DEBUG): Construct SpeedControl.
2020-12-08T22:39:03.621Z,1607467143.621 [SpeedControl] Loaded
2020-12-08T22:39:03.621Z,1607467143.621 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-12-08T22:39:03.624Z,1607467143.624 [LoopControl](DEBUG): Construct LoopControl.
2020-12-08T22:39:03.624Z,1607467143.624 [LoopControl] Loaded
2020-12-08T22:39:03.625Z,1607467143.625 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-12-08T22:39:03.625Z,1607467143.625 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-12-08T22:39:03.625Z,1607467143.625 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-12-08T22:39:03.681Z,1607467143.681 [DepthRateCalculator] Loaded
2020-12-08T22:39:03.681Z,1607467143.681 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-12-08T22:39:03.686Z,1607467143.686 [PitchRateCalculator] Loaded
2020-12-08T22:39:03.686Z,1607467143.686 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-12-08T22:39:03.696Z,1607467143.696 [SpeedCalculator] Loaded
2020-12-08T22:39:03.696Z,1607467143.696 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-12-08T22:39:03.709Z,1607467143.709 [TempGradientCalculator] Loaded
2020-12-08T22:39:03.709Z,1607467143.709 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-12-08T22:39:03.713Z,1607467143.713 [YawRateCalculator] Loaded
2020-12-08T22:39:03.714Z,1607467143.714 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-12-08T22:39:03.730Z,1607467143.730 [ElevatorOffsetCalculator] Loaded
2020-12-08T22:39:03.731Z,1607467143.731 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-12-08T22:39:03.731Z,1607467143.731 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-12-08T22:39:03.733Z,1607467143.733 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-12-08T22:39:03.774Z,1607467143.774 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-12-08T22:39:03.775Z,1607467143.775 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-12-08T22:39:03.851Z,1607467143.851 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-12-08T22:39:03.851Z,1607467143.851 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-12-08T22:39:04.204Z,1607467144.204 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-12-08T22:39:04.206Z,1607467144.206 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-12-08T22:39:04.331Z,1607467144.331 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-12-08T22:39:04.331Z,1607467144.331 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-12-08T22:39:04.980Z,1607467144.980 [AHRS_M2] Loaded
2020-12-08T22:39:04.981Z,1607467144.981 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-12-08T22:39:05.224Z,1607467145.224 [BackseatComponent] Loaded
2020-12-08T22:39:05.224Z,1607467145.224 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2020-12-08T22:39:05.225Z,1607467145.225 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408FC4E0
2020-12-08T22:39:05.226Z,1607467145.226 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 921
2020-12-08T22:39:05.228Z,1607467145.228 [LcmUniversalReporter] Loaded
2020-12-08T22:39:05.229Z,1607467145.229 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2020-12-08T22:39:05.985Z,1607467145.985 [BPC1] Loaded
2020-12-08T22:39:05.985Z,1607467145.985 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-12-08T22:39:06.211Z,1607467146.211 [DataOverHttps] Loaded
2020-12-08T22:39:06.211Z,1607467146.211 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-12-08T22:39:06.220Z,1607467146.220 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4092C4E0
2020-12-08T22:39:06.220Z,1607467146.220 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 922
2020-12-08T22:39:06.283Z,1607467146.283 [Depth_Keller] Loaded
2020-12-08T22:39:06.284Z,1607467146.284 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-12-08T22:39:06.299Z,1607467146.299 [DropWeight] Loaded
2020-12-08T22:39:06.299Z,1607467146.299 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-12-08T22:39:06.470Z,1607467146.470 [NAL9602] Loaded
2020-12-08T22:39:06.470Z,1607467146.470 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-12-08T22:39:06.498Z,1607467146.498 [Onboard] Loaded
2020-12-08T22:39:06.498Z,1607467146.498 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-12-08T22:39:06.499Z,1607467146.499 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4095C4E0
2020-12-08T22:39:06.499Z,1607467146.499 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 923
2020-12-08T22:39:06.512Z,1607467146.512 [Radio_Surface] Loaded
2020-12-08T22:39:06.512Z,1607467146.512 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-12-08T22:39:06.513Z,1607467146.513 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4098C4E0
2020-12-08T22:39:06.514Z,1607467146.514 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 924
2020-12-08T22:39:06.547Z,1607467146.547 [RDI_Pathfinder] Loaded
2020-12-08T22:39:06.548Z,1607467146.548 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-12-08T22:39:06.625Z,1607467146.625 [DAT] Loaded
2020-12-08T22:39:06.626Z,1607467146.626 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-12-08T22:39:06.626Z,1607467146.626 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-12-08T22:39:06.627Z,1607467146.627 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-12-08T22:39:06.721Z,1607467146.721 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-12-08T22:39:06.721Z,1607467146.721 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-12-08T22:39:06.734Z,1607467146.734 [NavChart] Loaded
2020-12-08T22:39:06.734Z,1607467146.734 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-12-08T22:39:06.740Z,1607467146.740 [UniversalFixResidualReporter] Loaded
2020-12-08T22:39:06.740Z,1607467146.740 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-12-08T22:39:06.740Z,1607467146.740 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-12-08T22:39:06.741Z,1607467146.741 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-12-08T22:39:06.905Z,1607467146.905 [SBIT](DEBUG): Construct Startup Built In Test.
2020-12-08T22:39:06.914Z,1607467146.914 [SBIT] Loaded
2020-12-08T22:39:06.914Z,1607467146.914 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-12-08T22:39:06.917Z,1607467146.917 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-12-08T22:39:06.930Z,1607467146.930 [IBIT] Loaded
2020-12-08T22:39:06.930Z,1607467146.930 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-12-08T22:39:06.935Z,1607467146.935 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-12-08T22:39:07.032Z,1607467147.032 [CBIT] Loaded
2020-12-08T22:39:07.032Z,1607467147.032 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-12-08T22:39:07.032Z,1607467147.032 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-12-08T22:39:07.033Z,1607467147.033 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-12-08T22:39:07.170Z,1607467147.170 [BuoyancyServo] Loaded
2020-12-08T22:39:07.170Z,1607467147.170 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-12-08T22:39:07.189Z,1607467147.189 [ElevatorServo] Loaded
2020-12-08T22:39:07.190Z,1607467147.190 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-12-08T22:39:07.208Z,1607467147.208 [MassServo] Loaded
2020-12-08T22:39:07.208Z,1607467147.208 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-12-08T22:39:07.226Z,1607467147.226 [RudderServo] Loaded
2020-12-08T22:39:07.226Z,1607467147.226 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-12-08T22:39:07.243Z,1607467147.243 [ThrusterServo] Loaded
2020-12-08T22:39:07.243Z,1607467147.243 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-12-08T22:39:07.243Z,1607467147.243 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-12-08T22:39:07.244Z,1607467147.244 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-12-08T22:39:07.260Z,1607467147.260 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-12-08T22:39:07.261Z,1607467147.261 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-12-08T22:39:07.475Z,1607467147.475 [CTD_Seabird] Loaded
2020-12-08T22:39:07.475Z,1607467147.475 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-12-08T22:39:07.476Z,1607467147.476 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40ABD4E0
2020-12-08T22:39:07.477Z,1607467147.477 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 925
2020-12-08T22:39:07.496Z,1607467147.496 [PAR_Licor] Loaded
2020-12-08T22:39:07.496Z,1607467147.496 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-12-08T22:39:07.528Z,1607467147.528 [WetLabsBB2FL] Loaded
2020-12-08T22:39:07.528Z,1607467147.528 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-12-08T22:39:07.529Z,1607467147.529 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AED4E0
2020-12-08T22:39:07.530Z,1607467147.530 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 926
2020-12-08T22:39:07.548Z,1607467147.548 [WetLabsUBAT] Loaded
2020-12-08T22:39:07.548Z,1607467147.548 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2020-12-08T22:39:07.549Z,1607467147.549 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40B1D4E0
2020-12-08T22:39:07.549Z,1607467147.549 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 927
2020-12-08T22:39:07.550Z,1607467147.550 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-12-08T22:39:07.556Z,1607467147.556 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-12-08T22:39:07.559Z,1607467147.559 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-12-08T22:39:07.569Z,1607467147.569 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-12-08T22:39:07.570Z,1607467147.570 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B4D4E0
2020-12-08T22:39:07.570Z,1607467147.570 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928
2020-12-08T22:39:07.575Z,1607467147.575 [Supervisor](INFO): Main Thread ID is 829
2020-12-08T22:39:07.575Z,1607467147.575 [Supervisor](DEBUG): Running supervisor.
2020-12-08T22:39:07.576Z,1607467147.576 [CommandLine ThreadHandler](INFO): Handler Thread ID is 929
2020-12-08T22:39:07.578Z,1607467147.578 [controlThread ThreadHandler](INFO): Handler Thread ID is 930
2020-12-08T22:39:07.578Z,1607467147.578 [controlThread](DEBUG): Initializing ControlThread
2020-12-08T22:39:07.579Z,1607467147.579 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-12-08T22:39:07.581Z,1607467147.581 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-12-08T22:39:07.582Z,1607467147.582 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-12-08T22:39:07.582Z,1607467147.582 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-12-08T22:39:07.583Z,1607467147.583 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-12-08T22:39:07.583Z,1607467147.583 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-12-08T22:39:07.583Z,1607467147.583 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-12-08T22:39:07.584Z,1607467147.584 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-12-08T22:39:07.584Z,1607467147.584 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-12-08T22:39:07.585Z,1607467147.585 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-12-08T22:39:07.590Z,1607467147.590 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-12-08T22:39:07.591Z,1607467147.591 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-12-08T22:39:07.591Z,1607467147.591 [SBIT](INFO): Initialize SBIT Component.
2020-12-08T22:39:07.591Z,1607467147.591 [SBIT](IMPORTANT): git: 2020-12-07
2020-12-08T22:39:07.592Z,1607467147.592 [SBIT](INFO): git hash: 99d2307c888ffe6e2636ea8c7d856dd5449ca1b0
2020-12-08T22:39:07.592Z,1607467147.592 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-12-08T22:39:07.593Z,1607467147.593 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2020-12-08T22:39:07.594Z,1607467147.594 [SBIT](INFO): Beginning SBIT in 50.000000 seconds.
2020-12-08T22:39:07.595Z,1607467147.595 [IBIT](INFO): Initialize IBIT Component.
2020-12-08T22:39:07.596Z,1607467147.596 [CBIT](DEBUG): Initialize CBIT Component.
2020-12-08T22:39:07.597Z,1607467147.597 [logger ThreadHandler](INFO): Handler Thread ID is 931
2020-12-08T22:39:07.608Z,1607467147.608 [CBIT](DEBUG): Initialized mux pins.
2020-12-08T22:39:07.608Z,1607467147.608 [CBIT](DEBUG): Initializing the watchdog timer.
2020-12-08T22:39:07.616Z,1607467147.616 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 932
2020-12-08T22:39:07.628Z,1607467147.628 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 933
2020-12-08T22:39:07.629Z,1607467147.629 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-12-08T22:39:07.632Z,1607467147.632 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-12-08T22:39:07.632Z,1607467147.632 [CBIT](DEBUG): Initializing heartbeat.
2020-12-08T22:39:07.640Z,1607467147.640 [Onboard ThreadHandler](INFO): Handler Thread ID is 934
2020-12-08T22:39:07.657Z,1607467147.657 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 935
2020-12-08T22:39:07.676Z,1607467147.676 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 936
2020-12-08T22:39:07.677Z,1607467147.677 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-12-08T22:39:07.681Z,1607467147.681 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 938
2020-12-08T22:39:07.684Z,1607467147.684 [WetLabsBB2FL](INFO): Powering up
2020-12-08T22:39:07.685Z,1607467147.685 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 940
2020-12-08T22:39:07.688Z,1607467147.688 [WetLabsUBAT](INFO): Powering up
2020-12-08T22:39:07.689Z,1607467147.689 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 942
2020-12-08T22:39:07.698Z,1607467147.698 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-12-08T22:39:07.699Z,1607467147.699 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-12-08T22:39:07.699Z,1607467147.699 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-12-08T22:39:07.699Z,1607467147.699 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-12-08T22:39:07.699Z,1607467147.699 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-12-08T22:39:07.699Z,1607467147.699 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-12-08T22:39:07.699Z,1607467147.699 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-12-08T22:39:07.700Z,1607467147.700 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-12-08T22:39:07.700Z,1607467147.700 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-12-08T22:39:07.700Z,1607467147.700 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-12-08T22:39:07.700Z,1607467147.700 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-12-08T22:39:07.700Z,1607467147.700 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-12-08T22:39:07.701Z,1607467147.701 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-12-08T22:39:07.701Z,1607467147.701 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-12-08T22:39:07.701Z,1607467147.701 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-12-08T22:39:07.701Z,1607467147.701 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-12-08T22:39:07.704Z,1607467147.704 [CBIT](DEBUG): Deactivating GF circuits.
2020-12-08T22:39:07.704Z,1607467147.704 [CBIT](DEBUG): Deactivating emergency mode.
2020-12-08T22:39:07.740Z,1607467147.740 [CBIT](DEBUG): Backplane powered.
2020-12-08T22:39:07.745Z,1607467147.745 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-12-08T22:39:07.805Z,1607467147.805 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-08T22:39:07.832Z,1607467147.832 [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>


2020-12-08T22:39:07.833Z,1607467147.833 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-12-08T22:39:07.923Z,1607467147.923 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-12-08T22:39:07.924Z,1607467147.924 [Default:A.Wait](DEBUG): Construct Wait.
2020-12-08T22:39:07.927Z,1607467147.927 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-08T22:39:07.970Z,1607467147.970 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-12-08T22:39:07.973Z,1607467147.973 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-12-08T22:39:07.994Z,1607467147.994 [Default:E.Execute](DEBUG): Construct Execute.
2020-12-08T22:39:07.998Z,1607467147.998 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2020-12-08T22:39:08.016Z,1607467148.016 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,RDI_Pathfinder,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2020-12-08T22:39:08.021Z,1607467148.021 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-12-08T22:39:08.068Z,1607467148.068 [Radio_Surface](INFO): Powering up
2020-12-08T22:39:08.296Z,1607467148.296 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-12-08T22:39:08.297Z,1607467148.297 [DAT](INFO): Powering up
2020-12-08T22:39:08.297Z,1607467148.297 [DAT](DEBUG): Initializing DAT.
2020-12-08T22:39:08.362Z,1607467148.362 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-12-08T22:39:08.368Z,1607467148.368 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-12-08T22:39:08.369Z,1607467148.369 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-12-08T22:39:08.376Z,1607467148.376 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-12-08T22:39:08.412Z,1607467148.412 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-12-08T22:39:08.413Z,1607467148.413 [MassServo](DEBUG): Initializing EZServoServo.
2020-12-08T22:39:08.420Z,1607467148.420 [MassServo](DEBUG): Initializing MassServo.
2020-12-08T22:39:08.421Z,1607467148.421 [RudderServo](DEBUG): Initializing EZServoServo.
2020-12-08T22:39:08.433Z,1607467148.433 [RudderServo](DEBUG): Initializing RudderServo.
2020-12-08T22:39:08.434Z,1607467148.434 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-12-08T22:39:08.444Z,1607467148.444 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-12-08T22:39:10.296Z,1607467150.296 [WetLabsBB2FL](INFO): Powering down
2020-12-08T22:39:17.008Z,1607467157.008 [WetLabsUBAT](INFO): Powering down
2020-12-08T22:39:22.604Z,1607467162.604 [DAT](INFO): commRate: 800
2020-12-08T22:39:24.634Z,1607467164.634 [DAT](INFO): entering command mode
2020-12-08T22:39:25.026Z,1607467165.026 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:25.430Z,1607467165.430 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:25.850Z,1607467165.850 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:26.249Z,1607467166.249 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:26.642Z,1607467166.642 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:27.090Z,1607467167.090 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:27.450Z,1607467167.450 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:27.854Z,1607467167.854 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:28.274Z,1607467168.274 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:28.666Z,1607467168.666 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:29.096Z,1607467169.096 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:29.470Z,1607467169.470 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:29.886Z,1607467169.886 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:30.289Z,1607467170.289 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:30.686Z,1607467170.686 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:31.128Z,1607467171.128 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:31.490Z,1607467171.490 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:31.894Z,1607467171.894 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:32.330Z,1607467172.330 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:32.702Z,1607467172.702 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:33.106Z,1607467173.106 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:33.532Z,1607467173.532 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:33.934Z,1607467173.934 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:34.321Z,1607467174.321 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:34.761Z,1607467174.761 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:35.137Z,1607467175.137 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:35.535Z,1607467175.535 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:35.934Z,1607467175.934 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:36.350Z,1607467176.350 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:36.749Z,1607467176.749 [NAL9602](INFO): Powering up NAL9602
2020-12-08T22:39:36.751Z,1607467176.751 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:37.185Z,1607467177.185 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:37.550Z,1607467177.550 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:37.954Z,1607467177.954 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:38.379Z,1607467178.379 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:38.762Z,1607467178.762 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:39.181Z,1607467179.181 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:39.570Z,1607467179.570 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:39.979Z,1607467179.979 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-08T22:39:39.980Z,1607467179.980 [DAT](FAULT): failed to enter command mode
2020-12-08T22:39:40.409Z,1607467180.409 [DAT](INFO): entering command mode
2020-12-08T22:39:40.783Z,1607467180.783 [DAT](INFO): setting verbose to 3
2020-12-08T22:39:41.245Z,1607467181.245 [DAT](INFO): set verbose to 3
2020-12-08T22:39:41.246Z,1607467181.246 [DAT](INFO): setting DatVerbose to 27440
2020-12-08T22:39:41.595Z,1607467181.595 [DAT](INFO): set DatVerbose to 27440
2020-12-08T22:39:41.596Z,1607467181.596 [DAT](INFO): setting transmit power to 8
2020-12-08T22:39:42.009Z,1607467182.009 [DAT](INFO): set transmit power to 8
2020-12-08T22:39:42.009Z,1607467182.009 [DAT](INFO): setting local address to 9
2020-12-08T22:39:42.399Z,1607467182.399 [DAT](INFO): set local address to 9
2020-12-08T22:39:47.650Z,1607467187.650 [NAL9602](INFO): NAL9602 initialized
2020-12-08T22:39:58.187Z,1607467198.187 [SBIT](IMPORTANT): Beginning Startup BIT
2020-12-08T22:39:58.207Z,1607467198.207 [CBIT](IMPORTANT): Beginning ground fault scan
2020-12-08T22:40:09.164Z,1607467209.164 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.011928
CHAN A1 (24V): -0.001923
CHAN A2 (12V): -0.007651
CHAN A3 (5V): -0.002159
CHAN B0 (3.3V): 0.000163
CHAN B1 (3.15aV): 0.000334
CHAN B2 (3.15bV): -0.000822
CHAN B3 (GND): 0.002398
OPEN: -0.003691
Full Scale Calc: 4.765 mA, -1.589 mA
2020-12-08T22:40:51.916Z,1607467251.916 [SBIT](IMPORTANT): SBIT PASSED
2020-12-08T22:40:51.916Z,1607467251.916 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-12-08T22:40:51.917Z,1607467251.917 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2020-12-08T22:40:51.917Z,1607467251.917 [SBIT](IMPORTANT): CBIT.gf24Offset=145 microampere;

2020-12-08T22:40:51.918Z,1607467251.918 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum;

2020-12-08T22:40:51.918Z,1607467251.918 [SBIT](IMPORTANT): DAT.surfaceThreshold=100 meter;

2020-12-08T22:40:51.918Z,1607467251.918 [SBIT](IMPORTANT): DAT.verbosity=0 count;

2020-12-08T22:40:51.918Z,1607467251.918 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 1.000000 liter_per_second;

2020-12-08T22:40:51.918Z,1607467251.918 [SBIT](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2020-12-08T22:40:51.918Z,1607467251.918 [SBIT](IMPORTANT): PAR_Licor.parCal=1.01146 none;

2020-12-08T22:40:51.918Z,1607467251.918 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool;

2020-12-08T22:40:51.918Z,1607467251.918 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=222.366592 cubic_centimeter;

2020-12-08T22:40:51.918Z,1607467251.918 [SBIT](IMPORTANT): VerticalControl.massDefault=7.567043 millimeter;

2020-12-08T22:40:51.919Z,1607467251.919 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool;

2020-12-08T22:40:52.338Z,1607467252.338 [MissionManager](IMPORTANT): Started mission Startup
2020-12-08T22:40:52.338Z,1607467252.338 [Startup] Running Loop=1
2020-12-08T22:40:52.339Z,1607467252.339 [Startup](DEBUG): Aggregate::initialize Startup
2020-12-08T22:40:52.339Z,1607467252.339 [Startup:A.GoToSurface] Running Loop=1
2020-12-08T22:40:52.339Z,1607467252.339 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-08T22:40:52.339Z,1607467252.339 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-08T22:40:52.344Z,1607467252.344 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-08T22:40:52.344Z,1607467252.344 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-08T22:40:52.345Z,1607467252.345 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-08T22:40:52.345Z,1607467252.345 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-08T22:40:52.349Z,1607467252.349 [Startup:StartupSatComms] Running Loop=1
2020-12-08T22:40:52.349Z,1607467252.349 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-12-08T22:40:52.349Z,1607467252.349 [Startup:StartupSatComms:A] Running Loop=1
2020-12-08T22:40:52.711Z,1607467252.711 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-12-08T22:41:52.512Z,1607467312.512 [Startup:StartupSatComms:A](INFO): Timed out from 2020-12-08T22:40:52.3Z
2020-12-08T22:41:52.512Z,1607467312.512 [Startup:StartupSatComms:A] Stopped
2020-12-08T22:41:52.512Z,1607467312.512 [Startup:StartupSatComms:B] Running Loop=1
2020-12-08T22:41:52.922Z,1607467312.922 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-08T22:42:07.875Z,1607467327.875 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-12-08T22:42:07.875Z,1607467327.875 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-08T22:42:07.885Z,1607467327.885 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-08T22:42:08.273Z,1607467328.273 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-08T22:42:08.273Z,1607467328.273 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-12-08T22:42:43.541Z,1607467363.541 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004434
2020-12-08T22:42:52.580Z,1607467372.580 [Startup:StartupSatComms:B](INFO): Timed out from 2020-12-08T22:41:52.5Z
2020-12-08T22:42:52.580Z,1607467372.580 [Startup:StartupSatComms:B] Stopped
2020-12-08T22:42:52.580Z,1607467372.580 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-12-08T22:42:52.580Z,1607467372.580 [Startup:StartupSatComms] Stopped
2020-12-08T22:42:52.581Z,1607467372.581 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-12-08T22:42:52.581Z,1607467372.581 [Startup](INFO): Completed Startup
2020-12-08T22:42:52.581Z,1607467372.581 [MissionManager](INFO): Startup is completed.
2020-12-08T22:42:52.582Z,1607467372.582 [MissionManager](INFO): Uninitializing Mission Startup
2020-12-08T22:42:52.582Z,1607467372.582 [Startup] Stopped
2020-12-08T22:42:52.582Z,1607467372.582 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-12-08T22:42:52.582Z,1607467372.582 [Startup:A.GoToSurface] Stopped
2020-12-08T22:42:52.586Z,1607467372.586 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-12-08T22:42:52.956Z,1607467372.956 [MissionManager](IMPORTANT): Started mission Default
2020-12-08T22:42:52.957Z,1607467372.957 [Default] Running Loop=1
2020-12-08T22:42:52.957Z,1607467372.957 [Default](DEBUG): Aggregate::initialize Default
2020-12-08T22:42:52.957Z,1607467372.957 [Default:B.GoToSurface] Running Loop=1
2020-12-08T22:42:52.957Z,1607467372.957 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-08T22:42:52.957Z,1607467372.957 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-08T22:42:52.957Z,1607467372.957 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-08T22:42:52.958Z,1607467372.958 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-08T22:42:52.958Z,1607467372.958 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-08T22:42:52.959Z,1607467372.959 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-08T22:42:52.959Z,1607467372.959 [Default:A.Wait] Running Loop=1
2020-12-08T22:42:52.959Z,1607467372.959 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-12-08T22:43:06.311Z,1607467386.311 [Default:A.Wait](INFO): Done Waiting.
2020-12-08T22:43:06.311Z,1607467386.311 [Default:A.Wait] Stopped
2020-12-08T22:43:06.311Z,1607467386.311 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-12-08T22:43:06.711Z,1607467386.711 [Default:CheckIn] Running Loop=1
2020-12-08T22:43:06.711Z,1607467386.711 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-08T22:43:06.711Z,1607467386.711 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-08T22:43:07.140Z,1607467387.140 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-12-08T22:44:50.577Z,1607467490.577 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-12-08T22:45:08.729Z,1607467508.729 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-12-08T22:45:08.729Z,1607467508.729 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-08T22:45:08.739Z,1607467508.739 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-08T22:45:09.141Z,1607467509.141 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-08T22:45:09.141Z,1607467509.141 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-12-08T22:46:03.237Z,1607467563.237 [BPC1](ERROR): BPC1B: No match for serial number FFFF in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2020-12-08T22:46:51.786Z,1607467611.786 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-12-08T22:46:51.789Z,1607467611.789 [BPC1](INFO): Received data from all battery sticks.
2020-12-08T22:48:06.938Z,1607467686.938 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-08T22:43:06.7Z
2020-12-08T22:48:06.938Z,1607467686.938 [Default:CheckIn:Read_GPS] Stopped
2020-12-08T22:48:06.938Z,1607467686.938 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-08T22:48:07.362Z,1607467687.362 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-08T22:48:09.771Z,1607467689.771 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-12-08T22:48:09.771Z,1607467689.771 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-08T22:48:09.781Z,1607467689.781 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-08T22:48:10.224Z,1607467690.224 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-08T22:48:10.224Z,1607467690.224 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-12-08T22:48:25.544Z,1607467705.544 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201208T222136/Courier0007.lzma
2020-12-08T22:48:26.544Z,1607467706.544 [DataOverHttps](INFO): Moved sent file to Logs/20201208T222136/Courier0007.lzma.bak
2020-12-08T22:48:26.545Z,1607467706.545 [DataOverHttps](INFO): SBD MOMSN=13421895
2020-12-08T22:48:45.378Z,1607467725.378 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20201208T223857/Courier0000.lzma
2020-12-08T22:48:46.380Z,1607467726.380 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Courier0000.lzma.bak
2020-12-08T22:48:46.380Z,1607467726.380 [DataOverHttps](INFO): SBD MOMSN=13421897
2020-12-08T22:49:02.278Z,1607467742.278 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20201208T223857/Courier0004.lzma
2020-12-08T22:49:03.280Z,1607467743.280 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Courier0004.lzma.bak
2020-12-08T22:49:03.280Z,1607467743.280 [DataOverHttps](INFO): SBD MOMSN=13421900
2020-12-08T22:49:19.015Z,1607467759.015 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20201208T222136/Express0008.lzma
2020-12-08T22:49:20.016Z,1607467760.016 [DataOverHttps](INFO): Moved sent file to Logs/20201208T222136/Express0008.lzma.bak
2020-12-08T22:49:20.016Z,1607467760.016 [DataOverHttps](INFO): SBD MOMSN=13421902
2020-12-08T22:49:36.047Z,1607467776.047 [DataOverHttps](INFO): Sending 956 bytes from file Logs/20201208T223857/Express0001.lzma
2020-12-08T22:49:37.051Z,1607467777.051 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Express0001.lzma.bak
2020-12-08T22:49:37.052Z,1607467777.052 [DataOverHttps](INFO): SBD MOMSN=13421914
2020-12-08T22:49:49.252Z,1607467789.252 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-12-08T22:49:49.252Z,1607467789.252 [NAL9602] Data Fault, FailCount= 1
2020-12-08T22:49:49.252Z,1607467789.252 [NAL9602](ERROR): Data Fault
2020-12-08T22:49:49.282Z,1607467789.282 [CBIT](ERROR): Data Fault in component: NAL9602
2020-12-08T22:49:49.659Z,1607467789.659 [NAL9602](INFO): Powering down
2020-12-08T22:49:50.530Z,1607467790.530 [CBIT](INFO): Clearing failed state for component NAL9602
2020-12-08T22:49:50.531Z,1607467790.531 [NAL9602] No Fault, FailCount= 1
2020-12-08T22:49:52.978Z,1607467792.978 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20201208T223857/Express0005.lzma
2020-12-08T22:49:53.980Z,1607467793.980 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Express0005.lzma.bak
2020-12-08T22:49:53.980Z,1607467793.980 [DataOverHttps](INFO): SBD MOMSN=13421939
2020-12-08T22:49:55.336Z,1607467795.336 [Default:CheckIn:Read_Iridium] Stopped
2020-12-08T22:49:55.336Z,1607467795.336 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-08T22:49:55.336Z,1607467795.336 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-08T22:50:19.956Z,1607467819.956 [NAL9602](INFO): Powering up NAL9602
2020-12-08T22:50:30.869Z,1607467830.869 [NAL9602](INFO): NAL9602 initialized
2020-12-08T22:51:10.891Z,1607467870.891 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-12-08T22:51:10.891Z,1607467870.891 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-08T22:51:10.929Z,1607467870.929 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-08T22:51:11.293Z,1607467871.293 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-08T22:51:11.293Z,1607467871.293 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-12-08T22:54:11.942Z,1607468051.942 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-12-08T22:54:11.942Z,1607468051.942 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-08T22:54:11.953Z,1607468051.953 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-08T22:54:12.364Z,1607468052.364 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-08T22:54:12.364Z,1607468052.364 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-12-08T22:54:55.984Z,1607468095.984 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-08T22:54:55.984Z,1607468095.984 [Default:CheckIn:C.Wait] Stopped
2020-12-08T22:54:55.984Z,1607468095.984 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-08T22:54:55.984Z,1607468095.984 [Default:CheckIn:D] Running Loop=1
2020-12-08T22:54:56.381Z,1607468096.381 [Default:CheckIn:D] Stopped
2020-12-08T22:54:56.381Z,1607468096.381 [Default:CheckIn:E] Running Loop=1
2020-12-08T22:54:56.799Z,1607468096.799 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.057065 min 
2020-12-08T22:54:56.800Z,1607468096.800 [Default:CheckIn:E] Stopped
2020-12-08T22:54:56.800Z,1607468096.800 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-12-08T22:54:56.800Z,1607468096.800 [Default:CheckIn] Stopped
2020-12-08T22:54:56.800Z,1607468096.800 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-08T22:54:56.800Z,1607468096.800 [Default:CheckIn](INFO): Running loop #2
2020-12-08T22:54:56.800Z,1607468096.800 [Default:CheckIn] Running Loop=2
2020-12-08T22:54:56.800Z,1607468096.800 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-08T22:54:56.800Z,1607468096.800 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-08T22:57:04.101Z,1607468224.101 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225702.00,A,3648.16571,N,12147.21437,W,0.136,25.14,081220,,,A*4C
2020-12-08T22:57:04.105Z,1607468224.105 [NAL9602](INFO): GPS fix at 20201208T225702: (36.802762, -121.786906)
2020-12-08T22:57:04.126Z,1607468224.126 [Default:CheckIn:Read_GPS] Stopped
2020-12-08T22:57:04.126Z,1607468224.126 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-08T22:57:36.539Z,1607468256.539 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-08T22:58:16.918Z,1607468296.918 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20201208T223857/Courier0007.lzma
2020-12-08T22:58:17.926Z,1607468297.926 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Courier0007.lzma.bak
2020-12-08T22:58:17.926Z,1607468297.926 [DataOverHttps](INFO): SBD MOMSN=13421954
2020-12-08T23:01:58.978Z,1607468518.978 [DataOverHttps](INFO): Sending 308 bytes from file Logs/20201208T223857/Express0008.lzma
2020-12-08T23:01:59.980Z,1607468519.980 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Express0008.lzma.bak
2020-12-08T23:01:59.980Z,1607468519.980 [DataOverHttps](INFO): SBD MOMSN=13422000
2020-12-08T23:02:01.507Z,1607468521.507 [Default:CheckIn:Read_Iridium] Stopped
2020-12-08T23:02:01.507Z,1607468521.507 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-08T23:02:01.508Z,1607468521.508 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-08T23:04:35.260Z,1607468675.260 [DataOverHttps](IMPORTANT): SBD MTMSN=20201208T230434
2020-12-08T23:04:42.845Z,1607468682.845 [DataOverHttps](INFO): Received command:ibit
2020-12-08T23:04:42.879Z,1607468682.879 [CommandLine](IMPORTANT): got command ibit
2020-12-08T23:04:43.178Z,1607468683.178 [IBIT](IMPORTANT): Beginning Initiated BIT
2020-12-08T23:04:43.179Z,1607468683.179 [IBIT](IMPORTANT): Beginning control surface checks.
2020-12-08T23:04:43.182Z,1607468683.182 [CBIT](IMPORTANT): Beginning ground fault scan
2020-12-08T23:04:44.773Z,1607468684.773 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230443.00,A,3648.16294,N,12147.20920,W,1.769,88.17,081220,,,D*44
2020-12-08T23:04:44.775Z,1607468684.775 [NAL9602](INFO): GPS fix at 20201208T230443: (36.802716, -121.786820)
2020-12-08T23:04:45.595Z,1607468685.595 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-12-08T23:04:54.080Z,1607468694.080 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009236
CHAN A1 (24V): -0.001252
CHAN A2 (12V): -0.007460
CHAN A3 (5V): -0.002923
CHAN B0 (3.3V): 0.000125
CHAN B1 (3.15aV): -0.000348
CHAN B2 (3.15bV): 0.000311
CHAN B3 (GND): 0.002080
OPEN: 0.005259
Full Scale Calc: 4.765 mA, -1.589 mA
2020-12-08T23:05:06.989Z,1607468706.989 [NAL9602](INFO): SBD MO Status=0, MOMSN=11715, MT Status=0, MTMSN=0
2020-12-08T23:05:06.989Z,1607468706.989 [NAL9602](INFO): No messages in MT queue
2020-12-08T23:05:08.206Z,1607468708.206 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230507.00,A,3648.16909,N,12147.19705,W,4.199,39.75,081220,,,D*4B
2020-12-08T23:05:08.208Z,1607468708.208 [NAL9602](INFO): GPS fix at 20201208T230507: (36.802818, -121.786618)
2020-12-08T23:05:11.431Z,1607468711.431 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230510.00,A,3648.17209,N,12147.19407,W,4.821,40.08,081220,,,D*48
2020-12-08T23:05:11.433Z,1607468711.433 [NAL9602](INFO): GPS fix at 20201208T230510: (36.802868, -121.786568)
2020-12-08T23:05:14.261Z,1607468714.261 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230513.00,A,3648.17508,N,12147.19077,W,4.665,43.72,081220,,,D*4E
2020-12-08T23:05:14.263Z,1607468714.263 [NAL9602](INFO): GPS fix at 20201208T230513: (36.802918, -121.786513)
2020-12-08T23:05:17.089Z,1607468717.089 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230516.00,A,3648.17776,N,12147.18737,W,4.374,46.47,081220,,,D*44
2020-12-08T23:05:17.091Z,1607468717.091 [NAL9602](INFO): GPS fix at 20201208T230516: (36.802963, -121.786456)
2020-12-08T23:05:20.325Z,1607468720.325 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230519.00,A,3648.18011,N,12147.18411,W,4.218,48.87,081220,,,D*4C
2020-12-08T23:05:20.327Z,1607468720.327 [NAL9602](INFO): GPS fix at 20201208T230519: (36.803002, -121.786402)
2020-12-08T23:05:23.153Z,1607468723.153 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230522.00,A,3648.18241,N,12147.18092,W,4.102,47.54,081220,,,D*45
2020-12-08T23:05:23.156Z,1607468723.156 [NAL9602](INFO): GPS fix at 20201208T230522: (36.803040, -121.786349)
2020-12-08T23:05:26.382Z,1607468726.382 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230525.00,A,3648.18466,N,12147.17777,W,3.888,47.57,081220,,,D*4D
2020-12-08T23:05:26.384Z,1607468726.384 [NAL9602](INFO): GPS fix at 20201208T230525: (36.803078, -121.786296)
2020-12-08T23:05:29.209Z,1607468729.209 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230528.00,A,3648.18693,N,12147.17484,W,3.946,44.54,081220,,,D*44
2020-12-08T23:05:29.212Z,1607468729.212 [NAL9602](INFO): GPS fix at 20201208T230528: (36.803115, -121.786247)
2020-12-08T23:05:29.669Z,1607468729.669 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.803116 Longitude: -121.786247
2020-12-08T23:05:30.040Z,1607468730.040 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.016001
2020-12-08T23:05:30.040Z,1607468730.040 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2020-12-08T23:05:30.040Z,1607468730.040 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2020-12-08T23:05:30.528Z,1607468730.528 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2020-12-08T23:05:30.528Z,1607468730.528 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2020-12-08T23:05:30.528Z,1607468730.528 [IBIT](IMPORTANT): Pressure:7.278172 PSI
2020-12-08T23:05:30.529Z,1607468730.529 [IBIT](IMPORTANT): Humidity:17.287266 %
2020-12-08T23:05:30.876Z,1607468730.876 [IBIT](IMPORTANT): Vehicle Pitch:0.605503 degrees
2020-12-08T23:05:30.876Z,1607468730.876 [IBIT](IMPORTANT): Vehicle  Roll:-10.469729 degrees
2020-12-08T23:05:30.877Z,1607468730.877 [IBIT](IMPORTANT): Vehicle  Heading:41.950867 degrees
2020-12-08T23:05:31.250Z,1607468731.250 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2020-12-08T23:05:31.251Z,1607468731.251 [IBIT](IMPORTANT): buoyancyNeutral: 222.366592 cc
2020-12-08T23:05:31.251Z,1607468731.251 [IBIT](IMPORTANT): massDefault: 0.756704 cm
2020-12-08T23:05:31.251Z,1607468731.251 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2020-12-08T23:05:31.252Z,1607468731.252 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2020-12-08T23:05:31.252Z,1607468731.252 [IBIT](IMPORTANT): IBIT PASSED
2020-12-08T23:06:01.935Z,1607468761.935 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-08T23:07:01.998Z,1607468821.998 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-08T23:07:01.998Z,1607468821.998 [Default:CheckIn:C.Wait] Stopped
2020-12-08T23:07:01.998Z,1607468821.998 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-08T23:07:01.998Z,1607468821.998 [Default:CheckIn:D] Running Loop=1
2020-12-08T23:07:02.406Z,1607468822.406 [Default:CheckIn:D] Stopped
2020-12-08T23:07:02.406Z,1607468822.406 [Default:CheckIn:E] Running Loop=1
2020-12-08T23:07:02.830Z,1607468822.830 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.157491 min 
2020-12-08T23:07:02.830Z,1607468822.830 [Default:CheckIn:E] Stopped
2020-12-08T23:07:02.830Z,1607468822.830 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-12-08T23:07:02.830Z,1607468822.830 [Default:CheckIn] Stopped
2020-12-08T23:07:02.839Z,1607468822.839 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-08T23:07:02.839Z,1607468822.839 [Default:CheckIn](INFO): Running loop #3
2020-12-08T23:07:02.839Z,1607468822.839 [Default:CheckIn] Running Loop=3
2020-12-08T23:07:02.839Z,1607468822.839 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-08T23:07:02.839Z,1607468822.839 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-08T23:07:04.775Z,1607468824.775 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230704.00,A,3648.29830,N,12147.12255,W,5.035,4.09,081220,,,D*75
2020-12-08T23:07:04.778Z,1607468824.778 [NAL9602](INFO): GPS fix at 20201208T230704: (36.804972, -121.785376)
2020-12-08T23:07:04.818Z,1607468824.818 [Default:CheckIn:Read_GPS] Stopped
2020-12-08T23:07:04.818Z,1607468824.818 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-08T23:07:14.078Z,1607468834.078 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20201208T223857/Courier0010.lzma
2020-12-08T23:07:15.081Z,1607468835.081 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Courier0010.lzma.bak
2020-12-08T23:07:15.081Z,1607468835.081 [DataOverHttps](INFO): SBD MOMSN=13422013
2020-12-08T23:07:17.709Z,1607468837.709 [NAL9602](INFO): SBD MO Status=0, MOMSN=11716, MT Status=0, MTMSN=0
2020-12-08T23:07:17.710Z,1607468837.710 [NAL9602](INFO): No messages in MT queue
2020-12-08T23:07:31.406Z,1607468851.406 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201208T223857/Courier0013.lzma
2020-12-08T23:07:32.409Z,1607468852.409 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Courier0013.lzma.bak
2020-12-08T23:07:32.409Z,1607468852.409 [DataOverHttps](INFO): SBD MOMSN=13422017
2020-12-08T23:07:48.468Z,1607468868.468 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-08T23:07:51.352Z,1607468871.352 [DataOverHttps](INFO): Sending 819 bytes from file Logs/20201208T223857/Express0011.lzma
2020-12-08T23:07:52.353Z,1607468872.353 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Express0011.lzma.bak
2020-12-08T23:07:52.353Z,1607468872.353 [DataOverHttps](INFO): SBD MOMSN=13422019
2020-12-08T23:08:08.814Z,1607468888.814 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201208T223857/Express0014.lzma
2020-12-08T23:08:09.817Z,1607468889.817 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Express0014.lzma.bak
2020-12-08T23:08:09.817Z,1607468889.817 [DataOverHttps](INFO): SBD MOMSN=13422045
2020-12-08T23:08:11.128Z,1607468891.128 [Default:CheckIn:Read_Iridium] Stopped
2020-12-08T23:08:11.128Z,1607468891.128 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-08T23:08:11.128Z,1607468891.128 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-08T23:13:11.890Z,1607469191.890 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-08T23:13:11.890Z,1607469191.890 [Default:CheckIn:C.Wait] Stopped
2020-12-08T23:13:11.890Z,1607469191.890 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-08T23:13:11.891Z,1607469191.891 [Default:CheckIn:D] Running Loop=1
2020-12-08T23:13:12.296Z,1607469192.296 [Default:CheckIn:D] Stopped
2020-12-08T23:13:12.296Z,1607469192.296 [Default:CheckIn:E] Running Loop=1
2020-12-08T23:13:12.755Z,1607469192.755 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.322319 min 
2020-12-08T23:13:12.755Z,1607469192.755 [Default:CheckIn:E] Stopped
2020-12-08T23:13:12.755Z,1607469192.755 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-12-08T23:13:12.755Z,1607469192.755 [Default:CheckIn] Stopped
2020-12-08T23:13:12.755Z,1607469192.755 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-08T23:13:12.755Z,1607469192.755 [Default:CheckIn](INFO): Running loop #4
2020-12-08T23:13:12.755Z,1607469192.755 [Default:CheckIn] Running Loop=4
2020-12-08T23:13:12.756Z,1607469192.756 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-08T23:13:12.756Z,1607469192.756 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-08T23:13:14.698Z,1607469194.698 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231313.00,A,3647.84688,N,12147.83456,W,31.918,207.63,081220,,,D*42
2020-12-08T23:13:14.700Z,1607469194.700 [NAL9602](INFO): GPS fix at 20201208T231313: (36.797448, -121.797243)
2020-12-08T23:13:14.722Z,1607469194.722 [Default:CheckIn:Read_GPS] Stopped
2020-12-08T23:13:14.722Z,1607469194.722 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-08T23:13:28.026Z,1607469208.026 [NAL9602](INFO): SBD MO Status=0, MOMSN=11717, MT Status=0, MTMSN=0
2020-12-08T23:13:28.026Z,1607469208.026 [NAL9602](INFO): No messages in MT queue
2020-12-08T23:13:58.735Z,1607469238.735 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-08T23:15:56.454Z,1607469356.454 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201208T223857/Courier0016.lzma
2020-12-08T23:15:57.457Z,1607469357.457 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Courier0016.lzma.bak
2020-12-08T23:15:57.457Z,1607469357.457 [DataOverHttps](INFO): SBD MOMSN=13422116
2020-12-08T23:16:13.930Z,1607469373.930 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20201208T223857/Express0017.lzma
2020-12-08T23:16:14.933Z,1607469374.933 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Express0017.lzma.bak
2020-12-08T23:16:14.933Z,1607469374.933 [DataOverHttps](INFO): SBD MOMSN=13422132
2020-12-08T23:16:16.266Z,1607469376.266 [Default:CheckIn:Read_Iridium] Stopped
2020-12-08T23:16:16.266Z,1607469376.266 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-08T23:16:16.266Z,1607469376.266 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-08T23:19:44.831Z,1607469584.831 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-12-08T23:19:46.839Z,1607469586.839 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239376
2020-12-08T23:20:19.971Z,1607469619.971 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-12-08T23:20:55.118Z,1607469655.118 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-12-08T23:21:16.978Z,1607469676.978 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-08T23:21:16.978Z,1607469676.978 [Default:CheckIn:C.Wait] Stopped
2020-12-08T23:21:16.978Z,1607469676.978 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-08T23:21:16.978Z,1607469676.978 [Default:CheckIn:D] Running Loop=1
2020-12-08T23:21:17.351Z,1607469677.351 [Default:CheckIn:D] Stopped
2020-12-08T23:21:17.351Z,1607469677.351 [Default:CheckIn:E] Running Loop=1
2020-12-08T23:21:17.831Z,1607469677.831 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.406576 min 
2020-12-08T23:21:17.831Z,1607469677.831 [Default:CheckIn:E] Stopped
2020-12-08T23:21:17.831Z,1607469677.831 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-12-08T23:21:17.831Z,1607469677.831 [Default:CheckIn] Stopped
2020-12-08T23:21:17.832Z,1607469677.832 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-08T23:21:17.832Z,1607469677.832 [Default:CheckIn](INFO): Running loop #5
2020-12-08T23:21:17.832Z,1607469677.832 [Default:CheckIn] Running Loop=5
2020-12-08T23:21:17.832Z,1607469677.832 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-08T23:21:17.832Z,1607469677.832 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-08T23:21:19.762Z,1607469679.762 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232118.00,A,3644.41264,N,12151.02891,W,34.464,218.78,081220,,,D*4A
2020-12-08T23:21:19.764Z,1607469679.764 [NAL9602](INFO): GPS fix at 20201208T232118: (36.740211, -121.850482)
2020-12-08T23:21:19.815Z,1607469679.815 [Default:CheckIn:Read_GPS] Stopped
2020-12-08T23:21:19.815Z,1607469679.815 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-08T23:21:21.695Z,1607469681.695 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002757
2020-12-08T23:21:29.326Z,1607469689.326 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201208T223857/Courier0019.lzma
2020-12-08T23:21:30.329Z,1607469690.329 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Courier0019.lzma.bak
2020-12-08T23:21:30.329Z,1607469690.329 [DataOverHttps](INFO): SBD MOMSN=13422139
2020-12-08T23:21:35.589Z,1607469695.589 [NAL9602](INFO): SBD MO Status=1, MOMSN=11718, MT Status=0, MTMSN=0
2020-12-08T23:21:35.639Z,1607469695.639 [NAL9602](INFO): Sent 72 bytes from file Logs/20201208T223857/Courier0019.lzma
2020-12-08T23:21:35.639Z,1607469695.639 [NAL9602](INFO): Packets left to send: 0
2020-12-08T23:21:46.946Z,1607469706.946 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20201208T223857/Express0020.lzma
2020-12-08T23:21:47.949Z,1607469707.949 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Express0020.lzma.bak
2020-12-08T23:21:47.949Z,1607469707.949 [DataOverHttps](INFO): SBD MOMSN=13422145
2020-12-08T23:21:49.342Z,1607469709.342 [Default:CheckIn:Read_Iridium] Stopped
2020-12-08T23:21:49.342Z,1607469709.342 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-08T23:21:49.342Z,1607469709.342 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-08T23:22:06.292Z,1607469726.292 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-08T23:26:50.006Z,1607470010.006 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-08T23:26:50.006Z,1607470010.006 [Default:CheckIn:C.Wait] Stopped
2020-12-08T23:26:50.006Z,1607470010.006 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-08T23:26:50.006Z,1607470010.006 [Default:CheckIn:D] Running Loop=1
2020-12-08T23:26:50.406Z,1607470010.406 [Default:CheckIn:D] Stopped
2020-12-08T23:26:50.406Z,1607470010.406 [Default:CheckIn:E] Running Loop=1
2020-12-08T23:26:50.859Z,1607470010.859 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.957491 min 
2020-12-08T23:26:50.860Z,1607470010.860 [Default:CheckIn:E] Stopped
2020-12-08T23:26:50.860Z,1607470010.860 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-12-08T23:26:50.860Z,1607470010.860 [Default:CheckIn] Stopped
2020-12-08T23:26:50.860Z,1607470010.860 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-08T23:26:50.860Z,1607470010.860 [Default:CheckIn](INFO): Running loop #6
2020-12-08T23:26:50.860Z,1607470010.860 [Default:CheckIn] Running Loop=6
2020-12-08T23:26:50.860Z,1607470010.860 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-08T23:26:50.860Z,1607470010.860 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-08T23:26:52.831Z,1607470012.831 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232651.00,A,3642.36601,N,12152.86203,W,25.503,213.41,081220,,,D*4E
2020-12-08T23:26:52.833Z,1607470012.833 [NAL9602](INFO): GPS fix at 20201208T232651: (36.706100, -121.881034)
2020-12-08T23:26:52.897Z,1607470012.897 [Default:CheckIn:Read_GPS] Stopped
2020-12-08T23:26:52.897Z,1607470012.897 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-08T23:27:17.465Z,1607470037.465 [NAL9602](INFO): SBD MO Status=2, MOMSN=11719, MT Status=2, MTMSN=0
2020-12-08T23:27:17.466Z,1607470037.466 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-12-08T23:27:28.374Z,1607470048.374 [NAL9602](INFO): SBD MO Status=0, MOMSN=11719, MT Status=0, MTMSN=0
2020-12-08T23:27:28.374Z,1607470048.374 [NAL9602](INFO): No messages in MT queue
2020-12-08T23:27:59.072Z,1607470079.072 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-08T23:30:14.424Z,1607470214.424 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201208T223857/Courier0022.lzma
2020-12-08T23:30:15.427Z,1607470215.427 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Courier0022.lzma.bak
2020-12-08T23:30:15.427Z,1607470215.427 [DataOverHttps](INFO): SBD MOMSN=13422222
2020-12-08T23:30:42.225Z,1607470242.225 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20201208T223857/Express0023.lzma
2020-12-08T23:30:43.227Z,1607470243.227 [DataOverHttps](INFO): Moved sent file to Logs/20201208T223857/Express0023.lzma.bak
2020-12-08T23:30:43.227Z,1607470243.227 [DataOverHttps](INFO): SBD MOMSN=13422228
2020-12-08T23:30:44.424Z,1607470244.424 [Default:CheckIn:Read_Iridium] Stopped
2020-12-08T23:30:44.424Z,1607470244.424 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-08T23:30:44.425Z,1607470244.425 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-08T23:34:29.301Z,1607470469.301 [DataOverHttps](IMPORTANT): SBD MTMSN=20201208T233428
2020-12-08T23:34:41.192Z,1607470481.192 [DataOverHttps](INFO): Received command:restart logs