2020-01-26T05:22:57.786Z,1580016177.786 [Supervisor](DEBUG): Initializing supervisor.
2020-01-26T05:22:57.788Z,1580016177.788 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-01-26T05:22:57.789Z,1580016177.789 [SyncHandler](INFO): Protected caller Thread ID is 3655
2020-01-26T05:22:57.789Z,1580016177.789 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-01-26T05:22:57.790Z,1580016177.790 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-01-26T05:22:57.791Z,1580016177.791 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3656
2020-01-26T05:22:57.794Z,1580016177.794 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-01-26T05:22:57.806Z,1580016177.806 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-01-26T05:22:57.807Z,1580016177.807 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-01-26T05:22:57.807Z,1580016177.807 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3657
2020-01-26T05:22:57.808Z,1580016177.808 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-01-26T05:22:57.809Z,1580016177.809 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-01-26T05:22:57.809Z,1580016177.809 [logger ThreadHandler](INFO): Protected caller Thread ID is 3658
2020-01-26T05:22:57.811Z,1580016177.811 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-01-26T05:22:57.811Z,1580016177.811 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-01-26T05:22:57.813Z,1580016177.813 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-01-26T05:22:58.244Z,1580016178.244 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-01-26T05:22:58.245Z,1580016178.245 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-01-26T05:22:58.342Z,1580016178.342 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-01-26T05:22:58.342Z,1580016178.342 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-01-26T05:22:58.653Z,1580016178.653 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-01-26T05:22:58.654Z,1580016178.654 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-01-26T05:22:58.791Z,1580016178.791 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-01-26T05:22:58.791Z,1580016178.791 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-01-26T05:22:58.981Z,1580016178.981 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-01-26T05:22:58.982Z,1580016178.982 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-01-26T05:22:59.431Z,1580016179.431 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-01-26T05:22:59.432Z,1580016179.432 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-01-26T05:22:59.876Z,1580016179.876 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-01-26T05:22:59.877Z,1580016179.877 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-01-26T05:23:00.019Z,1580016180.019 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-01-26T05:23:00.020Z,1580016180.020 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-01-26T05:23:00.208Z,1580016180.208 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-01-26T05:23:00.209Z,1580016180.209 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-01-26T05:23:00.304Z,1580016180.304 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-01-26T05:23:00.305Z,1580016180.305 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-01-26T05:23:00.607Z,1580016180.607 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-01-26T05:23:00.608Z,1580016180.608 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-01-26T05:23:00.688Z,1580016180.688 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-01-26T05:23:00.790Z,1580016180.790 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-01-26T05:23:00.790Z,1580016180.790 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-01-26T05:23:01.420Z,1580016181.420 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-01-26T05:23:01.420Z,1580016181.420 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-01-26T05:23:01.825Z,1580016181.825 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-01-26T05:23:01.827Z,1580016181.827 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-01-26T05:23:01.827Z,1580016181.827 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-01-26T05:23:02.037Z,1580016182.037 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-01-26T05:23:02.137Z,1580016182.137 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-01-26T05:23:02.236Z,1580016182.236 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-01-26T05:23:02.460Z,1580016182.460 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-01-26T05:23:02.461Z,1580016182.461 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-01-26T05:23:02.545Z,1580016182.545 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-01-26T05:23:02.638Z,1580016182.638 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-01-26T05:23:02.735Z,1580016182.735 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-01-26T05:23:02.817Z,1580016182.817 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-01-26T05:23:02.924Z,1580016182.924 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-01-26T05:23:03.016Z,1580016183.016 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-01-26T05:23:03.197Z,1580016183.197 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-01-26T05:23:03.326Z,1580016183.326 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-01-26T05:23:03.332Z,1580016183.332 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-01-26T05:23:03.640Z,1580016183.640 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-01-26T05:23:03.646Z,1580016183.646 [AHRS_M2](INFO): created writer for : platform_orientation
2020-01-26T05:23:03.648Z,1580016183.648 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-01-26T05:23:03.652Z,1580016183.652 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-01-26T05:23:03.653Z,1580016183.653 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-01-26T05:23:03.658Z,1580016183.658 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-01-26T05:23:03.659Z,1580016183.659 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-01-26T05:23:03.664Z,1580016183.664 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-01-26T05:23:03.731Z,1580016183.731 [AHRS_M2] Loaded
2020-01-26T05:23:03.731Z,1580016183.731 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-01-26T05:23:03.809Z,1580016183.809 [DataOverHttps] Loaded
2020-01-26T05:23:03.810Z,1580016183.810 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-01-26T05:23:03.811Z,1580016183.811 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407684E0
2020-01-26T05:23:03.811Z,1580016183.811 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3740
2020-01-26T05:23:03.834Z,1580016183.834 [DDM] Loaded
2020-01-26T05:23:03.834Z,1580016183.834 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-01-26T05:23:03.846Z,1580016183.846 [Depth_Keller] Loaded
2020-01-26T05:23:03.846Z,1580016183.846 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-01-26T05:23:03.905Z,1580016183.905 [DUSBL_Hydroid] Loaded
2020-01-26T05:23:03.905Z,1580016183.905 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-01-26T05:23:03.950Z,1580016183.950 [Micromodem] Loaded
2020-01-26T05:23:03.950Z,1580016183.950 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-01-26T05:23:04.041Z,1580016184.041 [NAL9602] Loaded
2020-01-26T05:23:04.042Z,1580016184.042 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-01-26T05:23:04.079Z,1580016184.079 [Onboard] Loaded
2020-01-26T05:23:04.079Z,1580016184.079 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-01-26T05:23:04.085Z,1580016184.085 [PowerOnly] Loaded
2020-01-26T05:23:04.085Z,1580016184.085 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2020-01-26T05:23:04.091Z,1580016184.091 [Radio_Surface] Loaded
2020-01-26T05:23:04.092Z,1580016184.092 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-01-26T05:23:04.093Z,1580016184.093 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407984E0
2020-01-26T05:23:04.093Z,1580016184.093 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3741
2020-01-26T05:23:04.134Z,1580016184.134 [RDI_Pathfinder] Loaded
2020-01-26T05:23:04.134Z,1580016184.134 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-01-26T05:23:06.385Z,1580016186.385 [BPC1] Loaded
2020-01-26T05:23:06.385Z,1580016186.385 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-01-26T05:23:06.386Z,1580016186.386 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-01-26T05:23:06.386Z,1580016186.386 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-01-26T05:23:06.399Z,1580016186.399 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-01-26T05:23:06.400Z,1580016186.400 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-01-26T05:23:06.512Z,1580016186.512 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-01-26T05:23:06.512Z,1580016186.512 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-01-26T05:23:06.532Z,1580016186.532 [NavChart] Loaded
2020-01-26T05:23:06.532Z,1580016186.532 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-01-26T05:23:06.536Z,1580016186.536 [UniversalFixResidualReporter] Loaded
2020-01-26T05:23:06.536Z,1580016186.536 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-01-26T05:23:06.536Z,1580016186.536 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-01-26T05:23:06.537Z,1580016186.537 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-01-26T05:23:06.641Z,1580016186.641 [BuoyancyServo] Loaded
2020-01-26T05:23:06.642Z,1580016186.642 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-01-26T05:23:06.656Z,1580016186.656 [ElevatorServo] Loaded
2020-01-26T05:23:06.656Z,1580016186.656 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-01-26T05:23:06.671Z,1580016186.671 [MassServo] Loaded
2020-01-26T05:23:06.671Z,1580016186.671 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-01-26T05:23:06.686Z,1580016186.686 [RudderServo] Loaded
2020-01-26T05:23:06.686Z,1580016186.686 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-01-26T05:23:06.700Z,1580016186.700 [ThrusterServo] Loaded
2020-01-26T05:23:06.700Z,1580016186.700 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-01-26T05:23:06.701Z,1580016186.701 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-01-26T05:23:06.701Z,1580016186.701 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-01-26T05:23:06.888Z,1580016186.888 [PAR_Licor] Loaded
2020-01-26T05:23:06.888Z,1580016186.888 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-01-26T05:23:06.929Z,1580016186.929 [WetLabsSeaOWL_UV_A] Loaded
2020-01-26T05:23:06.930Z,1580016186.930 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-01-26T05:23:06.931Z,1580016186.931 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408EC4E0
2020-01-26T05:23:06.931Z,1580016186.931 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 3742
2020-01-26T05:23:06.932Z,1580016186.932 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-01-26T05:23:06.932Z,1580016186.932 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-01-26T05:23:07.254Z,1580016187.254 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-01-26T05:23:07.255Z,1580016187.255 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-01-26T05:23:07.295Z,1580016187.295 [DepthRateCalculator] Loaded
2020-01-26T05:23:07.295Z,1580016187.295 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-01-26T05:23:07.300Z,1580016187.300 [PitchRateCalculator] Loaded
2020-01-26T05:23:07.301Z,1580016187.301 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-01-26T05:23:07.312Z,1580016187.312 [SpeedCalculator] Loaded
2020-01-26T05:23:07.312Z,1580016187.312 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-01-26T05:23:07.333Z,1580016187.333 [TempGradientCalculator] Loaded
2020-01-26T05:23:07.333Z,1580016187.333 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-01-26T05:23:07.338Z,1580016187.338 [YawRateCalculator] Loaded
2020-01-26T05:23:07.338Z,1580016187.338 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-01-26T05:23:07.376Z,1580016187.376 [ElevatorOffsetCalculator] Loaded
2020-01-26T05:23:07.377Z,1580016187.377 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-01-26T05:23:07.377Z,1580016187.377 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-01-26T05:23:07.378Z,1580016187.378 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-01-26T05:23:07.513Z,1580016187.513 [SBIT](DEBUG): Construct Startup Built In Test.
2020-01-26T05:23:07.534Z,1580016187.534 [SBIT] Loaded
2020-01-26T05:23:07.535Z,1580016187.535 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-01-26T05:23:07.535Z,1580016187.535 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-01-26T05:23:07.547Z,1580016187.547 [IBIT] Loaded
2020-01-26T05:23:07.548Z,1580016187.548 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-01-26T05:23:07.551Z,1580016187.551 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-01-26T05:23:07.683Z,1580016187.683 [CBIT] Loaded
2020-01-26T05:23:07.683Z,1580016187.683 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-01-26T05:23:07.684Z,1580016187.684 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-01-26T05:23:07.684Z,1580016187.684 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-01-26T05:23:07.767Z,1580016187.767 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-01-26T05:23:07.767Z,1580016187.767 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-01-26T05:23:07.863Z,1580016187.863 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-01-26T05:23:07.864Z,1580016187.864 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-01-26T05:23:07.911Z,1580016187.911 [VerticalControl](DEBUG): Construct VerticalControl.
2020-01-26T05:23:07.990Z,1580016187.990 [VerticalControl] Loaded
2020-01-26T05:23:07.990Z,1580016187.990 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-01-26T05:23:07.991Z,1580016187.991 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-01-26T05:23:08.057Z,1580016188.057 [HorizontalControl] Loaded
2020-01-26T05:23:08.057Z,1580016188.057 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-01-26T05:23:08.058Z,1580016188.058 [SpeedControl](DEBUG): Construct SpeedControl.
2020-01-26T05:23:08.059Z,1580016188.059 [SpeedControl] Loaded
2020-01-26T05:23:08.060Z,1580016188.060 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-01-26T05:23:08.060Z,1580016188.060 [LoopControl](DEBUG): Construct LoopControl.
2020-01-26T05:23:08.061Z,1580016188.061 [LoopControl] Loaded
2020-01-26T05:23:08.061Z,1580016188.061 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-01-26T05:23:08.062Z,1580016188.062 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-01-26T05:23:08.062Z,1580016188.062 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-01-26T05:23:08.094Z,1580016188.094 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-01-26T05:23:08.098Z,1580016188.098 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-01-26T05:23:08.099Z,1580016188.099 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-01-26T05:23:08.105Z,1580016188.105 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-01-26T05:23:08.106Z,1580016188.106 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACC4E0
2020-01-26T05:23:08.107Z,1580016188.107 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3743
2020-01-26T05:23:08.111Z,1580016188.111 [Supervisor](INFO): Main Thread ID is 815
2020-01-26T05:23:08.112Z,1580016188.112 [Supervisor](DEBUG): Running supervisor.
2020-01-26T05:23:08.112Z,1580016188.112 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3744
2020-01-26T05:23:08.115Z,1580016188.115 [controlThread ThreadHandler](INFO): Handler Thread ID is 3745
2020-01-26T05:23:08.115Z,1580016188.115 [controlThread](DEBUG): Initializing ControlThread
2020-01-26T05:23:08.119Z,1580016188.119 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-01-26T05:23:08.119Z,1580016188.119 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-01-26T05:23:08.121Z,1580016188.121 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-01-26T05:23:08.121Z,1580016188.121 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-01-26T05:23:08.122Z,1580016188.122 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-01-26T05:23:08.122Z,1580016188.122 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-01-26T05:23:08.123Z,1580016188.123 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-01-26T05:23:08.123Z,1580016188.123 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-01-26T05:23:08.123Z,1580016188.123 [SBIT](INFO): Initialize SBIT Component.
2020-01-26T05:23:08.124Z,1580016188.124 [SBIT](IMPORTANT): git: 2020-01-26-2-gfd51465
2020-01-26T05:23:08.124Z,1580016188.124 [SBIT](INFO): git hash: fd51465a4be0f2458cfa55fa910451fabf321855
2020-01-26T05:23:08.124Z,1580016188.124 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-01-26T05:23:08.125Z,1580016188.125 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Nov 13 12:38:10 PST 2019
2020-01-26T05:23:08.126Z,1580016188.126 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-01-26T05:23:08.127Z,1580016188.127 [IBIT](INFO): Initialize IBIT Component.
2020-01-26T05:23:08.128Z,1580016188.128 [CBIT](DEBUG): Initialize CBIT Component.
2020-01-26T05:23:08.129Z,1580016188.129 [logger ThreadHandler](INFO): Handler Thread ID is 3746
2020-01-26T05:23:08.141Z,1580016188.141 [CBIT](DEBUG): Initialized mux pins.
2020-01-26T05:23:08.141Z,1580016188.141 [CBIT](DEBUG): Initializing the watchdog timer.
2020-01-26T05:23:08.149Z,1580016188.149 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3747
2020-01-26T05:23:08.150Z,1580016188.150 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-01-26T05:23:08.161Z,1580016188.161 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3748
2020-01-26T05:23:08.165Z,1580016188.165 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-01-26T05:23:08.165Z,1580016188.165 [CBIT](DEBUG): Initializing heartbeat.
2020-01-26T05:23:08.173Z,1580016188.173 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 3749
2020-01-26T05:23:08.174Z,1580016188.174 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-26T05:23:08.201Z,1580016188.201 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3750
2020-01-26T05:23:08.204Z,1580016188.204 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-01-26T05:23:08.205Z,1580016188.205 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-01-26T05:23:08.205Z,1580016188.205 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-01-26T05:23:08.205Z,1580016188.205 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-01-26T05:23:08.205Z,1580016188.205 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-01-26T05:23:08.205Z,1580016188.205 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-01-26T05:23:08.206Z,1580016188.206 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-01-26T05:23:08.206Z,1580016188.206 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-01-26T05:23:08.206Z,1580016188.206 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-01-26T05:23:08.206Z,1580016188.206 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-01-26T05:23:08.206Z,1580016188.206 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-01-26T05:23:08.207Z,1580016188.207 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-01-26T05:23:08.207Z,1580016188.207 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-01-26T05:23:08.207Z,1580016188.207 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-01-26T05:23:08.207Z,1580016188.207 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-01-26T05:23:08.207Z,1580016188.207 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-01-26T05:23:08.237Z,1580016188.237 [CBIT](DEBUG): Deactivating GF circuits.
2020-01-26T05:23:08.237Z,1580016188.237 [CBIT](DEBUG): Deactivating emergency mode.
2020-01-26T05:23:08.273Z,1580016188.273 [CBIT](DEBUG): Backplane powered.
2020-01-26T05:23:08.273Z,1580016188.273 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-01-26T05:23:08.275Z,1580016188.275 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-01-26T05:23:08.276Z,1580016188.276 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-01-26T05:23:08.276Z,1580016188.276 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-01-26T05:23:08.277Z,1580016188.277 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-01-26T05:23:08.288Z,1580016188.288 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-26T05:23:08.306Z,1580016188.306 [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-26T05:23:08.307Z,1580016188.307 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-01-26T05:23:08.372Z,1580016188.372 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-01-26T05:23:08.374Z,1580016188.374 [Default:A.Wait](DEBUG): Construct Wait.
2020-01-26T05:23:08.375Z,1580016188.375 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-26T05:23:08.421Z,1580016188.421 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-01-26T05:23:08.424Z,1580016188.424 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-01-26T05:23:08.445Z,1580016188.445 [Default:E.Execute](DEBUG): Construct Execute.
2020-01-26T05:23:08.448Z,1580016188.448 [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-26T05:23:08.461Z,1580016188.461 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,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-26T05:23:08.473Z,1580016188.473 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-01-26T05:23:08.513Z,1580016188.513 [DDM](INFO): Powering up
2020-01-26T05:23:08.513Z,1580016188.513 [DDM](DEBUG): Initializing DDM.
2020-01-26T05:23:08.538Z,1580016188.538 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2020-01-26T05:23:08.538Z,1580016188.538 [DUSBL_Hydroid](INFO): Powering up
2020-01-26T05:23:08.539Z,1580016188.539 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-01-26T05:23:08.566Z,1580016188.566 [Radio_Surface](INFO): Powering up
2020-01-26T05:23:08.727Z,1580016188.727 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-01-26T05:23:08.750Z,1580016188.750 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-01-26T05:23:08.757Z,1580016188.757 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-01-26T05:23:08.758Z,1580016188.758 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-01-26T05:23:08.765Z,1580016188.765 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-01-26T05:23:08.766Z,1580016188.766 [MassServo](DEBUG): Initializing EZServoServo.
2020-01-26T05:23:08.773Z,1580016188.773 [MassServo](DEBUG): Initializing MassServo.
2020-01-26T05:23:08.774Z,1580016188.774 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-26T05:23:08.781Z,1580016188.781 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-26T05:23:08.782Z,1580016188.782 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-01-26T05:23:08.789Z,1580016188.789 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-01-26T05:23:08.000Z,1580016189.000 [Micromodem](INFO): Powering up
2020-01-26T05:23:09.000Z,1580016189.000 [Micromodem](DEBUG): Initializing Micromodem.
2020-01-26T05:23:09.657Z,1580016189.657 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-01-26T05:23:09.657Z,1580016189.657 [RudderServo](FAULT): Rudder failed to initialize
2020-01-26T05:23:09.657Z,1580016189.657 [RudderServo] Communications Fault, FailCount= 1
2020-01-26T05:23:09.657Z,1580016189.657 [RudderServo](ERROR): Communications Fault
2020-01-26T05:23:09.768Z,1580016189.768 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-01-26T05:23:09.964Z,1580016189.964 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-26T05:23:09.965Z,1580016189.965 [RudderServo](INFO): Powering down
2020-01-26T05:23:10.690Z,1580016190.690 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-26T05:23:10.810Z,1580016190.810 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-26T05:23:10.814Z,1580016190.814 [CBIT](INFO): Clearing failed state for component RudderServo
2020-01-26T05:23:10.814Z,1580016190.814 [RudderServo] No Fault, FailCount= 1
2020-01-26T05:23:13.855Z,1580016193.855 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2020-01-26T05:23:16.671Z,1580016196.671 [Micromodem](INFO): Nmea in: $CATMG,2020-01-26T05:23:15.484454Z,RTC,RTC*58

2020-01-26T05:23:16.672Z,1580016196.672 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-01-26T05:23:15.484454Z,RTC,RTC*58

2020-01-26T05:23:19.081Z,1580016199.081 [DDM](INFO): Dynamic Docking Module:
2020-01-26T05:23:21.932Z,1580016201.932 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2020-01-26T05:23:25.135Z,1580016205.135 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2020-01-26T05:23:25.944Z,1580016205.944 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2020-01-26T05:23:25.945Z,1580016205.945 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2020-01-26T05:23:26.347Z,1580016206.347 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2020-01-26T05:23:26.347Z,1580016206.347 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2020-01-26T05:23:26.750Z,1580016206.750 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-01-26T05:23:26.762Z,1580016206.762 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2020-01-26T05:23:26.762Z,1580016206.762 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2020-01-26T05:23:26.818Z,1580016206.818 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2020-01-26T05:23:27.155Z,1580016207.155 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2020-01-26T05:23:27.155Z,1580016207.155 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2020-01-26T05:23:27.559Z,1580016207.559 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2020-01-26T05:23:27.559Z,1580016207.559 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2020-01-26T05:23:27.963Z,1580016207.963 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2020-01-26T05:23:27.963Z,1580016207.963 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2020-01-26T05:23:28.367Z,1580016208.367 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2020-01-26T05:23:28.367Z,1580016208.367 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2020-01-26T05:23:28.771Z,1580016208.771 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2020-01-26T05:23:28.771Z,1580016208.771 [Micromodem](INFO): Nmea out: $CCCLK,2020,01,26,05,23,29*4E

2020-01-26T05:23:29.175Z,1580016209.175 [Micromodem](INFO): Nmea in: $CACLK,2020,1,26,5,23,29*4C

2020-01-26T05:23:29.584Z,1580016209.584 [Micromodem](INFO): Nmea in: $CATMS,0,2020-01-26T05:23:30Z*74

2020-01-26T05:23:29.983Z,1580016209.983 [Micromodem](INFO): Nmea in: $CATMG,2020-01-26T05:23:30.028463Z,USER_CMD,RTC*18

2020-01-26T05:23:34.427Z,1580016214.427 [NAL9602](INFO): Powering up NAL9602
2020-01-26T05:23:45.336Z,1580016225.336 [NAL9602](INFO): NAL9602 initialized
2020-01-26T05:23:47.824Z,1580016227.824 [SBIT](IMPORTANT): Beginning Startup BIT
2020-01-26T05:23:47.828Z,1580016227.828 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-26T05:23:57.306Z,1580016237.306 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-26T05:23:57.306Z,1580016237.306 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 354.44, 337.83, 359.43
2020-01-26T05:23:59.062Z,1580016239.062 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008890
CHAN A1 (24V): -0.027296
CHAN A2 (12V): -0.007309
CHAN A3 (5V): -0.002408
CHAN B0 (3.3V): 0.000240
CHAN B1 (3.15aV): -0.000169
CHAN B2 (3.15bV): 0.000175
CHAN B3 (GND): 0.001971
OPEN: 0.006528
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-26T05:24:10.401Z,1580016250.401 [NAL9602](INFO): SBD MO Status=0, MOMSN=10314, MT Status=0, MTMSN=0
2020-01-26T05:24:10.401Z,1580016250.401 [NAL9602](INFO): No messages in MT queue
2020-01-26T05:24:41.287Z,1580016281.287 [SBIT](IMPORTANT): SBIT PASSED
2020-01-26T05:24:41.287Z,1580016281.287 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-01-26T05:24:41.288Z,1580016281.288 [SBIT](IMPORTANT): DUSBL_Hydroid.detectionThreshold=75 count;

2020-01-26T05:24:41.288Z,1580016281.288 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2020-01-26T05:24:41.288Z,1580016281.288 [SBIT](IMPORTANT): Express none DDM.cablePresent;

2020-01-26T05:24:41.288Z,1580016281.288 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=105 cubic_centimeter;

2020-01-26T05:24:41.288Z,1580016281.288 [SBIT](IMPORTANT): VerticalControl.massDefault=0.5 centimeter;

2020-01-26T05:24:41.680Z,1580016281.680 [MissionManager](IMPORTANT): Started mission Startup
2020-01-26T05:24:41.680Z,1580016281.680 [Startup] Running Loop=1
2020-01-26T05:24:41.680Z,1580016281.680 [Startup](DEBUG): Aggregate::initialize Startup
2020-01-26T05:24:41.680Z,1580016281.680 [Startup:A.GoToSurface] Running Loop=1
2020-01-26T05:24:41.680Z,1580016281.680 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-26T05:24:41.681Z,1580016281.681 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-26T05:24:41.681Z,1580016281.681 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-26T05:24:41.682Z,1580016281.682 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-26T05:24:41.682Z,1580016281.682 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-26T05:24:41.682Z,1580016281.682 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-26T05:24:41.684Z,1580016281.684 [Startup:StartupSatComms] Running Loop=1
2020-01-26T05:24:41.684Z,1580016281.684 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-01-26T05:24:41.684Z,1580016281.684 [Startup:StartupSatComms:A] Running Loop=1
2020-01-26T05:24:42.108Z,1580016282.108 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-01-26T05:25:41.867Z,1580016341.867 [Startup:StartupSatComms:A](INFO): Timed out from 2020-01-26T05:24:41.7Z
2020-01-26T05:25:41.867Z,1580016341.867 [Startup:StartupSatComms:A] Stopped
2020-01-26T05:25:41.867Z,1580016341.867 [Startup:StartupSatComms:B] Running Loop=1
2020-01-26T05:25:42.292Z,1580016342.292 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-26T05:26:08.150Z,1580016368.150 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-01-26T05:26:08.150Z,1580016368.150 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-26T05:26:08.160Z,1580016368.160 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-26T05:26:08.550Z,1580016368.550 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-26T05:26:08.550Z,1580016368.550 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-01-26T05:26:42.103Z,1580016402.103 [Startup:StartupSatComms:B](INFO): Timed out from 2020-01-26T05:25:41.9Z
2020-01-26T05:26:42.104Z,1580016402.104 [Startup:StartupSatComms:B] Stopped
2020-01-26T05:26:42.104Z,1580016402.104 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-01-26T05:26:42.104Z,1580016402.104 [Startup:StartupSatComms] Stopped
2020-01-26T05:26:42.104Z,1580016402.104 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-01-26T05:26:42.104Z,1580016402.104 [Startup](INFO): Completed Startup
2020-01-26T05:26:42.109Z,1580016402.109 [MissionManager](INFO): Startup is completed.
2020-01-26T05:26:42.109Z,1580016402.109 [MissionManager](INFO): Uninitializing Mission Startup
2020-01-26T05:26:42.109Z,1580016402.109 [Startup] Stopped
2020-01-26T05:26:42.109Z,1580016402.109 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-01-26T05:26:42.109Z,1580016402.109 [Startup:A.GoToSurface] Stopped
2020-01-26T05:26:42.109Z,1580016402.109 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-26T05:26:42.490Z,1580016402.490 [MissionManager](IMPORTANT): Started mission Default
2020-01-26T05:26:42.490Z,1580016402.490 [Default] Running Loop=1
2020-01-26T05:26:42.491Z,1580016402.491 [Default](DEBUG): Aggregate::initialize Default
2020-01-26T05:26:42.491Z,1580016402.491 [Default:B.GoToSurface] Running Loop=1
2020-01-26T05:26:42.491Z,1580016402.491 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-26T05:26:42.491Z,1580016402.491 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-26T05:26:42.491Z,1580016402.491 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-26T05:26:42.492Z,1580016402.492 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-26T05:26:42.492Z,1580016402.492 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-26T05:26:42.492Z,1580016402.492 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-26T05:26:42.492Z,1580016402.492 [Default:A.Wait] Running Loop=1
2020-01-26T05:26:42.492Z,1580016402.492 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-01-26T05:26:47.859Z,1580016407.859 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004728
2020-01-26T05:26:55.806Z,1580016415.806 [Default:A.Wait](INFO): Done Waiting.
2020-01-26T05:26:55.806Z,1580016415.806 [Default:A.Wait] Stopped
2020-01-26T05:26:55.806Z,1580016415.806 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-26T05:26:56.225Z,1580016416.225 [Default:CheckIn] Running Loop=1
2020-01-26T05:26:56.225Z,1580016416.225 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-26T05:26:56.225Z,1580016416.225 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-26T05:26:56.628Z,1580016416.628 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-01-26T05:27:05.938Z,1580016425.938 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2020-01-26T05:27:05.939Z,1580016425.939 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,  -301, +BE,  -301,   +84,  +380,A
2020-01-26T05:27:34.679Z,1580016454.679 [CommandLine](IMPORTANT): got command failComponent
2020-01-26T05:27:34.680Z,1580016454.680 [CommandLine](IMPORTANT): Failed components:
2020-01-26T05:27:34.680Z,1580016454.680 [CommandLine](IMPORTANT): No failed Components.
2020-01-26T05:28:07.311Z,1580016487.311 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-26T05:28:07.311Z,1580016487.311 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 367.81, 337.81, 366.09
2020-01-26T05:29:09.179Z,1580016549.179 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-01-26T05:29:09.179Z,1580016549.179 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-26T05:29:09.217Z,1580016549.217 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-26T05:29:09.571Z,1580016549.571 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-26T05:29:09.571Z,1580016549.571 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-01-26T05:29:26.126Z,1580016566.126 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-26T05:29:26.127Z,1580016566.127 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012522422064,35.0, -0. 0.00
2020-01-26T05:29:32.565Z,1580016572.565 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,052921.00,A,3648.58874,N,12149.33706,W,0.739,3.73,260120,,,A*7D
2020-01-26T05:29:32.568Z,1580016572.568 [NAL9602](INFO): GPS fix at 20200126T052921: (36.809812, -121.822284)
2020-01-26T05:29:32.641Z,1580016572.641 [Default:CheckIn:Read_GPS] Stopped
2020-01-26T05:29:32.649Z,1580016572.649 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-26T05:29:33.033Z,1580016573.033 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-26T05:29:43.116Z,1580016583.116 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200126T050132/Courier0015.lzma
2020-01-26T05:29:45.124Z,1580016585.124 [DataOverHttps](INFO): Moved sent file to Logs/20200126T050132/Courier0015.lzma.bak
2020-01-26T05:29:45.124Z,1580016585.124 [DataOverHttps](INFO): SBD MOMSN=12204789
2020-01-26T05:30:03.028Z,1580016603.028 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200126T052257/Courier0000.lzma
2020-01-26T05:30:04.947Z,1580016604.947 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-26T05:30:05.034Z,1580016605.034 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Courier0000.lzma.bak
2020-01-26T05:30:05.035Z,1580016605.035 [DataOverHttps](INFO): SBD MOMSN=12204791
2020-01-26T05:30:19.739Z,1580016619.739 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-01-26T05:30:22.653Z,1580016622.653 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20200126T052257/Courier0004.lzma
2020-01-26T05:30:24.658Z,1580016624.658 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Courier0004.lzma.bak
2020-01-26T05:30:24.658Z,1580016624.658 [DataOverHttps](INFO): SBD MOMSN=12204794
2020-01-26T05:30:32.447Z,1580016632.447 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-01-26T05:30:32.450Z,1580016632.450 [BPC1](INFO): Received data from all battery sticks.
2020-01-26T05:30:42.581Z,1580016642.581 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20200126T050132/Express0016.lzma
2020-01-26T05:30:44.602Z,1580016644.602 [DataOverHttps](INFO): Moved sent file to Logs/20200126T050132/Express0016.lzma.bak
2020-01-26T05:30:44.603Z,1580016644.603 [DataOverHttps](INFO): SBD MOMSN=12204797
2020-01-26T05:31:01.958Z,1580016661.958 [DataOverHttps](INFO): Sending 728 bytes from file Logs/20200126T052257/Express0001.lzma
2020-01-26T05:31:03.959Z,1580016663.959 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Express0001.lzma.bak
2020-01-26T05:31:03.959Z,1580016663.959 [DataOverHttps](INFO): SBD MOMSN=12204801
2020-01-26T05:31:21.353Z,1580016681.353 [DataOverHttps](INFO): Sending 279 bytes from file Logs/20200126T052257/Express0005.lzma
2020-01-26T05:31:23.350Z,1580016683.350 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Express0005.lzma.bak
2020-01-26T05:31:23.350Z,1580016683.350 [DataOverHttps](INFO): SBD MOMSN=12204818
2020-01-26T05:31:24.565Z,1580016684.565 [Default:CheckIn:Read_Iridium] Stopped
2020-01-26T05:31:24.565Z,1580016684.565 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-26T05:31:24.565Z,1580016684.565 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-26T05:32:00.942Z,1580016720.942 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-26T05:32:00.942Z,1580016720.942 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 374.41, 327.83, 347.45
2020-01-26T05:33:59.310Z,1580016839.310 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-26T05:33:59.311Z,1580016839.311 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012522465, -0.1,   0.0,1448.9,  0
2020-01-26T05:36:25.149Z,1580016985.149 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-26T05:36:25.149Z,1580016985.149 [Default:CheckIn:C.Wait] Stopped
2020-01-26T05:36:25.149Z,1580016985.149 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-26T05:36:25.149Z,1580016985.149 [Default:CheckIn:D] Running Loop=1
2020-01-26T05:36:25.557Z,1580016985.557 [Default:CheckIn:D] Stopped
2020-01-26T05:36:25.557Z,1580016985.557 [Default:CheckIn:E] Running Loop=1
2020-01-26T05:36:25.974Z,1580016985.974 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.717778 min 
2020-01-26T05:36:25.975Z,1580016985.975 [Default:CheckIn:E] Stopped
2020-01-26T05:36:25.975Z,1580016985.975 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-26T05:36:25.975Z,1580016985.975 [Default:CheckIn] Stopped
2020-01-26T05:36:25.975Z,1580016985.975 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-26T05:36:25.975Z,1580016985.975 [Default:CheckIn](INFO): Running loop #2
2020-01-26T05:36:25.975Z,1580016985.975 [Default:CheckIn] Running Loop=2
2020-01-26T05:36:25.975Z,1580016985.975 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-26T05:36:25.975Z,1580016985.975 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-26T05:36:27.948Z,1580016987.948 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,053617.00,A,3648.59239,N,12149.35907,W,0.680,251.63,260120,,,D*7F
2020-01-26T05:36:27.954Z,1580016987.954 [NAL9602](INFO): GPS fix at 20200126T053617: (36.809873, -121.822651)
2020-01-26T05:36:28.009Z,1580016988.009 [Default:CheckIn:Read_GPS] Stopped
2020-01-26T05:36:28.009Z,1580016988.009 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-26T05:36:38.409Z,1580016998.409 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20200126T052257/Courier0007.lzma
2020-01-26T05:36:40.415Z,1580017000.415 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Courier0007.lzma.bak
2020-01-26T05:36:40.415Z,1580017000.415 [DataOverHttps](INFO): SBD MOMSN=12204824
2020-01-26T05:36:58.000Z,1580017018.000 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200126T052257/Express0008.lzma
2020-01-26T05:37:00.006Z,1580017020.006 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Express0008.lzma.bak
2020-01-26T05:37:00.007Z,1580017020.007 [DataOverHttps](INFO): SBD MOMSN=12204827
2020-01-26T05:37:01.564Z,1580017021.564 [Default:CheckIn:Read_Iridium] Stopped
2020-01-26T05:37:01.564Z,1580017021.564 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-26T05:37:01.564Z,1580017021.564 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-26T05:37:28.596Z,1580017048.596 [NAL9602](INFO): SBD MO Status=2, MOMSN=10315, MT Status=2, MTMSN=0
2020-01-26T05:37:28.596Z,1580017048.596 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-26T05:37:38.292Z,1580017058.292 [NAL9602](INFO): SBD MO Status=0, MOMSN=10315, MT Status=0, MTMSN=0
2020-01-26T05:37:38.292Z,1580017058.292 [NAL9602](INFO): No messages in MT queue
2020-01-26T05:38:08.994Z,1580017088.994 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-26T05:38:17.956Z,1580017097.956 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-26T05:38:17.961Z,1580017097.961 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,  -78,  +373,A
2020-01-26T05:39:18.932Z,1580017158.932 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-01-26T05:39:18.933Z,1580017158.933 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,       -4.22,      -85.49,    ,  36.36,  0.00
2020-01-26T05:40:02.973Z,1580017202.973 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-26T05:40:02.973Z,1580017202.973 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012522525864,35.0, -0.1,   0.0,144

2020-01-26T05:42:02.140Z,1580017322.140 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-26T05:42:02.140Z,1580017322.140 [Default:CheckIn:C.Wait] Stopped
2020-01-26T05:42:02.141Z,1580017322.141 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-26T05:42:02.141Z,1580017322.141 [Default:CheckIn:D] Running Loop=1
2020-01-26T05:42:02.549Z,1580017322.549 [Default:CheckIn:D] Stopped
2020-01-26T05:42:02.549Z,1580017322.549 [Default:CheckIn:E] Running Loop=1
2020-01-26T05:42:02.970Z,1580017322.970 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.334311 min 
2020-01-26T05:42:02.970Z,1580017322.970 [Default:CheckIn:E] Stopped
2020-01-26T05:42:02.970Z,1580017322.970 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-26T05:42:02.970Z,1580017322.970 [Default:CheckIn] Stopped
2020-01-26T05:42:02.970Z,1580017322.970 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-26T05:42:02.970Z,1580017322.970 [Default:CheckIn](INFO): Running loop #3
2020-01-26T05:42:02.970Z,1580017322.970 [Default:CheckIn] Running Loop=3
2020-01-26T05:42:02.970Z,1580017322.970 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-26T05:42:02.971Z,1580017322.971 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-26T05:42:04.940Z,1580017324.940 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,054154.00,A,3648.59961,N,12149.37576,W,0.272,263.74,260120,,,D*78
2020-01-26T05:42:04.943Z,1580017324.943 [NAL9602](INFO): GPS fix at 20200126T054154: (36.809993, -121.822929)
2020-01-26T05:42:04.997Z,1580017324.997 [Default:CheckIn:Read_GPS] Stopped
2020-01-26T05:42:04.998Z,1580017324.998 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-26T05:42:12.860Z,1580017332.860 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200126T052257/Courier0010.lzma
2020-01-26T05:42:14.869Z,1580017334.869 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Courier0010.lzma.bak
2020-01-26T05:42:14.869Z,1580017334.869 [DataOverHttps](INFO): SBD MOMSN=12204832
2020-01-26T05:42:20.336Z,1580017340.336 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-26T05:42:20.337Z,1580017340.337 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,200125225515 -0.1,   0.0,1448.9,  0
2020-01-26T05:42:26.356Z,1580017346.356 [NAL9602](INFO): SBD MO Status=0, MOMSN=10316, MT Status=0, MTMSN=0
2020-01-26T05:42:26.356Z,1580017346.356 [NAL9602](INFO): No messages in MT queue
2020-01-26T05:42:32.429Z,1580017352.429 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200126T052257/Express0011.lzma
2020-01-26T05:42:34.437Z,1580017354.437 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Express0011.lzma.bak
2020-01-26T05:42:34.437Z,1580017354.437 [DataOverHttps](INFO): SBD MOMSN=12204835
2020-01-26T05:42:36.109Z,1580017356.109 [Default:CheckIn:Read_Iridium] Stopped
2020-01-26T05:42:36.112Z,1580017356.112 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-26T05:42:36.112Z,1580017356.112 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-26T05:42:57.049Z,1580017377.049 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-26T05:45:00.307Z,1580017500.307 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-26T05:45:00.307Z,1580017500.307 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012522575, -0.1,   0.0,1448.9,  0
2020-01-26T05:45:17.393Z,1580017517.393 [CommandLine](IMPORTANT): got command load ./Missions/underIce/DefaultUnder.xml
2020-01-26T05:45:17.393Z,1580017517.393 [MissionManager](INFO): Loading Mission: ./Missions/underIce/DefaultUnder.xml
2020-01-26T05:45:17.499Z,1580017517.499 [MissionManager](INFO): DefineArg DefaultUnder.uModemCommsInterval = 10.000000 min
2020-01-26T05:45:17.519Z,1580017517.519 [MissionManager](INFO): DefineArg DefaultUnder.TransponderCode = 2.000000 count
2020-01-26T05:45:17.523Z,1580017517.523 [MissionManager](INFO): DefineArg DefaultUnder.AcousticUpdatePeriod = 60.000000 s
2020-01-26T05:45:17.526Z,1580017517.526 [MissionManager](INFO): DefineArg DefaultUnder.DockingAcousticUpdatePeriod = 2.500000 s
2020-01-26T05:45:17.529Z,1580017517.529 [MissionManager](INFO): DefineArg DefaultUnder.NumberOfPings = 1.000000 count
2020-01-26T05:45:17.533Z,1580017517.533 [MissionManager](INFO): DefineOutput DefaultUnder.TrackingUpdatePeriod = 60.000000 n/a
2020-01-26T05:45:17.536Z,1580017517.536 [MissionManager](INFO): DefineOutput DefaultUnder.Surface = -1.000000 count
2020-01-26T05:45:17.539Z,1580017517.539 [MissionManager](INFO): DefineOutput DefaultUnder.Docked = 0.000000 count
2020-01-26T05:45:17.543Z,1580017517.543 [MissionManager](INFO): DefineOutput DefaultUnder.Home = 1.000000 count
2020-01-26T05:45:17.546Z,1580017517.546 [MissionManager](INFO): DefineOutput DefaultUnder.DefaultMode = 0.000000 n/a
2020-01-26T05:45:17.550Z,1580017517.550 [MissionManager](INFO): DefineOutput DefaultUnder.CaptureMode = -1.000000 count
2020-01-26T05:45:17.601Z,1580017517.601 [MissionManager](INFO): DefineOutput DefaultUnder.ElapsedSinceDefaultStarted = 0.000000 min
2020-01-26T05:45:17.608Z,1580017517.608 [DefaultUnder:Notify:A:A:A.Wait](DEBUG): Construct Wait.
2020-01-26T05:45:17.677Z,1580017517.677 [DefaultUnder:Notify:A:C.Execute](DEBUG): Construct Execute.
2020-01-26T05:45:17.930Z,1580017517.930 [MissionManager](INFO): Inserting Stack: Missions/Insert/LineCapture.xml
2020-01-26T05:45:18.359Z,1580017518.359 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockDepth = 15.000000 _
2020-01-26T05:45:18.363Z,1580017518.363 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockLat = 0.642456 _
2020-01-26T05:45:18.367Z,1580017518.367 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockLon = -2.126000 _
2020-01-26T05:45:18.371Z,1580017518.371 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DetachRange = 8.000000 m
2020-01-26T05:45:18.374Z,1580017518.374 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DetachTimeout = 30.000000 min
2020-01-26T05:45:18.378Z,1580017518.378 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MidcourseDepth = 15.000000 m
2020-01-26T05:45:18.381Z,1580017518.381 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MidcourseSpeed = 1.000000 m/s
2020-01-26T05:45:18.384Z,1580017518.384 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MidcourseTimeout = 1.000000 h
2020-01-26T05:45:18.388Z,1580017518.388 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.TerminalRange = 650.000000 m
2020-01-26T05:45:18.391Z,1580017518.391 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.ArmRange = 40.000000 m
2020-01-26T05:45:18.395Z,1580017518.395 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockRange = 2.000000 m
2020-01-26T05:45:18.422Z,1580017518.422 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockTimeout = 60.000000 s
2020-01-26T05:45:18.427Z,1580017518.427 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.RolloutDistance = 250.000000 m
2020-01-26T05:45:18.492Z,1580017518.492 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.AcousticTimeout = 10.000000 min
2020-01-26T05:45:18.508Z,1580017518.508 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.TerminalSpeed = 0.800000 m/s
2020-01-26T05:45:18.528Z,1580017518.528 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.KpHeading = 0.800000 n/a
2020-01-26T05:45:18.542Z,1580017518.542 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.KiHeading = 0.002000 1/s
2020-01-26T05:45:18.558Z,1580017518.558 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.KpHeadingFinal = 1.600000 n/a
2020-01-26T05:45:18.563Z,1580017518.563 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.KiHeadingFinal = 0.004000 1/s
2020-01-26T05:45:18.582Z,1580017518.582 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.SearchTimeout = 1.000000 min
2020-01-26T05:45:18.590Z,1580017518.590 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.CircleRadius = 300.000000 m
2020-01-26T05:45:18.594Z,1580017518.594 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.CircleMaxError = 100.000000 m
2020-01-26T05:45:18.597Z,1580017518.597 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.CircleTurnToPort = 0 bool
2020-01-26T05:45:18.600Z,1580017518.600 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DepthDeadband = 0.010000 m
2020-01-26T05:45:18.630Z,1580017518.630 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.RudderDeadband = 0.001000 arcdeg
2020-01-26T05:45:18.633Z,1580017518.633 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MinAltitude = 5.000000 m
2020-01-26T05:45:18.636Z,1580017518.636 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MaxDepth = 205.000000 m
2020-01-26T05:45:18.675Z,1580017518.675 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MinOffshore = 500.000000 m
2020-01-26T05:45:18.679Z,1580017518.679 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Depth = 15.000000 n/a
2020-01-26T05:45:18.699Z,1580017518.699 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Speed = 1.000000 n/a
2020-01-26T05:45:18.702Z,1580017518.702 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.DoneTimeout = -1.000000 count
2020-01-26T05:45:18.706Z,1580017518.706 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Done = 0.000000 count
2020-01-26T05:45:18.741Z,1580017518.741 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.DetachFromDock = 1.000000 count
2020-01-26T05:45:18.744Z,1580017518.744 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Midcourse = 2.000000 count
2020-01-26T05:45:18.748Z,1580017518.748 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Terminal = 3.000000 count
2020-01-26T05:45:18.768Z,1580017518.768 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.GuidanceMode = 1.000000 n/a
2020-01-26T05:45:18.772Z,1580017518.772 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.ElapsedRange = 0.000000 min
2020-01-26T05:45:18.775Z,1580017518.775 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.Range = nan m
2020-01-26T05:45:18.793Z,1580017518.793 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2020-01-26T05:45:18.815Z,1580017518.815 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture:StandardEnvelopes.MinAltitude = 5.000000 m
2020-01-26T05:45:18.818Z,1580017518.818 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture:StandardEnvelopes.MaxDepth = 200.000000 m
2020-01-26T05:45:18.894Z,1580017518.894 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture:StandardEnvelopes.MinOffshore = 2000.000000 m
2020-01-26T05:45:18.905Z,1580017518.905 [DefaultUnder:LineCapture:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2020-01-26T05:45:18.938Z,1580017518.938 [DefaultUnder:LineCapture:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2020-01-26T05:45:18.953Z,1580017518.953 [DefaultUnder:LineCapture:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2020-01-26T05:45:19.006Z,1580017519.006 [DefaultUnder:LineCapture:H.Mass](DEBUG): Construct.
2020-01-26T05:45:19.019Z,1580017519.019 [DefaultUnder:LineCapture:DiveCmd:Guided:dive:B.Buoyancy](DEBUG): Construct Buoyancy.
2020-01-26T05:45:19.038Z,1580017519.038 [DefaultUnder:LineCapture:DiveCmd:Guided:dive:C.SetSpeed](DEBUG): Construct.
2020-01-26T05:45:19.045Z,1580017519.045 [DefaultUnder:LineCapture:DiveCmd:Guided:dive:D.Pitch](DEBUG): Construct.
2020-01-26T05:45:19.076Z,1580017519.076 [DefaultUnder:LineCapture:DiveCmd:DriftAwayFromDock:dive:A.SetSpeed](DEBUG): Construct.
2020-01-26T05:45:19.088Z,1580017519.088 [DefaultUnder:LineCapture:DiveCmd:DriftAwayFromDock:dive:B.Pitch](DEBUG): Construct.
2020-01-26T05:45:19.125Z,1580017519.125 [DefaultUnder:LineCapture:HomingSequence:DetachFromDock:guide:A.Undock](DEBUG): Construct.
2020-01-26T05:45:19.181Z,1580017519.181 [DefaultUnder:LineCapture:HomingSequence:MidcourseGuidance:guide:E.Waypoint](DEBUG): Construct Waypoint.
2020-01-26T05:45:19.210Z,1580017519.210 [DefaultUnder:LineCapture:HomingSequence:MidcourseGuidance:guide:G.Circle](DEBUG): Construct.
2020-01-26T05:45:19.345Z,1580017519.345 [DefaultUnder:LineCapture:HomingSequence:TerminalGuidance:guide:G.LineCapture](DEBUG): Construct.
2020-01-26T05:45:19.383Z,1580017519.383 [DefaultUnder:LineCapture:K.Wait](DEBUG): Construct Wait.
2020-01-26T05:45:19.401Z,1580017519.401 [MissionManager](INFO): Inserting Stack: Missions/Insert/SetNavAcoustic.xml
2020-01-26T05:45:19.466Z,1580017519.466 [MissionManager](INFO): DefineArg DefaultUnder:SetNavAcoustic.DockLat = 0.642456 _
2020-01-26T05:45:19.502Z,1580017519.502 [MissionManager](INFO): DefineArg DefaultUnder:SetNavAcoustic.DockLon = -2.126000 _
2020-01-26T05:45:19.505Z,1580017519.505 [MissionManager](INFO): DefineArg DefaultUnder:SetNavAcoustic.DockRange = 2.000000 m
2020-01-26T05:45:19.513Z,1580017519.513 [MissionManager](INFO): DefineArg DefaultUnder:SetNavAcoustic.RangeTimeout = 5.000000 min
2020-01-26T05:45:19.532Z,1580017519.532 [DefaultUnder:SetNavAcoustic:UpdateNav:B.SetNav](DEBUG): Construct SetNav.
2020-01-26T05:45:19.536Z,1580017519.536 [DefaultUnder:F.Wait](DEBUG): Construct Wait.
2020-01-26T05:45:19.562Z,1580017519.562 [DefaultUnder:Default:Docked:run:B.Docked](DEBUG): Construct.
2020-01-26T05:45:19.643Z,1580017519.643 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-26T05:45:19.728Z,1580017519.728 [DefaultUnder:Default:Surface:run:SurfaceComms:Read_Iridium_uModem:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-01-26T05:45:19.744Z,1580017519.744 [DefaultUnder:Default:Surface:run:SurfaceComms:C.Wait](DEBUG): Construct Wait.
2020-01-26T05:45:19.805Z,1580017519.805 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xmlns="Tethys"
    xmlns:Estimation="Tethys/Estimation"
    xmlns:Guidance="Tethys/Guidance"
    xmlns:Units="Tethys/Units"
    xmlns:Universal="Tethys/Universal"
    xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                        Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.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="DefaultUnder">

    <DefineArg Name="uModemCommsInterval"><Description>
        How often to trigger uModem communications
    </Description><Units:minute/><Value>10</Value></DefineArg>

    <DefineArg Name="TransponderCode"><Description>
        Dock transponder Address.
    </Description><Units:count/><Value>2</Value></DefineArg>

    <DefineArg Name="AcousticUpdatePeriod"><Description>
        How long to wait between acoustic queries while the mission
        is in an idle state (on the dock or surface).
    </Description><Units:second/><Value>60</Value></DefineArg>

    <DefineArg Name="DockingAcousticUpdatePeriod"><Description>
        How long to wait between acoustic queries while the mission
        is actively docking (line capture)
    </Description><Units:second/><Value>2.5</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <!-- Mission Variables (don't change!) -->

    <DefineOutput Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries.
    </Description><Arg Name="AcousticUpdatePeriod"/></DefineOutput>

    <DefineOutput Name="Surface"><Description>
        Mission variable (don't change).
        The mission will run in this mode to go to the surface after homing attempts have failed.
    </Description><Units:count/><Value>-1</Value></DefineOutput>

    <DefineOutput Name="Docked"><Description>
        Mission variable (don't change).
        The mission will run in this mode when the vehicle is docked.
    </Description><Units:count/><Value>0</Value></DefineOutput>

    <DefineOutput Name="Home"><Description>
        Mission variable (don't change).
        The mission will run in this mode when homing to the dock.
    </Description><Units:count/><Value>1</Value></DefineOutput>

    <DefineOutput Name="DefaultMode"><Description>
        Mission variable (don't change).
        The mission sets this variable to switch between default modes.
    </Description><Arg Name="Docked"/></DefineOutput>

    <DefineOutput Name="CaptureMode"><Description>
        Mission variable (don't change).
        The mission sets this variable to reflect the termination status of the LineCapture insert.
    </Description><Units:count/><Value>-1</Value></DefineOutput>

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



    <!-- TODO: Safety nets and surfacing behaviors? -->

    <!-- Communication directives -->

    <Aggregate Id="uModemComms">
        <While>
            <Arg Name="DefaultMode"/><Eq><Arg Name="Docked"/></Eq>
        </While>

        <Aggregate Id="CheckIn">

            <When>
                <Elapsed><Universal:platform_communications/></Elapsed>
                <Gt><Arg Name="uModemCommsInterval"/></Gt>
            </When>

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

        </Aggregate>
    </Aggregate>

    <!-- Notify directives. -->

    <Aggregate Id="Notify">
        <Parallel/>

        <Aggregate>
            <Sequence/>

            <Aggregate>
                <Sequence Repeat="288"/>

                <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.</Syslog>

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

   <!-- Add track acoustic contact directives. -->

    <Estimation:TrackAcousticContact>
        <Parallel/>
        <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
        <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:TrackAcousticContact>

    <!-- Add LineCapture directives. -->

    <Insert Filename="Insert/LineCapture.xml"/>

    <!-- Add SetNav directives. -->

    <Insert Filename="Insert/SetNavAcoustic.xml"/>

    <!-- Default mission sequence. -->

    <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>

    <Aggregate Id="Default">

        <Sequence/>

        <Aggregate Id="Docked">

            <While>
                <Arg Name="DefaultMode"/><Eq><Arg Name="Docked"/></Eq>
            </While>

            <Aggregate Id="run">
                <Sequence/>

                <Assign><Sequence/><Arg Name="TrackingUpdatePeriod"/><Arg Name="AcousticUpdatePeriod"/></Assign>

                <Guidance:Docked>
                    <Sequence/>
                </Guidance:Docked>

                <Assign><Sequence/><Arg Name="DefaultMode"/><Arg Name="Home"/></Assign>

            </Aggregate>
        </Aggregate>


        <Aggregate Id="Home">

            <While>
                <Arg Name="DefaultMode"/><Eq><Arg Name="Home"/></Eq>
            </While>

            <Aggregate Id="run">
                <Sequence/>

                <Assign><Sequence/><Arg Name="TrackingUpdatePeriod"/><Arg Name="DockingAcousticUpdatePeriod"/></Assign>

                <Assign><Sequence/><Arg Name="CaptureMode"/><Arg Name="Surface"/></Assign>

                <Call RefId="LineCapture"/>

                <Assign><Sequence/><Arg Name="CaptureMode"/><Arg Name="LineCapture:GuidanceMode"/></Assign>

                <Aggregate Id="CheckCaptureSuccess">
                    <Sequence/>

                    <Break>
                        <Not><Arg Name="CaptureMode"/><Eq><Arg Name="Docked"/></Eq></Not>
                    </Break>

                    <Assign><Sequence/><Arg Name="DefaultMode"/><Arg Name="Docked"/></Assign>
                </Aggregate>

                <Assign><Sequence/><Arg Name="DefaultMode"/><Arg Name="Surface"/></Assign>

            </Aggregate>
        </Aggregate>


        <Aggregate Id="Surface">

            <While>
                <Arg Name="DefaultMode"/><Eq><Arg Name="Surface"/></Eq>
            </While>

            <Aggregate Id="run">
                <Sequence/>

                <Assign><Sequence/><Arg Name="TrackingUpdatePeriod"/><Arg Name="AcousticUpdatePeriod"/></Assign>

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

                <Aggregate Id="SurfaceComms">

                    <Sequence Repeat="288"/>

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

                    <ReadDatum Id="Read_Iridium_uModem">
                        <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>

                </Aggregate>
            </Aggregate>

        </Aggregate>

    </Aggregate>

</Mission>


2020-01-26T05:45:19.805Z,1580017519.805 [CommandLine](IMPORTANT): Loaded ./Missions/underIce/DefaultUnder.xml
2020-01-26T05:45:26.061Z,1580017526.061 [CommandLine](INFO): End of History
2020-01-26T05:45:26.066Z,1580017526.066 [CommandLine](INFO): End of History
2020-01-26T05:45:26.070Z,1580017526.070 [CommandLine](INFO): End of History
2020-01-26T05:45:26.074Z,1580017526.074 [CommandLine](INFO): End of History
2020-01-26T05:45:26.141Z,1580017526.141 [CommandLine](INFO): End of History
2020-01-26T05:45:26.142Z,1580017526.142 [CommandLine](INFO): End of History
2020-01-26T05:45:26.143Z,1580017526.143 [CommandLine](INFO): End of History
2020-01-26T05:45:26.143Z,1580017526.143 [CommandLine](INFO): End of History
2020-01-26T05:45:26.144Z,1580017526.144 [CommandLine](INFO): End of History
2020-01-26T05:45:26.145Z,1580017526.145 [CommandLine](INFO): End of History
2020-01-26T05:45:26.166Z,1580017526.166 [CommandLine](INFO): End of History
2020-01-26T05:45:26.166Z,1580017526.166 [CommandLine](INFO): End of History
2020-01-26T05:45:26.167Z,1580017526.167 [CommandLine](INFO): End of History
2020-01-26T05:45:26.168Z,1580017526.168 [CommandLine](INFO): End of History
2020-01-26T05:45:26.168Z,1580017526.168 [CommandLine](INFO): End of History
2020-01-26T05:45:26.182Z,1580017526.182 [CommandLine](INFO): End of History
2020-01-26T05:45:26.183Z,1580017526.183 [CommandLine](INFO): End of History
2020-01-26T05:45:26.184Z,1580017526.184 [CommandLine](INFO): End of History
2020-01-26T05:45:26.184Z,1580017526.184 [CommandLine](INFO): End of History
2020-01-26T05:45:26.206Z,1580017526.206 [CommandLine](INFO): End of History
2020-01-26T05:45:26.206Z,1580017526.206 [CommandLine](INFO): End of History
2020-01-26T05:45:26.207Z,1580017526.207 [CommandLine](INFO): End of History
2020-01-26T05:45:26.346Z,1580017526.346 [CommandLine](INFO): End of History
2020-01-26T05:45:26.346Z,1580017526.346 [CommandLine](INFO): End of History
2020-01-26T05:45:26.347Z,1580017526.347 [CommandLine](INFO): End of History
2020-01-26T05:45:26.348Z,1580017526.348 [CommandLine](INFO): End of History
2020-01-26T05:45:26.348Z,1580017526.348 [CommandLine](INFO): End of History
2020-01-26T05:45:26.349Z,1580017526.349 [CommandLine](INFO): End of History
2020-01-26T05:45:26.435Z,1580017526.435 [CommandLine](INFO): End of History
2020-01-26T05:45:26.447Z,1580017526.447 [CommandLine](INFO): End of History
2020-01-26T05:45:26.448Z,1580017526.448 [CommandLine](INFO): End of History
2020-01-26T05:45:26.449Z,1580017526.449 [CommandLine](INFO): End of History
2020-01-26T05:45:26.449Z,1580017526.449 [CommandLine](INFO): End of History
2020-01-26T05:45:26.450Z,1580017526.450 [CommandLine](INFO): End of History
2020-01-26T05:45:26.451Z,1580017526.451 [CommandLine](INFO): End of History
2020-01-26T05:45:26.595Z,1580017526.595 [CommandLine](INFO): End of History
2020-01-26T05:45:26.596Z,1580017526.596 [CommandLine](INFO): End of History
2020-01-26T05:45:26.596Z,1580017526.596 [CommandLine](INFO): End of History
2020-01-26T05:45:26.597Z,1580017526.597 [CommandLine](INFO): End of History
2020-01-26T05:45:26.598Z,1580017526.598 [CommandLine](INFO): End of History
2020-01-26T05:45:26.599Z,1580017526.599 [CommandLine](INFO): End of History
2020-01-26T05:45:26.692Z,1580017526.692 [CommandLine](INFO): End of History
2020-01-26T05:45:26.927Z,1580017526.927 [CommandLine](INFO): End of History
2020-01-26T05:45:26.928Z,1580017526.928 [CommandLine](INFO): End of History
2020-01-26T05:45:26.928Z,1580017526.928 [CommandLine](INFO): End of History
2020-01-26T05:45:34.357Z,1580017534.357 [CommandLine](INFO): End of History
2020-01-26T05:45:34.953Z,1580017534.953 [CommandLine](INFO): End of History
2020-01-26T05:45:35.512Z,1580017535.512 [CommandLine](INFO): End of History
2020-01-26T05:45:50.040Z,1580017550.040 [CommandLine](IMPORTANT): got command load ./Missions/underIce/DefaultUnder.xml
2020-01-26T05:45:50.041Z,1580017550.041 [MissionManager](INFO): Uninitializing Mission DefaultUnder
2020-01-26T05:45:50.092Z,1580017550.092 [MissionManager](INFO): Loading Mission: ./Missions/underIce/DefaultUnder.xml
2020-01-26T05:45:50.255Z,1580017550.255 [MissionManager](INFO): DefineArg DefaultUnder.uModemCommsInterval = 10.000000 min
2020-01-26T05:45:50.257Z,1580017550.257 [MissionManager](INFO): DefineArg DefaultUnder.TransponderCode = 2.000000 count
2020-01-26T05:45:50.259Z,1580017550.259 [MissionManager](INFO): DefineArg DefaultUnder.AcousticUpdatePeriod = 60.000000 s
2020-01-26T05:45:50.261Z,1580017550.261 [MissionManager](INFO): DefineArg DefaultUnder.DockingAcousticUpdatePeriod = 2.500000 s
2020-01-26T05:45:50.263Z,1580017550.263 [MissionManager](INFO): DefineArg DefaultUnder.NumberOfPings = 1.000000 count
2020-01-26T05:45:50.265Z,1580017550.265 [MissionManager](INFO): DefineOutput DefaultUnder.TrackingUpdatePeriod = 60.000000 n/a
2020-01-26T05:45:50.267Z,1580017550.267 [MissionManager](INFO): DefineOutput DefaultUnder.Surface = -1.000000 count
2020-01-26T05:45:50.269Z,1580017550.269 [MissionManager](INFO): DefineOutput DefaultUnder.Docked = 0.000000 count
2020-01-26T05:45:50.271Z,1580017550.271 [MissionManager](INFO): DefineOutput DefaultUnder.Home = 1.000000 count
2020-01-26T05:45:50.274Z,1580017550.274 [MissionManager](INFO): DefineOutput DefaultUnder.DefaultMode = 0.000000 n/a
2020-01-26T05:45:50.276Z,1580017550.276 [MissionManager](INFO): DefineOutput DefaultUnder.CaptureMode = -1.000000 count
2020-01-26T05:45:50.278Z,1580017550.278 [MissionManager](INFO): DefineOutput DefaultUnder.ElapsedSinceDefaultStarted = 0.000000 min
2020-01-26T05:45:50.284Z,1580017550.284 [DefaultUnder:Notify:A:A:A.Wait](DEBUG): Construct Wait.
2020-01-26T05:45:50.340Z,1580017550.340 [DefaultUnder:Notify:A:C.Execute](DEBUG): Construct Execute.
2020-01-26T05:45:50.398Z,1580017550.398 [MissionManager](INFO): Inserting Stack: Missions/Insert/LineCapture.xml
2020-01-26T05:45:50.712Z,1580017550.712 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockDepth = 15.000000 _
2020-01-26T05:45:50.714Z,1580017550.714 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockLat = 0.642456 _
2020-01-26T05:45:50.716Z,1580017550.716 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockLon = -2.126000 _
2020-01-26T05:45:50.718Z,1580017550.718 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DetachRange = 8.000000 m
2020-01-26T05:45:50.720Z,1580017550.720 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DetachTimeout = 30.000000 min
2020-01-26T05:45:50.723Z,1580017550.723 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MidcourseDepth = 15.000000 m
2020-01-26T05:45:50.725Z,1580017550.725 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MidcourseSpeed = 1.000000 m/s
2020-01-26T05:45:50.727Z,1580017550.727 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MidcourseTimeout = 1.000000 h
2020-01-26T05:45:50.729Z,1580017550.729 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.TerminalRange = 650.000000 m
2020-01-26T05:45:50.731Z,1580017550.731 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.ArmRange = 40.000000 m
2020-01-26T05:45:50.733Z,1580017550.733 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockRange = 2.000000 m
2020-01-26T05:45:50.735Z,1580017550.735 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockTimeout = 60.000000 s
2020-01-26T05:45:50.737Z,1580017550.737 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.RolloutDistance = 250.000000 m
2020-01-26T05:45:50.739Z,1580017550.739 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.AcousticTimeout = 10.000000 min
2020-01-26T05:45:50.741Z,1580017550.741 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.TerminalSpeed = 0.800000 m/s
2020-01-26T05:45:50.743Z,1580017550.743 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.KpHeading = 0.800000 n/a
2020-01-26T05:45:50.746Z,1580017550.746 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.KiHeading = 0.002000 1/s
2020-01-26T05:45:50.747Z,1580017550.747 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.KpHeadingFinal = 1.600000 n/a
2020-01-26T05:45:50.750Z,1580017550.750 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.KiHeadingFinal = 0.004000 1/s
2020-01-26T05:45:50.752Z,1580017550.752 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.SearchTimeout = 1.000000 min
2020-01-26T05:45:50.850Z,1580017550.850 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.CircleRadius = 300.000000 m
2020-01-26T05:45:50.852Z,1580017550.852 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.CircleMaxError = 100.000000 m
2020-01-26T05:45:50.858Z,1580017550.858 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.CircleTurnToPort = 0 bool
2020-01-26T05:45:50.860Z,1580017550.860 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DepthDeadband = 0.010000 m
2020-01-26T05:45:50.874Z,1580017550.874 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.RudderDeadband = 0.001000 arcdeg
2020-01-26T05:45:50.876Z,1580017550.876 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MinAltitude = 5.000000 m
2020-01-26T05:45:50.906Z,1580017550.906 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MaxDepth = 205.000000 m
2020-01-26T05:45:50.926Z,1580017550.926 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MinOffshore = 500.000000 m
2020-01-26T05:45:50.928Z,1580017550.928 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Depth = 15.000000 n/a
2020-01-26T05:45:50.943Z,1580017550.943 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Speed = 1.000000 n/a
2020-01-26T05:45:50.956Z,1580017550.956 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.DoneTimeout = -1.000000 count
2020-01-26T05:45:50.958Z,1580017550.958 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Done = 0.000000 count
2020-01-26T05:45:50.960Z,1580017550.960 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.DetachFromDock = 1.000000 count
2020-01-26T05:45:50.972Z,1580017550.972 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Midcourse = 2.000000 count
2020-01-26T05:45:50.979Z,1580017550.979 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Terminal = 3.000000 count
2020-01-26T05:45:50.991Z,1580017550.991 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.GuidanceMode = 1.000000 n/a
2020-01-26T05:45:51.003Z,1580017551.003 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.ElapsedRange = 0.000000 min
2020-01-26T05:45:51.007Z,1580017551.007 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.Range = nan m
2020-01-26T05:45:51.020Z,1580017551.020 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2020-01-26T05:45:51.085Z,1580017551.085 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture:StandardEnvelopes.MinAltitude = 5.000000 m
2020-01-26T05:45:51.087Z,1580017551.087 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture:StandardEnvelopes.MaxDepth = 200.000000 m
2020-01-26T05:45:51.096Z,1580017551.096 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture:StandardEnvelopes.MinOffshore = 2000.000000 m
2020-01-26T05:45:51.096Z,1580017551.096 [DefaultUnder:LineCapture:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2020-01-26T05:45:51.118Z,1580017551.118 [DefaultUnder:LineCapture:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2020-01-26T05:45:51.128Z,1580017551.128 [DefaultUnder:LineCapture:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2020-01-26T05:45:51.213Z,1580017551.213 [DefaultUnder:LineCapture:H.Mass](DEBUG): Construct.
2020-01-26T05:45:51.228Z,1580017551.228 [DefaultUnder:LineCapture:DiveCmd:Guided:dive:B.Buoyancy](DEBUG): Construct Buoyancy.
2020-01-26T05:45:51.234Z,1580017551.234 [DefaultUnder:LineCapture:DiveCmd:Guided:dive:C.SetSpeed](DEBUG): Construct.
2020-01-26T05:45:51.237Z,1580017551.237 [DefaultUnder:LineCapture:DiveCmd:Guided:dive:D.Pitch](DEBUG): Construct.
2020-01-26T05:45:51.283Z,1580017551.283 [DefaultUnder:LineCapture:DiveCmd:DriftAwayFromDock:dive:A.SetSpeed](DEBUG): Construct.
2020-01-26T05:45:51.298Z,1580017551.298 [DefaultUnder:LineCapture:DiveCmd:DriftAwayFromDock:dive:B.Pitch](DEBUG): Construct.
2020-01-26T05:45:51.332Z,1580017551.332 [DefaultUnder:LineCapture:HomingSequence:DetachFromDock:guide:A.Undock](DEBUG): Construct.
2020-01-26T05:45:51.391Z,1580017551.391 [DefaultUnder:LineCapture:HomingSequence:MidcourseGuidance:guide:E.Waypoint](DEBUG): Construct Waypoint.
2020-01-26T05:45:51.398Z,1580017551.398 [DefaultUnder:LineCapture:HomingSequence:MidcourseGuidance:guide:G.Circle](DEBUG): Construct.
2020-01-26T05:45:51.464Z,1580017551.464 [DefaultUnder:LineCapture:HomingSequence:TerminalGuidance:guide:G.LineCapture](DEBUG): Construct.
2020-01-26T05:45:51.514Z,1580017551.514 [DefaultUnder:LineCapture:K.Wait](DEBUG): Construct Wait.
2020-01-26T05:45:51.516Z,1580017551.516 [MissionManager](INFO): Inserting Stack: Missions/Insert/SetNavAcoustic.xml
2020-01-26T05:45:51.607Z,1580017551.607 [MissionManager](INFO): DefineArg DefaultUnder:SetNavAcoustic.DockLat = 0.642456 _
2020-01-26T05:45:51.617Z,1580017551.617 [MissionManager](INFO): DefineArg DefaultUnder:SetNavAcoustic.DockLon = -2.126000 _
2020-01-26T05:45:51.619Z,1580017551.619 [MissionManager](INFO): DefineArg DefaultUnder:SetNavAcoustic.DockRange = 2.000000 m
2020-01-26T05:45:51.634Z,1580017551.634 [MissionManager](INFO): DefineArg DefaultUnder:SetNavAcoustic.RangeTimeout = 5.000000 min
2020-01-26T05:45:51.643Z,1580017551.643 [DefaultUnder:SetNavAcoustic:UpdateNav:B.SetNav](DEBUG): Construct SetNav.
2020-01-26T05:45:51.650Z,1580017551.650 [DefaultUnder:F.Wait](DEBUG): Construct Wait.
2020-01-26T05:45:51.659Z,1580017551.659 [DefaultUnder:Default:Docked:run:B.Docked](DEBUG): Construct.
2020-01-26T05:45:51.692Z,1580017551.692 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-26T05:45:51.708Z,1580017551.708 [DefaultUnder:Default:Surface:run:SurfaceComms:Read_Iridium_uModem:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-01-26T05:45:51.714Z,1580017551.714 [DefaultUnder:Default:Surface:run:SurfaceComms:C.Wait](DEBUG): Construct Wait.
2020-01-26T05:45:51.785Z,1580017551.785 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xmlns="Tethys"
    xmlns:Estimation="Tethys/Estimation"
    xmlns:Guidance="Tethys/Guidance"
    xmlns:Units="Tethys/Units"
    xmlns:Universal="Tethys/Universal"
    xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                        Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.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="DefaultUnder">

    <DefineArg Name="uModemCommsInterval"><Description>
        How often to trigger uModem communications
    </Description><Units:minute/><Value>10</Value></DefineArg>

    <DefineArg Name="TransponderCode"><Description>
        Dock transponder Address.
    </Description><Units:count/><Value>2</Value></DefineArg>

    <DefineArg Name="AcousticUpdatePeriod"><Description>
        How long to wait between acoustic queries while the mission
        is in an idle state (on the dock or surface).
    </Description><Units:second/><Value>60</Value></DefineArg>

    <DefineArg Name="DockingAcousticUpdatePeriod"><Description>
        How long to wait between acoustic queries while the mission
        is actively docking (line capture)
    </Description><Units:second/><Value>2.5</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <!-- Mission Variables (don't change!) -->

    <DefineOutput Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries.
    </Description><Arg Name="AcousticUpdatePeriod"/></DefineOutput>

    <DefineOutput Name="Surface"><Description>
        Mission variable (don't change).
        The mission will run in this mode to go to the surface after homing attempts have failed.
    </Description><Units:count/><Value>-1</Value></DefineOutput>

    <DefineOutput Name="Docked"><Description>
        Mission variable (don't change).
        The mission will run in this mode when the vehicle is docked.
    </Description><Units:count/><Value>0</Value></DefineOutput>

    <DefineOutput Name="Home"><Description>
        Mission variable (don't change).
        The mission will run in this mode when homing to the dock.
    </Description><Units:count/><Value>1</Value></DefineOutput>

    <DefineOutput Name="DefaultMode"><Description>
        Mission variable (don't change).
        The mission sets this variable to switch between default modes.
    </Description><Arg Name="Docked"/></DefineOutput>

    <DefineOutput Name="CaptureMode"><Description>
        Mission variable (don't change).
        The mission sets this variable to reflect the termination status of the LineCapture insert.
    </Description><Units:count/><Value>-1</Value></DefineOutput>

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



    <!-- TODO: Safety nets and surfacing behaviors? -->

    <!-- Communication directives -->

    <Aggregate Id="uModemComms">
        <While>
            <Arg Name="DefaultMode"/><Eq><Arg Name="Docked"/></Eq>
        </While>

        <Aggregate Id="CheckIn">

            <When>
                <Elapsed><Universal:platform_communications/></Elapsed>
                <Gt><Arg Name="uModemCommsInterval"/></Gt>
            </When>

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

        </Aggregate>
    </Aggregate>

    <!-- Notify directives. -->

    <Aggregate Id="Notify">
        <Parallel/>

        <Aggregate>
            <Sequence/>

            <Aggregate>
                <Sequence Repeat="288"/>

                <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.</Syslog>

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

   <!-- Add track acoustic contact directives. -->

    <Estimation:TrackAcousticContact>
        <Parallel/>
        <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
        <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:TrackAcousticContact>

    <!-- Add LineCapture directives. -->

    <Insert Filename="Insert/LineCapture.xml"/>

    <!-- Add SetNav directives. -->

    <Insert Filename="Insert/SetNavAcoustic.xml"/>

    <!-- Default mission sequence. -->

    <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>

    <Aggregate Id="Default">

        <Sequence/>

        <Aggregate Id="Docked">

            <While>
                <Arg Name="DefaultMode"/><Eq><Arg Name="Docked"/></Eq>
            </While>

            <Aggregate Id="run">
                <Sequence/>

                <Assign><Sequence/><Arg Name="TrackingUpdatePeriod"/><Arg Name="AcousticUpdatePeriod"/></Assign>

                <Guidance:Docked>
                    <Sequence/>
                </Guidance:Docked>

                <Assign><Sequence/><Arg Name="DefaultMode"/><Arg Name="Home"/></Assign>

            </Aggregate>
        </Aggregate>


        <Aggregate Id="Home">

            <While>
                <Arg Name="DefaultMode"/><Eq><Arg Name="Home"/></Eq>
            </While>

            <Aggregate Id="run">
                <Sequence/>

                <Assign><Sequence/><Arg Name="TrackingUpdatePeriod"/><Arg Name="DockingAcousticUpdatePeriod"/></Assign>

                <Assign><Sequence/><Arg Name="CaptureMode"/><Arg Name="Surface"/></Assign>

                <Call RefId="LineCapture"/>

                <Assign><Sequence/><Arg Name="CaptureMode"/><Arg Name="LineCapture:GuidanceMode"/></Assign>

                <Aggregate Id="CheckCaptureSuccess">
                    <Sequence/>

                    <Break>
                        <Not><Arg Name="CaptureMode"/><Eq><Arg Name="Docked"/></Eq></Not>
                    </Break>

                    <Assign><Sequence/><Arg Name="DefaultMode"/><Arg Name="Docked"/></Assign>
                </Aggregate>

                <Assign><Sequence/><Arg Name="DefaultMode"/><Arg Name="Surface"/></Assign>

            </Aggregate>
        </Aggregate>


        <Aggregate Id="Surface">

            <While>
                <Arg Name="DefaultMode"/><Eq><Arg Name="Surface"/></Eq>
            </While>

            <Aggregate Id="run">
                <Sequence/>

                <Assign><Sequence/><Arg Name="TrackingUpdatePeriod"/><Arg Name="AcousticUpdatePeriod"/></Assign>

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

                <Aggregate Id="SurfaceComms">

                    <Sequence Repeat="288"/>

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

                    <ReadDatum Id="Read_Iridium_uModem">
                        <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>

                </Aggregate>
            </Aggregate>

        </Aggregate>

    </Aggregate>

</Mission>


2020-01-26T05:45:51.786Z,1580017551.786 [CommandLine](IMPORTANT): Loaded ./Missions/underIce/DefaultUnder.xml
2020-01-26T05:46:00.917Z,1580017560.917 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-26T05:46:00.917Z,1580017560.917 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012522585664,35.0, -0.1,   0.0,144

2020-01-26T05:47:36.644Z,1580017656.644 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-26T05:47:36.644Z,1580017656.644 [Default:CheckIn:C.Wait] Stopped
2020-01-26T05:47:36.644Z,1580017656.644 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-26T05:47:36.645Z,1580017656.645 [Default:CheckIn:D] Running Loop=1
2020-01-26T05:47:37.062Z,1580017657.062 [Default:CheckIn:D] Stopped
2020-01-26T05:47:37.063Z,1580017657.063 [Default:CheckIn:E] Running Loop=1
2020-01-26T05:47:37.462Z,1580017657.462 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.909532 min 
2020-01-26T05:47:37.462Z,1580017657.462 [Default:CheckIn:E] Stopped
2020-01-26T05:47:37.462Z,1580017657.462 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-26T05:47:37.462Z,1580017657.462 [Default:CheckIn] Stopped
2020-01-26T05:47:37.462Z,1580017657.462 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-26T05:47:37.462Z,1580017657.462 [Default:CheckIn](INFO): Running loop #4
2020-01-26T05:47:37.462Z,1580017657.462 [Default:CheckIn] Running Loop=4
2020-01-26T05:47:37.462Z,1580017657.462 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-26T05:47:37.462Z,1580017657.462 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-26T05:47:39.452Z,1580017659.452 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,054729.00,A,3648.60568,N,12149.39099,W,0.292,294.94,260120,,,D*79
2020-01-26T05:47:39.455Z,1580017659.455 [NAL9602](INFO): GPS fix at 20200126T054729: (36.810095, -121.823183)
2020-01-26T05:47:39.513Z,1580017659.513 [Default:CheckIn:Read_GPS] Stopped
2020-01-26T05:47:39.513Z,1580017659.513 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-26T05:47:47.284Z,1580017667.284 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200126T052257/Courier0013.lzma
2020-01-26T05:47:49.290Z,1580017669.290 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Courier0013.lzma.bak
2020-01-26T05:47:49.290Z,1580017669.290 [DataOverHttps](INFO): SBD MOMSN=12204840
2020-01-26T05:48:00.861Z,1580017680.861 [NAL9602](INFO): SBD MO Status=0, MOMSN=10317, MT Status=0, MTMSN=0
2020-01-26T05:48:00.861Z,1580017680.861 [NAL9602](INFO): No messages in MT queue
2020-01-26T05:48:06.641Z,1580017686.641 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20200126T052257/Express0014.lzma
2020-01-26T05:48:08.646Z,1580017688.646 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Express0014.lzma.bak
2020-01-26T05:48:08.647Z,1580017688.647 [DataOverHttps](INFO): SBD MOMSN=12204843
2020-01-26T05:48:10.197Z,1580017690.197 [Default:CheckIn:Read_Iridium] Stopped
2020-01-26T05:48:10.197Z,1580017690.197 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-26T05:48:10.197Z,1580017690.197 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-26T05:48:31.568Z,1580017711.568 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-26T05:49:23.292Z,1580017763.292 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-26T05:49:23.292Z,1580017763.292 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 397.70, 324.50, 356.11
2020-01-26T05:52:24.297Z,1580017944.297 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,   +20,  -315,   +38,    +5,A
2020-01-26T05:53:10.773Z,1580017990.773 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-26T05:53:10.773Z,1580017990.773 [Default:CheckIn:C.Wait] Stopped
2020-01-26T05:53:10.773Z,1580017990.773 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-26T05:53:10.773Z,1580017990.773 [Default:CheckIn:D] Running Loop=1
2020-01-26T05:53:11.184Z,1580017991.184 [Default:CheckIn:D] Stopped
2020-01-26T05:53:11.184Z,1580017991.184 [Default:CheckIn:E] Running Loop=1
2020-01-26T05:53:11.579Z,1580017991.579 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.478221 min 
2020-01-26T05:53:11.579Z,1580017991.579 [Default:CheckIn:E] Stopped
2020-01-26T05:53:11.579Z,1580017991.579 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-26T05:53:11.579Z,1580017991.579 [Default:CheckIn] Stopped
2020-01-26T05:53:11.579Z,1580017991.579 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-26T05:53:11.579Z,1580017991.579 [Default:CheckIn](INFO): Running loop #5
2020-01-26T05:53:11.579Z,1580017991.579 [Default:CheckIn] Running Loop=5
2020-01-26T05:53:11.579Z,1580017991.579 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-26T05:53:11.579Z,1580017991.579 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-26T05:53:13.569Z,1580017993.569 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,055303.00,A,3648.61226,N,12149.40174,W,0.369,16.31,260120,,,D*46
2020-01-26T05:53:13.571Z,1580017993.571 [NAL9602](INFO): GPS fix at 20200126T055303: (36.810204, -121.823362)
2020-01-26T05:53:13.621Z,1580017993.621 [Default:CheckIn:Read_GPS] Stopped
2020-01-26T05:53:13.622Z,1580017993.622 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-26T05:53:21.668Z,1580018001.668 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200126T052257/Courier0016.lzma
2020-01-26T05:53:23.276Z,1580018003.276 [NAL9602](INFO): SBD MO Status=0, MOMSN=10318, MT Status=0, MTMSN=0
2020-01-26T05:53:23.276Z,1580018003.276 [NAL9602](INFO): No messages in MT queue
2020-01-26T05:53:23.675Z,1580018003.675 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Courier0016.lzma.bak
2020-01-26T05:53:23.675Z,1580018003.675 [DataOverHttps](INFO): SBD MOMSN=12204852
2020-01-26T05:53:41.000Z,1580018021.000 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200126T052257/Express0017.lzma
2020-01-26T05:53:43.006Z,1580018023.006 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Express0017.lzma.bak
2020-01-26T05:53:43.006Z,1580018023.006 [DataOverHttps](INFO): SBD MOMSN=12204856
2020-01-26T05:53:44.317Z,1580018024.317 [Default:CheckIn:Read_Iridium] Stopped
2020-01-26T05:53:44.317Z,1580018024.317 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-26T05:53:44.318Z,1580018024.318 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-26T05:53:53.986Z,1580018033.986 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-26T05:54:05.299Z,1580018045.299 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-26T05:54:05.299Z,1580018045.299 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,   88,   +13,A
2020-01-26T05:56:26.304Z,1580018186.304 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-26T05:56:26.304Z,1580018186.304 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,  -100,  -18,A
2020-01-26T05:58:03.275Z,1580018283.275 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-26T05:58:03.275Z,1580018283.275 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012523105864,35.0, -0.11448.9,  0
2020-01-26T05:58:44.952Z,1580018324.952 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-26T05:58:44.952Z,1580018324.952 [Default:CheckIn:C.Wait] Stopped
2020-01-26T05:58:44.953Z,1580018324.953 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-26T05:58:44.953Z,1580018324.953 [Default:CheckIn:D] Running Loop=1
2020-01-26T05:58:45.329Z,1580018325.329 [Default:CheckIn:D] Stopped
2020-01-26T05:58:45.329Z,1580018325.329 [Default:CheckIn:E] Running Loop=1
2020-01-26T05:58:45.737Z,1580018325.737 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.047310 min 
2020-01-26T05:58:45.737Z,1580018325.737 [Default:CheckIn:E] Stopped
2020-01-26T05:58:45.737Z,1580018325.737 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-26T05:58:45.737Z,1580018325.737 [Default:CheckIn] Stopped
2020-01-26T05:58:45.737Z,1580018325.737 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-26T05:58:45.738Z,1580018325.738 [Default:CheckIn](INFO): Running loop #6
2020-01-26T05:58:45.738Z,1580018325.738 [Default:CheckIn] Running Loop=6
2020-01-26T05:58:45.738Z,1580018325.738 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-26T05:58:45.738Z,1580018325.738 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-26T05:58:47.718Z,1580018327.718 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,055837.00,A,3648.62187,N,12149.41323,W,0.117,314.80,260120,,,D*70
2020-01-26T05:58:47.720Z,1580018327.720 [NAL9602](INFO): GPS fix at 20200126T055837: (36.810364, -121.823554)
2020-01-26T05:58:47.773Z,1580018327.773 [Default:CheckIn:Read_GPS] Stopped
2020-01-26T05:58:47.773Z,1580018327.773 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-26T05:58:55.756Z,1580018335.756 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200126T052257/Courier0019.lzma
2020-01-26T05:58:57.763Z,1580018337.763 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Courier0019.lzma.bak
2020-01-26T05:58:57.763Z,1580018337.763 [DataOverHttps](INFO): SBD MOMSN=12204861
2020-01-26T05:58:58.238Z,1580018338.238 [NAL9602](INFO): SBD MO Status=0, MOMSN=10319, MT Status=0, MTMSN=0
2020-01-26T05:58:58.238Z,1580018338.238 [NAL9602](INFO): No messages in MT queue
2020-01-26T05:59:15.056Z,1580018355.056 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200126T052257/Express0020.lzma
2020-01-26T05:59:17.062Z,1580018357.062 [DataOverHttps](INFO): Moved sent file to Logs/20200126T052257/Express0020.lzma.bak
2020-01-26T05:59:17.063Z,1580018357.063 [DataOverHttps](INFO): SBD MOMSN=12204864
2020-01-26T05:59:18.467Z,1580018358.467 [Default:CheckIn:Read_Iridium] Stopped
2020-01-26T05:59:18.467Z,1580018358.467 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-26T05:59:18.468Z,1580018358.468 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-26T05:59:28.932Z,1580018368.932 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-26T06:00:24.297Z,1580018424.297 [RDI_Pathfinder](ERROR): only read 0 of 4 data items
2020-01-26T06:00:24.297Z,1580018424.297 [RDI_Pathfinder](ERROR): Failed to parse:
:RA 396.03, 331.15, 356.11, 356.11
2020-01-26T06:03:22.924Z,1580018602.924 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-26T06:03:22.924Z,1580018602.924 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012523161864,35.0, -0.1, 48.9,  0
2020-01-26T06:03:37.050Z,1580018617.050 [DataOverHttps](IMPORTANT): SBD MTMSN=20200126T060325
2020-01-26T06:03:44.978Z,1580018624.978 [DataOverHttps](INFO): Received command:restart app
2020-01-26T06:03:45.031Z,1580018625.031 [CommandLine](IMPORTANT): got command restart application
2020-01-26T06:03:46.037Z,1580018626.037 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2020-01-26T06:03:46.037Z,1580018626.037 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-26T06:03:46.037Z,1580018626.037 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:46.101Z,1580018626.101 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-01-26T06:03:46.101Z,1580018626.101 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:46.102Z,1580018626.102 [CommandLine](INFO): Join timeout helper Thread ID is 3948
2020-01-26T06:03:46.102Z,1580018626.102 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-01-26T06:03:46.102Z,1580018626.102 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:46.103Z,1580018626.103 [NavChartDb](INFO): Join timeout helper Thread ID is 3949
2020-01-26T06:03:46.169Z,1580018626.169 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-26T06:03:46.169Z,1580018626.169 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:46.181Z,1580018626.181 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-01-26T06:03:46.182Z,1580018626.182 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:46.182Z,1580018626.182 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 3950
2020-01-26T06:03:46.581Z,1580018626.581 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-26T06:03:46.581Z,1580018626.581 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-26T06:03:46.582Z,1580018626.582 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:46.589Z,1580018626.589 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-01-26T06:03:46.589Z,1580018626.589 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:46.589Z,1580018626.589 [Radio_Surface](INFO): Join timeout helper Thread ID is 3951
2020-01-26T06:03:46.886Z,1580018626.886 [Radio_Surface](INFO): Powering down
2020-01-26T06:03:46.888Z,1580018626.888 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-26T06:03:46.888Z,1580018626.888 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:46.890Z,1580018626.890 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-01-26T06:03:46.890Z,1580018626.890 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:46.891Z,1580018626.891 [DataOverHttps](INFO): Join timeout helper Thread ID is 3952
2020-01-26T06:03:46.981Z,1580018626.981 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-26T06:03:46.986Z,1580018626.986 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:46.994Z,1580018626.994 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-01-26T06:03:46.994Z,1580018626.994 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:46.995Z,1580018626.995 [logger](INFO): Join timeout helper Thread ID is 3953
2020-01-26T06:03:47.033Z,1580018627.033 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-26T06:03:47.033Z,1580018627.033 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:47.054Z,1580018627.054 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-01-26T06:03:47.054Z,1580018627.054 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:47.054Z,1580018627.054 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-01-26T06:03:47.054Z,1580018627.054 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:47.054Z,1580018627.054 [controlThread](INFO): Join timeout helper Thread ID is 3954
2020-01-26T06:03:47.093Z,1580018627.093 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-26T06:03:47.093Z,1580018627.093 [controlThread](DEBUG): Uninitializing ControlThread
2020-01-26T06:03:47.094Z,1580018627.094 [AHRS_M2](INFO): Powering down
2020-01-26T06:03:47.165Z,1580018627.165 [DDM](INFO): Powering down
2020-01-26T06:03:47.258Z,1580018627.258 [DUSBL_Hydroid](INFO): Powering down
2020-01-26T06:03:47.349Z,1580018627.349 [Micromodem](INFO): Powering down
2020-01-26T06:03:47.445Z,1580018627.445 [NAL9602](INFO): Powering down
2020-01-26T06:03:47.517Z,1580018627.517 [RDI_Pathfinder](INFO): Powering down
2020-01-26T06:03:47.518Z,1580018627.518 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-01-26T06:03:47.519Z,1580018627.519 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-01-26T06:03:47.520Z,1580018627.520 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-01-26T06:03:47.520Z,1580018627.520 [MissionManager](INFO): Uninitializing Mission Default
2020-01-26T06:03:47.520Z,1580018627.520 [Default] Stopped
2020-01-26T06:03:47.520Z,1580018627.520 [Default](DEBUG): Aggregate::uninitialize Default
2020-01-26T06:03:47.521Z,1580018627.521 [Default:B.GoToSurface] Stopped
2020-01-26T06:03:47.521Z,1580018627.521 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-26T06:03:47.521Z,1580018627.521 [Default:CheckIn] Stopped
2020-01-26T06:03:47.521Z,1580018627.521 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-26T06:03:47.521Z,1580018627.521 [Default:CheckIn:C.Wait] Stopped
2020-01-26T06:03:47.521Z,1580018627.521 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-26T06:03:47.523Z,1580018627.523 [MissionManager](INFO): Uninitializing Mission DefaultUnder
2020-01-26T06:03:47.549Z,1580018627.549 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-01-26T06:03:47.549Z,1580018627.549 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-01-26T06:03:47.549Z,1580018627.549 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-01-26T06:03:47.550Z,1580018627.550 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-01-26T06:03:47.550Z,1580018627.550 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-01-26T06:03:47.550Z,1580018627.550 [BuoyancyServo](INFO): Powering down
2020-01-26T06:03:47.561Z,1580018627.561 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-01-26T06:03:47.561Z,1580018627.561 [ElevatorServo](INFO): Powering down
2020-01-26T06:03:47.562Z,1580018627.562 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-01-26T06:03:47.562Z,1580018627.562 [MassServo](INFO): Powering down
2020-01-26T06:03:47.563Z,1580018627.563 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-26T06:03:47.563Z,1580018627.563 [RudderServo](INFO): Powering down
2020-01-26T06:03:47.564Z,1580018627.564 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-01-26T06:03:47.564Z,1580018627.564 [ThrusterServo](INFO): Powering down
2020-01-26T06:03:47.564Z,1580018627.564 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-01-26T06:03:47.565Z,1580018627.565 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-01-26T06:03:47.565Z,1580018627.565 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-01-26T06:03:47.565Z,1580018627.565 [CBIT](DEBUG): Powering off loads.
2020-01-26T06:03:47.577Z,1580018627.577 [CBIT](DEBUG): Disabling WDT.
2020-01-26T06:03:47.589Z,1580018627.589 [CBIT](DEBUG): Opening all GF detection circuits.
2020-01-26T06:03:47.590Z,1580018627.590 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:47.633Z,1580018627.633 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:47.644Z,1580018627.644 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:47.690Z,1580018627.690 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:47.747Z,1580018627.747 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-26T06:03:47.820Z,1580018627.820 [logger ThreadHandler](INFO): Thread cancelled.