2019-05-08T18:35:45.576Z,1557340545.576 [Supervisor](DEBUG): Initializing supervisor.
2019-05-08T18:35:45.580Z,1557340545.580 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-08T18:35:45.580Z,1557340545.580 [SyncHandler](INFO): Protected caller Thread ID is 5230
2019-05-08T18:35:45.581Z,1557340545.581 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-08T18:35:45.582Z,1557340545.582 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-08T18:35:45.582Z,1557340545.582 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5231
2019-05-08T18:35:45.585Z,1557340545.585 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-08T18:35:45.598Z,1557340545.598 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-08T18:35:45.599Z,1557340545.599 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-08T18:35:45.599Z,1557340545.599 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5232
2019-05-08T18:35:45.600Z,1557340545.600 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-08T18:35:45.601Z,1557340545.601 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-08T18:35:45.602Z,1557340545.602 [logger ThreadHandler](INFO): Protected caller Thread ID is 5233
2019-05-08T18:35:45.604Z,1557340545.604 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-08T18:35:45.604Z,1557340545.604 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-08T18:35:45.606Z,1557340545.606 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-08T18:35:45.705Z,1557340545.705 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-08T18:35:45.705Z,1557340545.705 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-08T18:35:45.919Z,1557340545.919 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-08T18:35:45.920Z,1557340545.920 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-08T18:35:46.063Z,1557340546.063 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-08T18:35:46.064Z,1557340546.064 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-08T18:35:46.637Z,1557340546.637 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-08T18:35:46.638Z,1557340546.638 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-08T18:35:47.122Z,1557340547.122 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-08T18:35:47.122Z,1557340547.122 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-08T18:35:47.614Z,1557340547.614 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-08T18:35:47.614Z,1557340547.614 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-08T18:35:47.939Z,1557340547.939 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-08T18:35:47.940Z,1557340547.940 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-08T18:35:48.295Z,1557340548.295 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-08T18:35:48.296Z,1557340548.296 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-08T18:35:48.716Z,1557340548.716 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-08T18:35:48.717Z,1557340548.717 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-08T18:35:48.875Z,1557340548.875 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-08T18:35:48.876Z,1557340548.876 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-08T18:35:48.986Z,1557340548.986 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-08T18:35:48.986Z,1557340548.986 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-08T18:35:49.070Z,1557340549.070 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-08T18:35:49.176Z,1557340549.176 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-08T18:35:49.176Z,1557340549.176 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-08T18:35:49.387Z,1557340549.387 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-08T18:35:49.388Z,1557340549.388 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-08T18:35:49.622Z,1557340549.622 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-08T18:35:49.624Z,1557340549.624 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-05-08T18:35:49.625Z,1557340549.625 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-05-08T18:35:49.938Z,1557340549.938 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-05-08T18:35:50.435Z,1557340550.435 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-08T18:35:50.436Z,1557340550.436 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-05-08T18:35:50.548Z,1557340550.548 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-05-08T18:35:50.718Z,1557340550.718 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-05-08T18:35:50.936Z,1557340550.936 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-05-08T18:35:51.024Z,1557340551.024 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-05-08T18:35:51.126Z,1557340551.126 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-05-08T18:35:51.223Z,1557340551.223 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-05-08T18:35:51.387Z,1557340551.387 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-05-08T18:35:51.497Z,1557340551.497 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-05-08T18:35:51.600Z,1557340551.600 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2019-05-08T18:35:51.600Z,1557340551.600 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-08T18:35:51.608Z,1557340551.608 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-08T18:35:51.704Z,1557340551.704 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-08T18:35:51.705Z,1557340551.705 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-08T18:35:51.836Z,1557340551.836 [BuoyancyServo] Loaded
2019-05-08T18:35:51.836Z,1557340551.836 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-08T18:35:51.851Z,1557340551.851 [ElevatorServo] Loaded
2019-05-08T18:35:51.852Z,1557340551.852 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-08T18:35:51.866Z,1557340551.866 [MassServo] Loaded
2019-05-08T18:35:51.867Z,1557340551.867 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-08T18:35:51.882Z,1557340551.882 [RudderServo] Loaded
2019-05-08T18:35:51.882Z,1557340551.882 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-08T18:35:51.897Z,1557340551.897 [ThrusterServo] Loaded
2019-05-08T18:35:51.897Z,1557340551.897 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-08T18:35:51.898Z,1557340551.898 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-08T18:35:51.898Z,1557340551.898 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-08T18:35:52.031Z,1557340552.031 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-08T18:35:52.061Z,1557340552.061 [SBIT] Loaded
2019-05-08T18:35:52.062Z,1557340552.062 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-08T18:35:52.062Z,1557340552.062 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-08T18:35:52.091Z,1557340552.091 [IBIT] Loaded
2019-05-08T18:35:52.091Z,1557340552.091 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-08T18:35:52.094Z,1557340552.094 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-08T18:35:52.488Z,1557340552.488 [CBIT] Loaded
2019-05-08T18:35:52.488Z,1557340552.488 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-08T18:35:52.489Z,1557340552.489 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-08T18:35:52.489Z,1557340552.489 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-08T18:35:52.679Z,1557340552.679 [Aanderaa_O2] Loaded
2019-05-08T18:35:52.679Z,1557340552.679 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-05-08T18:35:52.688Z,1557340552.688 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-05-08T18:35:52.694Z,1557340552.694 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-05-08T18:35:52.696Z,1557340552.696 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-05-08T18:35:52.700Z,1557340552.700 [CTD_Seabird](INFO): created writer for : depth
2019-05-08T18:35:52.701Z,1557340552.701 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-05-08T18:35:52.706Z,1557340552.706 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-05-08T18:35:52.707Z,1557340552.707 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-05-08T18:35:52.712Z,1557340552.712 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-05-08T18:35:52.713Z,1557340552.713 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-05-08T18:35:52.718Z,1557340552.718 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-05-08T18:35:52.719Z,1557340552.719 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-05-08T18:35:52.724Z,1557340552.724 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-05-08T18:35:52.725Z,1557340552.725 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-05-08T18:35:52.730Z,1557340552.730 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-05-08T18:35:52.766Z,1557340552.766 [CTD_Seabird] Loaded
2019-05-08T18:35:52.766Z,1557340552.766 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-05-08T18:35:52.767Z,1557340552.767 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4066A4E0
2019-05-08T18:35:52.768Z,1557340552.768 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5312
2019-05-08T18:35:52.794Z,1557340552.794 [ESPComponent] Loaded
2019-05-08T18:35:52.794Z,1557340552.794 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-05-08T18:35:52.808Z,1557340552.808 [PAR_Licor] Loaded
2019-05-08T18:35:52.809Z,1557340552.809 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-05-08T18:35:52.858Z,1557340552.858 [WetLabsBB2FL] Loaded
2019-05-08T18:35:52.858Z,1557340552.858 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-05-08T18:35:52.859Z,1557340552.859 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4069A4E0
2019-05-08T18:35:52.859Z,1557340552.859 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5313
2019-05-08T18:35:52.860Z,1557340552.860 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-08T18:35:52.861Z,1557340552.861 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-08T18:35:52.901Z,1557340552.901 [DepthRateCalculator] Loaded
2019-05-08T18:35:52.901Z,1557340552.901 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-08T18:35:52.907Z,1557340552.907 [PitchRateCalculator] Loaded
2019-05-08T18:35:52.907Z,1557340552.907 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-08T18:35:52.924Z,1557340552.924 [SpeedCalculator] Loaded
2019-05-08T18:35:52.924Z,1557340552.924 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-08T18:35:52.946Z,1557340552.946 [TempGradientCalculator] Loaded
2019-05-08T18:35:52.946Z,1557340552.946 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-08T18:35:52.952Z,1557340552.952 [YawRateCalculator] Loaded
2019-05-08T18:35:52.953Z,1557340552.953 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-08T18:35:52.986Z,1557340552.986 [ElevatorOffsetCalculator] Loaded
2019-05-08T18:35:52.987Z,1557340552.987 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-08T18:35:52.987Z,1557340552.987 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-08T18:35:52.988Z,1557340552.988 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-08T18:35:53.014Z,1557340553.014 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-08T18:35:53.014Z,1557340553.014 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-08T18:35:53.118Z,1557340553.118 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-08T18:35:53.119Z,1557340553.119 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-08T18:35:53.140Z,1557340553.140 [NavChart] Loaded
2019-05-08T18:35:53.141Z,1557340553.141 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-08T18:35:53.145Z,1557340553.145 [UniversalFixResidualReporter] Loaded
2019-05-08T18:35:53.145Z,1557340553.145 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-08T18:35:53.146Z,1557340553.146 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-08T18:35:53.146Z,1557340553.146 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-08T18:35:53.446Z,1557340553.446 [AcousticModem_Benthos_ATM900] Loaded
2019-05-08T18:35:53.446Z,1557340553.446 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2019-05-08T18:35:53.520Z,1557340553.520 [DataOverHttps] Loaded
2019-05-08T18:35:53.520Z,1557340553.520 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-08T18:35:53.521Z,1557340553.521 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409714E0
2019-05-08T18:35:53.522Z,1557340553.522 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5314
2019-05-08T18:35:53.535Z,1557340553.535 [Depth_Keller] Loaded
2019-05-08T18:35:53.535Z,1557340553.535 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-08T18:35:53.627Z,1557340553.627 [NAL9602] Loaded
2019-05-08T18:35:53.627Z,1557340553.627 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-08T18:35:53.632Z,1557340553.632 [Onboard] Loaded
2019-05-08T18:35:53.633Z,1557340553.633 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-08T18:35:53.636Z,1557340553.636 [Radio_Surface] Loaded
2019-05-08T18:35:53.637Z,1557340553.637 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-08T18:35:53.638Z,1557340553.638 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409A14E0
2019-05-08T18:35:53.638Z,1557340553.638 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5315
2019-05-08T18:35:53.686Z,1557340553.686 [PNI_TCM] Loaded
2019-05-08T18:35:53.686Z,1557340553.686 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2019-05-08T18:35:55.240Z,1557340555.240 [BPC1] Loaded
2019-05-08T18:35:55.240Z,1557340555.240 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-08T18:35:55.240Z,1557340555.240 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-08T18:35:55.241Z,1557340555.241 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-08T18:35:55.415Z,1557340555.415 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-08T18:35:55.416Z,1557340555.416 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-08T18:35:55.574Z,1557340555.574 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-08T18:35:55.661Z,1557340555.661 [VerticalControl] Loaded
2019-05-08T18:35:55.661Z,1557340555.661 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-08T18:35:55.662Z,1557340555.662 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-08T18:35:55.722Z,1557340555.722 [HorizontalControl] Loaded
2019-05-08T18:35:55.722Z,1557340555.722 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-08T18:35:55.723Z,1557340555.723 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-08T18:35:55.724Z,1557340555.724 [SpeedControl] Loaded
2019-05-08T18:35:55.725Z,1557340555.725 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-08T18:35:55.725Z,1557340555.725 [LoopControl](DEBUG): Construct LoopControl.
2019-05-08T18:35:55.726Z,1557340555.726 [LoopControl] Loaded
2019-05-08T18:35:55.726Z,1557340555.726 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-08T18:35:55.727Z,1557340555.727 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-08T18:35:55.727Z,1557340555.727 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-08T18:35:55.740Z,1557340555.740 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-08T18:35:55.741Z,1557340555.741 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-08T18:35:56.034Z,1557340556.034 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-08T18:35:56.038Z,1557340556.038 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-08T18:35:56.038Z,1557340556.038 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-08T18:35:56.045Z,1557340556.045 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-08T18:35:56.046Z,1557340556.046 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ADB4E0
2019-05-08T18:35:56.047Z,1557340556.047 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5316
2019-05-08T18:35:56.052Z,1557340556.052 [Supervisor](INFO): Main Thread ID is 1340
2019-05-08T18:35:56.052Z,1557340556.052 [Supervisor](DEBUG): Running supervisor.
2019-05-08T18:35:56.052Z,1557340556.052 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5317
2019-05-08T18:35:56.055Z,1557340556.055 [controlThread ThreadHandler](INFO): Handler Thread ID is 5318
2019-05-08T18:35:56.055Z,1557340556.055 [controlThread](DEBUG): Initializing ControlThread
2019-05-08T18:35:56.057Z,1557340556.057 [SBIT](INFO): Initialize SBIT Component.
2019-05-08T18:35:56.058Z,1557340556.058 [SBIT](IMPORTANT): git: 2019-05-01-6-g08bb213
2019-05-08T18:35:56.058Z,1557340556.058 [SBIT](INFO): git hash: 08bb2137fac00bb96d649b4144ef516361bafd54
2019-05-08T18:35:56.058Z,1557340556.058 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-08T18:35:56.059Z,1557340556.059 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-05-08T18:35:56.061Z,1557340556.061 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2019-05-08T18:35:56.061Z,1557340556.061 [IBIT](INFO): Initialize IBIT Component.
2019-05-08T18:35:56.062Z,1557340556.062 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-08T18:35:56.063Z,1557340556.063 [logger ThreadHandler](INFO): Handler Thread ID is 5319
2019-05-08T18:35:56.073Z,1557340556.073 [CBIT](DEBUG): Initialized mux pins.
2019-05-08T18:35:56.073Z,1557340556.073 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-08T18:35:56.081Z,1557340556.081 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5320
2019-05-08T18:35:56.082Z,1557340556.082 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-05-08T18:35:56.085Z,1557340556.085 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-05-08T18:35:56.087Z,1557340556.087 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5322
2019-05-08T18:35:56.088Z,1557340556.088 [WetLabsBB2FL](INFO): Powering down
2019-05-08T18:35:56.098Z,1557340556.098 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-08T18:35:56.098Z,1557340556.098 [CBIT](DEBUG): Initializing heartbeat.
2019-05-08T18:35:56.117Z,1557340556.117 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5323
2019-05-08T18:35:56.118Z,1557340556.118 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-08T18:35:56.129Z,1557340556.129 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5324
2019-05-08T18:35:56.145Z,1557340556.145 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5325
2019-05-08T18:35:56.151Z,1557340556.151 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-08T18:35:56.151Z,1557340556.151 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-08T18:35:56.151Z,1557340556.151 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-08T18:35:56.151Z,1557340556.151 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-08T18:35:56.152Z,1557340556.152 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-08T18:35:56.152Z,1557340556.152 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-08T18:35:56.152Z,1557340556.152 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-08T18:35:56.152Z,1557340556.152 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-08T18:35:56.152Z,1557340556.152 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-08T18:35:56.152Z,1557340556.152 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-08T18:35:56.153Z,1557340556.153 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-08T18:35:56.153Z,1557340556.153 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-08T18:35:56.153Z,1557340556.153 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-08T18:35:56.153Z,1557340556.153 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-08T18:35:56.154Z,1557340556.154 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-08T18:35:56.154Z,1557340556.154 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-08T18:35:56.169Z,1557340556.169 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-08T18:35:56.169Z,1557340556.169 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-08T18:35:56.205Z,1557340556.205 [CBIT](DEBUG): Backplane powered.
2019-05-08T18:35:56.209Z,1557340556.209 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-08T18:35:56.210Z,1557340556.210 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-08T18:35:56.210Z,1557340556.210 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-08T18:35:56.210Z,1557340556.210 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-08T18:35:56.211Z,1557340556.211 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-08T18:35:56.211Z,1557340556.211 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-08T18:35:56.212Z,1557340556.212 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-08T18:35:56.213Z,1557340556.213 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-08T18:35:56.222Z,1557340556.222 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-08T18:35:56.224Z,1557340556.224 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-08T18:35:56.224Z,1557340556.224 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-08T18:35:56.233Z,1557340556.233 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-08T18:35:56.234Z,1557340556.234 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-08T18:35:56.260Z,1557340556.260 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-08T18:35:56.296Z,1557340556.296 [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>


2019-05-08T18:35:56.309Z,1557340556.309 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-08T18:35:56.387Z,1557340556.387 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-08T18:35:56.389Z,1557340556.389 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-08T18:35:56.390Z,1557340556.390 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-08T18:35:56.437Z,1557340556.437 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-08T18:35:56.440Z,1557340556.440 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-08T18:35:56.473Z,1557340556.473 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-08T18:35:56.483Z,1557340556.483 [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>


2019-05-08T18:35:56.488Z,1557340556.488 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-08T18:35:56.506Z,1557340556.506 [ESPComponent](INFO): powering down ESP
2019-05-08T18:35:56.533Z,1557340556.533 [Radio_Surface](INFO): Powering up
2019-05-08T18:35:56.818Z,1557340556.818 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-05-08T18:35:56.819Z,1557340556.819 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-05-08T18:35:56.842Z,1557340556.842 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar
2019-05-08T18:35:56.913Z,1557340556.913 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-08T18:35:56.935Z,1557340556.935 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-08T18:35:56.941Z,1557340556.941 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-08T18:35:56.942Z,1557340556.942 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-08T18:35:56.949Z,1557340556.949 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-08T18:35:56.950Z,1557340556.950 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-08T18:35:56.957Z,1557340556.957 [MassServo](DEBUG): Initializing MassServo.
2019-05-08T18:35:56.958Z,1557340556.958 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-08T18:35:56.965Z,1557340556.965 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-08T18:35:56.966Z,1557340556.966 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-08T18:35:56.973Z,1557340556.973 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-08T18:35:59.933Z,1557340559.933 [Aanderaa_O2](INFO): Powering down
2019-05-08T18:36:03.114Z,1557340563.114 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2019-05-08T18:36:03.878Z,1557340563.878 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:36:03.878Z,1557340563.878 [PNI_TCM] Data Fault, FailCount= 1
2019-05-08T18:36:03.878Z,1557340563.878 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:36:04.089Z,1557340564.089 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:36:04.281Z,1557340564.281 [PNI_TCM](INFO): Powering down
2019-05-08T18:36:05.641Z,1557340565.641 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:36:05.641Z,1557340565.641 [PNI_TCM] No Fault, FailCount= 1
2019-05-08T18:36:06.333Z,1557340566.333 [CBIT](CRITICAL): Environmental Failure. Press:14.780849 PSI. Humidity:36%. Temp:26 C. ABORTING MISSION
2019-05-08T18:36:06.333Z,1557340566.333 [Supervisor](INFO): Stop Mission called by CBIT::monitorEnvironmentals
2019-05-08T18:36:06.738Z,1557340566.738 [CommandLine](FAULT): Scheduling is paused
2019-05-08T18:36:06.738Z,1557340566.738 [CBIT](INFO): Critical error at 20190508T183606
2019-05-08T18:36:13.191Z,1557340573.191 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:36:13.191Z,1557340573.191 [PNI_TCM] Data Fault, FailCount= 2
2019-05-08T18:36:13.191Z,1557340573.191 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:36:13.231Z,1557340573.231 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:36:13.573Z,1557340573.573 [PNI_TCM](INFO): Powering down
2019-05-08T18:36:14.863Z,1557340574.863 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:36:14.863Z,1557340574.863 [PNI_TCM] No Fault, FailCount= 2
2019-05-08T18:36:17.189Z,1557340577.189 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-05-08T18:36:17.190Z,1557340577.190 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 1
2019-05-08T18:36:17.190Z,1557340577.190 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-05-08T18:36:17.252Z,1557340577.252 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-05-08T18:36:17.593Z,1557340577.593 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-05-08T18:36:18.452Z,1557340578.452 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-05-08T18:36:18.452Z,1557340578.452 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 1
2019-05-08T18:36:20.826Z,1557340580.826 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-05-08T18:36:20.826Z,1557340580.826 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-05-08T18:36:20.890Z,1557340580.890 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-08T18:36:20.894Z,1557340580.894 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-08T18:36:22.460Z,1557340582.460 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:36:22.460Z,1557340582.460 [PNI_TCM] Data Fault, FailCount= 3
2019-05-08T18:36:22.460Z,1557340582.460 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:36:22.646Z,1557340582.646 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:36:22.865Z,1557340582.865 [PNI_TCM](INFO): Powering down
2019-05-08T18:36:23.842Z,1557340583.842 [NAL9602](INFO): Powering up NAL9602
2019-05-08T18:36:23.974Z,1557340583.974 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:36:23.974Z,1557340583.974 [PNI_TCM] No Fault, FailCount= 3
2019-05-08T18:36:31.536Z,1557340591.536 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:36:31.536Z,1557340591.536 [PNI_TCM] Data Fault, FailCount= 4
2019-05-08T18:36:31.536Z,1557340591.536 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:36:31.610Z,1557340591.610 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:36:31.932Z,1557340591.932 [PNI_TCM](INFO): Powering down
2019-05-08T18:36:32.113Z,1557340592.113 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.008670
CHAN A1 (24V): 0.041262
CHAN A2 (12V): -0.005205
CHAN A3 (5V): -0.002645
CHAN B0 (3.3V): -0.001363
CHAN B1 (3.15aV): -0.001468
CHAN B2 (3.15bV): -0.001206
CHAN B3 (GND): 0.000237
OPEN: 0.006519
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-08T18:36:33.221Z,1557340593.221 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:36:33.221Z,1557340593.221 [PNI_TCM] No Fault, FailCount= 4
2019-05-08T18:36:34.746Z,1557340594.746 [NAL9602](INFO): NAL9602 initialized
2019-05-08T18:36:35.569Z,1557340595.569 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:36:40.605Z,1557340600.605 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:36:40.606Z,1557340600.606 [PNI_TCM] Data Fault, FailCount= 5
2019-05-08T18:36:40.606Z,1557340600.606 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:36:40.730Z,1557340600.730 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:36:40.730Z,1557340600.730 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2019-05-08T18:36:40.991Z,1557340600.991 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-05-08T18:36:40.991Z,1557340600.991 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 2
2019-05-08T18:36:40.991Z,1557340600.991 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-05-08T18:36:41.010Z,1557340601.010 [PNI_TCM](INFO): Powering down
2019-05-08T18:36:41.279Z,1557340601.279 [CBIT](INFO): Critical error at 20190508T183640
2019-05-08T18:36:41.282Z,1557340601.282 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-05-08T18:36:41.386Z,1557340601.386 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-05-08T18:36:42.290Z,1557340602.290 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-05-08T18:36:42.290Z,1557340602.290 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 2
2019-05-08T18:36:44.618Z,1557340604.618 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-05-08T18:36:44.618Z,1557340604.618 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-05-08T18:37:04.910Z,1557340624.910 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-05-08T18:37:04.910Z,1557340624.910 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 3
2019-05-08T18:37:04.910Z,1557340624.910 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-05-08T18:37:05.098Z,1557340625.098 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-05-08T18:37:05.314Z,1557340625.314 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-05-08T18:37:06.429Z,1557340626.429 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-05-08T18:37:06.430Z,1557340626.430 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 3
2019-05-08T18:37:08.550Z,1557340628.550 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-05-08T18:37:08.550Z,1557340628.550 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-05-08T18:37:14.649Z,1557340634.649 [SBIT](IMPORTANT): SBIT PASSED
2019-05-08T18:37:14.706Z,1557340634.706 [CommandLine](IMPORTANT): got command configSet list
2019-05-08T18:37:14.707Z,1557340634.707 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-08T18:37:14.707Z,1557340634.707 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-05-08T18:37:14.708Z,1557340634.708 [CommandLine](IMPORTANT): PAR_Licor.adcCal=8.765e-06 microampere_per_count;

2019-05-08T18:37:14.708Z,1557340634.708 [CommandLine](IMPORTANT): PAR_Licor.darkCount=0 count;

2019-05-08T18:37:14.708Z,1557340634.708 [CommandLine](IMPORTANT): PAR_Licor.multiplier=190.3 micromole_per_second_per_square_meter_per_microampere;

2019-05-08T18:37:14.708Z,1557340634.708 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2019-05-08T18:37:15.058Z,1557340635.058 [MissionManager](IMPORTANT): Started mission Startup
2019-05-08T18:37:15.058Z,1557340635.058 [Startup] Running Loop=1
2019-05-08T18:37:15.058Z,1557340635.058 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-08T18:37:15.058Z,1557340635.058 [Startup:A.GoToSurface] Running Loop=1
2019-05-08T18:37:15.058Z,1557340635.058 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-08T18:37:15.059Z,1557340635.059 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-08T18:37:15.059Z,1557340635.059 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-08T18:37:15.060Z,1557340635.060 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-08T18:37:15.060Z,1557340635.060 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-08T18:37:15.060Z,1557340635.060 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-08T18:37:15.062Z,1557340635.062 [Startup:StartupSatComms] Running Loop=1
2019-05-08T18:37:15.062Z,1557340635.062 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-08T18:37:15.062Z,1557340635.062 [Startup:StartupSatComms:A] Running Loop=1
2019-05-08T18:37:15.450Z,1557340635.450 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-08T18:37:28.751Z,1557340648.751 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-05-08T18:37:28.751Z,1557340648.751 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 4
2019-05-08T18:37:28.751Z,1557340648.751 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-05-08T18:37:28.783Z,1557340648.783 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-05-08T18:37:29.153Z,1557340649.153 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-05-08T18:37:30.013Z,1557340650.013 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-05-08T18:37:30.013Z,1557340650.013 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 4
2019-05-08T18:37:32.381Z,1557340652.381 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-05-08T18:37:32.382Z,1557340652.382 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-05-08T18:37:52.586Z,1557340672.586 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-05-08T18:37:52.586Z,1557340672.586 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 5
2019-05-08T18:37:52.586Z,1557340672.586 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-05-08T18:37:52.618Z,1557340672.618 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-05-08T18:37:52.985Z,1557340672.985 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-05-08T18:37:53.842Z,1557340673.842 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-05-08T18:37:53.842Z,1557340673.842 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 5
2019-05-08T18:37:56.223Z,1557340676.223 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-05-08T18:37:56.223Z,1557340676.223 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-05-08T18:37:56.280Z,1557340676.280 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T18:37:56.281Z,1557340676.281 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-08T18:37:56.281Z,1557340676.281 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T18:37:56.292Z,1557340676.292 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T18:37:56.673Z,1557340676.673 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T18:37:56.673Z,1557340676.673 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-08T18:38:15.231Z,1557340695.231 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-08T18:37:15.1Z
2019-05-08T18:38:15.231Z,1557340695.231 [Startup:StartupSatComms:A] Stopped
2019-05-08T18:38:15.232Z,1557340695.232 [Startup:StartupSatComms:B] Running Loop=1
2019-05-08T18:38:15.639Z,1557340695.639 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-08T18:38:16.421Z,1557340696.421 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-05-08T18:38:16.422Z,1557340696.422 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 6
2019-05-08T18:38:16.422Z,1557340696.422 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-05-08T18:38:16.470Z,1557340696.470 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-05-08T18:38:16.827Z,1557340696.827 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-05-08T18:38:17.679Z,1557340697.679 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-05-08T18:38:17.679Z,1557340697.679 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 6
2019-05-08T18:38:20.057Z,1557340700.057 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-05-08T18:38:20.058Z,1557340700.058 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-05-08T18:38:34.523Z,1557340714.523 [CommandLine](IMPORTANT): got command show stack
2019-05-08T18:38:34.523Z,1557340714.523 [CommandLine](IMPORTANT): Behavior Stack:

2019-05-08T18:38:34.523Z,1557340714.523 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2019-05-08T18:38:34.523Z,1557340714.523 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B
2019-05-08T18:38:35.615Z,1557340715.615 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004983
2019-05-08T18:38:40.261Z,1557340720.261 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-05-08T18:38:40.262Z,1557340720.262 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 7
2019-05-08T18:38:40.262Z,1557340720.262 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-05-08T18:38:40.318Z,1557340720.318 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-05-08T18:38:40.665Z,1557340720.665 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-05-08T18:38:41.542Z,1557340721.542 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-05-08T18:38:41.542Z,1557340721.542 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 7
2019-05-08T18:38:42.969Z,1557340722.969 [DataOverHttps](INFO): Sending 302 bytes from file Logs/20190508T181751/Courier0007.lzma
2019-05-08T18:38:43.774Z,1557340723.774 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181751/Courier0007.lzma.bak
2019-05-08T18:38:43.775Z,1557340723.775 [DataOverHttps](INFO): SBD MOMSN=10975569
2019-05-08T18:38:43.901Z,1557340723.901 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-05-08T18:38:43.902Z,1557340723.902 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-05-08T18:38:57.813Z,1557340737.813 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20190508T183545/Courier0000.lzma
2019-05-08T18:38:58.618Z,1557340738.618 [DataOverHttps](INFO): Moved sent file to Logs/20190508T183545/Courier0000.lzma.bak
2019-05-08T18:38:58.618Z,1557340738.618 [DataOverHttps](INFO): SBD MOMSN=10975573
2019-05-08T18:39:04.106Z,1557340744.106 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-05-08T18:39:04.106Z,1557340744.106 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 8
2019-05-08T18:39:04.106Z,1557340744.106 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-05-08T18:39:04.163Z,1557340744.163 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-05-08T18:39:04.163Z,1557340744.163 [CBIT](FAULT): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-05-08T18:39:04.501Z,1557340744.501 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-05-08T18:39:12.911Z,1557340752.911 [DataOverHttps](INFO): Sending 1131 bytes from file Logs/20190508T181751/Express0008.lzma
2019-05-08T18:39:13.714Z,1557340753.714 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181751/Express0008.lzma.bak
2019-05-08T18:39:13.715Z,1557340753.715 [DataOverHttps](INFO): SBD MOMSN=10975578
2019-05-08T18:39:15.469Z,1557340755.469 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-08T18:38:15.2Z
2019-05-08T18:39:15.469Z,1557340755.469 [Startup:StartupSatComms:B] Stopped
2019-05-08T18:39:15.469Z,1557340755.469 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-08T18:39:15.469Z,1557340755.469 [Startup:StartupSatComms] Stopped
2019-05-08T18:39:15.470Z,1557340755.470 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-08T18:39:15.470Z,1557340755.470 [Startup](INFO): Completed Startup
2019-05-08T18:39:15.470Z,1557340755.470 [MissionManager](INFO): Startup is completed.
2019-05-08T18:39:15.471Z,1557340755.471 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-08T18:39:15.471Z,1557340755.471 [Startup] Stopped
2019-05-08T18:39:15.471Z,1557340755.471 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-08T18:39:15.471Z,1557340755.471 [Startup:A.GoToSurface] Stopped
2019-05-08T18:39:15.471Z,1557340755.471 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-08T18:39:15.846Z,1557340755.846 [MissionManager](IMPORTANT): Started mission Default
2019-05-08T18:39:15.846Z,1557340755.846 [Default] Running Loop=1
2019-05-08T18:39:15.846Z,1557340755.846 [Default](DEBUG): Aggregate::initialize Default
2019-05-08T18:39:15.846Z,1557340755.846 [Default:B.GoToSurface] Running Loop=1
2019-05-08T18:39:15.846Z,1557340755.846 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-08T18:39:15.846Z,1557340755.846 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-08T18:39:15.847Z,1557340755.847 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-08T18:39:15.847Z,1557340755.847 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-08T18:39:15.847Z,1557340755.847 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-08T18:39:15.848Z,1557340755.848 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-08T18:39:15.848Z,1557340755.848 [Default:A.Wait] Running Loop=1
2019-05-08T18:39:15.848Z,1557340755.848 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:39:29.172Z,1557340769.172 [Default:A.Wait](INFO): Done Waiting.
2019-05-08T18:39:29.172Z,1557340769.172 [Default:A.Wait] Stopped
2019-05-08T18:39:29.172Z,1557340769.172 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:39:29.579Z,1557340769.579 [Default:CheckIn] Running Loop=1
2019-05-08T18:39:29.579Z,1557340769.579 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-08T18:39:29.579Z,1557340769.579 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-08T18:39:29.914Z,1557340769.914 [CommandLine](IMPORTANT): got command run ./Missions/test.xml
2019-05-08T18:39:29.914Z,1557340769.914 [MissionManager](INFO): Loading Mission: ./Missions/test.xml
2019-05-08T18:39:30.047Z,1557340770.047 [MissionManager](INFO): DefineArg SampleAtDepth.TargetDepth = 5.000000 m
2019-05-08T18:39:30.051Z,1557340770.051 [MissionManager](INFO): DefineArg SampleAtDepth.SettleTime = 10.000000 s
2019-05-08T18:39:30.054Z,1557340770.054 [MissionManager](INFO): DefineArg SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h
2019-05-08T18:39:30.057Z,1557340770.057 [MissionManager](INFO): DefineArg SampleAtDepth.RotateOnly = 0.000000 bool
2019-05-08T18:39:30.061Z,1557340770.061 [MissionManager](INFO): DefineArg SampleAtDepth.UseCANONSampler = 0.000000 bool
2019-05-08T18:39:30.065Z,1557340770.065 [MissionManager](INFO): DefineArg SampleAtDepth.UseESP = 1.000000 bool
2019-05-08T18:39:30.069Z,1557340770.069 [MissionManager](INFO): DefineArg SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min
2019-05-08T18:39:30.073Z,1557340770.073 [MissionManager](INFO): DefineArg SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2019-05-08T18:39:30.078Z,1557340770.078 [MissionManager](INFO): DefineArg SampleAtDepth.BuoyancyNeutral = 134.999995 cc
2019-05-08T18:39:30.082Z,1557340770.082 [SampleAtDepth:ApproachDepth:B.Pitch](DEBUG): Construct.
2019-05-08T18:39:30.089Z,1557340770.089 [SampleAtDepth:ApproachDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-05-08T18:39:30.092Z,1557340770.092 [SampleAtDepth:SampleWrapper:A.Pitch](DEBUG): Construct.
2019-05-08T18:39:30.099Z,1557340770.099 [SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Construct Wait.
2019-05-08T18:39:30.108Z,1557340770.108 [SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-05-08T18:39:30.111Z,1557340770.111 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2019-05-08T18:39:30.111Z,1557340770.111 [MissionManager](ERROR): Slate does not contain celsius
2019-05-08T18:39:30.116Z,1557340770.116 [SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-05-08T18:39:30.166Z,1557340770.166 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2019-05-08T18:39:30.167Z,1557340770.167 [MissionManager](ERROR): Slate does not contain celsius
2019-05-08T18:39:30.192Z,1557340770.192 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Aggregate xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
           xmlns="Tethys"
           xmlns:Units="Tethys/Units"
           xmlns:Universal="Tethys/Universal"
           xmlns:Control="Tethys/Control"
           xmlns:Guidance="Tethys/Guidance"
           xmlns:Science="Tethys/Science"
           xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                               Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                               Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd
                               Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                               Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                               Tethys/Science http://okeanids.mbari.org/tethys/Xml/Science.xsd"
       Id="SampleAtDepth">

    <Description>
        Take a water sample at a specified depth.
    </Description>

    <DefineArg Name="TargetDepth"><Description>
        Depth to sample at. Initialized to 5 m.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="SettleTime"><Description>
        Time to wait after reaching target depth before triggering sample.
        Initialized to 10 minutes.
    </Description><Units:second/><Value>10</Value></DefineArg>

    <DefineArg Name="MaxWaitNotReachingDepth"><Description>
        Maximum wait time the vehicle cannot reach the targeted depth.
        Initialized to 3 hours.
    </Description><Units:hour/><Value>3</Value></DefineArg>

    <DefineArg Name="RotateOnly"><Units:bool/><Value>0</Value></DefineArg>

    <DefineArg Name="UseCANONSampler"><Description>
        Whether to use CANON Sampler to sample.
    </Description><Science:CANONSampler.loadAtStartup/></DefineArg>

    <DefineArg Name="UseESP"><Description>
        Whether to use ESP to sample.
    </Description><Science:ESPComponent.loadAtStartup/></DefineArg>

    <DefineArg Name="CANONSamplerTriggerTimeout"><Description>
        How long to wait for a CANON Sampler sample to start.
    </Description><Units:minute/><Value>1</Value></DefineArg>

    <DefineArg Name="CANONSamplerTimeout"><Description>
        How long to wait for a CANON Sampler sample to complete.
    </Description><Science:CANONSampler.sampleTimeout/></DefineArg>

    <DefineArg Name="BuoyancyNeutral"><Description>
        Buoyancy bladder position during spiral or donut. Defaults to
        buoyancyNeutral setting in the Config/Control.cfg file. Set to NaN cc
        for active buoyancy
    </Description><Control:VerticalControl.buoyancyNeutral/></DefineArg>

    <When>
        <Called/>
    </When>

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

        <Syslog>Moving to <Arg Name="TargetDepth"/><Units:meter/></Syslog>

        <Guidance:Pitch>
            <Sequence/>
            <Timeout Duration="MaxWaitNotReachingDepth">
                <Syslog Severity="Important">Timed out trying to reach the targeted depth. Stopping mission.</Syslog>

                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>stop</String></Setting>
                </Guidance:Execute>
            </Timeout>
            <Setting><Guidance:Pitch.depth/><Arg Name="TargetDepth"/></Setting>
        </Guidance:Pitch>
    </Aggregate>

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

        <Guidance:Pitch>
            <Parallel/>
            <Setting><Guidance:Pitch.depth/><Arg Name="TargetDepth"/></Setting>
        </Guidance:Pitch>

        <Syslog Severity="Important">At <Universal:depth/><Units:meter/>, settling for <Arg Name="SettleTime"/><Units:minute/></Syslog>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Arg Name="SettleTime"/></Setting>
        </Guidance:Wait>

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

            <Break>
                <Not><Arg Name="UseCANONSampler"/></Not>
            </Break>

            <Assign><Parallel/><Science:CANONSampler.sampleTimeout/><Arg Name="CANONSamplerTimeout"/></Assign>

            <Assign><Parallel/><Science:CANONSampler.rotateOnly/><Arg Name="RotateOnly"/></Assign>

            <ReadDatum Id="TriggerCANONSampler">
                <Timeout Duration="CANONSamplerTriggerTimeout">
                    <Syslog Severity="Important">Timed out triggering CANONSampler. Stopping mission.</Syslog>

                    <Guidance:Execute>
                        <Sequence/>
                        <Setting><Guidance:Execute.command/><String>stop</String></Setting>
                    </Guidance:Execute>
                </Timeout>
                <Science:CANONSampler.sampling/>
            </ReadDatum>

            <Syslog Severity="Important">CANONSampler sampling at <Universal:depth/><Units:meter/> in <Science:CTD_NeilBrown.bin_mean_sea_water_temperature/><Units:celsius/> water with <Science:WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water/><Units:microgram_per_liter/> chlorophyll fluorescence.</Syslog>

            <ReadDatum>
                <Timeout Duration="CANONSamplerTimeout">
                    <Syslog Severity="Important">Timed out sampling with CANONSampler. Stopping mission.</Syslog>

                    <Guidance:Execute>
                        <Sequence/>
                        <Setting><Guidance:Execute.command/><String>stop</String></Setting>
                    </Guidance:Execute>
                </Timeout>
                <Science:CANONSampler.sample_number/>
            </ReadDatum>
        </Aggregate>

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

            <Break>
                <Not><Arg Name="UseESP"/></Not>
            </Break>

            <ReadDatum Id="TriggerESP">
                <Science:ESPComponent.sampling/>
            </ReadDatum>

            <Syslog Severity="Important">ESP sampling at <Universal:depth/><Units:meter/> in <Science:CTD_NeilBrown.bin_mean_sea_water_temperature/><Units:celsius/> water with <Science:WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water/><Units:microgram_per_liter/>chlorophyll fluorescence.</Syslog>

            <ReadDatum Id="WaitForESP">
                <Science:ESPComponent.sample_number/>
            </ReadDatum>
        </Aggregate>

        <Aggregate Id="TestEndFiltering">
            <Parallel/>
            <Timeout Duration="P1M">
                <Syslog Severity="Important">Timed out to test filtering-to-processing transition</Syslog>
                <Assign><Parallel/><Science:ESPComponent.endFiltering/><True/></Assign>
            </Timeout>
        </Aggregate>

    </Aggregate>
</Aggregate>


2019-05-08T18:39:30.194Z,1557340770.194 [CommandLine](IMPORTANT): Running ./Missions/test.xml
2019-05-08T18:39:30.422Z,1557340770.422 [Default] Stopped
2019-05-08T18:39:30.422Z,1557340770.422 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-08T18:39:30.422Z,1557340770.422 [Default:B.GoToSurface] Stopped
2019-05-08T18:39:30.422Z,1557340770.422 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-08T18:39:30.422Z,1557340770.422 [Default:CheckIn] Stopped
2019-05-08T18:39:30.422Z,1557340770.422 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-08T18:39:30.422Z,1557340770.422 [Default:CheckIn:Read_GPS] Stopped
2019-05-08T18:39:30.423Z,1557340770.423 [MissionManager](IMPORTANT): Started mission SampleAtDepth
2019-05-08T18:39:30.423Z,1557340770.423 [SampleAtDepth] Running Loop=1
2019-05-08T18:39:30.423Z,1557340770.423 [SampleAtDepth](DEBUG): Aggregate::initialize SampleAtDepth
2019-05-08T18:39:30.423Z,1557340770.423 [SampleAtDepth:ApproachDepth] Running Loop=1
2019-05-08T18:39:30.423Z,1557340770.423 [SampleAtDepth:ApproachDepth](DEBUG): Aggregate::initialize SampleAtDepth:ApproachDepth
2019-05-08T18:39:30.423Z,1557340770.423 [SampleAtDepth:ApproachDepth:A] Running Loop=1
2019-05-08T18:39:30.424Z,1557340770.424 [SampleAtDepth:ApproachDepth:A](INFO): Moving to 5.000000 m 
2019-05-08T18:39:30.424Z,1557340770.424 [SampleAtDepth:ApproachDepth:A] Stopped
2019-05-08T18:39:30.424Z,1557340770.424 [SampleAtDepth:ApproachDepth:B.Pitch] Running Loop=1
2019-05-08T18:39:30.424Z,1557340770.424 [SampleAtDepth:ApproachDepth:B.Pitch](DEBUG): Initialize.
2019-05-08T18:39:36.858Z,1557340776.858 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 5.000000 meter
2019-05-08T18:39:36.859Z,1557340776.859 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2019-05-08T18:39:36.939Z,1557340776.939 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-08T18:39:37.251Z,1557340777.251 [SampleAtDepth:ApproachDepth:B.Pitch] Stopped
2019-05-08T18:39:37.251Z,1557340777.251 [SampleAtDepth:ApproachDepth](INFO): Completed SampleAtDepth:ApproachDepth
2019-05-08T18:39:37.251Z,1557340777.251 [SampleAtDepth:ApproachDepth] Stopped
2019-05-08T18:39:37.252Z,1557340777.252 [SampleAtDepth:ApproachDepth](DEBUG): Aggregate::uninitialize SampleAtDepth:ApproachDepth
2019-05-08T18:39:37.252Z,1557340777.252 [SampleAtDepth:SampleWrapper] Running Loop=1
2019-05-08T18:39:37.252Z,1557340777.252 [SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize SampleAtDepth:SampleWrapper
2019-05-08T18:39:37.252Z,1557340777.252 [SampleAtDepth:SampleWrapper:A.Pitch] Running Loop=1
2019-05-08T18:39:37.252Z,1557340777.252 [SampleAtDepth:SampleWrapper:A.Pitch](DEBUG): Initialize.
2019-05-08T18:39:37.252Z,1557340777.252 [SampleAtDepth:SampleWrapper:TestEndFiltering] Running Loop=1
2019-05-08T18:39:37.252Z,1557340777.252 [SampleAtDepth:SampleWrapper:TestEndFiltering](DEBUG): Aggregate::initialize SampleAtDepth:SampleWrapper:TestEndFiltering
2019-05-08T18:39:37.252Z,1557340777.252 [SampleAtDepth:SampleWrapper:B] Running Loop=1
2019-05-08T18:39:37.662Z,1557340777.662 [SampleAtDepth:SampleWrapper:TestEndFiltering] Running Loop=1
2019-05-08T18:39:37.662Z,1557340777.662 [SampleAtDepth:SampleWrapper:B](IMPORTANT): At 5.000000 m , settling for 0.166667 min 
2019-05-08T18:39:37.663Z,1557340777.663 [SampleAtDepth:SampleWrapper:B] Stopped
2019-05-08T18:39:37.663Z,1557340777.663 [SampleAtDepth:SampleWrapper:C.Wait] Running Loop=1
2019-05-08T18:39:37.663Z,1557340777.663 [SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:39:37.663Z,1557340777.663 [SampleAtDepth:SampleWrapper:A.Pitch] Running Loop=1
2019-05-08T18:39:48.158Z,1557340788.158 [SampleAtDepth:SampleWrapper:C.Wait](INFO): Done Waiting.
2019-05-08T18:39:48.158Z,1557340788.158 [SampleAtDepth:SampleWrapper:C.Wait] Stopped
2019-05-08T18:39:48.158Z,1557340788.158 [SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:39:48.159Z,1557340788.159 [SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1
2019-05-08T18:39:48.159Z,1557340788.159 [SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize SampleAtDepth:SampleWrapper:SampleCANONSampler
2019-05-08T18:39:48.159Z,1557340788.159 [SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2019-05-08T18:39:48.159Z,1557340788.159 [SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2019-05-08T18:39:48.159Z,1557340788.159 [SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1
2019-05-08T18:39:48.566Z,1557340788.566 [SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped
2019-05-08T18:39:48.566Z,1557340788.566 [SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize SampleAtDepth:SampleWrapper:SampleCANONSampler
2019-05-08T18:39:48.566Z,1557340788.566 [SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped
2019-05-08T18:39:48.567Z,1557340788.567 [SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped
2019-05-08T18:39:48.567Z,1557340788.567 [SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped
2019-05-08T18:39:48.567Z,1557340788.567 [SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1
2019-05-08T18:39:48.567Z,1557340788.567 [SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize SampleAtDepth:SampleWrapper:SampleESP
2019-05-08T18:39:48.567Z,1557340788.567 [SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1
2019-05-08T18:39:48.973Z,1557340788.973 [SampleAtDepth:SampleWrapper:SampleESP:TriggerESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sampling
2019-05-08T18:39:49.746Z,1557340789.746 [ESPComponent](IMPORTANT): Setting regex for ESP Log summary: 'Selecting Cartridge|Sampled|Error|Fail|Retry|Cmd::|Sampler::'
2019-05-08T18:39:49.748Z,1557340789.748 [ESPComponent](INFO): compiled regex: "Selecting Cartridge|Sampled|Error|Fail|Retry|Cmd::|Sampler::"
2019-05-08T18:39:50.152Z,1557340790.152 [ESPComponent](INFO): powering up ESP. espAlwaysServer_ = 0
2019-05-08T18:39:50.152Z,1557340790.152 [ESPComponent](INFO): manually powering up ESP
2019-05-08T18:39:50.154Z,1557340790.154 [ESPComponent](IMPORTANT): Powered ESP with command: ! echo 1 > /dev/loadA6
2019-05-08T18:39:50.155Z,1557340790.155 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyTX1 linkname esp noauth local lock 115200 10.89.5.2:10.89.5.3 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 8.8.8.8
2019-05-08T18:39:50.229Z,1557340790.229 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadA6
2019-05-08T18:39:50.482Z,1557340790.482 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=150.0000)
2019-05-08T18:39:50.641Z,1557340790.641 [ESPComponent](INFO): console:
2019-05-08T18:39:51.789Z,1557340791.789 [ESPComponent](INFO): console:

2019-05-08T18:39:52.194Z,1557340792.194 [ESPComponent](INFO): console:NAND:  256 MiB
2019-05-08T18:39:52.598Z,1557340792.598 [ESPComponent](INFO): console:
BOOTMODE: SPI
2019-05-08T18:39:53.075Z,1557340793.075 [DataOverHttps](INFO): Sending 997 bytes from file Logs/20190508T183545/Express0001.lzma
2019-05-08T18:39:53.079Z,1557340793.079 [ESPComponent](INFO): console:
reading SPI NOR..
2019-05-08T18:39:53.878Z,1557340793.878 [DataOverHttps](INFO): Moved sent file to Logs/20190508T183545/Express0001.lzma.bak
2019-05-08T18:39:53.879Z,1557340793.879 [DataOverHttps](INFO): SBD MOMSN=10975615
2019-05-08T18:39:54.214Z,1557340794.214 [ESPComponent](INFO): console:Done
2019-05-08T18:39:54.618Z,1557340794.618 [ESPComponent](INFO): console:

2019-05-08T18:39:55.022Z,1557340795.022 [ESPComponent](INFO): console:

2019-05-08T18:39:55.426Z,1557340795.426 [ESPComponent](INFO): console:
U-Boot 2009.11-mbariB (Dec 14 2018 - 09:20:52)
2019-05-08T18:39:55.830Z,1557340795.830 [ESPComponent](INFO): console:

2019-05-08T18:39:56.234Z,1557340796.234 [ESPComponent](INFO): console:
MBARI LPC31xx ESP 3G
2019-05-08T18:39:56.638Z,1557340796.638 [ESPComponent](INFO): console:
flash params are already written into flash
2019-05-08T18:39:57.042Z,1557340797.042 [ESPComponent](INFO): console:
DRAM:  64 MB
2019-05-08T18:39:57.090Z,1557340797.091 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T18:39:57.091Z,1557340797.091 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-05-08T18:39:57.091Z,1557340797.091 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T18:39:57.105Z,1557340797.105 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T18:39:57.446Z,1557340797.446 [ESPComponent](INFO): console:
In:    serial
2019-05-08T18:39:57.504Z,1557340797.504 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T18:39:57.504Z,1557340797.504 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-05-08T18:39:57.850Z,1557340797.850 [ESPComponent](INFO): console:
Out:   serial
2019-05-08T18:39:58.254Z,1557340798.254 [ESPComponent](INFO): console:
Err:   serial
2019-05-08T18:39:58.658Z,1557340798.658 [ESPComponent](INFO): console:
Net:   ks8851_mll
2019-05-08T18:39:59.279Z,1557340799.279 [ESPComponent](INFO): console:
Hit <ctrl-C> to stop autoboot:  1  0 
2019-05-08T18:39:59.670Z,1557340799.670 [ESPComponent](INFO): console:
mmc1 is available
2019-05-08T18:40:00.075Z,1557340800.075 [ESPComponent](INFO): console:
reading uImage
2019-05-08T18:40:00.478Z,1557340800.478 [ESPComponent](INFO): console:

2019-05-08T18:40:00.882Z,1557340800.882 [ESPComponent](INFO): console:
1681452 bytes read
2019-05-08T18:40:01.286Z,1557340801.286 [ESPComponent](INFO): console:
## Booting kernel from Legacy Image at 31000000 ...
2019-05-08T18:40:01.691Z,1557340801.691 [ESPComponent](INFO): console:
   Image Name:   Linux-2.6.33-ea3131-mbari6
2019-05-08T18:40:02.095Z,1557340802.095 [ESPComponent](INFO): console:
   Image Type:   ARM Linux Kernel Image (uncompressed)
2019-05-08T18:40:02.498Z,1557340802.498 [ESPComponent](INFO): console:
   Data Size:    1681388 Bytes =  1.6 MB
2019-05-08T18:40:02.902Z,1557340802.902 [ESPComponent](INFO): console:
   Load Address: 30008000
2019-05-08T18:40:03.306Z,1557340803.306 [ESPComponent](INFO): console:
   Entry Point:  30008000
2019-05-08T18:40:03.710Z,1557340803.710 [ESPComponent](INFO): console:
   Verifying Checksum ... OK
2019-05-08T18:40:04.114Z,1557340804.114 [ESPComponent](INFO): console:
   Loading Kernel Image ... OK
2019-05-08T18:40:04.518Z,1557340804.518 [ESPComponent](INFO): console:
OK
2019-05-08T18:40:04.922Z,1557340804.922 [ESPComponent](INFO): console:

2019-05-08T18:40:05.326Z,1557340805.326 [ESPComponent](INFO): console:
Starting kernel ...
2019-05-08T18:40:05.730Z,1557340805.730 [ESPComponent](INFO): console:

2019-05-08T18:40:06.134Z,1557340806.134 [ESPComponent](INFO): console:
Uncompressing Linux... done, booting the kernel.
2019-05-08T18:40:06.539Z,1557340806.539 [ESPComponent](INFO): console:
[    0.00] CPU: ARM926EJ-S [41069265] revision 5 (ARMv5TEJ), cr=00053177
2019-05-08T18:40:06.942Z,1557340806.942 [ESPComponent](INFO): console:
[    0.00] CPU: VIVT data cache, VIVT instruction cache
2019-05-08T18:40:07.346Z,1557340807.346 [ESPComponent](INFO): console:
[    0.00] Machine: NXP EA313X
2019-05-08T18:40:07.751Z,1557340807.751 [ESPComponent](INFO): console:
[    0.00] Memory policy: ECC disabled, Data cache writeback
2019-05-08T18:40:08.155Z,1557340808.155 [ESPComponent](INFO): console:
[    0.00] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 16256
2019-05-08T18:40:08.559Z,1557340808.559 [ESPComponent](INFO): console:
[    0.24] Mount-cache hash table entries: 512
2019-05-08T18:40:08.962Z,1557340808.962 [ESPComponent](INFO): console:
[    0.30] MBARI ESP 3G
2019-05-08T18:40:09.367Z,1557340809.367 [ESPComponent](INFO): console:
[    0.40] bio: create slab <bio-0> at 0
2019-05-08T18:40:09.771Z,1557340809.771 [ESPComponent](INFO): console:
[    0.45] NetWinder Floating Point Emulator V0.97 (double precision)
2019-05-08T18:40:10.175Z,1557340810.175 [ESPComponent](INFO): console:
[    0.47] yaffs Dec 14 2018 09:19:05 Installing. 
2019-05-08T18:40:10.578Z,1557340810.578 [ESPComponent](INFO): console:
[    0.61] m25p80 spi0.3: m25p80 found s25sl032a flash
2019-05-08T18:40:10.983Z,1557340810.983 [ESPComponent](INFO): console:
[    2.13] VFS: Mounted root (ext2 filesystem) readonly on device 179:2.
2019-05-08T18:40:11.386Z,1557340811.386 [ESPComponent](INFO): console:

2019-05-08T18:40:11.790Z,1557340811.790 [ESPComponent](INFO): console:INIT: version 2.85 booting
2019-05-08T18:40:12.194Z,1557340812.194 [ESPComponent](INFO): console:

2019-05-08T18:40:12.599Z,1557340812.599 [ESPComponent](INFO): console:MBARI ESP Embedded Linux    http://www.mbari.org   mailto:brent@mbari.org
2019-05-08T18:40:13.002Z,1557340813.002 [ESPComponent](INFO): console:
ESPlrauvSIM
2019-05-08T18:40:13.405Z,1557340813.405 [ESPComponent](INFO): console:

2019-05-08T18:40:13.810Z,1557340813.810 [ESPComponent](INFO): console:INIT: Entering runlevel: 3
2019-05-08T18:40:14.214Z,1557340814.214 [ESPComponent](INFO): console:

2019-05-08T18:40:14.618Z,1557340814.618 [ESPComponent](INFO): console:Loading kernel modules
2019-05-08T18:40:15.023Z,1557340815.023 [ESPComponent](INFO): console:
Mounting filesystems and adding swapfiles listed in /etc/fstab
2019-05-08T18:40:15.426Z,1557340815.426 [ESPComponent](INFO): console:
mount: /dev/mmcblk0p2 already mounted or /card busy
2019-05-08T18:40:15.831Z,1557340815.831 [ESPComponent](INFO): console:
Starting hotplug events dispatcher udevd
2019-05-08T18:40:16.235Z,1557340816.235 [ESPComponent](INFO): console:
Set system clock to:  Wed May  8 11:32:56 PDT 2019
2019-05-08T18:40:16.638Z,1557340816.638 [ESPComponent](INFO): console:
Starting syslogd klogd...
2019-05-08T18:40:17.042Z,1557340817.042 [ESPComponent](INFO): console:
Bringing up interface lo ...
2019-05-08T18:40:17.446Z,1557340817.446 [ESPComponent](INFO): console:
lo IP=127.0.0.1
2019-05-08T18:40:17.851Z,1557340817.851 [ESPComponent](INFO): console:
Packet forwarding enabled
2019-05-08T18:40:18.254Z,1557340818.254 [ESPComponent](INFO): console:
Bringing up interface ppp2 ...
2019-05-08T18:40:18.658Z,1557340818.658 [ESPComponent](INFO): console:
Bringing up interface eth0 ...
2019-05-08T18:40:19.063Z,1557340819.063 [ESPComponent](INFO): console:
Determining IP configuration for eth0....udhcpc (v1.11.2) started
2019-05-08T18:40:19.466Z,1557340819.466 [ESPComponent](INFO): console:
Sending discover...
2019-05-08T18:40:19.870Z,1557340819.870 [ESPComponent](INFO): console:
Sending discover...
2019-05-08T18:40:20.274Z,1557340820.274 [ESPComponent](INFO): console:
Sending discover...
2019-05-08T18:40:20.678Z,1557340820.678 [ESPComponent](INFO): console:
No lease, forking to background
2019-05-08T18:40:21.082Z,1557340821.082 [ESPComponent](INFO): console:
Bringing up interface eth0:10 ...
2019-05-08T18:40:21.486Z,1557340821.486 [ESPComponent](INFO): console:
eth0:10 IP=10.10.10.10
2019-05-08T18:40:21.890Z,1557340821.890 [ESPComponent](INFO): console:
Starting portmap...
2019-05-08T18:40:22.295Z,1557340822.295 [ESPComponent](INFO): console:
Clock sycn'd with us.pool.ntp.org at Wed May  8 11:33:08 PDT 2019 via ntp
2019-05-08T18:40:22.697Z,1557340822.697 [ESPComponent](IMPORTANT): ESP has connected as client
2019-05-08T18:40:23.511Z,1557340823.511 [ESPComponent](IMPORTANT): [sample #1] Explicit cartridge argument not given
2019-05-08T18:40:23.512Z,1557340823.512 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence starting. Sampling state: S_WAITING_INITIAL_PROMPT
2019-05-08T18:40:23.512Z,1557340823.512 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=1
2019-05-08T18:40:23.581Z,1557340823.581 [SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped
2019-05-08T18:40:23.582Z,1557340823.582 [SampleAtDepth:SampleWrapper:SampleESP:B] Running Loop=1
2019-05-08T18:40:23.954Z,1557340823.954 [SampleAtDepth:SampleWrapper:SampleESP:B](ERROR): data element is not active.
2019-05-08T18:40:23.954Z,1557340823.954 [SampleAtDepth:SampleWrapper:SampleESP:B](IMPORTANT): ESP sampling at 5.000000 m inwater with nan ug/l chlorophyll fluorescence.
2019-05-08T18:40:23.954Z,1557340823.954 [SampleAtDepth:SampleWrapper:SampleESP:B] Stopped
2019-05-08T18:40:23.954Z,1557340823.954 [SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Running Loop=1
2019-05-08T18:40:24.358Z,1557340824.358 [SampleAtDepth:SampleWrapper:SampleESP:WaitForESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sample_number
2019-05-08T18:40:24.718Z,1557340824.718 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_LOG
2019-05-08T18:40:25.122Z,1557340825.122 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_STATUS
2019-05-08T18:40:26.738Z,1557340826.738 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_LOADING_CARTRIDGE
2019-05-08T18:40:28.760Z,1557340828.760 [ESPComponent](ERROR): In state S_LOADING_CARTRIDGE got exception while awaiting result for cmd='Cmd.loadCartridge' exception=<<Cartridge::None in LRAUV -- No dry cartridges remain
>>. Elapsed time since command issued: 2.4241
2019-05-08T18:40:29.162Z,1557340829.162 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_STOPPING
2019-05-08T18:40:31.587Z,1557340831.587 [ESPComponent](CRITICAL): [sample #1] ESP sampling sequence terminated with error: In state S_LOADING_CARTRIDGE got exception while awaiting result for cmd='Cmd.loadCartridge' exception=<<Cartridge::None in LRAUV -- No dry cartridges remain
>>. Elapsed time since command issued: 2.4241
2019-05-08T18:40:31.587Z,1557340831.587 [ESPComponent] Communications Fault, FailCount= 1
2019-05-08T18:40:31.587Z,1557340831.587 [ESPComponent](ERROR): Communications Fault
2019-05-08T18:40:31.622Z,1557340831.622 [CBIT](INFO): Critical error at 20190508T184031
2019-05-08T18:40:31.622Z,1557340831.622 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-05-08T18:40:31.625Z,1557340831.625 [CBIT](ERROR): Communications Fault in component: ESPComponent
2019-05-08T18:40:31.990Z,1557340831.990 [ESPComponent](IMPORTANT): [sample #1] No ESP summary messages.
2019-05-08T18:40:31.990Z,1557340831.990 [ESPComponent](INFO): powering down ESP
2019-05-08T18:40:32.148Z,1557340832.148 [MissionManager](INFO): MissionManager is completed.
2019-05-08T18:40:32.149Z,1557340832.149 [MissionManager](INFO): Uninitializing Mission SampleAtDepth
2019-05-08T18:40:32.149Z,1557340832.149 [SampleAtDepth] Stopped
2019-05-08T18:40:32.149Z,1557340832.149 [SampleAtDepth](DEBUG): Aggregate::uninitialize SampleAtDepth
2019-05-08T18:40:32.150Z,1557340832.150 [SampleAtDepth:SampleWrapper] Stopped
2019-05-08T18:40:32.150Z,1557340832.150 [SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize SampleAtDepth:SampleWrapper
2019-05-08T18:40:32.150Z,1557340832.150 [SampleAtDepth:SampleWrapper:A.Pitch] Stopped
2019-05-08T18:40:32.150Z,1557340832.150 [SampleAtDepth:SampleWrapper:SampleESP] Stopped
2019-05-08T18:40:32.150Z,1557340832.150 [SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize SampleAtDepth:SampleWrapper:SampleESP
2019-05-08T18:40:32.150Z,1557340832.150 [SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Stopped
2019-05-08T18:40:32.150Z,1557340832.150 [SampleAtDepth:SampleWrapper:TestEndFiltering] Stopped
2019-05-08T18:40:32.150Z,1557340832.150 [SampleAtDepth:SampleWrapper:TestEndFiltering](DEBUG): Aggregate::uninitialize SampleAtDepth:SampleWrapper:TestEndFiltering
2019-05-08T18:40:32.436Z,1557340832.436 [MissionManager](IMPORTANT): Started mission Default
2019-05-08T18:40:32.437Z,1557340832.437 [Default] Running Loop=1
2019-05-08T18:40:32.437Z,1557340832.437 [Default](DEBUG): Aggregate::initialize Default
2019-05-08T18:40:32.437Z,1557340832.437 [Default:B.GoToSurface] Running Loop=1
2019-05-08T18:40:32.437Z,1557340832.437 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-08T18:40:32.437Z,1557340832.437 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-08T18:40:32.438Z,1557340832.438 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-08T18:40:32.438Z,1557340832.438 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-08T18:40:32.438Z,1557340832.438 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-08T18:40:32.439Z,1557340832.439 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-08T18:40:32.439Z,1557340832.439 [Default:A.Wait] Running Loop=1
2019-05-08T18:40:32.439Z,1557340832.439 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:40:33.169Z,1557340833.169 [BuoyancyServo](ERROR): getPosition uart error serial timeout
2019-05-08T18:40:33.169Z,1557340833.169 [BuoyancyServo](FAULT): Buoyancy getPosition uart error.serial timeout
2019-05-08T18:40:33.169Z,1557340833.169 [BuoyancyServo] Communications Fault, FailCount= 1
2019-05-08T18:40:33.169Z,1557340833.169 [BuoyancyServo](ERROR): Communications Fault
2019-05-08T18:40:33.175Z,1557340833.175 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2019-05-08T18:40:33.175Z,1557340833.175 [CBIT](INFO): Clearing failed state for component ESPComponent
2019-05-08T18:40:33.175Z,1557340833.175 [ESPComponent] No Fault, FailCount= 1
2019-05-08T18:40:33.606Z,1557340833.606 [ESPComponent](IMPORTANT): [sample #1] No ESP summary messages.
2019-05-08T18:40:33.606Z,1557340833.606 [ESPComponent](INFO): powering down ESP
2019-05-08T18:40:34.892Z,1557340834.892 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-08T18:40:34.892Z,1557340834.892 [BuoyancyServo](INFO): Powering down
2019-05-08T18:40:35.745Z,1557340835.745 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2019-05-08T18:40:35.746Z,1557340835.746 [BuoyancyServo] No Fault, FailCount= 1
2019-05-08T18:40:36.099Z,1557340836.099 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-08T18:40:36.100Z,1557340836.100 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-08T18:40:37.002Z,1557340837.002 [CommandLine](IMPORTANT): got command maintain clear
2019-05-08T18:40:37.028Z,1557340837.028 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-08T18:40:45.805Z,1557340845.805 [Default:A.Wait](INFO): Done Waiting.
2019-05-08T18:40:45.805Z,1557340845.805 [Default:A.Wait] Stopped
2019-05-08T18:40:45.805Z,1557340845.805 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:40:46.223Z,1557340846.223 [Default:CheckIn] Running Loop=1
2019-05-08T18:40:46.223Z,1557340846.223 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-08T18:40:46.223Z,1557340846.223 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-08T18:40:46.606Z,1557340846.606 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-08T18:41:37.472Z,1557340897.472 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-05-08T18:41:38.301Z,1557340898.301 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:41:40.757Z,1557340900.757 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:41:40.757Z,1557340900.757 [PNI_TCM] No Fault, FailCount= 5
2019-05-08T18:41:42.341Z,1557340902.341 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:41:45.569Z,1557340905.569 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:41:48.401Z,1557340908.401 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:41:48.416Z,1557340908.416 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:41:48.416Z,1557340908.416 [PNI_TCM] Data Fault, FailCount= 1
2019-05-08T18:41:48.416Z,1557340908.416 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:41:48.473Z,1557340908.473 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:41:48.819Z,1557340908.819 [PNI_TCM](INFO): Powering down
2019-05-08T18:41:50.033Z,1557340910.033 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:41:50.033Z,1557340910.033 [PNI_TCM] No Fault, FailCount= 1
2019-05-08T18:41:51.225Z,1557340911.225 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:41:53.241Z,1557340913.241 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:41:55.269Z,1557340915.269 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:41:57.690Z,1557340917.690 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:41:57.690Z,1557340917.690 [PNI_TCM] Data Fault, FailCount= 2
2019-05-08T18:41:57.690Z,1557340917.690 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:41:57.734Z,1557340917.734 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:41:58.094Z,1557340918.094 [PNI_TCM](INFO): Powering down
2019-05-08T18:41:58.192Z,1557340918.192 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T18:41:58.192Z,1557340918.192 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-05-08T18:41:58.192Z,1557340918.192 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T18:41:58.203Z,1557340918.203 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T18:41:58.501Z,1557340918.501 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:41:58.548Z,1557340918.548 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T18:41:58.548Z,1557340918.548 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-05-08T18:41:59.342Z,1557340919.342 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:41:59.342Z,1557340919.342 [PNI_TCM] No Fault, FailCount= 2
2019-05-08T18:42:01.329Z,1557340921.329 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:04.561Z,1557340924.561 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:06.985Z,1557340926.985 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:42:06.986Z,1557340926.986 [PNI_TCM] Data Fault, FailCount= 3
2019-05-08T18:42:06.986Z,1557340926.986 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:42:06.000Z,1557340927.000 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:42:07.389Z,1557340927.389 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:07.403Z,1557340927.403 [PNI_TCM](INFO): Powering down
2019-05-08T18:42:08.616Z,1557340928.616 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:42:08.616Z,1557340928.616 [PNI_TCM] No Fault, FailCount= 3
2019-05-08T18:42:10.621Z,1557340930.621 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:13.449Z,1557340933.449 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:16.277Z,1557340936.277 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:16.291Z,1557340936.291 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:42:16.291Z,1557340936.291 [PNI_TCM] Data Fault, FailCount= 4
2019-05-08T18:42:16.291Z,1557340936.291 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:42:16.311Z,1557340936.311 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:42:16.695Z,1557340936.695 [PNI_TCM](INFO): Powering down
2019-05-08T18:42:17.913Z,1557340937.913 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:42:17.913Z,1557340937.913 [PNI_TCM] No Fault, FailCount= 4
2019-05-08T18:42:18.297Z,1557340938.297 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:20.317Z,1557340940.317 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:23.565Z,1557340943.565 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:25.570Z,1557340945.570 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:42:25.570Z,1557340945.570 [PNI_TCM] Data Fault, FailCount= 5
2019-05-08T18:42:25.570Z,1557340945.570 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:42:25.620Z,1557340945.620 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:42:25.620Z,1557340945.620 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2019-05-08T18:42:25.973Z,1557340945.973 [PNI_TCM](INFO): Powering down
2019-05-08T18:42:26.076Z,1557340946.076 [CBIT](INFO): Critical error at 20190508T184225
2019-05-08T18:42:26.377Z,1557340946.377 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:29.609Z,1557340949.609 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:32.437Z,1557340952.437 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:35.669Z,1557340955.669 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:38.493Z,1557340958.493 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:41.321Z,1557340961.321 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:43.341Z,1557340963.341 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:46.573Z,1557340966.573 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:49.425Z,1557340969.425 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:52.633Z,1557340972.633 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:55.461Z,1557340975.461 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:42:58.689Z,1557340978.689 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:01.525Z,1557340981.525 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:04.353Z,1557340984.353 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:06.373Z,1557340986.373 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:08.393Z,1557340988.393 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:11.625Z,1557340991.625 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:14.453Z,1557340994.453 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:17.685Z,1557340997.685 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:20.513Z,1557341000.513 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:23.741Z,1557341003.741 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:26.573Z,1557341006.573 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:29.401Z,1557341009.401 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:31.421Z,1557341011.421 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:34.653Z,1557341014.653 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:35.079Z,1557341015.079 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-05-08T18:43:35.082Z,1557341015.082 [BPC1](INFO): Received data from all battery sticks.
2019-05-08T18:43:37.473Z,1557341017.473 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:40.713Z,1557341020.713 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:43.533Z,1557341023.533 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:46.773Z,1557341026.773 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:49.593Z,1557341029.593 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:52.425Z,1557341032.425 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:54.441Z,1557341034.441 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:56.469Z,1557341036.469 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:59.301Z,1557341039.301 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T18:43:59.302Z,1557341039.302 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-05-08T18:43:59.302Z,1557341039.302 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T18:43:59.312Z,1557341039.312 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T18:43:59.701Z,1557341039.701 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:43:59.728Z,1557341039.728 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T18:43:59.728Z,1557341039.728 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-05-08T18:44:02.529Z,1557341042.529 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:04.170Z,1557341044.170 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-05-08T18:44:04.170Z,1557341044.170 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 8
2019-05-08T18:44:04.533Z,1557341044.533 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-05-08T18:44:04.534Z,1557341044.534 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-05-08T18:44:05.761Z,1557341045.761 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:08.589Z,1557341048.589 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:11.821Z,1557341051.821 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:14.649Z,1557341054.649 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:15.442Z,1557341055.442 [AcousticModem_Benthos_ATM900](DEBUG): 
2019-05-08T18:44:16.654Z,1557341056.654 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos DAT-900 Series
2019-05-08T18:44:16.655Z,1557341056.655 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2019-05-08T18:44:16.656Z,1557341056.656 [AcousticModem_Benthos_ATM900](DEBUG): Directional Acoustic Transponder version 8.12.21
2019-05-08T18:44:17.455Z,1557341057.455 [AcousticModem_Benthos_ATM900](DEBUG): Jan 13 2000 09:21:43 
2019-05-08T18:44:17.471Z,1557341057.471 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:17.866Z,1557341057.866 [AcousticModem_Benthos_ATM900](DEBUG): Features enabled [Bearing]
2019-05-08T18:44:17.867Z,1557341057.867 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: diag.rom image not found; POST not performed
2019-05-08T18:44:18.667Z,1557341058.667 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2019-05-08T18:44:19.074Z,1557341059.074 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2019-05-08T18:44:19.074Z,1557341059.074 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2019-05-08T18:44:19.074Z,1557341059.074 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2019-05-08T18:44:19.482Z,1557341059.482 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2019-05-08T18:44:19.882Z,1557341059.882 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2019-05-08T18:44:19.882Z,1557341059.882 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2019-05-08T18:44:20.286Z,1557341060.286 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2019-05-08T18:44:20.709Z,1557341060.709 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:23.533Z,1557341063.533 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:26.769Z,1557341066.769 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:29.589Z,1557341069.589 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:32.829Z,1557341072.829 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:35.649Z,1557341075.649 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:38.485Z,1557341078.485 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:40.497Z,1557341080.497 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:42.525Z,1557341082.525 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:45.757Z,1557341085.757 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:48.585Z,1557341088.585 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:51.813Z,1557341091.813 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:54.641Z,1557341094.641 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:44:57.877Z,1557341097.877 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:00.705Z,1557341100.705 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:03.525Z,1557341103.525 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:05.553Z,1557341105.553 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:07.573Z,1557341107.573 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:10.797Z,1557341110.797 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:13.633Z,1557341113.633 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:16.857Z,1557341116.857 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:19.693Z,1557341119.693 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:22.925Z,1557341122.925 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:25.753Z,1557341125.753 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:28.581Z,1557341128.581 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:30.601Z,1557341130.601 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:32.613Z,1557341132.613 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:35.853Z,1557341135.853 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:38.673Z,1557341138.673 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:41.913Z,1557341141.913 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:44.733Z,1557341144.733 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:46.363Z,1557341146.363 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-05-08T18:40:46.2Z
2019-05-08T18:45:46.363Z,1557341146.363 [Default:CheckIn:Read_GPS] Stopped
2019-05-08T18:45:46.363Z,1557341146.363 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-08T18:45:46.770Z,1557341146.770 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-08T18:45:48.069Z,1557341148.069 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:50.897Z,1557341150.897 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:53.725Z,1557341153.725 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:53.966Z,1557341153.966 [DataOverHttps](INFO): Sending 446 bytes from file Logs/20190508T183545/Courier0004.lzma
2019-05-08T18:45:54.770Z,1557341154.770 [DataOverHttps](INFO): Moved sent file to Logs/20190508T183545/Courier0004.lzma.bak
2019-05-08T18:45:54.770Z,1557341154.770 [DataOverHttps](INFO): SBD MOMSN=10975708
2019-05-08T18:45:56.957Z,1557341156.957 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:45:59.789Z,1557341159.789 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:00.228Z,1557341160.228 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T18:46:00.228Z,1557341160.228 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2019-05-08T18:46:00.228Z,1557341160.228 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T18:46:00.239Z,1557341160.239 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T18:46:00.642Z,1557341160.642 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T18:46:00.643Z,1557341160.643 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2019-05-08T18:46:02.613Z,1557341162.613 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:04.637Z,1557341164.637 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:06.665Z,1557341166.665 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:09.885Z,1557341169.885 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:10.184Z,1557341170.184 [DataOverHttps](INFO): Sending 1425 bytes from file Logs/20190508T183545/Express0005.lzma
2019-05-08T18:46:10.986Z,1557341170.986 [DataOverHttps](INFO): Moved sent file to Logs/20190508T183545/Express0005.lzma.bak
2019-05-08T18:46:10.986Z,1557341170.986 [DataOverHttps](INFO): SBD MOMSN=10975712
2019-05-08T18:46:12.713Z,1557341172.713 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:14.346Z,1557341174.346 [Default:CheckIn:Read_Iridium] Stopped
2019-05-08T18:46:14.346Z,1557341174.346 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-08T18:46:14.346Z,1557341174.346 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:46:15.945Z,1557341175.945 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:18.769Z,1557341178.769 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:22.005Z,1557341182.005 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:24.829Z,1557341184.829 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:27.657Z,1557341187.657 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:29.681Z,1557341189.681 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:31.705Z,1557341191.705 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:34.937Z,1557341194.937 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:46:37.756Z,1557341197.756 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-05-08T18:46:37.756Z,1557341197.756 [NAL9602] Data Fault, FailCount= 1
2019-05-08T18:46:37.756Z,1557341197.756 [NAL9602](ERROR): Data Fault
2019-05-08T18:46:37.807Z,1557341197.807 [CBIT](ERROR): Data Fault in component: NAL9602
2019-05-08T18:46:38.151Z,1557341198.151 [NAL9602](INFO): Powering down
2019-05-08T18:46:38.990Z,1557341198.990 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-08T18:46:38.990Z,1557341198.990 [NAL9602] No Fault, FailCount= 1
2019-05-08T18:47:08.449Z,1557341228.449 [NAL9602](INFO): Powering up NAL9602
2019-05-08T18:47:19.374Z,1557341239.374 [NAL9602](INFO): NAL9602 initialized
2019-05-08T18:47:20.181Z,1557341240.181 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:22.621Z,1557341242.621 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:25.433Z,1557341245.433 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:25.895Z,1557341245.895 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:47:25.895Z,1557341245.895 [PNI_TCM] No Fault, FailCount= 5
2019-05-08T18:47:28.665Z,1557341248.665 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:31.497Z,1557341251.497 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:33.525Z,1557341253.525 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:47:33.526Z,1557341253.526 [PNI_TCM] Data Fault, FailCount= 1
2019-05-08T18:47:33.526Z,1557341253.526 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:47:33.589Z,1557341253.589 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:47:33.931Z,1557341253.931 [PNI_TCM](INFO): Powering down
2019-05-08T18:47:34.729Z,1557341254.729 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:35.161Z,1557341255.161 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:47:35.161Z,1557341255.161 [PNI_TCM] No Fault, FailCount= 1
2019-05-08T18:47:37.557Z,1557341257.557 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:40.377Z,1557341260.377 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:42.405Z,1557341262.405 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:42.819Z,1557341262.819 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:47:42.819Z,1557341262.819 [PNI_TCM] Data Fault, FailCount= 2
2019-05-08T18:47:42.819Z,1557341262.819 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:47:42.838Z,1557341262.838 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:47:43.227Z,1557341263.227 [PNI_TCM](INFO): Powering down
2019-05-08T18:47:44.425Z,1557341264.425 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:44.472Z,1557341264.472 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:47:44.472Z,1557341264.472 [PNI_TCM] No Fault, FailCount= 2
2019-05-08T18:47:46.437Z,1557341266.437 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:49.677Z,1557341269.677 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:52.102Z,1557341272.102 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:47:52.102Z,1557341272.102 [PNI_TCM] Data Fault, FailCount= 3
2019-05-08T18:47:52.102Z,1557341272.102 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:47:52.117Z,1557341272.117 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:47:52.497Z,1557341272.497 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:52.511Z,1557341272.511 [PNI_TCM](INFO): Powering down
2019-05-08T18:47:53.735Z,1557341273.735 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:47:53.735Z,1557341273.735 [PNI_TCM] No Fault, FailCount= 3
2019-05-08T18:47:55.737Z,1557341275.737 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:47:58.557Z,1557341278.557 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:01.393Z,1557341281.393 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:48:01.393Z,1557341281.393 [PNI_TCM] Data Fault, FailCount= 4
2019-05-08T18:48:01.393Z,1557341281.393 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:48:01.404Z,1557341281.404 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T18:48:01.404Z,1557341281.404 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2019-05-08T18:48:01.404Z,1557341281.404 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T18:48:01.468Z,1557341281.468 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T18:48:01.468Z,1557341281.468 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:48:01.793Z,1557341281.793 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:01.807Z,1557341281.807 [PNI_TCM](INFO): Powering down
2019-05-08T18:48:01.917Z,1557341281.917 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T18:48:01.917Z,1557341281.917 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2019-05-08T18:48:03.069Z,1557341283.069 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:48:03.069Z,1557341283.069 [PNI_TCM] No Fault, FailCount= 4
2019-05-08T18:48:04.617Z,1557341284.617 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:07.453Z,1557341287.453 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:09.465Z,1557341289.465 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:10.685Z,1557341290.685 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:48:10.685Z,1557341290.685 [PNI_TCM] Data Fault, FailCount= 5
2019-05-08T18:48:10.685Z,1557341290.685 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:48:10.699Z,1557341290.699 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:48:10.700Z,1557341290.700 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2019-05-08T18:48:11.093Z,1557341291.093 [PNI_TCM](INFO): Powering down
2019-05-08T18:48:11.212Z,1557341291.212 [CBIT](INFO): Critical error at 20190508T184810
2019-05-08T18:48:12.705Z,1557341292.705 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:15.525Z,1557341295.525 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:18.765Z,1557341298.765 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:21.585Z,1557341301.585 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:24.825Z,1557341304.825 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:27.649Z,1557341307.649 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:30.477Z,1557341310.477 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:32.493Z,1557341312.493 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:35.733Z,1557341315.733 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:38.553Z,1557341318.553 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:41.793Z,1557341321.793 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:44.617Z,1557341324.617 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:47.853Z,1557341327.853 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:50.673Z,1557341330.673 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:53.509Z,1557341333.509 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:55.521Z,1557341335.521 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:48:58.761Z,1557341338.761 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:01.581Z,1557341341.581 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:04.821Z,1557341344.821 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:07.641Z,1557341347.641 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:10.881Z,1557341350.881 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:13.701Z,1557341353.701 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:16.537Z,1557341356.537 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:18.549Z,1557341358.549 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:20.577Z,1557341360.577 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:23.809Z,1557341363.809 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:26.637Z,1557341366.637 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:29.865Z,1557341369.865 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:32.697Z,1557341372.697 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:35.929Z,1557341375.929 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:38.757Z,1557341378.757 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:41.577Z,1557341381.577 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:43.605Z,1557341383.605 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:46.837Z,1557341386.837 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:49.665Z,1557341389.665 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:52.897Z,1557341392.897 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:55.725Z,1557341395.725 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:49:58.953Z,1557341398.953 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:01.785Z,1557341401.785 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:02.616Z,1557341402.616 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T18:50:02.616Z,1557341402.616 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2019-05-08T18:50:02.616Z,1557341402.616 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T18:50:02.627Z,1557341402.627 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T18:50:03.011Z,1557341403.011 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T18:50:03.011Z,1557341403.011 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2019-05-08T18:50:04.605Z,1557341404.605 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:06.633Z,1557341406.633 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:08.653Z,1557341408.653 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:11.885Z,1557341411.885 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:14.713Z,1557341414.713 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:17.945Z,1557341417.945 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:20.773Z,1557341420.773 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:24.005Z,1557341424.005 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:26.833Z,1557341426.833 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:29.657Z,1557341429.657 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:31.681Z,1557341431.681 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:33.701Z,1557341433.701 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:36.933Z,1557341436.933 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:39.753Z,1557341439.753 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:42.993Z,1557341442.993 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:45.813Z,1557341445.813 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:49.053Z,1557341449.053 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:51.877Z,1557341451.877 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:54.709Z,1557341454.709 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:56.721Z,1557341456.721 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:50:59.957Z,1557341459.957 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:02.781Z,1557341462.781 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:06.021Z,1557341466.021 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:08.841Z,1557341468.841 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:12.081Z,1557341472.081 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:14.909Z,1557341474.909 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:14.934Z,1557341474.934 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-08T18:51:14.934Z,1557341474.934 [Default:CheckIn:C.Wait] Stopped
2019-05-08T18:51:14.934Z,1557341474.934 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T18:51:14.934Z,1557341474.934 [Default:CheckIn:D] Running Loop=1
2019-05-08T18:51:15.338Z,1557341475.338 [Default:CheckIn:D] Stopped
2019-05-08T18:51:15.338Z,1557341475.338 [Default:CheckIn:E] Running Loop=1
2019-05-08T18:51:15.736Z,1557341475.736 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.715015 min 
2019-05-08T18:51:15.736Z,1557341475.736 [Default:CheckIn:E] Stopped
2019-05-08T18:51:15.737Z,1557341475.737 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-08T18:51:15.737Z,1557341475.737 [Default:CheckIn] Stopped
2019-05-08T18:51:15.737Z,1557341475.737 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-08T18:51:15.737Z,1557341475.737 [Default:CheckIn](INFO): Running loop #2
2019-05-08T18:51:15.737Z,1557341475.737 [Default:CheckIn] Running Loop=2
2019-05-08T18:51:15.737Z,1557341475.737 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-08T18:51:15.737Z,1557341475.737 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-08T18:51:17.737Z,1557341477.737 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:19.749Z,1557341479.749 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:22.989Z,1557341482.989 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:25.809Z,1557341485.809 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:29.045Z,1557341489.045 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:31.873Z,1557341491.873 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:35.109Z,1557341495.109 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:37.937Z,1557341497.937 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:40.761Z,1557341500.761 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:42.777Z,1557341502.777 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:44.805Z,1557341504.805 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:48.037Z,1557341508.037 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:50.865Z,1557341510.865 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:54.097Z,1557341514.097 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:51:56.925Z,1557341516.925 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:00.157Z,1557341520.157 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:02.981Z,1557341522.981 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:03.416Z,1557341523.416 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T18:52:03.416Z,1557341523.416 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2019-05-08T18:52:03.416Z,1557341523.416 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T18:52:03.439Z,1557341523.439 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T18:52:03.833Z,1557341523.833 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T18:52:03.834Z,1557341523.834 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2019-05-08T18:52:05.805Z,1557341525.805 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:07.833Z,1557341527.833 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:11.065Z,1557341531.065 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:13.893Z,1557341533.893 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:17.121Z,1557341537.121 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:19.953Z,1557341539.953 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:23.185Z,1557341543.185 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:26.013Z,1557341546.013 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:28.833Z,1557341548.833 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:30.853Z,1557341550.853 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:32.881Z,1557341552.881 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:36.113Z,1557341556.113 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:38.941Z,1557341558.941 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:42.169Z,1557341562.169 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:45.001Z,1557341565.001 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:48.229Z,1557341568.229 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:51.069Z,1557341571.069 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:53.905Z,1557341573.905 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:57.121Z,1557341577.121 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:52:59.945Z,1557341579.945 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:03.181Z,1557341583.181 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:06.009Z,1557341586.009 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:09.241Z,1557341589.241 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:10.871Z,1557341590.871 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:53:10.871Z,1557341590.871 [PNI_TCM] No Fault, FailCount= 5
2019-05-08T18:53:12.069Z,1557341592.069 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:14.889Z,1557341594.889 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:16.917Z,1557341596.917 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:18.527Z,1557341598.527 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:53:18.528Z,1557341598.528 [PNI_TCM] Data Fault, FailCount= 1
2019-05-08T18:53:18.528Z,1557341598.528 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:53:18.542Z,1557341598.542 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:53:18.941Z,1557341598.941 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:18.955Z,1557341598.955 [PNI_TCM](INFO): Powering down
2019-05-08T18:53:20.174Z,1557341600.174 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:53:20.174Z,1557341600.174 [PNI_TCM] No Fault, FailCount= 1
2019-05-08T18:53:20.957Z,1557341600.957 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:24.185Z,1557341604.185 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:27.017Z,1557341607.017 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:27.839Z,1557341607.839 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:53:27.839Z,1557341607.839 [PNI_TCM] Data Fault, FailCount= 2
2019-05-08T18:53:27.839Z,1557341607.839 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:53:27.878Z,1557341607.878 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:53:28.223Z,1557341608.223 [PNI_TCM](INFO): Powering down
2019-05-08T18:53:29.470Z,1557341609.470 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:53:29.470Z,1557341609.470 [PNI_TCM] No Fault, FailCount= 2
2019-05-08T18:53:30.245Z,1557341610.245 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:33.077Z,1557341613.077 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:36.309Z,1557341616.309 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:37.131Z,1557341617.131 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:53:37.131Z,1557341617.131 [PNI_TCM] Data Fault, FailCount= 3
2019-05-08T18:53:37.132Z,1557341617.132 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:53:37.175Z,1557341617.175 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:53:37.524Z,1557341617.524 [PNI_TCM](INFO): Powering down
2019-05-08T18:53:38.744Z,1557341618.744 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:53:38.744Z,1557341618.744 [PNI_TCM] No Fault, FailCount= 3
2019-05-08T18:53:39.137Z,1557341619.137 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:41.965Z,1557341621.965 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:43.985Z,1557341623.985 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:46.415Z,1557341626.415 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:53:46.415Z,1557341626.415 [PNI_TCM] Data Fault, FailCount= 4
2019-05-08T18:53:46.415Z,1557341626.415 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:53:46.434Z,1557341626.434 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:53:46.813Z,1557341626.813 [PNI_TCM](INFO): Powering down
2019-05-08T18:53:47.217Z,1557341627.217 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:48.058Z,1557341628.058 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:53:48.058Z,1557341628.058 [PNI_TCM] No Fault, FailCount= 4
2019-05-08T18:53:50.045Z,1557341630.045 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:53.277Z,1557341633.277 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:55.702Z,1557341635.702 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:53:55.702Z,1557341635.702 [PNI_TCM] Data Fault, FailCount= 5
2019-05-08T18:53:55.702Z,1557341635.702 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:53:55.716Z,1557341635.716 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:53:55.716Z,1557341635.716 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2019-05-08T18:53:56.105Z,1557341636.105 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:53:56.119Z,1557341636.119 [PNI_TCM](INFO): Powering down
2019-05-08T18:53:56.224Z,1557341636.224 [CBIT](INFO): Critical error at 20190508T185355
2019-05-08T18:53:59.337Z,1557341639.337 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:02.161Z,1557341642.161 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:04.588Z,1557341644.588 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T18:54:04.588Z,1557341644.588 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2019-05-08T18:54:04.588Z,1557341644.588 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T18:54:04.599Z,1557341644.599 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T18:54:04.989Z,1557341644.989 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:05.022Z,1557341645.022 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T18:54:05.022Z,1557341645.022 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2019-05-08T18:54:07.014Z,1557341647.014 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:10.245Z,1557341650.245 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:13.073Z,1557341653.073 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:16.305Z,1557341656.305 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:19.133Z,1557341659.133 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:22.365Z,1557341662.365 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:25.193Z,1557341665.193 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:28.021Z,1557341668.021 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:30.037Z,1557341670.037 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:32.057Z,1557341672.057 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:35.293Z,1557341675.293 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:38.121Z,1557341678.121 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:41.353Z,1557341681.353 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:44.181Z,1557341684.181 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:47.413Z,1557341687.413 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:50.241Z,1557341690.241 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:53.069Z,1557341693.069 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:55.089Z,1557341695.089 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:54:58.321Z,1557341698.321 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:01.146Z,1557341701.146 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:04.381Z,1557341704.381 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:07.209Z,1557341707.209 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:10.441Z,1557341710.441 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:13.269Z,1557341713.269 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:16.097Z,1557341716.097 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:18.117Z,1557341718.117 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:21.349Z,1557341721.349 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:24.177Z,1557341724.177 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:27.409Z,1557341727.409 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:30.233Z,1557341730.233 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:33.469Z,1557341733.469 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:36.297Z,1557341736.297 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:39.125Z,1557341739.125 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:41.145Z,1557341741.145 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:43.165Z,1557341743.165 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:46.389Z,1557341746.389 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:49.225Z,1557341749.225 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:52.449Z,1557341752.449 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:55.285Z,1557341755.285 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:55:58.509Z,1557341758.509 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:01.345Z,1557341761.345 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:04.173Z,1557341764.173 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:05.791Z,1557341765.791 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T18:56:05.791Z,1557341765.791 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2019-05-08T18:56:05.792Z,1557341765.792 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T18:56:05.802Z,1557341765.802 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T18:56:06.193Z,1557341766.193 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:06.226Z,1557341766.226 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T18:56:06.226Z,1557341766.226 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2019-05-08T18:56:09.421Z,1557341769.421 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:12.257Z,1557341772.257 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:15.481Z,1557341775.481 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:15.918Z,1557341775.918 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-05-08T18:51:15.7Z
2019-05-08T18:56:15.918Z,1557341775.918 [Default:CheckIn:Read_GPS] Stopped
2019-05-08T18:56:15.918Z,1557341775.918 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-08T18:56:18.317Z,1557341778.317 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:21.545Z,1557341781.545 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:23.496Z,1557341783.496 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20190508T183545/Courier0007.lzma
2019-05-08T18:56:24.302Z,1557341784.302 [DataOverHttps](INFO): Moved sent file to Logs/20190508T183545/Courier0007.lzma.bak
2019-05-08T18:56:24.302Z,1557341784.302 [DataOverHttps](INFO): SBD MOMSN=10975841
2019-05-08T18:56:24.380Z,1557341784.380 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:27.201Z,1557341787.201 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:29.225Z,1557341789.225 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:31.245Z,1557341791.245 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:34.481Z,1557341794.481 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:37.301Z,1557341797.301 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:38.789Z,1557341798.789 [DataOverHttps](INFO): Sending 352 bytes from file Logs/20190508T183545/Express0008.lzma
2019-05-08T18:56:39.594Z,1557341799.594 [DataOverHttps](INFO): Moved sent file to Logs/20190508T183545/Express0008.lzma.bak
2019-05-08T18:56:39.594Z,1557341799.594 [DataOverHttps](INFO): SBD MOMSN=10975846
2019-05-08T18:56:40.533Z,1557341800.533 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:42.978Z,1557341802.978 [Default:CheckIn:Read_Iridium] Stopped
2019-05-08T18:56:42.978Z,1557341802.978 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-08T18:56:42.978Z,1557341802.978 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T18:56:43.361Z,1557341803.361 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:46.597Z,1557341806.597 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:49.417Z,1557341809.417 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:52.253Z,1557341812.253 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:54.269Z,1557341814.269 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:56:57.501Z,1557341817.501 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:57:00.329Z,1557341820.329 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:57:03.565Z,1557341823.565 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:57:06.385Z,1557341826.385 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:57:09.625Z,1557341829.625 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:57:12.445Z,1557341832.445 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:57:15.281Z,1557341835.281 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:57:17.301Z,1557341837.301 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:57:20.518Z,1557341840.518 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-05-08T18:57:20.518Z,1557341840.518 [NAL9602] Data Fault, FailCount= 2
2019-05-08T18:57:20.518Z,1557341840.518 [NAL9602](ERROR): Data Fault
2019-05-08T18:57:20.602Z,1557341840.602 [CBIT](ERROR): Data Fault in component: NAL9602
2019-05-08T18:57:20.922Z,1557341840.922 [NAL9602](INFO): Powering down
2019-05-08T18:57:21.794Z,1557341841.794 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-08T18:57:21.794Z,1557341841.794 [NAL9602] No Fault, FailCount= 2
2019-05-08T18:57:51.223Z,1557341871.223 [NAL9602](INFO): Powering up NAL9602
2019-05-08T18:58:02.132Z,1557341882.132 [NAL9602](INFO): NAL9602 initialized
2019-05-08T18:58:02.953Z,1557341882.953 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:05.377Z,1557341885.377 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:07.008Z,1557341887.008 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T18:58:07.008Z,1557341887.008 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2019-05-08T18:58:07.009Z,1557341887.009 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T18:58:07.019Z,1557341887.019 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T18:58:07.429Z,1557341887.429 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T18:58:07.429Z,1557341887.429 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2019-05-08T18:58:08.205Z,1557341888.205 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:11.437Z,1557341891.437 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:14.265Z,1557341894.265 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:17.497Z,1557341897.497 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:20.317Z,1557341900.317 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:23.153Z,1557341903.153 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:25.173Z,1557341905.173 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:27.189Z,1557341907.189 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:29.217Z,1557341909.217 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:32.437Z,1557341912.437 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:35.273Z,1557341915.273 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:38.497Z,1557341918.497 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:41.333Z,1557341921.333 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:44.560Z,1557341924.560 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:47.393Z,1557341927.393 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:50.221Z,1557341930.221 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:52.241Z,1557341932.241 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:55.465Z,1557341935.465 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:58:55.918Z,1557341935.918 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:58:55.918Z,1557341935.918 [PNI_TCM] No Fault, FailCount= 5
2019-05-08T18:58:58.301Z,1557341938.301 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:01.525Z,1557341941.525 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:03.555Z,1557341943.555 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:59:03.555Z,1557341943.555 [PNI_TCM] Data Fault, FailCount= 1
2019-05-08T18:59:03.555Z,1557341943.555 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:59:03.569Z,1557341943.569 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:59:03.951Z,1557341943.951 [PNI_TCM](INFO): Powering down
2019-05-08T18:59:04.361Z,1557341944.361 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:05.202Z,1557341945.202 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:59:05.202Z,1557341945.202 [PNI_TCM] No Fault, FailCount= 1
2019-05-08T18:59:07.585Z,1557341947.585 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:10.421Z,1557341950.421 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:12.846Z,1557341952.846 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:59:12.846Z,1557341952.846 [PNI_TCM] Data Fault, FailCount= 2
2019-05-08T18:59:12.846Z,1557341952.846 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:59:12.860Z,1557341952.860 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:59:13.245Z,1557341953.245 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:13.259Z,1557341953.259 [PNI_TCM](INFO): Powering down
2019-05-08T18:59:14.476Z,1557341954.476 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:59:14.476Z,1557341954.476 [PNI_TCM] No Fault, FailCount= 2
2019-05-08T18:59:15.269Z,1557341955.269 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:18.493Z,1557341958.493 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:21.329Z,1557341961.329 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:22.151Z,1557341962.151 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:59:22.151Z,1557341962.151 [PNI_TCM] Data Fault, FailCount= 3
2019-05-08T18:59:22.152Z,1557341962.152 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:59:22.170Z,1557341962.170 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:59:22.552Z,1557341962.552 [PNI_TCM](INFO): Powering down
2019-05-08T18:59:23.774Z,1557341963.774 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:59:23.774Z,1557341963.774 [PNI_TCM] No Fault, FailCount= 3
2019-05-08T18:59:24.553Z,1557341964.553 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:27.389Z,1557341967.389 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:30.613Z,1557341970.613 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:31.443Z,1557341971.443 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:59:31.443Z,1557341971.443 [PNI_TCM] Data Fault, FailCount= 4
2019-05-08T18:59:31.443Z,1557341971.443 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:59:31.457Z,1557341971.457 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:59:31.827Z,1557341971.827 [PNI_TCM](INFO): Powering down
2019-05-08T18:59:33.069Z,1557341973.069 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T18:59:33.069Z,1557341973.069 [PNI_TCM] No Fault, FailCount= 4
2019-05-08T18:59:33.449Z,1557341973.449 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:36.277Z,1557341976.277 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:38.297Z,1557341978.297 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:40.309Z,1557341980.309 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:40.735Z,1557341980.735 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T18:59:40.735Z,1557341980.735 [PNI_TCM] Data Fault, FailCount= 5
2019-05-08T18:59:40.735Z,1557341980.735 [PNI_TCM](ERROR): Data Fault
2019-05-08T18:59:40.782Z,1557341980.782 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T18:59:40.782Z,1557341980.782 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2019-05-08T18:59:41.139Z,1557341981.139 [PNI_TCM](INFO): Powering down
2019-05-08T18:59:41.244Z,1557341981.244 [CBIT](INFO): Critical error at 20190508T185940
2019-05-08T18:59:43.549Z,1557341983.549 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:46.369Z,1557341986.369 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:49.609Z,1557341989.609 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:52.429Z,1557341992.429 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:55.669Z,1557341995.669 [NAL9602](DEBUG): Fix Requested
2019-05-08T18:59:58.493Z,1557341998.493 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:01.325Z,1557342001.325 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:03.340Z,1557342003.340 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:06.577Z,1557342006.577 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:08.204Z,1557342008.204 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T19:00:08.204Z,1557342008.204 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2019-05-08T19:00:08.204Z,1557342008.204 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T19:00:08.215Z,1557342008.215 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T19:00:08.622Z,1557342008.622 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T19:00:08.622Z,1557342008.622 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2019-05-08T19:00:09.397Z,1557342009.397 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:12.637Z,1557342012.637 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:15.457Z,1557342015.457 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:18.697Z,1557342018.697 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:21.517Z,1557342021.517 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:24.353Z,1557342024.353 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:26.365Z,1557342026.365 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:28.389Z,1557342028.389 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:31.625Z,1557342031.625 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:34.454Z,1557342034.454 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:37.685Z,1557342037.685 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:40.513Z,1557342040.513 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:43.741Z,1557342043.741 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:46.573Z,1557342046.573 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:49.393Z,1557342049.393 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:51.421Z,1557342051.421 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:54.653Z,1557342054.653 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:00:57.477Z,1557342057.477 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:00.713Z,1557342060.713 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:03.541Z,1557342063.541 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:06.773Z,1557342066.773 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:09.601Z,1557342069.601 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:12.421Z,1557342072.421 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:14.449Z,1557342074.449 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:16.469Z,1557342076.469 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:19.693Z,1557342079.693 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:22.529Z,1557342082.529 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:25.753Z,1557342085.753 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:28.589Z,1557342088.589 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:31.813Z,1557342091.813 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:34.649Z,1557342094.649 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:37.477Z,1557342097.477 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:39.497Z,1557342099.497 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:42.721Z,1557342102.721 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:43.557Z,1557342103.557 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-08T19:01:43.557Z,1557342103.557 [Default:CheckIn:C.Wait] Stopped
2019-05-08T19:01:43.558Z,1557342103.558 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T19:01:43.558Z,1557342103.558 [Default:CheckIn:D] Running Loop=1
2019-05-08T19:01:43.945Z,1557342103.945 [Default:CheckIn:D] Stopped
2019-05-08T19:01:43.945Z,1557342103.945 [Default:CheckIn:E] Running Loop=1
2019-05-08T19:01:44.354Z,1557342104.354 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.191809 min 
2019-05-08T19:01:44.354Z,1557342104.354 [Default:CheckIn:E] Stopped
2019-05-08T19:01:44.354Z,1557342104.354 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-08T19:01:44.354Z,1557342104.354 [Default:CheckIn] Stopped
2019-05-08T19:01:44.355Z,1557342104.355 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-08T19:01:44.355Z,1557342104.355 [Default:CheckIn](INFO): Running loop #3
2019-05-08T19:01:44.355Z,1557342104.355 [Default:CheckIn] Running Loop=3
2019-05-08T19:01:44.355Z,1557342104.355 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-08T19:01:44.355Z,1557342104.355 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-08T19:01:45.557Z,1557342105.557 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:48.781Z,1557342108.781 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:51.617Z,1557342111.617 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:54.841Z,1557342114.841 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:01:57.673Z,1557342117.673 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:00.509Z,1557342120.509 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:02.525Z,1557342122.525 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:04.537Z,1557342124.537 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:07.777Z,1557342127.777 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:09.391Z,1557342129.391 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T19:02:09.391Z,1557342129.391 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2019-05-08T19:02:09.391Z,1557342129.391 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T19:02:09.402Z,1557342129.402 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T19:02:09.826Z,1557342129.826 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T19:02:09.826Z,1557342129.826 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2019-05-08T19:02:10.597Z,1557342130.597 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:13.837Z,1557342133.837 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:16.657Z,1557342136.657 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:19.897Z,1557342139.897 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:22.725Z,1557342142.725 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:25.553Z,1557342145.553 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:27.565Z,1557342147.565 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:30.805Z,1557342150.805 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:33.633Z,1557342153.633 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:36.865Z,1557342156.865 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:39.685Z,1557342159.685 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:42.921Z,1557342162.921 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:45.751Z,1557342165.751 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:48.589Z,1557342168.589 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:50.597Z,1557342170.597 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:52.617Z,1557342172.617 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:55.853Z,1557342175.853 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:02:58.677Z,1557342178.677 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:01.917Z,1557342181.917 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:04.741Z,1557342184.741 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:07.973Z,1557342187.973 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:10.801Z,1557342190.801 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:13.621Z,1557342193.621 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:15.649Z,1557342195.649 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:18.881Z,1557342198.881 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:21.709Z,1557342201.709 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:24.941Z,1557342204.941 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:27.765Z,1557342207.765 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:31.001Z,1557342211.001 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:33.829Z,1557342213.829 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:36.649Z,1557342216.649 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:38.677Z,1557342218.677 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:41.909Z,1557342221.909 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:44.737Z,1557342224.737 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:47.969Z,1557342227.969 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:50.798Z,1557342230.798 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:54.025Z,1557342234.025 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:56.857Z,1557342236.857 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:03:59.681Z,1557342239.681 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:01.705Z,1557342241.705 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:03.725Z,1557342243.725 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:06.957Z,1557342246.957 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:09.785Z,1557342249.785 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:10.608Z,1557342250.608 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T19:04:10.608Z,1557342250.608 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2019-05-08T19:04:10.609Z,1557342250.609 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T19:04:10.619Z,1557342250.619 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T19:04:11.018Z,1557342251.018 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T19:04:11.018Z,1557342251.018 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2019-05-08T19:04:13.017Z,1557342253.017 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:15.845Z,1557342255.845 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:19.077Z,1557342259.077 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:21.905Z,1557342261.905 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:24.733Z,1557342264.733 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:26.753Z,1557342266.753 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:29.981Z,1557342269.981 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:32.813Z,1557342272.813 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:36.045Z,1557342276.045 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:38.873Z,1557342278.873 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:40.901Z,1557342280.901 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T19:04:40.901Z,1557342280.901 [PNI_TCM] No Fault, FailCount= 5
2019-05-08T19:04:42.105Z,1557342282.105 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:44.933Z,1557342284.933 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:47.765Z,1557342287.765 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:48.583Z,1557342288.583 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T19:04:48.583Z,1557342288.583 [PNI_TCM] Data Fault, FailCount= 1
2019-05-08T19:04:48.584Z,1557342288.584 [PNI_TCM](ERROR): Data Fault
2019-05-08T19:04:48.602Z,1557342288.602 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T19:04:48.980Z,1557342288.980 [PNI_TCM](INFO): Powering down
2019-05-08T19:04:49.781Z,1557342289.781 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:50.228Z,1557342290.228 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T19:04:50.228Z,1557342290.228 [PNI_TCM] No Fault, FailCount= 1
2019-05-08T19:04:51.793Z,1557342291.793 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:55.033Z,1557342295.033 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:57.857Z,1557342297.857 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:04:57.872Z,1557342297.872 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T19:04:57.872Z,1557342297.872 [PNI_TCM] Data Fault, FailCount= 2
2019-05-08T19:04:57.872Z,1557342297.872 [PNI_TCM](ERROR): Data Fault
2019-05-08T19:04:57.899Z,1557342297.899 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T19:04:58.280Z,1557342298.280 [PNI_TCM](INFO): Powering down
2019-05-08T19:04:59.514Z,1557342299.514 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T19:04:59.514Z,1557342299.514 [PNI_TCM] No Fault, FailCount= 2
2019-05-08T19:05:01.093Z,1557342301.093 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:03.913Z,1557342303.913 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:07.153Z,1557342307.153 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:07.167Z,1557342307.167 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T19:05:07.167Z,1557342307.167 [PNI_TCM] Data Fault, FailCount= 3
2019-05-08T19:05:07.167Z,1557342307.167 [PNI_TCM](ERROR): Data Fault
2019-05-08T19:05:07.205Z,1557342307.205 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T19:05:07.563Z,1557342307.563 [PNI_TCM](INFO): Powering down
2019-05-08T19:05:08.777Z,1557342308.777 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T19:05:08.778Z,1557342308.778 [PNI_TCM] No Fault, FailCount= 3
2019-05-08T19:05:09.973Z,1557342309.973 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:12.809Z,1557342312.809 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:14.821Z,1557342314.821 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:16.448Z,1557342316.448 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T19:05:16.448Z,1557342316.448 [PNI_TCM] Data Fault, FailCount= 4
2019-05-08T19:05:16.448Z,1557342316.448 [PNI_TCM](ERROR): Data Fault
2019-05-08T19:05:16.463Z,1557342316.463 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T19:05:16.858Z,1557342316.858 [PNI_TCM](INFO): Powering down
2019-05-08T19:05:18.061Z,1557342318.061 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:18.105Z,1557342318.105 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-05-08T19:05:18.105Z,1557342318.105 [PNI_TCM] No Fault, FailCount= 4
2019-05-08T19:05:20.881Z,1557342320.881 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:24.121Z,1557342324.121 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:25.732Z,1557342325.732 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-05-08T19:05:25.732Z,1557342325.732 [PNI_TCM] Data Fault, FailCount= 5
2019-05-08T19:05:25.732Z,1557342325.732 [PNI_TCM](ERROR): Data Fault
2019-05-08T19:05:25.746Z,1557342325.746 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-05-08T19:05:25.747Z,1557342325.747 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2019-05-08T19:05:26.149Z,1557342326.149 [PNI_TCM](INFO): Powering down
2019-05-08T19:05:26.254Z,1557342326.254 [CBIT](INFO): Critical error at 20190508T190525
2019-05-08T19:05:26.949Z,1557342326.949 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:30.177Z,1557342330.177 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:33.001Z,1557342333.001 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:35.837Z,1557342335.837 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:37.849Z,1557342337.849 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:41.090Z,1557342341.090 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:43.909Z,1557342343.909 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:47.149Z,1557342347.149 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:49.969Z,1557342349.969 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:53.209Z,1557342353.209 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:56.037Z,1557342356.037 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:05:58.865Z,1557342358.865 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:00.877Z,1557342360.877 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:02.905Z,1557342362.905 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:06.137Z,1557342366.137 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:08.965Z,1557342368.965 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:11.796Z,1557342371.796 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T19:06:11.796Z,1557342371.796 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2019-05-08T19:06:11.796Z,1557342371.796 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T19:06:11.807Z,1557342371.807 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T19:06:12.197Z,1557342372.197 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:12.234Z,1557342372.234 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T19:06:12.234Z,1557342372.234 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2019-05-08T19:06:15.025Z,1557342375.025 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:18.257Z,1557342378.257 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:21.085Z,1557342381.085 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:23.905Z,1557342383.905 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:25.934Z,1557342385.934 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:29.161Z,1557342389.161 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:31.993Z,1557342391.993 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:35.225Z,1557342395.225 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:38.053Z,1557342398.053 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:41.285Z,1557342401.285 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:44.113Z,1557342404.113 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:44.534Z,1557342404.534 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-05-08T19:01:44.4Z
2019-05-08T19:06:44.534Z,1557342404.534 [Default:CheckIn:Read_GPS] Stopped
2019-05-08T19:06:44.534Z,1557342404.534 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-08T19:06:46.937Z,1557342406.937 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:48.957Z,1557342408.957 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:50.977Z,1557342410.977 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:52.356Z,1557342412.356 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20190508T183545/Courier0010.lzma
2019-05-08T19:06:53.163Z,1557342413.163 [DataOverHttps](INFO): Moved sent file to Logs/20190508T183545/Courier0010.lzma.bak
2019-05-08T19:06:53.163Z,1557342413.163 [DataOverHttps](INFO): SBD MOMSN=10975952
2019-05-08T19:06:54.209Z,1557342414.209 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:06:57.041Z,1557342417.041 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:00.272Z,1557342420.272 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:03.101Z,1557342423.101 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:06.329Z,1557342426.329 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:08.482Z,1557342428.482 [DataOverHttps](INFO): Sending 317 bytes from file Logs/20190508T183545/Express0011.lzma
2019-05-08T19:07:09.161Z,1557342429.161 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:09.286Z,1557342429.286 [DataOverHttps](INFO): Moved sent file to Logs/20190508T183545/Express0011.lzma.bak
2019-05-08T19:07:09.287Z,1557342429.287 [DataOverHttps](INFO): SBD MOMSN=10975956
2019-05-08T19:07:11.985Z,1557342431.985 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:12.421Z,1557342432.421 [Default:CheckIn:Read_Iridium] Stopped
2019-05-08T19:07:12.421Z,1557342432.421 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-08T19:07:12.421Z,1557342432.421 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-08T19:07:14.005Z,1557342434.005 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:17.240Z,1557342437.240 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:20.065Z,1557342440.065 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:23.297Z,1557342443.297 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:26.129Z,1557342446.129 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:29.361Z,1557342449.361 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:32.185Z,1557342452.185 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:35.013Z,1557342455.013 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:37.041Z,1557342457.041 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:39.049Z,1557342459.049 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:42.285Z,1557342462.285 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:45.117Z,1557342465.117 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:48.349Z,1557342468.349 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:51.177Z,1557342471.177 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:54.405Z,1557342474.405 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:07:57.237Z,1557342477.237 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:08:00.065Z,1557342480.065 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:08:02.081Z,1557342482.081 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:08:05.304Z,1557342485.304 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-05-08T19:08:05.304Z,1557342485.304 [NAL9602] Data Fault, FailCount= 3
2019-05-08T19:08:05.304Z,1557342485.304 [NAL9602](ERROR): Data Fault
2019-05-08T19:08:05.331Z,1557342485.331 [CBIT](ERROR): Data Fault in component: NAL9602
2019-05-08T19:08:05.703Z,1557342485.703 [NAL9602](INFO): Powering down
2019-05-08T19:08:06.541Z,1557342486.541 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-08T19:08:06.541Z,1557342486.541 [NAL9602] No Fault, FailCount= 3
2019-05-08T19:08:12.998Z,1557342492.998 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-08T19:08:12.998Z,1557342492.998 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16
2019-05-08T19:08:12.998Z,1557342492.998 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-08T19:08:13.009Z,1557342493.009 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-08T19:08:13.417Z,1557342493.417 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-08T19:08:13.417Z,1557342493.417 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16
2019-05-08T19:08:36.007Z,1557342516.007 [NAL9602](INFO): Powering up NAL9602
2019-05-08T19:08:46.915Z,1557342526.915 [NAL9602](INFO): NAL9602 initialized
2019-05-08T19:08:47.729Z,1557342527.729 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:08:50.161Z,1557342530.161 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:08:52.985Z,1557342532.985 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:08:56.221Z,1557342536.221 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:08:59.089Z,1557342539.089 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:02.277Z,1557342542.277 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:05.109Z,1557342545.109 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:07.973Z,1557342547.973 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:09.953Z,1557342549.953 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:11.969Z,1557342551.969 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:13.997Z,1557342553.997 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:17.229Z,1557342557.229 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:20.057Z,1557342560.057 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:23.285Z,1557342563.285 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:26.113Z,1557342566.113 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:29.349Z,1557342569.349 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:32.177Z,1557342572.177 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:35.005Z,1557342575.005 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:37.025Z,1557342577.025 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:40.257Z,1557342580.257 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:43.085Z,1557342583.085 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:43.711Z,1557342583.711 [CommandLine](IMPORTANT): got command restart application
2019-05-08T19:09:44.717Z,1557342584.717 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T19:09:44.717Z,1557342584.717 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:44.773Z,1557342584.773 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-05-08T19:09:44.773Z,1557342584.773 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:44.774Z,1557342584.774 [CommandLine](INFO): Join timeout helper Thread ID is 5433
2019-05-08T19:09:44.774Z,1557342584.774 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-08T19:09:44.774Z,1557342584.774 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:44.775Z,1557342584.775 [NavChartDb](INFO): Join timeout helper Thread ID is 5434
2019-05-08T19:09:45.013Z,1557342585.013 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T19:09:45.013Z,1557342585.013 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:45.033Z,1557342585.033 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-08T19:09:45.033Z,1557342585.033 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:45.033Z,1557342585.033 [Radio_Surface](INFO): Join timeout helper Thread ID is 5435
2019-05-08T19:09:45.257Z,1557342585.257 [Radio_Surface](INFO): Powering down
2019-05-08T19:09:45.258Z,1557342585.258 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T19:09:45.258Z,1557342585.258 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:45.273Z,1557342585.273 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-08T19:09:45.273Z,1557342585.273 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:45.273Z,1557342585.273 [DataOverHttps](INFO): Join timeout helper Thread ID is 5436
2019-05-08T19:09:45.413Z,1557342585.413 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T19:09:45.413Z,1557342585.413 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:45.433Z,1557342585.433 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-05-08T19:09:45.433Z,1557342585.433 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:45.433Z,1557342585.433 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5437
2019-05-08T19:09:45.898Z,1557342585.898 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T19:09:45.899Z,1557342585.899 [WetLabsBB2FL](INFO): Powering down
2019-05-08T19:09:45.899Z,1557342585.899 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:45.914Z,1557342585.914 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-05-08T19:09:45.914Z,1557342585.914 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:45.914Z,1557342585.914 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5438
2019-05-08T19:09:46.313Z,1557342586.313 [NAL9602](DEBUG): Fix Requested
2019-05-08T19:09:46.441Z,1557342586.441 [CTD_Seabird](INFO): Powering down
2019-05-08T19:09:46.453Z,1557342586.453 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T19:09:46.453Z,1557342586.453 [CTD_Seabird](INFO): Powering down
2019-05-08T19:09:46.465Z,1557342586.465 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:46.474Z,1557342586.474 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-08T19:09:46.474Z,1557342586.474 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:46.474Z,1557342586.474 [logger](INFO): Join timeout helper Thread ID is 5439
2019-05-08T19:09:46.477Z,1557342586.477 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T19:09:46.477Z,1557342586.477 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:46.494Z,1557342586.494 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-08T19:09:46.494Z,1557342586.494 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:46.494Z,1557342586.494 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-08T19:09:46.494Z,1557342586.494 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:46.494Z,1557342586.494 [controlThread](INFO): Join timeout helper Thread ID is 5440
2019-05-08T19:09:46.693Z,1557342586.693 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T19:09:46.693Z,1557342586.693 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-08T19:09:46.694Z,1557342586.694 [Aanderaa_O2](INFO): Powering down
2019-05-08T19:09:46.696Z,1557342586.696 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-05-08T19:09:46.813Z,1557342586.813 [NAL9602](INFO): Powering down
2019-05-08T19:09:46.815Z,1557342586.815 [PNI_TCM](INFO): Powering down
2019-05-08T19:09:46.816Z,1557342586.816 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-08T19:09:46.817Z,1557342586.817 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-08T19:09:46.817Z,1557342586.817 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-08T19:09:46.818Z,1557342586.818 [MissionManager](INFO): Uninitializing Mission Default
2019-05-08T19:09:46.818Z,1557342586.818 [Default] Stopped
2019-05-08T19:09:46.818Z,1557342586.818 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-08T19:09:46.818Z,1557342586.818 [Default:B.GoToSurface] Stopped
2019-05-08T19:09:46.818Z,1557342586.818 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-08T19:09:46.818Z,1557342586.818 [Default:CheckIn] Stopped
2019-05-08T19:09:46.818Z,1557342586.818 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-08T19:09:46.818Z,1557342586.818 [Default:CheckIn:C.Wait] Stopped
2019-05-08T19:09:46.819Z,1557342586.819 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-08T19:09:46.821Z,1557342586.821 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-08T19:09:46.821Z,1557342586.821 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-08T19:09:46.822Z,1557342586.822 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-08T19:09:46.822Z,1557342586.822 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-08T19:09:46.822Z,1557342586.822 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-08T19:09:46.822Z,1557342586.822 [BuoyancyServo](INFO): Powering down
2019-05-08T19:09:46.837Z,1557342586.837 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-08T19:09:46.837Z,1557342586.837 [ElevatorServo](INFO): Powering down
2019-05-08T19:09:46.838Z,1557342586.838 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-08T19:09:46.838Z,1557342586.838 [MassServo](INFO): Powering down
2019-05-08T19:09:46.839Z,1557342586.839 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-08T19:09:46.839Z,1557342586.839 [RudderServo](INFO): Powering down
2019-05-08T19:09:46.839Z,1557342586.839 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-08T19:09:46.839Z,1557342586.839 [ThrusterServo](INFO): Powering down
2019-05-08T19:09:46.840Z,1557342586.840 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-08T19:09:46.840Z,1557342586.840 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-08T19:09:46.841Z,1557342586.841 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-08T19:09:46.841Z,1557342586.841 [CBIT](DEBUG): Powering off loads.
2019-05-08T19:09:46.853Z,1557342586.853 [CBIT](DEBUG): Disabling WDT.
2019-05-08T19:09:46.865Z,1557342586.865 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-08T19:09:46.865Z,1557342586.865 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:46.905Z,1557342586.905 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:46.982Z,1557342586.982 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:47.056Z,1557342587.056 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:47.061Z,1557342587.061 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:47.121Z,1557342587.121 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-08T19:09:47.178Z,1557342587.178 [logger ThreadHandler](INFO): Thread cancelled.