2020-01-08T23:31:51.476Z,1578526311.476 [Supervisor](DEBUG): Initializing supervisor.
2020-01-08T23:31:51.479Z,1578526311.479 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-01-08T23:31:51.480Z,1578526311.480 [SyncHandler](INFO): Protected caller Thread ID is 892
2020-01-08T23:31:51.481Z,1578526311.481 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-01-08T23:31:51.482Z,1578526311.482 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-01-08T23:31:51.482Z,1578526311.482 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 893
2020-01-08T23:31:51.485Z,1578526311.485 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-01-08T23:31:51.497Z,1578526311.497 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-01-08T23:31:51.498Z,1578526311.498 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-01-08T23:31:51.498Z,1578526311.498 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 894
2020-01-08T23:31:51.499Z,1578526311.499 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-01-08T23:31:51.500Z,1578526311.500 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-01-08T23:31:51.500Z,1578526311.500 [logger ThreadHandler](INFO): Protected caller Thread ID is 895
2020-01-08T23:31:51.502Z,1578526311.502 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-01-08T23:31:51.502Z,1578526311.502 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-01-08T23:31:51.504Z,1578526311.504 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-01-08T23:31:51.920Z,1578526311.920 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-01-08T23:31:51.920Z,1578526311.920 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-01-08T23:31:52.015Z,1578526312.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-01-08T23:31:52.015Z,1578526312.015 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-01-08T23:31:52.326Z,1578526312.326 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-01-08T23:31:52.327Z,1578526312.327 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-01-08T23:31:52.460Z,1578526312.460 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-01-08T23:31:52.461Z,1578526312.461 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-01-08T23:31:52.643Z,1578526312.643 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-01-08T23:31:52.643Z,1578526312.643 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-01-08T23:31:53.075Z,1578526313.075 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-01-08T23:31:53.076Z,1578526313.076 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-01-08T23:31:53.275Z,1578526313.275 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-01-08T23:31:53.276Z,1578526313.276 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-01-08T23:31:53.415Z,1578526313.415 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-01-08T23:31:53.416Z,1578526313.416 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-01-08T23:31:53.596Z,1578526313.596 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-01-08T23:31:53.597Z,1578526313.597 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-01-08T23:31:53.689Z,1578526313.689 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-01-08T23:31:53.690Z,1578526313.690 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-01-08T23:31:53.979Z,1578526313.979 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-01-08T23:31:53.980Z,1578526313.980 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-01-08T23:31:54.058Z,1578526314.058 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-01-08T23:31:54.158Z,1578526314.158 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-01-08T23:31:54.158Z,1578526314.158 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-01-08T23:31:54.774Z,1578526314.774 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-01-08T23:31:54.775Z,1578526314.775 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-01-08T23:31:55.172Z,1578526315.172 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-01-08T23:31:55.174Z,1578526315.174 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-01-08T23:31:55.175Z,1578526315.175 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-01-08T23:31:55.372Z,1578526315.372 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-01-08T23:31:55.467Z,1578526315.467 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-01-08T23:31:55.562Z,1578526315.562 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-01-08T23:31:55.870Z,1578526315.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-01-08T23:31:55.870Z,1578526315.870 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-01-08T23:31:56.044Z,1578526316.044 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-01-08T23:31:56.184Z,1578526316.184 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-01-08T23:31:56.317Z,1578526316.317 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-01-08T23:31:56.453Z,1578526316.453 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-01-08T23:31:56.709Z,1578526316.709 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-01-08T23:31:56.984Z,1578526316.984 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-01-08T23:31:57.111Z,1578526317.111 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2020-01-08T23:31:57.111Z,1578526317.111 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-01-08T23:31:57.134Z,1578526317.134 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-01-08T23:31:57.456Z,1578526317.456 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-01-08T23:31:57.461Z,1578526317.461 [AHRS_M2](INFO): created writer for : platform_orientation
2020-01-08T23:31:57.463Z,1578526317.463 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-01-08T23:31:57.468Z,1578526317.468 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-01-08T23:31:57.468Z,1578526317.468 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-01-08T23:31:57.474Z,1578526317.474 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-01-08T23:31:57.474Z,1578526317.474 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-01-08T23:31:57.479Z,1578526317.479 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-01-08T23:31:57.554Z,1578526317.554 [AHRS_M2] Loaded
2020-01-08T23:31:57.554Z,1578526317.554 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-01-08T23:31:57.634Z,1578526317.634 [DataOverHttps] Loaded
2020-01-08T23:31:57.634Z,1578526317.634 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-01-08T23:31:57.635Z,1578526317.635 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407684E0
2020-01-08T23:31:57.635Z,1578526317.635 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 974
2020-01-08T23:31:57.659Z,1578526317.659 [DDM] Loaded
2020-01-08T23:31:57.660Z,1578526317.660 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-01-08T23:31:57.673Z,1578526317.673 [Depth_Keller] Loaded
2020-01-08T23:31:57.673Z,1578526317.673 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-01-08T23:31:57.678Z,1578526317.678 [DropWeight] Loaded
2020-01-08T23:31:57.678Z,1578526317.678 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-01-08T23:31:57.739Z,1578526317.739 [DUSBL_Hydroid] Loaded
2020-01-08T23:31:57.739Z,1578526317.739 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-01-08T23:31:57.785Z,1578526317.785 [Micromodem] Loaded
2020-01-08T23:31:57.786Z,1578526317.786 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-01-08T23:31:57.883Z,1578526317.883 [NAL9602] Loaded
2020-01-08T23:31:57.883Z,1578526317.883 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-01-08T23:31:57.920Z,1578526317.920 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now
2020-01-08T23:31:57.920Z,1578526317.920 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now
2020-01-08T23:31:57.921Z,1578526317.921 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now
2020-01-08T23:31:57.922Z,1578526317.922 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full
2020-01-08T23:31:57.922Z,1578526317.922 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now
2020-01-08T23:31:57.923Z,1578526317.923 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now
2020-01-08T23:31:57.923Z,1578526317.923 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now
2020-01-08T23:31:57.924Z,1578526317.924 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full
2020-01-08T23:31:57.924Z,1578526317.924 [Onboard] Loaded
2020-01-08T23:31:57.924Z,1578526317.924 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-01-08T23:31:57.930Z,1578526317.930 [PowerOnly] Loaded
2020-01-08T23:31:57.930Z,1578526317.930 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2020-01-08T23:31:57.937Z,1578526317.937 [Radio_Surface] Loaded
2020-01-08T23:31:57.937Z,1578526317.937 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-01-08T23:31:57.938Z,1578526317.938 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407984E0
2020-01-08T23:31:57.938Z,1578526317.938 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 975
2020-01-08T23:31:57.982Z,1578526317.982 [RDI_Pathfinder] Loaded
2020-01-08T23:31:57.982Z,1578526317.982 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-01-08T23:31:59.465Z,1578526319.465 [BPC1] Loaded
2020-01-08T23:31:59.465Z,1578526319.465 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-01-08T23:31:59.465Z,1578526319.465 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-01-08T23:31:59.466Z,1578526319.466 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-01-08T23:31:59.479Z,1578526319.479 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-01-08T23:31:59.479Z,1578526319.479 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-01-08T23:31:59.582Z,1578526319.582 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-01-08T23:31:59.582Z,1578526319.582 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-01-08T23:31:59.602Z,1578526319.602 [NavChart] Loaded
2020-01-08T23:31:59.602Z,1578526319.602 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-01-08T23:31:59.606Z,1578526319.606 [UniversalFixResidualReporter] Loaded
2020-01-08T23:31:59.607Z,1578526319.607 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-01-08T23:31:59.607Z,1578526319.607 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-01-08T23:31:59.608Z,1578526319.608 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-01-08T23:31:59.714Z,1578526319.714 [BuoyancyServo] Loaded
2020-01-08T23:31:59.714Z,1578526319.714 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-01-08T23:31:59.729Z,1578526319.729 [ElevatorServo] Loaded
2020-01-08T23:31:59.729Z,1578526319.729 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-01-08T23:31:59.744Z,1578526319.744 [MassServo] Loaded
2020-01-08T23:31:59.744Z,1578526319.744 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-01-08T23:31:59.759Z,1578526319.759 [RudderServo] Loaded
2020-01-08T23:31:59.759Z,1578526319.759 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-01-08T23:31:59.773Z,1578526319.773 [ThrusterServo] Loaded
2020-01-08T23:31:59.774Z,1578526319.774 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-01-08T23:31:59.774Z,1578526319.774 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-01-08T23:31:59.775Z,1578526319.775 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-01-08T23:32:00.030Z,1578526320.030 [CTD_NeilBrown] Loaded
2020-01-08T23:32:00.030Z,1578526320.030 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2020-01-08T23:32:00.031Z,1578526320.031 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408EC4E0
2020-01-08T23:32:00.032Z,1578526320.032 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 976
2020-01-08T23:32:00.046Z,1578526320.046 [PAR_Licor] Loaded
2020-01-08T23:32:00.046Z,1578526320.046 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-01-08T23:32:00.089Z,1578526320.089 [WetLabsSeaOWL_UV_A] Loaded
2020-01-08T23:32:00.090Z,1578526320.090 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-01-08T23:32:00.091Z,1578526320.091 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4091C4E0
2020-01-08T23:32:00.091Z,1578526320.091 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 977
2020-01-08T23:32:00.092Z,1578526320.092 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-01-08T23:32:00.092Z,1578526320.092 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-01-08T23:32:00.401Z,1578526320.401 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-01-08T23:32:00.401Z,1578526320.401 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-01-08T23:32:00.441Z,1578526320.441 [DepthRateCalculator] Loaded
2020-01-08T23:32:00.441Z,1578526320.441 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-01-08T23:32:00.447Z,1578526320.447 [PitchRateCalculator] Loaded
2020-01-08T23:32:00.447Z,1578526320.447 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-01-08T23:32:00.459Z,1578526320.459 [SpeedCalculator] Loaded
2020-01-08T23:32:00.460Z,1578526320.460 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-01-08T23:32:00.480Z,1578526320.480 [TempGradientCalculator] Loaded
2020-01-08T23:32:00.481Z,1578526320.481 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-01-08T23:32:00.486Z,1578526320.486 [YawRateCalculator] Loaded
2020-01-08T23:32:00.487Z,1578526320.487 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-01-08T23:32:00.526Z,1578526320.526 [ElevatorOffsetCalculator] Loaded
2020-01-08T23:32:00.527Z,1578526320.527 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-01-08T23:32:00.527Z,1578526320.527 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-01-08T23:32:00.528Z,1578526320.528 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-01-08T23:32:00.663Z,1578526320.663 [SBIT](DEBUG): Construct Startup Built In Test.
2020-01-08T23:32:00.684Z,1578526320.684 [SBIT] Loaded
2020-01-08T23:32:00.684Z,1578526320.684 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-01-08T23:32:00.685Z,1578526320.685 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-01-08T23:32:00.697Z,1578526320.697 [IBIT] Loaded
2020-01-08T23:32:00.698Z,1578526320.698 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-01-08T23:32:00.701Z,1578526320.701 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-01-08T23:32:00.839Z,1578526320.839 [CBIT] Loaded
2020-01-08T23:32:00.839Z,1578526320.839 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-01-08T23:32:00.839Z,1578526320.839 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-01-08T23:32:00.840Z,1578526320.840 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-01-08T23:32:00.921Z,1578526320.921 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-01-08T23:32:00.922Z,1578526320.922 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-01-08T23:32:01.114Z,1578526321.114 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-01-08T23:32:01.115Z,1578526321.115 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-01-08T23:32:01.165Z,1578526321.165 [VerticalControl](DEBUG): Construct VerticalControl.
2020-01-08T23:32:01.247Z,1578526321.247 [VerticalControl] Loaded
2020-01-08T23:32:01.247Z,1578526321.247 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-01-08T23:32:01.248Z,1578526321.248 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-01-08T23:32:01.317Z,1578526321.317 [HorizontalControl] Loaded
2020-01-08T23:32:01.318Z,1578526321.318 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-01-08T23:32:01.318Z,1578526321.318 [SpeedControl](DEBUG): Construct SpeedControl.
2020-01-08T23:32:01.320Z,1578526321.320 [SpeedControl] Loaded
2020-01-08T23:32:01.320Z,1578526321.320 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-01-08T23:32:01.321Z,1578526321.321 [LoopControl](DEBUG): Construct LoopControl.
2020-01-08T23:32:01.321Z,1578526321.321 [LoopControl] Loaded
2020-01-08T23:32:01.322Z,1578526321.322 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-01-08T23:32:01.322Z,1578526321.322 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-01-08T23:32:01.323Z,1578526321.323 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-01-08T23:32:01.355Z,1578526321.355 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-01-08T23:32:01.358Z,1578526321.358 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-01-08T23:32:01.359Z,1578526321.359 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-01-08T23:32:01.366Z,1578526321.366 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-01-08T23:32:01.367Z,1578526321.367 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AFB4E0
2020-01-08T23:32:01.367Z,1578526321.367 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 978
2020-01-08T23:32:01.372Z,1578526321.372 [Supervisor](INFO): Main Thread ID is 9800
2020-01-08T23:32:01.372Z,1578526321.372 [Supervisor](DEBUG): Running supervisor.
2020-01-08T23:32:01.372Z,1578526321.372 [CommandLine ThreadHandler](INFO): Handler Thread ID is 979
2020-01-08T23:32:01.375Z,1578526321.375 [controlThread ThreadHandler](INFO): Handler Thread ID is 980
2020-01-08T23:32:01.375Z,1578526321.375 [controlThread](DEBUG): Initializing ControlThread
2020-01-08T23:32:01.384Z,1578526321.384 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-01-08T23:32:01.384Z,1578526321.384 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-01-08T23:32:01.389Z,1578526321.389 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-01-08T23:32:01.389Z,1578526321.389 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-01-08T23:32:01.390Z,1578526321.390 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-01-08T23:32:01.390Z,1578526321.390 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-01-08T23:32:01.390Z,1578526321.390 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-01-08T23:32:01.391Z,1578526321.391 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-01-08T23:32:01.391Z,1578526321.391 [SBIT](INFO): Initialize SBIT Component.
2020-01-08T23:32:01.392Z,1578526321.392 [SBIT](IMPORTANT): git: 2019-12-03-17-g4812c94
2020-01-08T23:32:01.392Z,1578526321.392 [SBIT](INFO): git hash: 4812c9429720da7730f61311b178b42396aebb36
2020-01-08T23:32:01.392Z,1578526321.392 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-01-08T23:32:01.394Z,1578526321.394 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #2 PREEMPT Wed May 15 08:34:03 PDT 2019
2020-01-08T23:32:01.395Z,1578526321.395 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-01-08T23:32:01.395Z,1578526321.395 [IBIT](INFO): Initialize IBIT Component.
2020-01-08T23:32:01.396Z,1578526321.396 [CBIT](DEBUG): Initialize CBIT Component.
2020-01-08T23:32:01.397Z,1578526321.397 [logger ThreadHandler](INFO): Handler Thread ID is 981
2020-01-08T23:32:01.409Z,1578526321.409 [CBIT](DEBUG): Initialized mux pins.
2020-01-08T23:32:01.409Z,1578526321.409 [CBIT](DEBUG): Initializing the watchdog timer.
2020-01-08T23:32:01.417Z,1578526321.417 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 982
2020-01-08T23:32:01.418Z,1578526321.418 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-01-08T23:32:01.429Z,1578526321.429 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 983
2020-01-08T23:32:01.433Z,1578526321.433 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2020-01-08T23:32:01.433Z,1578526321.433 [CBIT](DEBUG): Initializing heartbeat.
2020-01-08T23:32:01.441Z,1578526321.441 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 984
2020-01-08T23:32:01.442Z,1578526321.442 [CTD_NeilBrown](INFO): Powering down
2020-01-08T23:32:01.461Z,1578526321.461 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 985
2020-01-08T23:32:01.469Z,1578526321.469 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-08T23:32:01.493Z,1578526321.493 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 986
2020-01-08T23:32:01.496Z,1578526321.496 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-01-08T23:32:01.496Z,1578526321.496 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-01-08T23:32:01.497Z,1578526321.497 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-01-08T23:32:01.497Z,1578526321.497 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-01-08T23:32:01.497Z,1578526321.497 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-01-08T23:32:01.497Z,1578526321.497 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-01-08T23:32:01.497Z,1578526321.497 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-01-08T23:32:01.498Z,1578526321.498 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-01-08T23:32:01.498Z,1578526321.498 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-01-08T23:32:01.498Z,1578526321.498 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-01-08T23:32:01.498Z,1578526321.498 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-01-08T23:32:01.498Z,1578526321.498 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-01-08T23:32:01.498Z,1578526321.498 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-01-08T23:32:01.499Z,1578526321.499 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-01-08T23:32:01.499Z,1578526321.499 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-01-08T23:32:01.499Z,1578526321.499 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-01-08T23:32:01.505Z,1578526321.505 [CBIT](DEBUG): Deactivating GF circuits.
2020-01-08T23:32:01.505Z,1578526321.505 [CBIT](DEBUG): Deactivating emergency mode.
2020-01-08T23:32:01.541Z,1578526321.541 [CBIT](DEBUG): Backplane powered.
2020-01-08T23:32:01.541Z,1578526321.541 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-01-08T23:32:01.543Z,1578526321.543 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-01-08T23:32:01.543Z,1578526321.543 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-01-08T23:32:01.544Z,1578526321.544 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-01-08T23:32:01.545Z,1578526321.545 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-01-08T23:32:01.555Z,1578526321.555 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-08T23:32:01.590Z,1578526321.590 [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-01-08T23:32:01.591Z,1578526321.591 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-01-08T23:32:01.665Z,1578526321.665 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-01-08T23:32:01.666Z,1578526321.666 [Default:A.Wait](DEBUG): Construct Wait.
2020-01-08T23:32:01.668Z,1578526321.668 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-08T23:32:01.712Z,1578526321.712 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-01-08T23:32:01.714Z,1578526321.714 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-01-08T23:32:01.734Z,1578526321.734 [Default:E.Execute](DEBUG): Construct Execute.
2020-01-08T23:32:01.738Z,1578526321.738 [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-01-08T23:32:01.765Z,1578526321.765 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,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,Reporter,LogSplitter,
2020-01-08T23:32:01.770Z,1578526321.770 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-01-08T23:32:01.801Z,1578526321.801 [DDM](INFO): Powering up
2020-01-08T23:32:01.802Z,1578526321.802 [DDM](DEBUG): Initializing DDM.
2020-01-08T23:32:01.827Z,1578526321.827 [DUSBL_Hydroid](INFO): Powering up
2020-01-08T23:32:01.827Z,1578526321.827 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-01-08T23:32:01.833Z,1578526321.833 [Radio_Surface](INFO): Powering up
2020-01-08T23:32:01.935Z,1578526321.935 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-01-08T23:32:01.941Z,1578526321.941 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-01-08T23:32:01.942Z,1578526321.942 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-01-08T23:32:01.949Z,1578526321.949 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-01-08T23:32:01.950Z,1578526321.950 [MassServo](DEBUG): Initializing EZServoServo.
2020-01-08T23:32:01.957Z,1578526321.957 [MassServo](DEBUG): Initializing MassServo.
2020-01-08T23:32:01.958Z,1578526321.958 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-08T23:32:01.965Z,1578526321.965 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-08T23:32:01.966Z,1578526321.966 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-01-08T23:32:01.973Z,1578526321.973 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-01-08T23:32:01.975Z,1578526321.975 [CommandLine](FAULT): Scheduling is paused
2020-01-08T23:32:01.976Z,1578526321.976 [CBIT](INFO): Critical error at 20200108T233201
2020-01-08T23:32:01.976Z,1578526321.976 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-01-08T23:32:02.194Z,1578526322.194 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2020-01-08T23:32:02.194Z,1578526322.194 [DropWeight] Hardware Fault, FailCount= 1
2020-01-08T23:32:02.194Z,1578526322.194 [DropWeight](ERROR): Hardware Fault
2020-01-08T23:32:02.196Z,1578526322.196 [Micromodem](INFO): Powering up
2020-01-08T23:32:02.196Z,1578526322.196 [Micromodem](DEBUG): Initializing Micromodem.
2020-01-08T23:32:02.261Z,1578526322.261 [CBIT](INFO): Critical error at 20200108T233202
2020-01-08T23:32:02.263Z,1578526322.263 [CBIT](ERROR): Hardware Fault in component: DropWeight
2020-01-08T23:32:02.263Z,1578526322.263 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2020-01-08T23:32:02.933Z,1578526322.933 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-01-08T23:32:02.933Z,1578526322.933 [RudderServo](FAULT): Rudder failed to initialize
2020-01-08T23:32:02.933Z,1578526322.933 [RudderServo] Communications Fault, FailCount= 1
2020-01-08T23:32:02.933Z,1578526322.933 [RudderServo](ERROR): Communications Fault
2020-01-08T23:32:03.042Z,1578526323.042 [CBIT](INFO): Critical error at 20200108T233202
2020-01-08T23:32:03.045Z,1578526323.045 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-01-08T23:32:03.250Z,1578526323.250 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-08T23:32:03.250Z,1578526323.250 [RudderServo](INFO): Powering down
2020-01-08T23:32:03.928Z,1578526323.928 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-08T23:32:04.046Z,1578526324.046 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-08T23:32:04.051Z,1578526324.051 [CBIT](INFO): Clearing failed state for component RudderServo
2020-01-08T23:32:04.051Z,1578526324.051 [RudderServo] No Fault, FailCount= 1
2020-01-08T23:32:07.133Z,1578526327.133 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2020-01-08T23:32:07.540Z,1578526327.540 [Micromodem](INFO): Nmea in: $CATMG,2020-01-08T23:32:06.537126Z,RTC,RTC*5B

2020-01-08T23:32:07.540Z,1578526327.540 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-01-08T23:32:06.537126Z,RTC,RTC*5B

2020-01-08T23:32:07.967Z,1578526327.967 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2020-01-08T23:32:07.967Z,1578526327.967 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2020-01-08T23:32:08.371Z,1578526328.371 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2020-01-08T23:32:08.371Z,1578526328.371 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2020-01-08T23:32:08.775Z,1578526328.775 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2020-01-08T23:32:08.775Z,1578526328.775 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2020-01-08T23:32:09.179Z,1578526329.179 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2020-01-08T23:32:09.179Z,1578526329.179 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2020-01-08T23:32:09.583Z,1578526329.583 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2020-01-08T23:32:09.583Z,1578526329.583 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2020-01-08T23:32:09.983Z,1578526329.983 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2020-01-08T23:32:09.983Z,1578526329.983 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2020-01-08T23:32:10.403Z,1578526330.403 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2020-01-08T23:32:10.403Z,1578526330.403 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2020-01-08T23:32:10.770Z,1578526330.770 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2020-01-08T23:32:10.771Z,1578526330.771 [Micromodem](INFO): Nmea out: $CCCLK,2020,01,08,23,32,11*4D

2020-01-08T23:32:11.183Z,1578526331.183 [Micromodem](INFO): Nmea in: $CACLK,2020,1,8,23,32,11*4F

2020-01-08T23:32:11.978Z,1578526331.978 [Micromodem](INFO): Nmea in: $CATMS,0,2020-01-08T23:32:12Z*7C

2020-01-08T23:32:11.991Z,1578526331.991 [Micromodem](INFO): Nmea in: $CATMG,2020-01-08T23:32:12.027080Z,USER_CMD,RTC*16

2020-01-08T23:32:12.386Z,1578526332.386 [DDM](INFO): Dynamic Docking Module:C REMUS Capture Rev 1.1
2020-01-08T23:32:15.228Z,1578526335.228 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2020-01-08T23:32:19.654Z,1578526339.654 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-01-08T23:32:28.131Z,1578526348.131 [NAL9602](INFO): Powering up NAL9602
2020-01-08T23:32:39.039Z,1578526359.039 [NAL9602](INFO): NAL9602 initialized
2020-01-08T23:32:41.136Z,1578526361.136 [SBIT](IMPORTANT): Beginning Startup BIT
2020-01-08T23:32:41.148Z,1578526361.148 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-08T23:32:52.276Z,1578526372.276 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002169
CHAN A1 (24V): -0.028423
CHAN A2 (12V): -0.007241
CHAN A3 (5V): -0.002249
CHAN B0 (3.3V): 0.000329
CHAN B1 (3.15aV): 0.000016
CHAN B2 (3.15bV): 0.000323
CHAN B3 (GND): 0.002590
OPEN: 0.005529
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-08T23:32:54.223Z,1578526374.223 [SBIT](FAULT): Rudder: EXPECTED:15.000000 ACTUAL:14.980227
2020-01-08T23:33:35.216Z,1578526415.216 [SBIT](CRITICAL): SBIT FAILED
2020-01-08T23:33:35.236Z,1578526415.236 [CBIT](INFO): Critical error at 20200108T233335
2020-01-08T23:33:35.246Z,1578526415.246 [CommandLine](IMPORTANT): got command configSet list
2020-01-08T23:33:35.246Z,1578526415.246 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-01-08T23:33:35.247Z,1578526415.247 [CommandLine](IMPORTANT): Courier linearApproximation depth 5.000000 meter;

2020-01-08T23:33:35.247Z,1578526415.247 [CommandLine](IMPORTANT): Courier linearApproximation latitude 0.000500 angular_degree;

2020-01-08T23:33:35.248Z,1578526415.248 [CommandLine](IMPORTANT): Courier linearApproximation longitude 0.000500 angular_degree;

2020-01-08T23:33:35.248Z,1578526415.248 [CommandLine](IMPORTANT): DDM.loadAtStartup=1 bool;

2020-01-08T23:33:35.248Z,1578526415.248 [CommandLine](IMPORTANT): DDM.verbosity=3 count;

2020-01-08T23:33:35.248Z,1578526415.248 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=75 count;

2020-01-08T23:33:35.248Z,1578526415.248 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout=40 millisecond;

2020-01-08T23:33:35.248Z,1578526415.248 [CommandLine](IMPORTANT): Express linearApproximation DDM.DDMMode 1.000000 count;

2020-01-08T23:33:35.248Z,1578526415.248 [CommandLine](IMPORTANT): Express all DDM.cablePresent;

2020-01-08T23:33:35.248Z,1578526415.248 [CommandLine](IMPORTANT): Express linearApproximation DDM.latchState 1.000000 count;

2020-01-08T23:33:35.248Z,1578526415.248 [CommandLine](IMPORTANT): Express linearApproximation DDM.whiskerState 1.000000 count;

2020-01-08T23:33:35.249Z,1578526415.249 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.acoustic_contact_range 1.000000 meter;

2020-01-08T23:33:35.249Z,1578526415.249 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 degree;

2020-01-08T23:33:35.249Z,1578526415.249 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;

2020-01-08T23:33:35.249Z,1578526415.249 [CommandLine](IMPORTANT): Express linearApproximation platform_orientation 5.000000 degree;

2020-01-08T23:33:35.249Z,1578526415.249 [CommandLine](IMPORTANT): Express linearApproximation platform_x_velocity_wrt_ground 0.100000 meter_per_second;

2020-01-08T23:33:35.249Z,1578526415.249 [CommandLine](IMPORTANT): Express linearApproximation platform_y_velocity_wrt_ground 0.100000 meter_per_second;

2020-01-08T23:33:35.249Z,1578526415.249 [CommandLine](IMPORTANT): HorizontalControl.kiHeading=0.002 reciprocal_second;

2020-01-08T23:33:35.249Z,1578526415.249 [CommandLine](IMPORTANT): HorizontalControl.kpHeading=0.8 none;

2020-01-08T23:33:35.250Z,1578526415.250 [CommandLine](IMPORTANT): HorizontalControl.rudDeadband=0.05 degree;

2020-01-08T23:33:35.250Z,1578526415.250 [CommandLine](IMPORTANT): Micromodem.destinationAddress=12 enum;

2020-01-08T23:33:35.250Z,1578526415.250 [CommandLine](IMPORTANT): Micromodem.surfaceThreshold=0 meter;

2020-01-08T23:33:35.250Z,1578526415.250 [CommandLine](IMPORTANT): PowerOnly.sampleTime=90 second;

2020-01-08T23:33:35.250Z,1578526415.250 [CommandLine](IMPORTANT): RudderServo.deviationAngle=0.0001 degree;

2020-01-08T23:33:35.250Z,1578526415.250 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=105 cubic_centimeter;

2020-01-08T23:33:35.250Z,1578526415.250 [CommandLine](IMPORTANT): VerticalControl.massDefault=-5 millimeter;

2020-01-08T23:33:35.592Z,1578526415.592 [MissionManager](IMPORTANT): Started mission Startup
2020-01-08T23:33:35.592Z,1578526415.592 [Startup] Running Loop=1
2020-01-08T23:33:35.601Z,1578526415.601 [Startup](DEBUG): Aggregate::initialize Startup
2020-01-08T23:33:35.601Z,1578526415.601 [Startup:A.GoToSurface] Running Loop=1
2020-01-08T23:33:35.601Z,1578526415.601 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-08T23:33:35.602Z,1578526415.602 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-08T23:33:35.602Z,1578526415.602 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-08T23:33:35.602Z,1578526415.602 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-08T23:33:35.603Z,1578526415.603 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-08T23:33:35.603Z,1578526415.603 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-08T23:33:35.609Z,1578526415.609 [Startup:StartupSatComms] Running Loop=1
2020-01-08T23:33:35.609Z,1578526415.609 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-01-08T23:33:35.609Z,1578526415.609 [Startup:StartupSatComms:A] Running Loop=1
2020-01-08T23:33:36.031Z,1578526416.031 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-01-08T23:34:30.655Z,1578526470.655 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005057
2020-01-08T23:34:35.779Z,1578526475.779 [Startup:StartupSatComms:A](INFO): Timed out from 2020-01-08T23:33:35.6Z
2020-01-08T23:34:35.779Z,1578526475.779 [Startup:StartupSatComms:A] Stopped
2020-01-08T23:34:35.779Z,1578526475.779 [Startup:StartupSatComms:B] Running Loop=1
2020-01-08T23:34:36.201Z,1578526476.201 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-08T23:34:37.400Z,1578526477.400 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 8663165E070001005D00000400360300000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567
2020-01-08T23:34:37.400Z,1578526477.400 [Micromodem](INFO): Outgoing frame #2, 64 bytes: 266CC0E6F1A517638CB0C0B8BE372A0B00F6D61E05F93094AA77DEFC753FE61F094712E1114D8E0AD7B6106F0F7B016211E5CA62E332602D1D41ACBF7CDB6A31
2020-01-08T23:34:37.401Z,1578526477.401 [Micromodem](INFO): Outgoing frame #3, 64 bytes: 6612EED8A8416BB29191C1CCB1D608CF1AC7D5382E0295D324E3FB9C1C2302F2C3889792149C6D6DF406A218E47F75290FD65E23824F901508F051383D0A8ED3
2020-01-08T23:34:37.401Z,1578526477.401 [Micromodem](INFO): Nmea out: $CCCYC,0,1,12,1,0,3*69

2020-01-08T23:34:37.599Z,1578526477.599 [Micromodem](INFO): Nmea in: $CACYC,0,1,12,1,0,3*6B

2020-01-08T23:34:37.992Z,1578526477.992 [Micromodem](INFO): Nmea in: $CADRQ,233437,1,12,0,64,1*76

2020-01-08T23:34:37.993Z,1578526477.993 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,8663165E070001005D00000400360300000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*4D

2020-01-08T23:34:38.391Z,1578526478.391 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-08T23:34:38.795Z,1578526478.795 [Micromodem](INFO): Nmea in: $CADRQ,233438,1,12,0,64,2*7A

2020-01-08T23:34:38.795Z,1578526478.795 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,266CC0E6F1A517638CB0C0B8BE372A0B00F6D61E05F93094AA77DEFC753FE61F094712E1114D8E0AD7B6106F0F7B016211E5CA62E332602D1D41ACBF7CDB6A31*3C

2020-01-08T23:34:39.199Z,1578526479.199 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-08T23:34:39.617Z,1578526479.617 [Micromodem](INFO): Nmea in: $CADRQ,233439,1,12,0,64,3*7A

2020-01-08T23:34:39.618Z,1578526479.618 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,6612EED8A8416BB29191C1CCB1D608CF1AC7D5382E0295D324E3FB9C1C2302F2C3889792149C6D6DF406A218E47F75290FD65E23824F901508F051383D0A8ED3*39

2020-01-08T23:34:40.007Z,1578526480.007 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-08T23:34:40.410Z,1578526480.410 [Micromodem](INFO): Nmea in: $CATXP,192*48

2020-01-08T23:34:43.697Z,1578526483.697 [DataOverHttps](INFO): Sending 282 bytes from file Logs/20200108T231934/Courier0007.lzma
2020-01-08T23:34:44.047Z,1578526484.047 [Micromodem](INFO): Nmea in: $CATXF,192*5E

2020-01-08T23:34:44.452Z,1578526484.452 [Micromodem](INFO): Nmea in: $CAXST,6,20200108,233440.214377,3,0,200,4000,10000,1,1,12,1,3,3,3,192*75

2020-01-08T23:34:45.268Z,1578526485.268 [Micromodem](INFO): Nmea in: $CAACK,12,1,1,1*79

2020-01-08T23:34:45.667Z,1578526485.667 [Micromodem](INFO): Nmea in: $CAACK,12,1,2,1*7A

2020-01-08T23:34:45.703Z,1578526485.703 [DataOverHttps](INFO): Moved sent file to Logs/20200108T231934/Courier0007.lzma.bak
2020-01-08T23:34:45.703Z,1578526485.703 [DataOverHttps](INFO): SBD MOMSN=12187337
2020-01-08T23:34:46.071Z,1578526486.071 [Micromodem](INFO): Nmea in: $CAACK,12,1,3,1*7B

2020-01-08T23:34:46.072Z,1578526486.072 [Micromodem](INFO): Sent 184 bytes from file Logs/20200108T231934/Courier0007.lzma.parts
2020-01-08T23:34:46.072Z,1578526486.072 [Micromodem](INFO): Packets left to send: 1
2020-01-08T23:34:46.478Z,1578526486.478 [Micromodem](INFO): Nmea in: $CACST,6,0,20200108233444.770867,06,568,27,0095,0150,59,01,01,00,03,1,012,001,0,4,1,0,150,22.5,6.00,13,-3.00,-01,-0.05,26,10000,4000*4F

2020-01-08T23:34:47.239Z,1578526487.239 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 6766165E000001005D000004008D0100000000000000151D80030C5669BF31555EAE1409A708CE248A694289805E92F8B20B7420A5EA58D0BD60900BFC759167
2020-01-08T23:34:47.239Z,1578526487.239 [Micromodem](INFO): Outgoing frame #2, 64 bytes: 0636AD7A94B765FB477A822FBF28BDBE1951543A6AEA7A1FD8806E64FE38AB5A4130924DBB9B259CA196FB87392822724C744BD8EA7BBF915ED7633F2076D11F
2020-01-08T23:34:47.240Z,1578526487.240 [Micromodem](INFO): Outgoing frame #3, 64 bytes: 8EC2681FE9D8B238CC2C9154D026DAE5E1D62F4623CFBC8E56620EEDB389CD14BE5F66A2751DEDCEEDFDCAC0C37EC774A83F88A37A211C375C401D8EA77517BF
2020-01-08T23:34:47.240Z,1578526487.240 [Micromodem](INFO): Nmea out: $CCCYC,0,1,12,1,0,3*69

2020-01-08T23:34:48.207Z,1578526488.207 [Micromodem](INFO): Nmea in: $CACYC,0,1,12,1,0,3*6B

2020-01-08T23:34:48.607Z,1578526488.607 [Micromodem](INFO): Nmea in: $CADRQ,233447,1,12,0,64,1*71

2020-01-08T23:34:48.607Z,1578526488.607 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,6766165E000001005D000004008D0100000000000000151D80030C5669BF31555EAE1409A708CE248A694289805E92F8B20B7420A5EA58D0BD60900BFC759167*32

2020-01-08T23:34:49.019Z,1578526489.019 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-08T23:34:49.423Z,1578526489.423 [Micromodem](INFO): Nmea in: $CADRQ,233449,1,12,0,64,2*7C

2020-01-08T23:34:49.423Z,1578526489.423 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,0636AD7A94B765FB477A822FBF28BDBE1951543A6AEA7A1FD8806E64FE38AB5A4130924DBB9B259CA196FB87392822724C744BD8EA7BBF915ED7633F2076D11F*4C

2020-01-08T23:34:49.825Z,1578526489.825 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-08T23:34:50.223Z,1578526490.223 [Micromodem](INFO): Nmea in: $CADRQ,233449,1,12,0,64,3*7D

2020-01-08T23:34:50.223Z,1578526490.223 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,8EC2681FE9D8B238CC2C9154D026DAE5E1D62F4623CFBC8E56620EEDB389CD14BE5F66A2751DEDCEEDFDCAC0C37EC774A83F88A37A211C375C401D8EA77517BF*30

2020-01-08T23:34:50.627Z,1578526490.627 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-08T23:34:51.046Z,1578526491.046 [Micromodem](INFO): Nmea in: $CATXP,192*48

2020-01-08T23:34:54.671Z,1578526494.671 [Micromodem](INFO): Nmea in: $CATXF,192*5E

2020-01-08T23:34:55.072Z,1578526495.072 [Micromodem](INFO): Nmea in: $CAXST,6,20200108,233450.816422,3,0,200,4000,10000,1,1,12,1,3,3,3,192*7B

2020-01-08T23:35:01.579Z,1578526501.579 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-01-08T23:35:01.580Z,1578526501.580 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-08T23:35:01.601Z,1578526501.601 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-08T23:35:02.006Z,1578526502.006 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-08T23:35:02.006Z,1578526502.006 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-01-08T23:35:03.533Z,1578526503.533 [DataOverHttps](INFO): Sending 299 bytes from file Logs/20200108T233151/Courier0000.lzma
2020-01-08T23:35:05.538Z,1578526505.538 [DataOverHttps](INFO): Moved sent file to Logs/20200108T233151/Courier0000.lzma.bak
2020-01-08T23:35:05.538Z,1578526505.538 [DataOverHttps](INFO): SBD MOMSN=12187340
2020-01-08T23:35:13.685Z,1578526513.685 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00,   0.00
2020-01-08T23:35:25.283Z,1578526525.283 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20200108T225634/Express0008.lzma
2020-01-08T23:35:27.286Z,1578526527.286 [DataOverHttps](INFO): Moved sent file to Logs/20200108T225634/Express0008.lzma.bak
2020-01-08T23:35:27.286Z,1578526527.286 [DataOverHttps](INFO): SBD MOMSN=12187348
2020-01-08T23:35:35.911Z,1578526535.911 [Startup:StartupSatComms:B](INFO): Timed out from 2020-01-08T23:34:35.8Z
2020-01-08T23:35:35.911Z,1578526535.911 [Startup:StartupSatComms:B] Stopped
2020-01-08T23:35:35.911Z,1578526535.911 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-01-08T23:35:35.911Z,1578526535.911 [Startup:StartupSatComms] Stopped
2020-01-08T23:35:35.912Z,1578526535.912 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-01-08T23:35:35.912Z,1578526535.912 [Startup](INFO): Completed Startup
2020-01-08T23:35:35.912Z,1578526535.912 [MissionManager](INFO): Startup is completed.
2020-01-08T23:35:35.913Z,1578526535.913 [MissionManager](INFO): Uninitializing Mission Startup
2020-01-08T23:35:35.913Z,1578526535.913 [Startup] Stopped
2020-01-08T23:35:35.913Z,1578526535.913 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-01-08T23:35:35.913Z,1578526535.913 [Startup:A.GoToSurface] Stopped
2020-01-08T23:35:35.913Z,1578526535.913 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-08T23:35:36.398Z,1578526536.398 [MissionManager](IMPORTANT): Started mission Default
2020-01-08T23:35:36.399Z,1578526536.399 [Default] Running Loop=1
2020-01-08T23:35:36.399Z,1578526536.399 [Default](DEBUG): Aggregate::initialize Default
2020-01-08T23:35:36.399Z,1578526536.399 [Default:B.GoToSurface] Running Loop=1
2020-01-08T23:35:36.399Z,1578526536.399 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-08T23:35:36.399Z,1578526536.399 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-08T23:35:36.400Z,1578526536.400 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-08T23:35:36.400Z,1578526536.400 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-08T23:35:36.400Z,1578526536.400 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-08T23:35:36.400Z,1578526536.400 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-08T23:35:36.401Z,1578526536.401 [Default:A.Wait] Running Loop=1
2020-01-08T23:35:36.401Z,1578526536.401 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-01-08T23:35:45.504Z,1578526545.504 [DataOverHttps](INFO): Sending 49 bytes from file Logs/20200108T225634/Express0011.lzma
2020-01-08T23:35:47.510Z,1578526547.510 [DataOverHttps](INFO): Moved sent file to Logs/20200108T225634/Express0011.lzma.bak
2020-01-08T23:35:47.510Z,1578526547.510 [DataOverHttps](INFO): SBD MOMSN=12187354
2020-01-08T23:35:49.652Z,1578526549.652 [Default:A.Wait](INFO): Done Waiting.
2020-01-08T23:35:49.652Z,1578526549.652 [Default:A.Wait] Stopped
2020-01-08T23:35:49.652Z,1578526549.652 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-08T23:35:50.144Z,1578526550.144 [Default:CheckIn] Running Loop=1
2020-01-08T23:35:50.144Z,1578526550.144 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-08T23:35:50.144Z,1578526550.144 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-08T23:35:50.465Z,1578526550.465 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-01-08T23:35:58.107Z,1578526558.107 [Micromodem](INFO): Nmea in: $CACYC,1,12,1,1,0,1*68

2020-01-08T23:35:58.107Z,1578526558.107 [Micromodem](INFO): Have incoming data
2020-01-08T23:35:58.110Z,1578526558.110 [Micromodem](INFO): Nmea in: $CARXD,12,1,0,1,3D90B8D172D0E11A94BB9A0D6EC0434A2AB488F6*51

2020-01-08T23:35:58.111Z,1578526558.111 [Micromodem](INFO): Data:3D90B8D172D0E11A94BB9A0D6EC0434A2AB488F6*51

2020-01-08T23:35:58.111Z,1578526558.111 [Micromodem](INFO): FrameFormat:%128s
2020-01-08T23:35:58.112Z,1578526558.112 [Micromodem](INFO): Frame:1
2020-01-08T23:35:58.112Z,1578526558.112 [Micromodem](INFO): HexData:1
2020-01-08T23:35:58.112Z,1578526558.112 [Micromodem](INFO): IncomingPacketHex:1
2020-01-08T23:35:58.121Z,1578526558.121 [Micromodem](INFO): binSize:0
2020-01-08T23:35:58.123Z,1578526558.123 [Micromodem](INFO): InRXSBD:0
2020-01-08T23:35:58.126Z,1578526558.126 [Micromodem](INFO): Data Is:
2020-01-08T23:35:58.128Z,1578526558.128 [Micromodem](INFO): InTryRXSBD:0
2020-01-08T23:35:58.201Z,1578526558.201 [Micromodem](INFO): Data Is:
2020-01-08T23:35:58.201Z,1578526558.201 [Micromodem](CRITICAL): Packet size is not N*16+4: 0x0
2020-01-08T23:35:58.201Z,1578526558.201 [Micromodem](CRITICAL): Failed to parse uplink message:
2020-01-08T23:35:58.340Z,1578526558.340 [CBIT](INFO): Critical error at 20200108T233558
2020-01-08T23:35:58.511Z,1578526558.511 [Micromodem](INFO): Nmea in: $CACST,6,0,20200108233556.643775,06,1415,31,0123,0150,59,02,02,00,04,1,012,001,0,3,1,0,150,24.5,7.00,00,-4.00,-01,-0.02,26,10000,4000*74

2020-01-08T23:35:59.346Z,1578526559.346 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-08T23:35:59.346Z,1578526559.346 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-3768,-32768,V
2020-01-08T23:37:42.343Z,1578526662.343 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-01-08T23:37:48.805Z,1578526668.805 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233732.00,A,3648.16474,N,12147.29418,W,0.253,0.00,080120,,,A*79
2020-01-08T23:37:48.808Z,1578526668.808 [NAL9602](INFO): GPS fix at 20200108T233732: (36.802746, -121.788236)
2020-01-08T23:37:48.865Z,1578526668.865 [Default:CheckIn:Read_GPS] Stopped
2020-01-08T23:37:48.865Z,1578526668.865 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-08T23:37:49.279Z,1578526669.279 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-08T23:37:49.842Z,1578526669.842 [Micromodem](ERROR): Buffer fill timout failure.
2020-01-08T23:37:51.587Z,1578526671.587 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 6766165E040001005D00000400880300000000000000151D80030C5669BF31555EAE1409A708CE2489B190EA4D9D68DCD8D7AAA11AD9F0ED77F7C27FB6E9EF60
2020-01-08T23:37:51.588Z,1578526671.588 [Micromodem](INFO): Outgoing frame #2, 64 bytes: 68D9E51BA885236CCB111BF377A633888F84545E83054234E83BB5F9778F89137A58ECD12DBDDDAD48ECE586CD20A5DE9AD30FF70B9DAA2B50EF601763232D0A
2020-01-08T23:37:51.588Z,1578526671.588 [Micromodem](INFO): Outgoing frame #3, 64 bytes: E1BB663D86E53CD28816C536673567F2D6F006805C78EBBA72743103223D73DE7A77E80E522C1F62A12EACD8C14DFF2E14284EBFC0BDEBB2A259BEFD4FD19114
2020-01-08T23:37:51.597Z,1578526671.597 [Micromodem](INFO): Nmea out: $CCCYC,0,1,12,1,0,3*69

2020-01-08T23:37:52.073Z,1578526672.073 [Micromodem](INFO): Nmea in: $CACYC,0,1,12,1,0,3*6B

2020-01-08T23:37:52.403Z,1578526672.403 [Micromodem](INFO): Nmea in: $CADRQ,233752,1,12,0,64,1*76

2020-01-08T23:37:52.403Z,1578526672.403 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,6766165E040001005D00000400880300000000000000151D80030C5669BF31555EAE1409A708CE2489B190EA4D9D68DCD8D7AAA11AD9F0ED77F7C27FB6E9EF60*49

2020-01-08T23:37:52.810Z,1578526672.810 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-08T23:37:53.210Z,1578526673.210 [Micromodem](INFO): Nmea in: $CADRQ,233752,1,12,0,64,2*75

2020-01-08T23:37:53.211Z,1578526673.211 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,68D9E51BA885236CCB111BF377A633888F84545E83054234E83BB5F9778F89137A58ECD12DBDDDAD48ECE586CD20A5DE9AD30FF70B9DAA2B50EF601763232D0A*35

2020-01-08T23:37:53.330Z,1578526673.330 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-08T23:37:53.330Z,1578526673.330 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,32768,-32768,V
2020-01-08T23:37:53.614Z,1578526673.614 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-08T23:37:54.022Z,1578526674.022 [Micromodem](INFO): Nmea in: $CADRQ,233753,1,12,0,64,3*75

2020-01-08T23:37:54.023Z,1578526674.023 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,E1BB663D86E53CD28816C536673567F2D6F006805C78EBBA72743103223D73DE7A77E80E522C1F62A12EACD8C14DFF2E14284EBFC0BDEBB2A259BEFD4FD19114*4B

2020-01-08T23:37:54.422Z,1578526674.422 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-08T23:37:55.019Z,1578526675.019 [Micromodem](INFO): Nmea in: $CATXP,192*48

2020-01-08T23:37:58.542Z,1578526678.542 [Micromodem](INFO): Nmea in: $CATXF,192*5E

2020-01-08T23:37:59.769Z,1578526679.769 [Micromodem](INFO): Nmea in: $CAXST,6,20200108,233754.613401,3,0,200,4000,10000,1,1,12,1,3,3,3,192*76

2020-01-08T23:38:00.159Z,1578526680.159 [Micromodem](INFO): Nmea in: $CAACK,12,1,1,1*79

2020-01-08T23:38:00.563Z,1578526680.563 [Micromodem](INFO): Nmea in: $CAACK,12,1,2,1*7A

2020-01-08T23:38:00.967Z,1578526680.967 [Micromodem](INFO): Nmea in: $CAACK,12,1,3,1*7B

2020-01-08T23:38:00.967Z,1578526680.967 [Micromodem](INFO): Sent 184 bytes from file Logs/20200108T233151/Courier0004.lzma.parts
2020-01-08T23:38:00.968Z,1578526680.968 [Micromodem](INFO): Packets left to send: 1
2020-01-08T23:38:01.394Z,1578526681.394 [Micromodem](INFO): Nmea in: $CACST,6,0,20200108233759.165113,06,572,27,0095,0150,29,01,01,00,03,1,012,001,0,4,1,0,150,1.5,7.00,18,-4.00,-01,-0.04,39,10000,4000*77

2020-01-08T23:38:02.521Z,1578526682.521 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 6766165E04000000DAF9E868C7E417575DD45294E89FAE6D12094FAD6645F8CE798E604D88ED158DAEF1D7C03CEF25E19609798626ED95795F52E72BEF150529
2020-01-08T23:38:02.522Z,1578526682.522 [Micromodem](INFO): Outgoing frame #2, 64 bytes: BFCEA894AB68A7A1589ABA8A967C4932111AE6422D9F4CCFDDC6BAF74725C62A1C2EF5DC1F989693AEFB5C45559E78D56A64E0D17D1B1DB70AAD1167ABC3C4D7
2020-01-08T23:38:02.522Z,1578526682.522 [Micromodem](INFO): Outgoing frame #3, 51 bytes: 7BD9F8CFA57713611D45E691352F7C8CDC9EBCDFC7F19F8D396A0747D04497A61C911C8E172D50B33632F9DB006E9B56596000
2020-01-08T23:38:02.523Z,1578526682.523 [Micromodem](INFO): Nmea out: $CCCYC,0,1,12,1,0,3*69

2020-01-08T23:38:03.532Z,1578526683.532 [Micromodem](INFO): Nmea in: $CACYC,0,1,12,1,0,3*6B

2020-01-08T23:38:03.919Z,1578526683.919 [Micromodem](INFO): Nmea in: $CADRQ,233802,1,12,0,64,1*7C

2020-01-08T23:38:03.919Z,1578526683.919 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,6766165E04000000DAF9E868C7E417575DD45294E89FAE6D12094FAD6645F8CE798E604D88ED158DAEF1D7C03CEF25E19609798626ED95795F52E72BEF150529*3B

2020-01-08T23:38:04.339Z,1578526684.339 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-08T23:38:04.405Z,1578526684.405 [DataOverHttps](INFO): Sending 355 bytes from file Logs/20200108T233151/Courier0004.lzma
2020-01-08T23:38:04.723Z,1578526684.723 [Micromodem](INFO): Nmea in: $CADRQ,233804,1,12,0,64,2*79

2020-01-08T23:38:04.723Z,1578526684.723 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,BFCEA894AB68A7A1589ABA8A967C4932111AE6422D9F4CCFDDC6BAF74725C62A1C2EF5DC1F989693AEFB5C45559E78D56A64E0D17D1B1DB70AAD1167ABC3C4D7*35

2020-01-08T23:38:05.134Z,1578526685.134 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-08T23:38:05.531Z,1578526685.531 [Micromodem](INFO): Nmea in: $CADRQ,233805,1,12,0,64,3*79

2020-01-08T23:38:05.531Z,1578526685.531 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,7BD9F8CFA57713611D45E691352F7C8CDC9EBCDFC7F19F8D396A0747D04497A61C911C8E172D50B33632F9DB006E9B56596000*3A

2020-01-08T23:38:05.978Z,1578526685.978 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,51*4D

2020-01-08T23:38:06.342Z,1578526686.342 [Micromodem](INFO): Nmea in: $CATXP,179*4D

2020-01-08T23:38:06.410Z,1578526686.410 [DataOverHttps](INFO): Moved sent file to Logs/20200108T233151/Courier0004.lzma.bak
2020-01-08T23:38:06.411Z,1578526686.411 [DataOverHttps](INFO): SBD MOMSN=12187356
2020-01-08T23:38:10.006Z,1578526690.006 [Micromodem](INFO): Nmea in: $CATXF,179*5B

2020-01-08T23:38:10.412Z,1578526690.412 [Micromodem](INFO): Nmea in: $CAXST,6,20200108,233806.115449,3,0,200,4000,10000,1,1,12,1,3,3,3,179*76

2020-01-08T23:38:11.619Z,1578526691.619 [Micromodem](INFO): Nmea in: $CAACK,12,1,1,1*79

2020-01-08T23:38:12.023Z,1578526692.023 [Micromodem](INFO): Nmea in: $CAACK,12,1,2,1*7A

2020-01-08T23:38:12.431Z,1578526692.431 [Micromodem](INFO): Nmea in: $CAACK,12,1,3,1*7B

2020-01-08T23:38:12.432Z,1578526692.432 [Micromodem](INFO): Sent 171 bytes from file Logs/20200108T233151/Courier0004.lzma.parts
2020-01-08T23:38:12.432Z,1578526692.432 [Micromodem](INFO): Packets left to send: 0
2020-01-08T23:38:12.834Z,1578526692.834 [Micromodem](INFO): Nmea in: $CACST,6,0,20200108233810.654337,06,562,27,0098,0150,59,01,01,00,03,1,012,001,0,4,1,0,150,24.5,6.00,12,-3.00,-01,-0.03,23,10000,4000*48

2020-01-08T23:38:13.882Z,1578526693.882 [Default:CheckIn:Read_Iridium] Stopped
2020-01-08T23:38:13.882Z,1578526693.882 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-08T23:38:13.883Z,1578526693.883 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-08T23:38:22.447Z,1578526702.447 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-08T23:38:29.332Z,1578526709.332 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-08T23:38:29.332Z,1578526709.332 [RDI_Pathfinder](ERROR): Failed to parse:
:TS6510200,35.0, -0.1,   0.0,1448.9,  0
2020-01-08T23:38:30.855Z,1578526710.855 [DataOverHttps](INFO): Sending 1425 bytes from file Logs/20200108T231506/Express0001.lzma
2020-01-08T23:38:32.858Z,1578526712.858 [DataOverHttps](INFO): Moved sent file to Logs/20200108T231506/Express0001.lzma.bak
2020-01-08T23:38:32.859Z,1578526712.859 [DataOverHttps](INFO): SBD MOMSN=12187361
2020-01-08T23:38:40.762Z,1578526720.762 [CommandLine](IMPORTANT): got command restart application
2020-01-08T23:38:41.769Z,1578526721.769 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-08T23:38:41.769Z,1578526721.769 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:41.901Z,1578526721.901 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-01-08T23:38:41.901Z,1578526721.901 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:41.902Z,1578526721.902 [CommandLine](INFO): Join timeout helper Thread ID is 1016
2020-01-08T23:38:41.902Z,1578526721.902 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-01-08T23:38:41.902Z,1578526721.902 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:41.903Z,1578526721.903 [NavChartDb](INFO): Join timeout helper Thread ID is 1017
2020-01-08T23:38:42.142Z,1578526722.142 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-08T23:38:42.142Z,1578526722.142 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.161Z,1578526722.161 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-01-08T23:38:42.161Z,1578526722.161 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.161Z,1578526722.161 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1018
2020-01-08T23:38:42.357Z,1578526722.357 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-08T23:38:42.357Z,1578526722.357 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-08T23:38:42.358Z,1578526722.358 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.361Z,1578526722.361 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2020-01-08T23:38:42.361Z,1578526722.361 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.361Z,1578526722.361 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1019
2020-01-08T23:38:42.457Z,1578526722.457 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-08T23:38:42.457Z,1578526722.457 [CTD_NeilBrown](INFO): Powering down
2020-01-08T23:38:42.469Z,1578526722.469 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.483Z,1578526722.483 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-01-08T23:38:42.483Z,1578526722.483 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.484Z,1578526722.484 [Radio_Surface](INFO): Join timeout helper Thread ID is 1020
2020-01-08T23:38:42.793Z,1578526722.793 [Radio_Surface](INFO): Powering down
2020-01-08T23:38:42.794Z,1578526722.794 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-08T23:38:42.794Z,1578526722.794 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.802Z,1578526722.802 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-01-08T23:38:42.802Z,1578526722.802 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.802Z,1578526722.802 [DataOverHttps](INFO): Join timeout helper Thread ID is 1021
2020-01-08T23:38:42.897Z,1578526722.897 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-08T23:38:42.897Z,1578526722.897 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.905Z,1578526722.905 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-01-08T23:38:42.906Z,1578526722.906 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.906Z,1578526722.906 [logger](INFO): Join timeout helper Thread ID is 1022
2020-01-08T23:38:42.945Z,1578526722.945 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-08T23:38:42.945Z,1578526722.945 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.965Z,1578526722.965 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-01-08T23:38:42.966Z,1578526722.966 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.966Z,1578526722.966 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-01-08T23:38:42.966Z,1578526722.966 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:42.966Z,1578526722.966 [controlThread](INFO): Join timeout helper Thread ID is 1023
2020-01-08T23:38:43.029Z,1578526723.029 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-08T23:38:43.029Z,1578526723.029 [controlThread](DEBUG): Uninitializing ControlThread
2020-01-08T23:38:43.030Z,1578526723.030 [AHRS_M2](INFO): Powering down
2020-01-08T23:38:43.101Z,1578526723.101 [DDM](INFO): Powering down
2020-01-08T23:38:43.193Z,1578526723.193 [DUSBL_Hydroid](INFO): Powering down
2020-01-08T23:38:43.286Z,1578526723.286 [Micromodem](INFO): Powering down
2020-01-08T23:38:43.381Z,1578526723.381 [NAL9602](INFO): Powering down
2020-01-08T23:38:43.453Z,1578526723.453 [RDI_Pathfinder](INFO): Powering down
2020-01-08T23:38:43.455Z,1578526723.455 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-01-08T23:38:43.456Z,1578526723.456 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-01-08T23:38:43.456Z,1578526723.456 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-01-08T23:38:43.457Z,1578526723.457 [MissionManager](INFO): Uninitializing Mission Default
2020-01-08T23:38:43.457Z,1578526723.457 [Default] Stopped
2020-01-08T23:38:43.457Z,1578526723.457 [Default](DEBUG): Aggregate::uninitialize Default
2020-01-08T23:38:43.457Z,1578526723.457 [Default:B.GoToSurface] Stopped
2020-01-08T23:38:43.457Z,1578526723.457 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-08T23:38:43.457Z,1578526723.457 [Default:CheckIn] Stopped
2020-01-08T23:38:43.457Z,1578526723.457 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-08T23:38:43.457Z,1578526723.457 [Default:CheckIn:C.Wait] Stopped
2020-01-08T23:38:43.457Z,1578526723.457 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-08T23:38:43.460Z,1578526723.460 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-01-08T23:38:43.460Z,1578526723.460 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-01-08T23:38:43.460Z,1578526723.460 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-01-08T23:38:43.460Z,1578526723.460 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-01-08T23:38:43.461Z,1578526723.461 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-01-08T23:38:43.461Z,1578526723.461 [BuoyancyServo](INFO): Powering down
2020-01-08T23:38:43.473Z,1578526723.473 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-01-08T23:38:43.473Z,1578526723.473 [ElevatorServo](INFO): Powering down
2020-01-08T23:38:43.474Z,1578526723.474 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-01-08T23:38:43.474Z,1578526723.474 [MassServo](INFO): Powering down
2020-01-08T23:38:43.475Z,1578526723.475 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-08T23:38:43.475Z,1578526723.475 [RudderServo](INFO): Powering down
2020-01-08T23:38:43.475Z,1578526723.475 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-01-08T23:38:43.476Z,1578526723.476 [ThrusterServo](INFO): Powering down
2020-01-08T23:38:43.476Z,1578526723.476 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-01-08T23:38:43.477Z,1578526723.477 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-01-08T23:38:43.477Z,1578526723.477 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-01-08T23:38:43.477Z,1578526723.477 [CBIT](DEBUG): Powering off loads.
2020-01-08T23:38:43.489Z,1578526723.489 [CBIT](DEBUG): Disabling WDT.
2020-01-08T23:38:43.501Z,1578526723.501 [CBIT](DEBUG): Opening all GF detection circuits.
2020-01-08T23:38:43.502Z,1578526723.502 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:43.549Z,1578526723.549 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:43.559Z,1578526723.559 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:43.607Z,1578526723.607 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:43.610Z,1578526723.610 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:43.669Z,1578526723.669 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-08T23:38:43.744Z,1578526723.744 [logger ThreadHandler](INFO): Thread cancelled.