2020-01-21T17:44:59.701Z,1579628699.701 [Supervisor](DEBUG): Initializing supervisor.
2020-01-21T17:44:59.704Z,1579628699.704 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-01-21T17:44:59.704Z,1579628699.704 [SyncHandler](INFO): Protected caller Thread ID is 6999
2020-01-21T17:44:59.705Z,1579628699.705 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-01-21T17:44:59.706Z,1579628699.706 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-01-21T17:44:59.706Z,1579628699.706 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7000
2020-01-21T17:44:59.709Z,1579628699.709 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-01-21T17:44:59.721Z,1579628699.721 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-01-21T17:44:59.722Z,1579628699.722 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-01-21T17:44:59.722Z,1579628699.722 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7001
2020-01-21T17:44:59.723Z,1579628699.723 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-01-21T17:44:59.724Z,1579628699.724 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-01-21T17:44:59.724Z,1579628699.724 [logger ThreadHandler](INFO): Protected caller Thread ID is 7002
2020-01-21T17:44:59.726Z,1579628699.726 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-01-21T17:44:59.727Z,1579628699.727 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-01-21T17:44:59.728Z,1579628699.728 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-01-21T17:45:00.239Z,1579628700.239 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-01-21T17:45:00.240Z,1579628700.240 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-01-21T17:45:00.338Z,1579628700.338 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-01-21T17:45:00.338Z,1579628700.338 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-01-21T17:45:00.647Z,1579628700.647 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-01-21T17:45:00.647Z,1579628700.647 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-01-21T17:45:00.784Z,1579628700.784 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-01-21T17:45:00.784Z,1579628700.784 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-01-21T17:45:00.974Z,1579628700.974 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-01-21T17:45:00.975Z,1579628700.975 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-01-21T17:45:01.410Z,1579628701.410 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-01-21T17:45:01.410Z,1579628701.410 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-01-21T17:45:01.617Z,1579628701.617 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-01-21T17:45:01.617Z,1579628701.617 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-01-21T17:45:01.760Z,1579628701.760 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-01-21T17:45:01.761Z,1579628701.761 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-01-21T17:45:01.948Z,1579628701.948 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-01-21T17:45:01.949Z,1579628701.949 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-01-21T17:45:02.045Z,1579628702.045 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-01-21T17:45:02.046Z,1579628702.046 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-01-21T17:45:02.339Z,1579628702.339 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-01-21T17:45:02.340Z,1579628702.340 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-01-21T17:45:02.421Z,1579628702.421 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-01-21T17:45:02.523Z,1579628702.523 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-01-21T17:45:02.524Z,1579628702.524 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-01-21T17:45:03.148Z,1579628703.148 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-01-21T17:45:03.148Z,1579628703.148 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-01-21T17:45:03.548Z,1579628703.548 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-01-21T17:45:03.550Z,1579628703.550 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-01-21T17:45:03.551Z,1579628703.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-01-21T17:45:03.761Z,1579628703.761 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-01-21T17:45:03.862Z,1579628703.862 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-01-21T17:45:03.961Z,1579628703.961 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-01-21T17:45:04.186Z,1579628704.186 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-01-21T17:45:04.186Z,1579628704.186 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-01-21T17:45:04.272Z,1579628704.272 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-01-21T17:45:04.366Z,1579628704.366 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-01-21T17:45:04.465Z,1579628704.465 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-01-21T17:45:04.549Z,1579628704.549 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-01-21T17:45:04.656Z,1579628704.656 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-01-21T17:45:04.750Z,1579628704.750 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-01-21T17:45:04.933Z,1579628704.933 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-01-21T17:45:05.063Z,1579628705.063 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2020-01-21T17:45:05.064Z,1579628705.064 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-01-21T17:45:05.071Z,1579628705.071 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-01-21T17:45:05.376Z,1579628705.376 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-01-21T17:45:05.381Z,1579628705.381 [AHRS_M2](INFO): created writer for : platform_orientation
2020-01-21T17:45:05.383Z,1579628705.383 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-01-21T17:45:05.387Z,1579628705.387 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-01-21T17:45:05.388Z,1579628705.388 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-01-21T17:45:05.393Z,1579628705.393 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-01-21T17:45:05.393Z,1579628705.393 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-01-21T17:45:05.398Z,1579628705.398 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-01-21T17:45:05.464Z,1579628705.464 [AHRS_M2] Loaded
2020-01-21T17:45:05.464Z,1579628705.464 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-01-21T17:45:05.543Z,1579628705.543 [DataOverHttps] Loaded
2020-01-21T17:45:05.543Z,1579628705.543 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-01-21T17:45:05.544Z,1579628705.544 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407684E0
2020-01-21T17:45:05.544Z,1579628705.544 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7084
2020-01-21T17:45:05.567Z,1579628705.567 [DDM] Loaded
2020-01-21T17:45:05.567Z,1579628705.567 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-01-21T17:45:05.579Z,1579628705.579 [Depth_Keller] Loaded
2020-01-21T17:45:05.579Z,1579628705.579 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-01-21T17:45:05.584Z,1579628705.584 [DropWeight] Loaded
2020-01-21T17:45:05.584Z,1579628705.584 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-01-21T17:45:05.641Z,1579628705.641 [DUSBL_Hydroid] Loaded
2020-01-21T17:45:05.641Z,1579628705.641 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-01-21T17:45:05.685Z,1579628705.685 [Micromodem] Loaded
2020-01-21T17:45:05.685Z,1579628705.685 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-01-21T17:45:05.775Z,1579628705.775 [NAL9602] Loaded
2020-01-21T17:45:05.775Z,1579628705.775 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-01-21T17:45:05.809Z,1579628705.809 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now
2020-01-21T17:45:05.810Z,1579628705.810 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now
2020-01-21T17:45:05.810Z,1579628705.810 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now
2020-01-21T17:45:05.811Z,1579628705.811 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full
2020-01-21T17:45:05.811Z,1579628705.811 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now
2020-01-21T17:45:05.812Z,1579628705.812 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now
2020-01-21T17:45:05.812Z,1579628705.812 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now
2020-01-21T17:45:05.813Z,1579628705.813 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full
2020-01-21T17:45:05.813Z,1579628705.813 [Onboard] Loaded
2020-01-21T17:45:05.813Z,1579628705.813 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-01-21T17:45:05.819Z,1579628705.819 [PowerOnly] Loaded
2020-01-21T17:45:05.819Z,1579628705.819 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2020-01-21T17:45:05.825Z,1579628705.825 [Radio_Surface] Loaded
2020-01-21T17:45:05.825Z,1579628705.825 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-01-21T17:45:05.826Z,1579628705.826 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407984E0
2020-01-21T17:45:05.827Z,1579628705.827 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7085
2020-01-21T17:45:06.034Z,1579628706.034 [RDI_Pathfinder] Loaded
2020-01-21T17:45:06.035Z,1579628706.035 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-01-21T17:45:07.808Z,1579628707.808 [BPC1] Loaded
2020-01-21T17:45:07.808Z,1579628707.808 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-01-21T17:45:07.809Z,1579628707.809 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-01-21T17:45:07.809Z,1579628707.809 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-01-21T17:45:07.822Z,1579628707.822 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-01-21T17:45:07.822Z,1579628707.822 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-01-21T17:45:07.920Z,1579628707.920 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-01-21T17:45:07.920Z,1579628707.920 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-01-21T17:45:07.939Z,1579628707.939 [NavChart] Loaded
2020-01-21T17:45:07.940Z,1579628707.940 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-01-21T17:45:07.943Z,1579628707.943 [UniversalFixResidualReporter] Loaded
2020-01-21T17:45:07.944Z,1579628707.944 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-01-21T17:45:07.944Z,1579628707.944 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-01-21T17:45:07.945Z,1579628707.945 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-01-21T17:45:08.045Z,1579628708.045 [BuoyancyServo] Loaded
2020-01-21T17:45:08.046Z,1579628708.046 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-01-21T17:45:08.060Z,1579628708.060 [ElevatorServo] Loaded
2020-01-21T17:45:08.060Z,1579628708.060 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-01-21T17:45:08.074Z,1579628708.074 [MassServo] Loaded
2020-01-21T17:45:08.074Z,1579628708.074 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-01-21T17:45:08.088Z,1579628708.088 [RudderServo] Loaded
2020-01-21T17:45:08.089Z,1579628708.089 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-01-21T17:45:08.102Z,1579628708.102 [ThrusterServo] Loaded
2020-01-21T17:45:08.103Z,1579628708.103 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-01-21T17:45:08.103Z,1579628708.103 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-01-21T17:45:08.104Z,1579628708.104 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-01-21T17:45:08.346Z,1579628708.346 [CTD_NeilBrown] Loaded
2020-01-21T17:45:08.346Z,1579628708.346 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2020-01-21T17:45:08.347Z,1579628708.347 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408EC4E0
2020-01-21T17:45:08.347Z,1579628708.347 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 7086
2020-01-21T17:45:08.361Z,1579628708.361 [PAR_Licor] Loaded
2020-01-21T17:45:08.361Z,1579628708.361 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-01-21T17:45:08.402Z,1579628708.402 [WetLabsSeaOWL_UV_A] Loaded
2020-01-21T17:45:08.402Z,1579628708.402 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-01-21T17:45:08.403Z,1579628708.403 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4091C4E0
2020-01-21T17:45:08.403Z,1579628708.403 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 7087
2020-01-21T17:45:08.404Z,1579628708.404 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-01-21T17:45:08.404Z,1579628708.404 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-01-21T17:45:08.713Z,1579628708.713 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-01-21T17:45:08.713Z,1579628708.713 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-01-21T17:45:08.751Z,1579628708.751 [DepthRateCalculator] Loaded
2020-01-21T17:45:08.752Z,1579628708.752 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-01-21T17:45:08.757Z,1579628708.757 [PitchRateCalculator] Loaded
2020-01-21T17:45:08.757Z,1579628708.757 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-01-21T17:45:08.769Z,1579628708.769 [SpeedCalculator] Loaded
2020-01-21T17:45:08.769Z,1579628708.769 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-01-21T17:45:08.789Z,1579628708.789 [TempGradientCalculator] Loaded
2020-01-21T17:45:08.789Z,1579628708.789 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-01-21T17:45:08.794Z,1579628708.794 [YawRateCalculator] Loaded
2020-01-21T17:45:08.794Z,1579628708.794 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-01-21T17:45:08.833Z,1579628708.833 [ElevatorOffsetCalculator] Loaded
2020-01-21T17:45:08.833Z,1579628708.833 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-01-21T17:45:08.833Z,1579628708.833 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-01-21T17:45:08.834Z,1579628708.834 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-01-21T17:45:08.960Z,1579628708.960 [SBIT](DEBUG): Construct Startup Built In Test.
2020-01-21T17:45:08.980Z,1579628708.980 [SBIT] Loaded
2020-01-21T17:45:08.980Z,1579628708.980 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-01-21T17:45:08.981Z,1579628708.981 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-01-21T17:45:08.993Z,1579628708.993 [IBIT] Loaded
2020-01-21T17:45:08.993Z,1579628708.993 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-01-21T17:45:08.996Z,1579628708.996 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-01-21T17:45:09.126Z,1579628709.126 [CBIT] Loaded
2020-01-21T17:45:09.126Z,1579628709.126 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-01-21T17:45:09.127Z,1579628709.127 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-01-21T17:45:09.127Z,1579628709.127 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-01-21T17:45:09.204Z,1579628709.204 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-01-21T17:45:09.204Z,1579628709.204 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-01-21T17:45:09.296Z,1579628709.296 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-01-21T17:45:09.296Z,1579628709.296 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-01-21T17:45:09.341Z,1579628709.341 [VerticalControl](DEBUG): Construct VerticalControl.
2020-01-21T17:45:09.421Z,1579628709.421 [VerticalControl] Loaded
2020-01-21T17:45:09.421Z,1579628709.421 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-01-21T17:45:09.422Z,1579628709.422 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-01-21T17:45:09.487Z,1579628709.487 [HorizontalControl] Loaded
2020-01-21T17:45:09.487Z,1579628709.487 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-01-21T17:45:09.488Z,1579628709.488 [SpeedControl](DEBUG): Construct SpeedControl.
2020-01-21T17:45:09.489Z,1579628709.489 [SpeedControl] Loaded
2020-01-21T17:45:09.490Z,1579628709.490 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-01-21T17:45:09.490Z,1579628709.490 [LoopControl](DEBUG): Construct LoopControl.
2020-01-21T17:45:09.491Z,1579628709.491 [LoopControl] Loaded
2020-01-21T17:45:09.491Z,1579628709.491 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-01-21T17:45:09.491Z,1579628709.491 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-01-21T17:45:09.492Z,1579628709.492 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-01-21T17:45:09.522Z,1579628709.522 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-01-21T17:45:09.526Z,1579628709.526 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-01-21T17:45:09.527Z,1579628709.527 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-01-21T17:45:09.533Z,1579628709.533 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-01-21T17:45:09.534Z,1579628709.534 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2020-01-21T17:45:09.535Z,1579628709.535 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7088
2020-01-21T17:45:09.539Z,1579628709.539 [Supervisor](INFO): Main Thread ID is 6859
2020-01-21T17:45:09.539Z,1579628709.539 [Supervisor](DEBUG): Running supervisor.
2020-01-21T17:45:09.540Z,1579628709.540 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7089
2020-01-21T17:45:09.542Z,1579628709.542 [controlThread ThreadHandler](INFO): Handler Thread ID is 7090
2020-01-21T17:45:09.543Z,1579628709.543 [controlThread](DEBUG): Initializing ControlThread
2020-01-21T17:45:09.548Z,1579628709.548 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-01-21T17:45:09.548Z,1579628709.548 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-01-21T17:45:09.553Z,1579628709.553 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-01-21T17:45:09.553Z,1579628709.553 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-01-21T17:45:09.554Z,1579628709.554 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-01-21T17:45:09.554Z,1579628709.554 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-01-21T17:45:09.554Z,1579628709.554 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-01-21T17:45:09.555Z,1579628709.555 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-01-21T17:45:09.555Z,1579628709.555 [SBIT](INFO): Initialize SBIT Component.
2020-01-21T17:45:09.556Z,1579628709.556 [SBIT](IMPORTANT): git: 2019-12-03-59-g5fe9486
2020-01-21T17:45:09.556Z,1579628709.556 [SBIT](INFO): git hash: 5fe9486a96d29e351d9528fb1f5de3b9dfa3514e
2020-01-21T17:45:09.556Z,1579628709.556 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-01-21T17:45:09.557Z,1579628709.557 [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-21T17:45:09.558Z,1579628709.558 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-01-21T17:45:09.559Z,1579628709.559 [IBIT](INFO): Initialize IBIT Component.
2020-01-21T17:45:09.560Z,1579628709.560 [CBIT](DEBUG): Initialize CBIT Component.
2020-01-21T17:45:09.561Z,1579628709.561 [logger ThreadHandler](INFO): Handler Thread ID is 7091
2020-01-21T17:45:09.573Z,1579628709.573 [CBIT](DEBUG): Initialized mux pins.
2020-01-21T17:45:09.573Z,1579628709.573 [CBIT](DEBUG): Initializing the watchdog timer.
2020-01-21T17:45:09.581Z,1579628709.581 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7092
2020-01-21T17:45:09.582Z,1579628709.582 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-01-21T17:45:09.593Z,1579628709.593 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7093
2020-01-21T17:45:09.597Z,1579628709.597 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-01-21T17:45:09.597Z,1579628709.597 [CBIT](DEBUG): Initializing heartbeat.
2020-01-21T17:45:09.605Z,1579628709.605 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 7094
2020-01-21T17:45:09.606Z,1579628709.606 [CTD_NeilBrown](INFO): Powering down
2020-01-21T17:45:09.633Z,1579628709.633 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 7095
2020-01-21T17:45:09.634Z,1579628709.634 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-21T17:45:09.657Z,1579628709.657 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7096
2020-01-21T17:45:09.660Z,1579628709.660 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-01-21T17:45:09.660Z,1579628709.660 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-01-21T17:45:09.660Z,1579628709.660 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-01-21T17:45:09.661Z,1579628709.661 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-01-21T17:45:09.661Z,1579628709.661 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-01-21T17:45:09.661Z,1579628709.661 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-01-21T17:45:09.661Z,1579628709.661 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-01-21T17:45:09.661Z,1579628709.661 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-01-21T17:45:09.662Z,1579628709.662 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-01-21T17:45:09.662Z,1579628709.662 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-01-21T17:45:09.662Z,1579628709.662 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-01-21T17:45:09.662Z,1579628709.662 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-01-21T17:45:09.662Z,1579628709.662 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-01-21T17:45:09.662Z,1579628709.662 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-01-21T17:45:09.662Z,1579628709.662 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-01-21T17:45:09.663Z,1579628709.663 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-01-21T17:45:09.669Z,1579628709.669 [CBIT](DEBUG): Deactivating GF circuits.
2020-01-21T17:45:09.669Z,1579628709.669 [CBIT](DEBUG): Deactivating emergency mode.
2020-01-21T17:45:09.705Z,1579628709.705 [CBIT](DEBUG): Backplane powered.
2020-01-21T17:45:09.705Z,1579628709.705 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-01-21T17:45:09.707Z,1579628709.707 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-01-21T17:45:09.708Z,1579628709.708 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-01-21T17:45:09.708Z,1579628709.708 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-01-21T17:45:09.709Z,1579628709.709 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-01-21T17:45:09.719Z,1579628709.719 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-21T17:45:09.746Z,1579628709.746 [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-21T17:45:09.747Z,1579628709.747 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-01-21T17:45:09.835Z,1579628709.835 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-01-21T17:45:09.841Z,1579628709.841 [Default:A.Wait](DEBUG): Construct Wait.
2020-01-21T17:45:09.843Z,1579628709.843 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-21T17:45:09.866Z,1579628709.866 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-01-21T17:45:09.891Z,1579628709.891 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-01-21T17:45:09.908Z,1579628709.908 [Default:E.Execute](DEBUG): Construct Execute.
2020-01-21T17:45:09.912Z,1579628709.912 [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-21T17:45:09.930Z,1579628709.930 [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-21T17:45:09.944Z,1579628709.944 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-01-21T17:45:09.981Z,1579628709.981 [DDM](INFO): Powering up
2020-01-21T17:45:09.981Z,1579628709.981 [DDM](DEBUG): Initializing DDM.
2020-01-21T17:45:09.997Z,1579628709.997 [Radio_Surface](INFO): Powering up
2020-01-21T17:45:10.011Z,1579628710.011 [DUSBL_Hydroid](INFO): Powering up
2020-01-21T17:45:10.011Z,1579628710.011 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-01-21T17:45:10.227Z,1579628710.227 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-01-21T17:45:10.233Z,1579628710.233 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-01-21T17:45:10.234Z,1579628710.234 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-01-21T17:45:10.241Z,1579628710.241 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-01-21T17:45:10.242Z,1579628710.242 [MassServo](DEBUG): Initializing EZServoServo.
2020-01-21T17:45:10.249Z,1579628710.249 [MassServo](DEBUG): Initializing MassServo.
2020-01-21T17:45:10.250Z,1579628710.250 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-21T17:45:10.257Z,1579628710.257 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-21T17:45:10.258Z,1579628710.258 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-01-21T17:45:10.265Z,1579628710.265 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-01-21T17:45:10.360Z,1579628710.360 [Micromodem](INFO): Powering up
2020-01-21T17:45:10.360Z,1579628710.360 [Micromodem](DEBUG): Initializing Micromodem.
2020-01-21T17:45:11.149Z,1579628711.149 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-01-21T17:45:11.149Z,1579628711.149 [RudderServo](FAULT): Rudder failed to initialize
2020-01-21T17:45:11.149Z,1579628711.149 [RudderServo] Communications Fault, FailCount= 1
2020-01-21T17:45:11.149Z,1579628711.149 [RudderServo](ERROR): Communications Fault
2020-01-21T17:45:11.260Z,1579628711.260 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-01-21T17:45:11.443Z,1579628711.443 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-21T17:45:11.443Z,1579628711.443 [RudderServo](INFO): Powering down
2020-01-21T17:45:12.135Z,1579628712.135 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-21T17:45:12.254Z,1579628712.254 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-21T17:45:12.258Z,1579628712.258 [CBIT](INFO): Clearing failed state for component RudderServo
2020-01-21T17:45:12.258Z,1579628712.258 [RudderServo] No Fault, FailCount= 1
2020-01-21T17:45:15.349Z,1579628715.349 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2020-01-21T17:45:15.755Z,1579628715.755 [Micromodem](INFO): Nmea in: $CATMG,2020-01-21T17:45:15.124627Z,RTC,RTC*55

2020-01-21T17:45:15.756Z,1579628715.756 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-01-21T17:45:15.124627Z,RTC,RTC*55

2020-01-21T17:45:16.175Z,1579628716.175 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2020-01-21T17:45:16.175Z,1579628716.175 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2020-01-21T17:45:16.579Z,1579628716.579 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2020-01-21T17:45:16.579Z,1579628716.579 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2020-01-21T17:45:16.983Z,1579628716.983 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2020-01-21T17:45:16.984Z,1579628716.984 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,1*2E

2020-01-21T17:45:17.387Z,1579628717.387 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,1*2C

2020-01-21T17:45:17.387Z,1579628717.387 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2020-01-21T17:45:17.795Z,1579628717.795 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2020-01-21T17:45:17.795Z,1579628717.795 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2020-01-21T17:45:18.184Z,1579628718.184 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2020-01-21T17:45:18.184Z,1579628718.184 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2020-01-21T17:45:18.626Z,1579628718.626 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2020-01-21T17:45:18.627Z,1579628718.627 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2020-01-21T17:45:18.982Z,1579628718.982 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2020-01-21T17:45:18.983Z,1579628718.983 [Micromodem](INFO): Nmea out: $CCCLK,2020,01,21,17,45,19*49

2020-01-21T17:45:19.392Z,1579628719.392 [Micromodem](INFO): Nmea in: $CACLK,2020,1,21,17,45,19*7B

2020-01-21T17:45:19.393Z,1579628719.393 [Micromodem](INFO): Nmea in: $CATMS,0,2020-01-21T17:45:20Z*71

2020-01-21T17:45:19.395Z,1579628719.395 [Micromodem](INFO): Nmea in: $CATMG,2020-01-21T17:45:20.026641Z,USER_CMD,RTC*11

2020-01-21T17:45:20.597Z,1579628720.597 [DDM](INFO): Dynamic Docking Module:
2020-01-21T17:45:23.440Z,1579628723.440 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2020-01-21T17:45:24.654Z,1579628724.654 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-21T17:45:24.654Z,1579628724.654 [RDI_Pathfinder](ERROR): Failed to parse:
:TS057293121.0,   0.0,1524.2,  0
2020-01-21T17:45:27.858Z,1579628727.858 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-01-21T17:45:35.936Z,1579628735.936 [NAL9602](INFO): Powering up NAL9602
2020-01-21T17:45:46.849Z,1579628746.849 [NAL9602](INFO): NAL9602 initialized
2020-01-21T17:45:49.346Z,1579628749.346 [SBIT](IMPORTANT): Beginning Startup BIT
2020-01-21T17:45:49.358Z,1579628749.358 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-21T17:46:00.447Z,1579628760.447 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.020492
CHAN A1 (24V): -0.028441
CHAN A2 (12V): -0.007254
CHAN A3 (5V): -0.002098
CHAN B0 (3.3V): 0.000247
CHAN B1 (3.15aV): 0.000227
CHAN B2 (3.15bV): 0.000037
CHAN B3 (GND): 0.001959
OPEN: 0.005002
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-21T17:46:42.683Z,1579628802.683 [SBIT](IMPORTANT): SBIT PASSED
2020-01-21T17:46:42.684Z,1579628802.684 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-01-21T17:46:42.684Z,1579628802.684 [SBIT](IMPORTANT): DDM.verbosity=3 count;

2020-01-21T17:46:42.685Z,1579628802.685 [SBIT](IMPORTANT): DUSBL_Hydroid.detectionThreshold=30 count;

2020-01-21T17:46:42.685Z,1579628802.685 [SBIT](IMPORTANT): Micromodem.pwrampTXLevel=1 enum;

2020-01-21T17:46:42.685Z,1579628802.685 [SBIT](IMPORTANT): Micromodem.sendExpress=1 bool;

2020-01-21T17:46:42.685Z,1579628802.685 [SBIT](IMPORTANT): Micromodem.surfaceThreshold=0 meter;

2020-01-21T17:46:42.685Z,1579628802.685 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=105 cubic_centimeter;

2020-01-21T17:46:42.685Z,1579628802.685 [SBIT](IMPORTANT): VerticalControl.massDefault=-5 millimeter;

2020-01-21T17:46:43.047Z,1579628803.047 [MissionManager](IMPORTANT): Started mission Startup
2020-01-21T17:46:43.047Z,1579628803.047 [Startup] Running Loop=1
2020-01-21T17:46:43.047Z,1579628803.047 [Startup](DEBUG): Aggregate::initialize Startup
2020-01-21T17:46:43.047Z,1579628803.047 [Startup:A.GoToSurface] Running Loop=1
2020-01-21T17:46:43.047Z,1579628803.047 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-21T17:46:43.048Z,1579628803.048 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-21T17:46:43.048Z,1579628803.048 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-21T17:46:43.049Z,1579628803.049 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-21T17:46:43.049Z,1579628803.049 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-21T17:46:43.050Z,1579628803.050 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-21T17:46:43.051Z,1579628803.051 [Startup:StartupSatComms] Running Loop=1
2020-01-21T17:46:43.051Z,1579628803.051 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-01-21T17:46:43.051Z,1579628803.051 [Startup:StartupSatComms:A] Running Loop=1
2020-01-21T17:46:43.437Z,1579628803.437 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-01-21T17:47:05.658Z,1579628825.658 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-21T17:47:05.658Z,1579628825.658 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012110591031,35.0, -0.1, 48.9,  0
2020-01-21T17:47:38.779Z,1579628858.779 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004972
2020-01-21T17:47:43.258Z,1579628863.258 [Startup:StartupSatComms:A](INFO): Timed out from 2020-01-21T17:46:43.1Z
2020-01-21T17:47:43.258Z,1579628863.258 [Startup:StartupSatComms:A] Stopped
2020-01-21T17:47:43.258Z,1579628863.258 [Startup:StartupSatComms:B] Running Loop=1
2020-01-21T17:47:43.634Z,1579628863.634 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-21T17:47:44.068Z,1579628864.068 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 9B38275E000000005D000004003C0100000000000000151D80030C5669BF3148E2FA22188B6A316CB341FA2208D03B2B9B32C3C10A70A7C01315A162EB88A1EB
2020-01-21T17:47:44.068Z,1579628864.068 [Micromodem](INFO): Outgoing frame #2, 64 bytes: BF7D53FA13ADDCAF8A6841E9F913914665EC9B7B634BB00059FFFE7B92B9B53BC0E19179E23DC776A7C3AC971D54D2DEBAC667F1B91CD16D99A28C3DB4DC557E
2020-01-21T17:47:44.069Z,1579628864.069 [Micromodem](INFO): Outgoing frame #3, 60 bytes: 6AF97B85BD0FF6FBDA060E1BC4ACC801EE43D8AD859887422115A976C4135A3B4ED9A38DA0A2609400C7F5BCBB7C890CEA87E7A8DA2A95EE263D1743
2020-01-21T17:47:44.069Z,1579628864.069 [Micromodem](INFO): Nmea out: $CCCYC,0,1,12,1,0,3*69

2020-01-21T17:47:44.407Z,1579628864.407 [Micromodem](INFO): Nmea in: $CACYC,0,1,12,1,0,3*6B

2020-01-21T17:47:44.803Z,1579628864.803 [Micromodem](INFO): Nmea in: $CADRQ,174744,1,12,0,64,1*71

2020-01-21T17:47:44.804Z,1579628864.804 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,9B38275E000000005D000004003C0100000000000000151D80030C5669BF3148E2FA22188B6A316CB341FA2208D03B2B9B32C3C10A70A7C01315A162EB88A1EB*41

2020-01-21T17:47:45.219Z,1579628865.219 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-21T17:47:45.619Z,1579628865.619 [Micromodem](INFO): Nmea in: $CADRQ,174745,1,12,0,64,2*73

2020-01-21T17:47:45.620Z,1579628865.620 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,BF7D53FA13ADDCAF8A6841E9F913914665EC9B7B634BB00059FFFE7B92B9B53BC0E19179E23DC776A7C3AC971D54D2DEBAC667F1B91CD16D99A28C3DB4DC557E*4A

2020-01-21T17:47:46.024Z,1579628866.024 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-21T17:47:46.423Z,1579628866.423 [Micromodem](INFO): Nmea in: $CADRQ,174746,1,12,0,64,3*71

2020-01-21T17:47:46.424Z,1579628866.424 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,6AF97B85BD0FF6FBDA060E1BC4ACC801EE43D8AD859887422115A976C4135A3B4ED9A38DA0A2609400C7F5BCBB7C890CEA87E7A8DA2A95EE263D1743*43

2020-01-21T17:47:46.831Z,1579628866.831 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,60*4F

2020-01-21T17:47:47.244Z,1579628867.244 [Micromodem](INFO): Nmea in: $CATXP,188*43

2020-01-21T17:47:48.471Z,1579628868.471 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-21T17:47:48.471Z,1579628868.471 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768,-3
2020-01-21T17:47:50.867Z,1579628870.867 [Micromodem](INFO): Nmea in: $CATXF,188*55

2020-01-21T17:47:52.084Z,1579628872.084 [Micromodem](INFO): Nmea in: $CAXST,6,20200121,174747.433671,3,0,200,4000,10000,1,1,12,1,3,3,3,188*71

2020-01-21T17:47:59.644Z,1579628879.644 [DataOverHttps](INFO): Sending 180 bytes from file Logs/20200121T174459/Courier0000.lzma
2020-01-21T17:48:01.650Z,1579628881.650 [DataOverHttps](INFO): Moved sent file to Logs/20200121T174459/Courier0000.lzma.bak
2020-01-21T17:48:01.650Z,1579628881.650 [DataOverHttps](INFO): SBD MOMSN=12197795
2020-01-21T17:48:09.898Z,1579628889.898 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-01-21T17:48:09.898Z,1579628889.898 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-21T17:48:09.912Z,1579628889.912 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-21T17:48:10.298Z,1579628890.298 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-21T17:48:10.298Z,1579628890.298 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-01-21T17:48:23.944Z,1579628903.944 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200121T163405/Express0005.lzma
2020-01-21T17:48:25.950Z,1579628905.950 [DataOverHttps](INFO): Moved sent file to Logs/20200121T163405/Express0005.lzma.bak
2020-01-21T17:48:25.950Z,1579628905.950 [DataOverHttps](INFO): SBD MOMSN=12197798
2020-01-21T17:48:43.477Z,1579628923.477 [Startup:StartupSatComms:B](INFO): Timed out from 2020-01-21T17:47:43.3Z
2020-01-21T17:48:43.477Z,1579628923.477 [Startup:StartupSatComms:B] Stopped
2020-01-21T17:48:43.477Z,1579628923.477 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-01-21T17:48:43.477Z,1579628923.477 [Startup:StartupSatComms] Stopped
2020-01-21T17:48:43.478Z,1579628923.478 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-01-21T17:48:43.478Z,1579628923.478 [Startup](INFO): Completed Startup
2020-01-21T17:48:43.478Z,1579628923.478 [MissionManager](INFO): Startup is completed.
2020-01-21T17:48:43.478Z,1579628923.478 [MissionManager](INFO): Uninitializing Mission Startup
2020-01-21T17:48:43.479Z,1579628923.479 [Startup] Stopped
2020-01-21T17:48:43.479Z,1579628923.479 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-01-21T17:48:43.479Z,1579628923.479 [Startup:A.GoToSurface] Stopped
2020-01-21T17:48:43.479Z,1579628923.479 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-21T17:48:43.842Z,1579628923.842 [MissionManager](IMPORTANT): Started mission Default
2020-01-21T17:48:43.843Z,1579628923.843 [Default] Running Loop=1
2020-01-21T17:48:43.843Z,1579628923.843 [Default](DEBUG): Aggregate::initialize Default
2020-01-21T17:48:43.843Z,1579628923.843 [Default:B.GoToSurface] Running Loop=1
2020-01-21T17:48:43.843Z,1579628923.843 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-21T17:48:43.843Z,1579628923.843 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-21T17:48:43.843Z,1579628923.843 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-21T17:48:43.844Z,1579628923.844 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-21T17:48:43.844Z,1579628923.844 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-21T17:48:43.844Z,1579628923.844 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-21T17:48:43.844Z,1579628923.844 [Default:A.Wait] Running Loop=1
2020-01-21T17:48:43.865Z,1579628923.865 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-01-21T17:48:47.762Z,1579628927.762 [DataOverHttps](INFO): Sending 883 bytes from file Logs/20200121T173754/Express0001.lzma
2020-01-21T17:48:48.677Z,1579628928.677 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-21T17:48:48.677Z,1579628928.677 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-3268,-32768,V
2020-01-21T17:48:49.766Z,1579628929.766 [DataOverHttps](INFO): Moved sent file to Logs/20200121T173754/Express0001.lzma.bak
2020-01-21T17:48:49.766Z,1579628929.766 [DataOverHttps](INFO): SBD MOMSN=12197801
2020-01-21T17:48:57.188Z,1579628937.188 [Default:A.Wait](INFO): Done Waiting.
2020-01-21T17:48:57.188Z,1579628937.188 [Default:A.Wait] Stopped
2020-01-21T17:48:57.188Z,1579628937.188 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-21T17:48:57.571Z,1579628937.571 [Default:CheckIn] Running Loop=1
2020-01-21T17:48:57.571Z,1579628937.571 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-21T17:48:57.571Z,1579628937.571 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-21T17:48:57.987Z,1579628937.987 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-01-21T17:49:48.472Z,1579628988.472 [RDI_Pathfinder](ERROR): Failed to parse:
:SA,   +0.00,   +0.00,  0.00
2020-01-21T17:50:48.661Z,1579629048.661 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2020-01-21T17:50:50.247Z,1579629050.247 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-01-21T17:51:10.914Z,1579629070.914 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-01-21T17:51:10.914Z,1579629070.914 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-21T17:51:10.924Z,1579629070.924 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-21T17:51:11.325Z,1579629071.325 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-21T17:51:11.325Z,1579629071.325 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-01-21T17:52:27.642Z,1579629147.642 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-21T17:52:27.642Z,1579629147.642 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012111043231,35.0, -0.1,   0.0, 0
2020-01-21T17:52:46.619Z,1579629166.619 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-21T17:52:46.619Z,1579629166.619 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2020-01-21T17:52:49.855Z,1579629169.855 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-01-21T17:52:49.892Z,1579629169.892 [BPC1](INFO): Received data from all battery sticks.
2020-01-21T17:53:35.900Z,1579629215.900 [CommandLine](IMPORTANT): got command failComponent
2020-01-21T17:53:35.900Z,1579629215.900 [CommandLine](IMPORTANT): Failed components:
2020-01-21T17:53:35.900Z,1579629215.900 [CommandLine](IMPORTANT): No failed Components.
2020-01-21T17:53:40.227Z,1579629220.227 [CommandLine](IMPORTANT): got command strobe off
2020-01-21T17:53:40.227Z,1579629220.227 [CommandLine](IMPORTANT): Deactivating strobe
2020-01-21T17:53:57.735Z,1579629237.735 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-21T17:48:57.6Z
2020-01-21T17:53:57.735Z,1579629237.735 [Default:CheckIn:Read_GPS] Stopped
2020-01-21T17:53:57.736Z,1579629237.736 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-21T17:53:58.138Z,1579629238.138 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-21T17:53:58.511Z,1579629238.511 [Micromodem](ERROR): Buffer fill timout failure.
2020-01-21T17:53:58.976Z,1579629238.976 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 9B38275E040001005D00000400540100000000000000151D80030C5669BF3148E2FA22188B6A3173E5573572661C0BCBDFFAB423BD32D9A51E8904B0A920CE9A
2020-01-21T17:53:58.977Z,1579629238.977 [Micromodem](INFO): Outgoing frame #2, 64 bytes: EF9F66414C9B9FD6761AD008C3E3DC4FCA2E4E25B6359B14B772C4B6AB8CB62EC77F4B11CE3F413145360DD3796D0EF36AE23762292A1EE74F3C2A63268A8647
2020-01-21T17:53:58.977Z,1579629238.977 [Micromodem](INFO): Outgoing frame #3, 64 bytes: ABFD082D0517C40D06268F3340D9FB48DA86FAE0AE83532875C2591456EB2DC157F08FAB11A684AFB53DAD3C66E368EEC109B20C37A957889B67864A52248F66
2020-01-21T17:53:58.978Z,1579629238.978 [Micromodem](INFO): Nmea out: $CCCYC,0,1,12,1,0,3*69

2020-01-21T17:53:59.337Z,1579629239.337 [Micromodem](INFO): Nmea in: $CACYC,0,1,12,1,0,3*6B

2020-01-21T17:53:59.719Z,1579629239.719 [Micromodem](INFO): Nmea in: $CADRQ,175359,1,12,0,64,1*78

2020-01-21T17:53:59.720Z,1579629239.720 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,9B38275E040001005D00000400540100000000000000151D80030C5669BF3148E2FA22188B6A3173E5573572661C0BCBDFFAB423BD32D9A51E8904B0A920CE9A*48

2020-01-21T17:54:00.130Z,1579629240.130 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-21T17:54:00.527Z,1579629240.527 [Micromodem](INFO): Nmea in: $CADRQ,175400,1,12,0,64,2*70

2020-01-21T17:54:00.528Z,1579629240.528 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,EF9F66414C9B9FD6761AD008C3E3DC4FCA2E4E25B6359B14B772C4B6AB8CB62EC77F4B11CE3F413145360DD3796D0EF36AE23762292A1EE74F3C2A63268A8647*4C

2020-01-21T17:54:00.931Z,1579629240.931 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-21T17:54:01.335Z,1579629241.335 [Micromodem](INFO): Nmea in: $CADRQ,175401,1,12,0,64,3*70

2020-01-21T17:54:01.336Z,1579629241.336 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,ABFD082D0517C40D06268F3340D9FB48DA86FAE0AE83532875C2591456EB2DC157F08FAB11A684AFB53DAD3C66E368EEC109B20C37A957889B67864A52248F66*39

2020-01-21T17:54:01.743Z,1579629241.743 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-21T17:54:02.148Z,1579629242.148 [Micromodem](INFO): Nmea in: $CATXP,192*48

2020-01-21T17:54:05.779Z,1579629245.779 [Micromodem](INFO): Nmea in: $CATXF,192*5E

2020-01-21T17:54:06.184Z,1579629246.184 [Micromodem](INFO): Nmea in: $CAXST,6,20200121,175402.353349,3,0,200,4000,10000,1,1,12,1,3,3,3,192*76

2020-01-21T17:54:06.985Z,1579629246.985 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20200121T174459/Courier0004.lzma
2020-01-21T17:54:08.990Z,1579629248.990 [DataOverHttps](INFO): Moved sent file to Logs/20200121T174459/Courier0004.lzma.bak
2020-01-21T17:54:08.990Z,1579629248.990 [DataOverHttps](INFO): SBD MOMSN=12197825
2020-01-21T17:54:11.899Z,1579629251.899 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-01-21T17:54:11.899Z,1579629251.899 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-21T17:54:11.909Z,1579629251.909 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-21T17:54:12.314Z,1579629252.314 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-21T17:54:12.314Z,1579629252.314 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-01-21T17:54:28.161Z,1579629268.161 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20200121T173754/Express0005.lzma
2020-01-21T17:54:30.166Z,1579629270.166 [DataOverHttps](INFO): Moved sent file to Logs/20200121T173754/Express0005.lzma.bak
2020-01-21T17:54:30.166Z,1579629270.166 [DataOverHttps](INFO): SBD MOMSN=12197827
2020-01-21T17:54:51.442Z,1579629291.442 [DataOverHttps](INFO): Sending 760 bytes from file Logs/20200121T174459/Express0001.lzma
2020-01-21T17:54:53.447Z,1579629293.447 [DataOverHttps](INFO): Moved sent file to Logs/20200121T174459/Express0001.lzma.bak
2020-01-21T17:54:53.447Z,1579629293.447 [DataOverHttps](INFO): SBD MOMSN=12197835
2020-01-21T17:55:04.363Z,1579629304.363 [Micromodem](ERROR): Buffer fill timout failure.
2020-01-21T17:55:04.891Z,1579629304.891 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 9B38275E050001005D00000400680100000000000000151D80030C5669BF5A5AE2877B5CB833E8A76EE919FA1C06F38F3A8E569D2BB7B061B59AFCE7DDF8DE08
2020-01-21T17:55:04.891Z,1579629304.891 [Micromodem](INFO): Outgoing frame #2, 64 bytes: CD8FA0B4E4AC01410861B975F843861E59BF8A192EF8CF402EA82883288480B0C0F64E96123FBA6BB131E61F86D73C3D1A712C7A7042147E62AD3FD65C0B5194
2020-01-21T17:55:04.891Z,1579629304.891 [Micromodem](INFO): Outgoing frame #3, 64 bytes: A66DDDB666B717B35FEDF2DD7FD5061E84E955A732D070122AFA6394BDE7EE6FD30AAB84BA741E92EED293DCA34F7086699166AADC73B56094F7C65ED44D8848
2020-01-21T17:55:04.892Z,1579629304.892 [Micromodem](INFO): Nmea out: $CCCYC,0,1,12,1,0,3*69

2020-01-21T17:55:05.163Z,1579629305.163 [Micromodem](INFO): Nmea in: $CACYC,0,1,12,1,0,3*6B

2020-01-21T17:55:05.575Z,1579629305.575 [Micromodem](INFO): Nmea in: $CADRQ,175505,1,12,0,64,1*77

2020-01-21T17:55:05.575Z,1579629305.575 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,9B38275E050001005D00000400680100000000000000151D80030C5669BF5A5AE2877B5CB833E8A76EE919FA1C06F38F3A8E569D2BB7B061B59AFCE7DDF8DE08*4A

2020-01-21T17:55:05.977Z,1579629305.977 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-21T17:55:06.379Z,1579629306.379 [Micromodem](INFO): Nmea in: $CADRQ,175506,1,12,0,64,2*77

2020-01-21T17:55:06.380Z,1579629306.380 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,CD8FA0B4E4AC01410861B975F843861E59BF8A192EF8CF402EA82883288480B0C0F64E96123FBA6BB131E61F86D73C3D1A712C7A7042147E62AD3FD65C0B5194*4A

2020-01-21T17:55:06.787Z,1579629306.787 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-21T17:55:07.195Z,1579629307.195 [Micromodem](INFO): Nmea in: $CADRQ,175507,1,12,0,64,3*77

2020-01-21T17:55:07.196Z,1579629307.196 [Micromodem](INFO): Nmea out: $CCTXD,1,12,1,A66DDDB666B717B35FEDF2DD7FD5061E84E955A732D070122AFA6394BDE7EE6FD30AAB84BA741E92EED293DCA34F7086699166AADC73B56094F7C65ED44D8848*47

2020-01-21T17:55:07.587Z,1579629307.587 [Micromodem](INFO): Nmea in: $CATXD,1,12,1,64*4B

2020-01-21T17:55:07.995Z,1579629307.995 [Micromodem](INFO): Nmea in: $CATXP,192*48

2020-01-21T17:55:11.635Z,1579629311.635 [Micromodem](INFO): Nmea in: $CATXF,192*5E

2020-01-21T17:55:12.844Z,1579629312.844 [Micromodem](INFO): Nmea in: $CAXST,6,20200121,175508.214658,3,0,200,4000,10000,1,1,12,1,3,3,3,192*7A

2020-01-21T17:55:15.405Z,1579629315.405 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20200121T174459/Express0005.lzma
2020-01-21T17:55:17.410Z,1579629317.410 [DataOverHttps](INFO): Moved sent file to Logs/20200121T174459/Express0005.lzma.bak
2020-01-21T17:55:17.410Z,1579629317.410 [DataOverHttps](INFO): SBD MOMSN=12197854
2020-01-21T17:55:18.950Z,1579629318.950 [Default:CheckIn:Read_Iridium] Stopped
2020-01-21T17:55:18.950Z,1579629318.950 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-21T17:55:18.950Z,1579629318.950 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-21T17:55:48.396Z,1579629348.396 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-01-21T17:55:48.396Z,1579629348.396 [NAL9602] Data Fault, FailCount= 1
2020-01-21T17:55:48.396Z,1579629348.396 [NAL9602](ERROR): Data Fault
2020-01-21T17:55:48.481Z,1579629348.481 [CBIT](ERROR): Data Fault in component: NAL9602
2020-01-21T17:55:48.795Z,1579629348.795 [NAL9602](INFO): Powering down
2020-01-21T17:55:49.652Z,1579629349.652 [CBIT](INFO): Clearing failed state for component NAL9602
2020-01-21T17:55:49.652Z,1579629349.652 [NAL9602] No Fault, FailCount= 1
2020-01-21T17:56:19.095Z,1579629379.095 [NAL9602](INFO): Powering up NAL9602
2020-01-21T17:56:30.007Z,1579629390.007 [NAL9602](INFO): NAL9602 initialized
2020-01-21T17:57:12.902Z,1579629432.902 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-01-21T17:57:12.902Z,1579629432.902 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-21T17:57:12.920Z,1579629432.920 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-21T17:57:13.336Z,1579629433.336 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-21T17:57:13.336Z,1579629433.336 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-01-21T17:57:53.291Z,1579629473.291 [RDI_Pathfinder](ERROR): only read 0 of 4 data items
2020-01-21T17:57:53.291Z,1579629473.291 [RDI_Pathfinder](ERROR): Failed to parse:
:BS-32768,-32768,V
2020-01-21T17:58:12.753Z,1579629492.753 [CommandLine](IMPORTANT): got command quit
2020-01-21T17:58:13.757Z,1579629493.757 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2020-01-21T17:58:13.757Z,1579629493.757 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-21T17:58:13.757Z,1579629493.757 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:13.765Z,1579629493.765 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-01-21T17:58:13.765Z,1579629493.765 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:13.766Z,1579629493.766 [CommandLine](INFO): Join timeout helper Thread ID is 7136
2020-01-21T17:58:13.766Z,1579629493.766 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-01-21T17:58:13.766Z,1579629493.766 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:13.766Z,1579629493.766 [NavChartDb](INFO): Join timeout helper Thread ID is 7137
2020-01-21T17:58:14.161Z,1579629494.161 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-21T17:58:14.161Z,1579629494.161 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:14.169Z,1579629494.169 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-01-21T17:58:14.169Z,1579629494.169 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:14.169Z,1579629494.169 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 7138
2020-01-21T17:58:14.237Z,1579629494.237 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-21T17:58:14.238Z,1579629494.238 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-21T17:58:14.240Z,1579629494.240 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:14.253Z,1579629494.253 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2020-01-21T17:58:14.253Z,1579629494.253 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:14.255Z,1579629494.255 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 7139
2020-01-21T17:58:14.365Z,1579629494.365 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-21T17:58:14.365Z,1579629494.365 [CTD_NeilBrown](INFO): Powering down
2020-01-21T17:58:14.377Z,1579629494.377 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:14.397Z,1579629494.397 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-01-21T17:58:14.397Z,1579629494.397 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:14.397Z,1579629494.397 [Radio_Surface](INFO): Join timeout helper Thread ID is 7140
2020-01-21T17:58:14.769Z,1579629494.769 [Radio_Surface](INFO): Powering down
2020-01-21T17:58:14.770Z,1579629494.770 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-21T17:58:14.770Z,1579629494.770 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:14.786Z,1579629494.786 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-01-21T17:58:14.786Z,1579629494.786 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:14.786Z,1579629494.786 [DataOverHttps](INFO): Join timeout helper Thread ID is 7141
2020-01-21T17:58:15.649Z,1579629495.649 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-21T17:58:15.649Z,1579629495.649 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:15.669Z,1579629495.669 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-01-21T17:58:15.669Z,1579629495.669 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:15.669Z,1579629495.669 [logger](INFO): Join timeout helper Thread ID is 7142
2020-01-21T17:58:15.717Z,1579629495.717 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-21T17:58:15.717Z,1579629495.717 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:15.729Z,1579629495.729 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-01-21T17:58:15.730Z,1579629495.730 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:15.730Z,1579629495.730 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-01-21T17:58:15.730Z,1579629495.730 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:15.730Z,1579629495.730 [controlThread](INFO): Join timeout helper Thread ID is 7143
2020-01-21T17:58:15.841Z,1579629495.841 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-21T17:58:15.841Z,1579629495.841 [controlThread](DEBUG): Uninitializing ControlThread
2020-01-21T17:58:15.842Z,1579629495.842 [AHRS_M2](INFO): Powering down
2020-01-21T17:58:15.913Z,1579629495.913 [DDM](INFO): Powering down
2020-01-21T17:58:16.001Z,1579629496.001 [DUSBL_Hydroid](INFO): Powering down
2020-01-21T17:58:16.089Z,1579629496.089 [Micromodem](INFO): Powering down
2020-01-21T17:58:16.185Z,1579629496.185 [NAL9602](INFO): Powering down
2020-01-21T17:58:16.257Z,1579629496.257 [RDI_Pathfinder](INFO): Powering down
2020-01-21T17:58:16.258Z,1579629496.258 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-01-21T17:58:16.259Z,1579629496.259 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-01-21T17:58:16.260Z,1579629496.260 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-01-21T17:58:16.260Z,1579629496.260 [MissionManager](INFO): Uninitializing Mission Default
2020-01-21T17:58:16.260Z,1579629496.260 [Default] Stopped
2020-01-21T17:58:16.260Z,1579629496.260 [Default](DEBUG): Aggregate::uninitialize Default
2020-01-21T17:58:16.260Z,1579629496.260 [Default:B.GoToSurface] Stopped
2020-01-21T17:58:16.260Z,1579629496.260 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-21T17:58:16.261Z,1579629496.261 [Default:CheckIn] Stopped
2020-01-21T17:58:16.261Z,1579629496.261 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-21T17:58:16.261Z,1579629496.261 [Default:CheckIn:C.Wait] Stopped
2020-01-21T17:58:16.261Z,1579629496.261 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-21T17:58:16.263Z,1579629496.263 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-01-21T17:58:16.263Z,1579629496.263 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-01-21T17:58:16.264Z,1579629496.264 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-01-21T17:58:16.264Z,1579629496.264 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-01-21T17:58:16.264Z,1579629496.264 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-01-21T17:58:16.264Z,1579629496.264 [BuoyancyServo](INFO): Powering down
2020-01-21T17:58:16.277Z,1579629496.277 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-01-21T17:58:16.277Z,1579629496.277 [ElevatorServo](INFO): Powering down
2020-01-21T17:58:16.278Z,1579629496.278 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-01-21T17:58:16.278Z,1579629496.278 [MassServo](INFO): Powering down
2020-01-21T17:58:16.279Z,1579629496.279 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-21T17:58:16.279Z,1579629496.279 [RudderServo](INFO): Powering down
2020-01-21T17:58:16.279Z,1579629496.279 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-01-21T17:58:16.280Z,1579629496.280 [ThrusterServo](INFO): Powering down
2020-01-21T17:58:16.280Z,1579629496.280 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-01-21T17:58:16.281Z,1579629496.281 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-01-21T17:58:16.281Z,1579629496.281 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-01-21T17:58:16.281Z,1579629496.281 [CBIT](DEBUG): Powering off loads.
2020-01-21T17:58:16.293Z,1579629496.293 [CBIT](DEBUG): Disabling WDT.
2020-01-21T17:58:16.305Z,1579629496.305 [CBIT](DEBUG): Opening all GF detection circuits.
2020-01-21T17:58:16.306Z,1579629496.306 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:16.346Z,1579629496.346 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:16.357Z,1579629496.357 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:16.399Z,1579629496.399 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:16.402Z,1579629496.402 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:16.461Z,1579629496.461 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-21T17:58:16.521Z,1579629496.521 [logger ThreadHandler](INFO): Thread cancelled.