2019-05-27T00:34:37.617Z,1558917277.617 [Supervisor](DEBUG): Initializing supervisor.
2019-05-27T00:34:37.620Z,1558917277.620 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-27T00:34:37.621Z,1558917277.621 [SyncHandler](INFO): Protected caller Thread ID is 300
2019-05-27T00:34:37.621Z,1558917277.621 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-27T00:34:37.622Z,1558917277.622 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-27T00:34:37.622Z,1558917277.622 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 301
2019-05-27T00:34:37.625Z,1558917277.625 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-27T00:34:37.674Z,1558917277.674 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-27T00:34:37.675Z,1558917277.675 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-27T00:34:37.675Z,1558917277.675 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 302
2019-05-27T00:34:37.676Z,1558917277.676 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-27T00:34:37.677Z,1558917277.677 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-27T00:34:37.678Z,1558917277.678 [logger ThreadHandler](INFO): Protected caller Thread ID is 303
2019-05-27T00:34:37.680Z,1558917277.680 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-27T00:34:37.680Z,1558917277.680 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-27T00:34:37.682Z,1558917277.682 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-27T00:34:37.779Z,1558917277.779 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-27T00:34:37.779Z,1558917277.779 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-27T00:34:38.335Z,1558917278.335 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-27T00:34:38.336Z,1558917278.336 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-27T00:34:38.436Z,1558917278.436 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-27T00:34:38.437Z,1558917278.437 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-27T00:34:38.541Z,1558917278.541 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-27T00:34:38.542Z,1558917278.542 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-27T00:34:38.623Z,1558917278.623 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-27T00:34:38.765Z,1558917278.765 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-27T00:34:38.766Z,1558917278.766 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-27T00:34:39.065Z,1558917279.065 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-27T00:34:39.066Z,1558917279.066 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-27T00:34:39.533Z,1558917279.533 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-27T00:34:39.534Z,1558917279.534 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-27T00:34:39.682Z,1558917279.682 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-27T00:34:39.682Z,1558917279.682 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-27T00:34:39.885Z,1558917279.885 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-27T00:34:39.886Z,1558917279.886 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-27T00:34:40.349Z,1558917280.349 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-27T00:34:40.349Z,1558917280.349 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-27T00:34:40.569Z,1558917280.569 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-27T00:34:40.570Z,1558917280.570 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-27T00:34:40.774Z,1558917280.774 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-27T00:34:40.775Z,1558917280.775 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-27T00:34:41.166Z,1558917281.166 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-27T00:34:41.167Z,1558917281.167 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-27T00:34:41.505Z,1558917281.505 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-27T00:34:41.507Z,1558917281.507 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2019-05-27T00:34:41.508Z,1558917281.508 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2019-05-27T00:34:41.592Z,1558917281.592 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2019-05-27T00:34:41.749Z,1558917281.749 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2019-05-27T00:34:41.859Z,1558917281.859 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2019-05-27T00:34:41.946Z,1558917281.946 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2019-05-27T00:34:42.042Z,1558917282.042 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2019-05-27T00:34:42.239Z,1558917282.239 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2019-05-27T00:34:42.491Z,1558917282.491 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-27T00:34:42.491Z,1558917282.491 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2019-05-27T00:34:42.772Z,1558917282.772 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2019-05-27T00:34:42.957Z,1558917282.957 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2019-05-27T00:34:43.170Z,1558917283.170 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2019-05-27T00:34:43.612Z,1558917283.612 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/LOGIN/
2019-05-27T00:34:43.612Z,1558917283.612 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-27T00:34:43.620Z,1558917283.620 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-27T00:34:43.688Z,1558917283.688 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-27T00:34:43.801Z,1558917283.801 [VerticalControl] Loaded
2019-05-27T00:34:43.801Z,1558917283.801 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-27T00:34:43.802Z,1558917283.802 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-27T00:34:43.869Z,1558917283.869 [HorizontalControl] Loaded
2019-05-27T00:34:43.869Z,1558917283.869 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-27T00:34:43.870Z,1558917283.870 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-27T00:34:43.876Z,1558917283.876 [SpeedControl] Loaded
2019-05-27T00:34:43.876Z,1558917283.876 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-27T00:34:43.877Z,1558917283.877 [LoopControl](DEBUG): Construct LoopControl.
2019-05-27T00:34:43.877Z,1558917283.877 [LoopControl] Loaded
2019-05-27T00:34:43.878Z,1558917283.878 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-27T00:34:43.878Z,1558917283.878 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-27T00:34:43.878Z,1558917283.878 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-27T00:34:43.919Z,1558917283.919 [DepthRateCalculator] Loaded
2019-05-27T00:34:43.919Z,1558917283.919 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-27T00:34:43.925Z,1558917283.925 [PitchRateCalculator] Loaded
2019-05-27T00:34:43.925Z,1558917283.925 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-27T00:34:43.940Z,1558917283.940 [SpeedCalculator] Loaded
2019-05-27T00:34:43.941Z,1558917283.941 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-27T00:34:43.961Z,1558917283.961 [TempGradientCalculator] Loaded
2019-05-27T00:34:43.962Z,1558917283.962 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-27T00:34:43.967Z,1558917283.967 [YawRateCalculator] Loaded
2019-05-27T00:34:43.967Z,1558917283.967 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-27T00:34:43.995Z,1558917283.995 [ElevatorOffsetCalculator] Loaded
2019-05-27T00:34:43.996Z,1558917283.996 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-27T00:34:43.996Z,1558917283.996 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-27T00:34:43.997Z,1558917283.997 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-27T00:34:44.023Z,1558917284.023 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-27T00:34:44.024Z,1558917284.024 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-27T00:34:44.091Z,1558917284.091 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-27T00:34:44.092Z,1558917284.092 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-27T00:34:44.384Z,1558917284.384 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-27T00:34:44.384Z,1558917284.384 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-27T00:34:44.481Z,1558917284.481 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-27T00:34:44.481Z,1558917284.481 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-27T00:34:44.841Z,1558917284.841 [DataOverHttps] Loaded
2019-05-27T00:34:44.841Z,1558917284.841 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-27T00:34:44.842Z,1558917284.842 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408D04E0
2019-05-27T00:34:44.843Z,1558917284.843 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 383
2019-05-27T00:34:44.856Z,1558917284.856 [Depth_Keller] Loaded
2019-05-27T00:34:44.856Z,1558917284.856 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-27T00:34:44.909Z,1558917284.909 [Micromodem] Loaded
2019-05-27T00:34:44.909Z,1558917284.909 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-05-27T00:34:45.006Z,1558917285.006 [NAL9602] Loaded
2019-05-27T00:34:45.006Z,1558917285.006 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-27T00:34:45.021Z,1558917285.021 [Onboard] Loaded
2019-05-27T00:34:45.022Z,1558917285.022 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-27T00:34:45.025Z,1558917285.025 [Radio_Surface] Loaded
2019-05-27T00:34:45.025Z,1558917285.025 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-27T00:34:45.026Z,1558917285.026 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409004E0
2019-05-27T00:34:45.027Z,1558917285.027 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 384
2019-05-27T00:34:46.562Z,1558917286.562 [BPC1] Loaded
2019-05-27T00:34:46.562Z,1558917286.562 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-27T00:34:46.562Z,1558917286.562 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-27T00:34:46.563Z,1558917286.563 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-27T00:34:46.666Z,1558917286.666 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-27T00:34:46.666Z,1558917286.666 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-27T00:34:46.687Z,1558917286.687 [NavChart] Loaded
2019-05-27T00:34:46.688Z,1558917286.688 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-27T00:34:46.691Z,1558917286.691 [UniversalFixResidualReporter] Loaded
2019-05-27T00:34:46.692Z,1558917286.692 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-27T00:34:46.692Z,1558917286.692 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-27T00:34:46.693Z,1558917286.693 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-27T00:34:46.828Z,1558917286.828 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-27T00:34:46.839Z,1558917286.839 [SBIT] Loaded
2019-05-27T00:34:46.839Z,1558917286.839 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-27T00:34:46.840Z,1558917286.840 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-27T00:34:46.851Z,1558917286.851 [IBIT] Loaded
2019-05-27T00:34:46.852Z,1558917286.852 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-27T00:34:46.855Z,1558917286.855 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-27T00:34:46.991Z,1558917286.991 [CBIT] Loaded
2019-05-27T00:34:46.991Z,1558917286.991 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-27T00:34:46.992Z,1558917286.992 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-27T00:34:46.992Z,1558917286.992 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-27T00:34:47.095Z,1558917287.095 [BuoyancyServo] Loaded
2019-05-27T00:34:47.096Z,1558917287.096 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-27T00:34:47.107Z,1558917287.107 [ElevatorServo] Loaded
2019-05-27T00:34:47.107Z,1558917287.107 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-27T00:34:47.118Z,1558917287.118 [MassServo] Loaded
2019-05-27T00:34:47.118Z,1558917287.118 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-27T00:34:47.129Z,1558917287.129 [RudderServo] Loaded
2019-05-27T00:34:47.130Z,1558917287.130 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-27T00:34:47.140Z,1558917287.140 [ThrusterServo] Loaded
2019-05-27T00:34:47.140Z,1558917287.140 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-27T00:34:47.141Z,1558917287.141 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-27T00:34:47.141Z,1558917287.141 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-27T00:34:47.154Z,1558917287.154 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-27T00:34:47.155Z,1558917287.155 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-27T00:34:47.401Z,1558917287.401 [CTD_NeilBrown] Loaded
2019-05-27T00:34:47.401Z,1558917287.401 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-27T00:34:47.402Z,1558917287.402 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 40A7C4E0
2019-05-27T00:34:47.403Z,1558917287.403 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 385
2019-05-27T00:34:47.417Z,1558917287.417 [PAR_Licor] Loaded
2019-05-27T00:34:47.417Z,1558917287.417 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-05-27T00:34:47.465Z,1558917287.465 [WetLabsBB2FL] Loaded
2019-05-27T00:34:47.465Z,1558917287.465 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-05-27T00:34:47.466Z,1558917287.466 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AAC4E0
2019-05-27T00:34:47.466Z,1558917287.466 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 386
2019-05-27T00:34:47.467Z,1558917287.467 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-27T00:34:47.471Z,1558917287.471 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-27T00:34:47.471Z,1558917287.471 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-27T00:34:47.478Z,1558917287.478 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-27T00:34:47.479Z,1558917287.479 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ADC4E0
2019-05-27T00:34:47.479Z,1558917287.479 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 388
2019-05-27T00:34:47.484Z,1558917287.484 [Supervisor](INFO): Main Thread ID is 9999
2019-05-27T00:34:47.484Z,1558917287.484 [Supervisor](DEBUG): Running supervisor.
2019-05-27T00:34:47.485Z,1558917287.485 [CommandLine ThreadHandler](INFO): Handler Thread ID is 389
2019-05-27T00:34:47.487Z,1558917287.487 [controlThread ThreadHandler](INFO): Handler Thread ID is 390
2019-05-27T00:34:47.487Z,1558917287.487 [controlThread](DEBUG): Initializing ControlThread
2019-05-27T00:34:47.488Z,1558917287.488 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-27T00:34:47.490Z,1558917287.490 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-27T00:34:47.490Z,1558917287.490 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-27T00:34:47.491Z,1558917287.491 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-27T00:34:47.491Z,1558917287.491 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-27T00:34:47.491Z,1558917287.491 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-27T00:34:47.492Z,1558917287.492 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-27T00:34:47.492Z,1558917287.492 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-27T00:34:47.493Z,1558917287.493 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-27T00:34:47.493Z,1558917287.493 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-27T00:34:47.498Z,1558917287.498 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-27T00:34:47.499Z,1558917287.499 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-27T00:34:47.499Z,1558917287.499 [SBIT](INFO): Initialize SBIT Component.
2019-05-27T00:34:47.499Z,1558917287.499 [SBIT](IMPORTANT): git: 2019-05-01-19-g6ef4ecc
2019-05-27T00:34:47.500Z,1558917287.500 [SBIT](INFO): git hash: 6ef4ecc926d3cc84e5878e2d73d98fd38ff7dcf7
2019-05-27T00:34:47.500Z,1558917287.500 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-27T00:34:47.500Z,1558917287.500 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-05-27T00:34:47.501Z,1558917287.501 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-05-27T00:34:47.502Z,1558917287.502 [IBIT](INFO): Initialize IBIT Component.
2019-05-27T00:34:47.503Z,1558917287.503 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-27T00:34:47.504Z,1558917287.504 [logger ThreadHandler](INFO): Handler Thread ID is 391
2019-05-27T00:34:47.517Z,1558917287.517 [CBIT](DEBUG): Initialized mux pins.
2019-05-27T00:34:47.517Z,1558917287.517 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-27T00:34:47.541Z,1558917287.541 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-27T00:34:47.541Z,1558917287.541 [CBIT](DEBUG): Initializing heartbeat.
2019-05-27T00:34:47.547Z,1558917287.547 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 392
2019-05-27T00:34:47.548Z,1558917287.548 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-27T00:34:47.565Z,1558917287.565 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 393
2019-05-27T00:34:47.567Z,1558917287.567 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 394
2019-05-27T00:34:47.569Z,1558917287.569 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 396
2019-05-27T00:34:47.572Z,1558917287.572 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-27T00:34:47.573Z,1558917287.573 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-27T00:34:47.573Z,1558917287.573 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-27T00:34:47.573Z,1558917287.573 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-27T00:34:47.573Z,1558917287.573 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-27T00:34:47.573Z,1558917287.573 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-27T00:34:47.574Z,1558917287.574 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-27T00:34:47.574Z,1558917287.574 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-27T00:34:47.574Z,1558917287.574 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-27T00:34:47.574Z,1558917287.574 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-27T00:34:47.574Z,1558917287.574 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-27T00:34:47.574Z,1558917287.574 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-27T00:34:47.575Z,1558917287.575 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-27T00:34:47.575Z,1558917287.575 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-27T00:34:47.575Z,1558917287.575 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-27T00:34:47.575Z,1558917287.575 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-27T00:34:47.613Z,1558917287.613 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-27T00:34:47.613Z,1558917287.613 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-27T00:34:47.621Z,1558917287.621 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 395
2019-05-27T00:34:47.622Z,1558917287.622 [WetLabsBB2FL](INFO): Powering down
2019-05-27T00:34:47.649Z,1558917287.649 [CBIT](DEBUG): Backplane powered.
2019-05-27T00:34:47.654Z,1558917287.654 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-27T00:34:47.685Z,1558917287.685 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-27T00:34:47.720Z,1558917287.720 [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-27T00:34:47.721Z,1558917287.721 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-27T00:34:47.786Z,1558917287.786 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-27T00:34:47.787Z,1558917287.787 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-27T00:34:47.789Z,1558917287.789 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-27T00:34:47.828Z,1558917287.828 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-27T00:34:47.846Z,1558917287.846 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-27T00:34:47.852Z,1558917287.852 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-27T00:34:47.871Z,1558917287.871 [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-27T00:34:47.876Z,1558917287.876 [controlThread](DEBUG): Component order: CycleStarter,Depth_Keller,Micromodem,NAL9602,Onboard,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-27T00:34:47.922Z,1558917287.922 [Depth_Keller](ERROR): Pressure reading out of range: 1925.893799 decibar
2019-05-27T00:34:47.922Z,1558917287.922 [Micromodem](INFO): Start
2019-05-27T00:34:47.970Z,1558917287.970 [Radio_Surface](INFO): Powering up
2019-05-27T00:34:48.016Z,1558917288.016 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-27T00:34:48.034Z,1558917288.034 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-27T00:34:48.041Z,1558917288.041 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-27T00:34:48.042Z,1558917288.042 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-27T00:34:48.049Z,1558917288.049 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-27T00:34:48.050Z,1558917288.050 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-27T00:34:48.057Z,1558917288.057 [MassServo](DEBUG): Initializing MassServo.
2019-05-27T00:34:48.058Z,1558917288.058 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-27T00:34:48.065Z,1558917288.065 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-27T00:34:48.066Z,1558917288.066 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-27T00:34:48.073Z,1558917288.073 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-27T00:34:48.126Z,1558917288.126 [WetLabsBB2FL](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown. Software Overcurrent. Current Limiter Activated.
2019-05-27T00:34:48.126Z,1558917288.126 [WetLabsBB2FL] Hardware Fault, FailCount= 1
2019-05-27T00:34:48.126Z,1558917288.126 [WetLabsBB2FL](ERROR): Hardware Fault
2019-05-27T00:34:48.299Z,1558917288.299 [Micromodem](INFO): Starting
2019-05-27T00:34:48.299Z,1558917288.299 [Micromodem](INFO): Powering up
2019-05-27T00:34:48.300Z,1558917288.300 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-27T00:34:48.387Z,1558917288.387 [CBIT](ERROR): Hardware Fault in component: WetLabsBB2FL
2019-05-27T00:34:48.690Z,1558917288.690 [Micromodem](INFO): Starting
2019-05-27T00:34:49.061Z,1558917289.061 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-05-27T00:34:49.061Z,1558917289.061 [RudderServo](FAULT): Rudder failed to initialize
2019-05-27T00:34:49.061Z,1558917289.061 [RudderServo] Communications Fault, FailCount= 1
2019-05-27T00:34:49.061Z,1558917289.061 [RudderServo](ERROR): Communications Fault
2019-05-27T00:34:49.172Z,1558917289.172 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-05-27T00:34:49.172Z,1558917289.172 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2019-05-27T00:34:49.172Z,1558917289.172 [WetLabsBB2FL] No Fault, FailCount= 1
2019-05-27T00:34:49.182Z,1558917289.182 [Micromodem](INFO): Starting
2019-05-27T00:34:49.349Z,1558917289.349 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-05-27T00:34:49.349Z,1558917289.349 [WetLabsBB2FL](INFO): Powering up
2019-05-27T00:34:49.354Z,1558917289.354 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-27T00:34:49.354Z,1558917289.354 [RudderServo](INFO): Powering down
2019-05-27T00:34:49.590Z,1558917289.590 [Micromodem](INFO): Starting
2019-05-27T00:34:49.986Z,1558917289.986 [Micromodem](INFO): Starting
2019-05-27T00:34:50.043Z,1558917290.043 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-27T00:34:50.162Z,1558917290.162 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-27T00:34:50.166Z,1558917290.166 [CBIT](INFO): Clearing failed state for component RudderServo
2019-05-27T00:34:50.166Z,1558917290.166 [RudderServo] No Fault, FailCount= 1
2019-05-27T00:34:50.398Z,1558917290.398 [Micromodem](INFO): Starting
2019-05-27T00:34:50.802Z,1558917290.802 [Micromodem](INFO): Starting
2019-05-27T00:34:50.979Z,1558917290.979 [WetLabsBB2FL](ERROR): Uart error: serial buffer full
2019-05-27T00:34:50.979Z,1558917290.979 [WetLabsBB2FL] Communications Fault, FailCount= 2
2019-05-27T00:34:50.979Z,1558917290.979 [WetLabsBB2FL](ERROR): Communications Fault
2019-05-27T00:34:51.068Z,1558917291.068 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2019-05-27T00:34:51.206Z,1558917291.206 [Micromodem](INFO): Starting
2019-05-27T00:34:51.477Z,1558917291.477 [WetLabsBB2FL](INFO): Powering down
2019-05-27T00:34:51.610Z,1558917291.610 [Micromodem](INFO): Starting
2019-05-27T00:34:51.881Z,1558917291.881 [WetLabsBB2FL](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown. Software Overcurrent. Current Limiter Activated.
2019-05-27T00:34:51.882Z,1558917291.882 [WetLabsBB2FL] Hardware Fault, FailCount= 2
2019-05-27T00:34:51.882Z,1558917291.882 [WetLabsBB2FL](ERROR): Hardware Fault
2019-05-27T00:34:52.014Z,1558917292.014 [Micromodem](INFO): Starting
2019-05-27T00:34:52.305Z,1558917292.305 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2019-05-27T00:34:52.305Z,1558917292.305 [WetLabsBB2FL] No Fault, FailCount= 2
2019-05-27T00:34:52.418Z,1558917292.418 [Micromodem](INFO): Starting
2019-05-27T00:34:52.721Z,1558917292.721 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-05-27T00:34:52.722Z,1558917292.722 [WetLabsBB2FL](INFO): Powering up
2019-05-27T00:34:52.822Z,1558917292.822 [Micromodem](INFO): Starting
2019-05-27T00:34:52.939Z,1558917292.939 [MassServo](FAULT): Bad Operand Error
2019-05-27T00:34:52.939Z,1558917292.939 [MassServo] Hardware Fault, FailCount= 1
2019-05-27T00:34:52.939Z,1558917292.939 [MassServo](ERROR): Hardware Fault
2019-05-27T00:34:52.939Z,1558917292.939 [MassServo](FAULT): Mass Shifter error waiting for homing. Uart error: no error
2019-05-27T00:34:52.978Z,1558917292.978 [MassServo](FAULT): Reading outside of valid range:1091463.000000

2019-05-27T00:34:52.983Z,1558917292.983 [CBIT](ERROR): Hardware Fault in component: MassServo
2019-05-27T00:34:53.230Z,1558917293.230 [Micromodem](INFO): Starting
2019-05-27T00:34:53.230Z,1558917293.230 [Micromodem](INFO): Starting
2019-05-27T00:34:53.231Z,1558917293.231 [Micromodem](DEBUG): Nmea buf: $CCCFG,ALL,0*33

2019-05-27T00:34:53.231Z,1558917293.231 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-05-27T00:34:53.231Z,1558917293.231 [Micromodem](DEBUG): Nmea buf: $CCCFG,SRC,7*37

2019-05-27T00:34:53.232Z,1558917293.232 [Micromodem](DEBUG): Nmea buf: $CCCFG,BND,1*3B

2019-05-27T00:34:53.354Z,1558917293.354 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-27T00:34:53.355Z,1558917293.355 [MassServo](INFO): Powering down
2019-05-27T00:34:53.387Z,1558917293.387 [WetLabsBB2FL](ERROR): Uart error: serial buffer full
2019-05-27T00:34:53.387Z,1558917293.387 [WetLabsBB2FL] Communications Fault, FailCount= 3
2019-05-27T00:34:53.387Z,1558917293.387 [WetLabsBB2FL](ERROR): Communications Fault
2019-05-27T00:34:53.501Z,1558917293.501 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2019-05-27T00:34:53.630Z,1558917293.630 [Micromodem](INFO): Starting
2019-05-27T00:34:53.885Z,1558917293.885 [WetLabsBB2FL](INFO): Powering down
2019-05-27T00:34:54.042Z,1558917294.042 [Micromodem](INFO): Starting
2019-05-27T00:34:54.123Z,1558917294.123 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-27T00:34:54.242Z,1558917294.242 [MassServo](DEBUG): Initializing MassServo.
2019-05-27T00:34:54.246Z,1558917294.246 [CBIT](INFO): Clearing failed state for component MassServo
2019-05-27T00:34:54.246Z,1558917294.246 [MassServo] No Fault, FailCount= 1
2019-05-27T00:34:54.289Z,1558917294.289 [WetLabsBB2FL](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown. Software Overcurrent. Current Limiter Activated.
2019-05-27T00:34:54.290Z,1558917294.290 [WetLabsBB2FL] Hardware Fault, FailCount= 3
2019-05-27T00:34:54.290Z,1558917294.290 [WetLabsBB2FL](ERROR): Hardware Fault
2019-05-27T00:34:54.444Z,1558917294.444 [Micromodem](INFO): Starting
2019-05-27T00:34:54.842Z,1558917294.842 [Micromodem](INFO): Starting
2019-05-27T00:34:54.930Z,1558917294.930 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2019-05-27T00:34:54.931Z,1558917294.931 [WetLabsBB2FL] No Fault, FailCount= 3
2019-05-27T00:34:55.109Z,1558917295.109 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-05-27T00:34:55.109Z,1558917295.109 [WetLabsBB2FL](INFO): Powering up
2019-05-27T00:34:55.243Z,1558917295.243 [Micromodem](INFO): Starting
2019-05-27T00:34:55.244Z,1558917295.244 [Micromodem](INFO): Nmea in: 
$CAREV,051423,INIT,0.93.0.34*57

2019-05-27T00:34:55.244Z,1558917295.244 [Micromodem](ERROR): CFG response from modem unexpected: 
$CAREV,051423,INIT,0.93.0.34*57

2019-05-27T00:34:55.630Z,1558917295.630 [WetLabsBB2FL](ERROR): Uart error: serial buffer full
2019-05-27T00:34:55.630Z,1558917295.630 [WetLabsBB2FL] Communications Fault, FailCount= 4
2019-05-27T00:34:55.630Z,1558917295.630 [WetLabsBB2FL](ERROR): Communications Fault
2019-05-27T00:34:55.658Z,1558917295.658 [Micromodem](INFO): Starting
2019-05-27T00:34:55.737Z,1558917295.737 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2019-05-27T00:34:56.051Z,1558917296.051 [Micromodem](INFO): Starting
2019-05-27T00:34:56.157Z,1558917296.157 [WetLabsBB2FL](INFO): Powering down
2019-05-27T00:34:56.455Z,1558917296.455 [Micromodem](INFO): Starting
2019-05-27T00:34:56.561Z,1558917296.561 [WetLabsBB2FL](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown. Software Overcurrent. Current Limiter Activated.
2019-05-27T00:34:56.561Z,1558917296.561 [WetLabsBB2FL] Hardware Fault, FailCount= 4
2019-05-27T00:34:56.562Z,1558917296.562 [WetLabsBB2FL](ERROR): Hardware Fault
2019-05-27T00:34:56.859Z,1558917296.859 [Micromodem](INFO): Starting
2019-05-27T00:34:56.970Z,1558917296.970 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2019-05-27T00:34:56.970Z,1558917296.970 [WetLabsBB2FL] No Fault, FailCount= 4
2019-05-27T00:34:57.263Z,1558917297.263 [Micromodem](INFO): Starting
2019-05-27T00:34:57.381Z,1558917297.381 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-05-27T00:34:57.381Z,1558917297.381 [WetLabsBB2FL](INFO): Powering up
2019-05-27T00:34:57.667Z,1558917297.667 [Micromodem](INFO): Starting
2019-05-27T00:34:57.881Z,1558917297.881 [MassServo](ERROR): isCommunicating uart error serial timeout
2019-05-27T00:34:57.881Z,1558917297.881 [MassServo](FAULT): Invalid EZ Servo response:"\n"
2019-05-27T00:34:57.881Z,1558917297.881 [MassServo] Communications Fault, FailCount= 2
2019-05-27T00:34:57.881Z,1558917297.881 [MassServo](ERROR): Communications Fault
2019-05-27T00:34:57.882Z,1558917297.882 [MassServo](FAULT): Mass Shifter error waiting for homing. Uart error: serial timeout
2019-05-27T00:34:57.882Z,1558917297.882 [MassServo] Hardware Fault, FailCount= 2
2019-05-27T00:34:57.882Z,1558917297.882 [MassServo](ERROR): Hardware Fault
2019-05-27T00:34:57.963Z,1558917297.963 [WetLabsBB2FL](ERROR): Uart error: serial buffer full
2019-05-27T00:34:57.963Z,1558917297.963 [WetLabsBB2FL] Communications Fault, FailCount= 5
2019-05-27T00:34:57.963Z,1558917297.963 [WetLabsBB2FL](ERROR): Communications Fault
2019-05-27T00:34:58.269Z,1558917298.269 [CBIT](ERROR): Hardware Fault in component: MassServo
2019-05-27T00:34:58.269Z,1558917298.269 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2019-05-27T00:34:58.269Z,1558917298.269 [CBIT](FAULT): Communications Fault in component: WetLabsBB2FL
2019-05-27T00:34:58.278Z,1558917298.278 [Micromodem](INFO): Starting
2019-05-27T00:34:58.345Z,1558917298.345 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-27T00:34:58.345Z,1558917298.345 [MassServo](INFO): Powering down
2019-05-27T00:34:58.461Z,1558917298.461 [WetLabsBB2FL](INFO): Powering down
2019-05-27T00:34:58.682Z,1558917298.682 [Micromodem](INFO): Starting
2019-05-27T00:34:58.865Z,1558917298.865 [WetLabsBB2FL](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown. Software Overcurrent. Current Limiter Activated.
2019-05-27T00:34:58.866Z,1558917298.866 [WetLabsBB2FL] Hardware Fault, FailCount= 5
2019-05-27T00:34:58.866Z,1558917298.866 [WetLabsBB2FL](ERROR): Hardware Fault
2019-05-27T00:34:59.086Z,1558917299.086 [Micromodem](INFO): Starting
2019-05-27T00:34:59.153Z,1558917299.153 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-27T00:34:59.274Z,1558917299.274 [MassServo](DEBUG): Initializing MassServo.
2019-05-27T00:34:59.278Z,1558917299.278 [CBIT](INFO): Clearing failed state for component MassServo
2019-05-27T00:34:59.278Z,1558917299.278 [MassServo] No Fault, FailCount= 2
2019-05-27T00:34:59.490Z,1558917299.490 [Micromodem](INFO): Starting
2019-05-27T00:34:59.718Z,1558917299.718 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004476
2019-05-27T00:34:59.894Z,1558917299.894 [Micromodem](INFO): Starting
2019-05-27T00:35:00.298Z,1558917300.298 [Micromodem](INFO): Starting
2019-05-27T00:35:00.702Z,1558917300.702 [Micromodem](INFO): Starting
2019-05-27T00:35:01.106Z,1558917301.106 [Micromodem](INFO): Starting
2019-05-27T00:35:01.510Z,1558917301.510 [Micromodem](INFO): Starting
2019-05-27T00:35:01.914Z,1558917301.914 [Micromodem](INFO): Starting
2019-05-27T00:35:02.318Z,1558917302.318 [Micromodem](INFO): Starting
2019-05-27T00:35:02.722Z,1558917302.722 [Micromodem](INFO): Starting
2019-05-27T00:35:03.126Z,1558917303.126 [Micromodem](INFO): Starting
2019-05-27T00:35:03.530Z,1558917303.530 [Micromodem](INFO): Starting
2019-05-27T00:35:03.934Z,1558917303.934 [Micromodem](INFO): Starting
2019-05-27T00:35:04.338Z,1558917304.338 [Micromodem](INFO): Starting
2019-05-27T00:35:04.338Z,1558917304.338 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2019-05-27T00:35:04.742Z,1558917304.742 [Micromodem](INFO): Starting
2019-05-27T00:35:04.742Z,1558917304.742 [Micromodem](INFO): Nmea in: .34*0F

2019-05-27T00:35:04.743Z,1558917304.743 [Micromodem](ERROR): Response from modem failed NMEA checksum: .34*0F
 expected 0
2019-05-27T00:35:04.743Z,1558917304.743 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-05-27T00:35:05.146Z,1558917305.146 [Micromodem](INFO): Starting
2019-05-27T00:35:05.550Z,1558917305.550 [Micromodem](INFO): Starting
2019-05-27T00:35:05.962Z,1558917305.962 [Micromodem](INFO): Starting
2019-05-27T00:35:06.358Z,1558917306.358 [Micromodem](INFO): Starting
2019-05-27T00:35:06.359Z,1558917306.359 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2019-05-27T00:35:06.359Z,1558917306.359 [Micromodem](INFO): Nmea out: $CCCFG,SRC,7*37

2019-05-27T00:35:06.762Z,1558917306.762 [Micromodem](INFO): Starting
2019-05-27T00:35:07.166Z,1558917307.166 [Micromodem](INFO): Starting
2019-05-27T00:35:07.570Z,1558917307.570 [Micromodem](INFO): Starting
2019-05-27T00:35:07.974Z,1558917307.974 [Micromodem](INFO): Starting
2019-05-27T00:35:08.378Z,1558917308.378 [Micromodem](INFO): Starting
2019-05-27T00:35:08.782Z,1558917308.782 [Micromodem](INFO): Starting
2019-05-27T00:35:09.186Z,1558917309.186 [Micromodem](INFO): Starting
2019-05-27T00:35:09.590Z,1558917309.590 [Micromodem](INFO): Starting
2019-05-27T00:35:09.994Z,1558917309.994 [Micromodem](INFO): Starting
2019-05-27T00:35:10.398Z,1558917310.398 [Micromodem](INFO): Starting
2019-05-27T00:35:10.802Z,1558917310.802 [Micromodem](INFO): Starting
2019-05-27T00:35:11.206Z,1558917311.206 [Micromodem](INFO): Starting
2019-05-27T00:35:11.610Z,1558917311.610 [Micromodem](INFO): Starting
2019-05-27T00:35:12.014Z,1558917312.014 [Micromodem](INFO): Starting
2019-05-27T00:35:12.418Z,1558917312.418 [Micromodem](INFO): Starting
2019-05-27T00:35:12.822Z,1558917312.822 [Micromodem](INFO): Starting
2019-05-27T00:35:13.226Z,1558917313.226 [Micromodem](INFO): Starting
2019-05-27T00:35:13.630Z,1558917313.630 [Micromodem](INFO): Starting
2019-05-27T00:35:14.034Z,1558917314.034 [Micromodem](INFO): Starting
2019-05-27T00:35:14.438Z,1558917314.438 [Micromodem](INFO): Starting
2019-05-27T00:35:14.842Z,1558917314.842 [Micromodem](INFO): Starting
2019-05-27T00:35:15.246Z,1558917315.246 [Micromodem](INFO): Starting
2019-05-27T00:35:15.247Z,1558917315.247 [NAL9602](INFO): Powering up NAL9602
2019-05-27T00:35:15.650Z,1558917315.650 [Micromodem](INFO): Starting
2019-05-27T00:35:16.054Z,1558917316.054 [Micromodem](INFO): Starting
2019-05-27T00:35:16.122Z,1558917316.122 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-27T00:35:16.126Z,1558917316.126 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-27T00:35:16.458Z,1558917316.458 [Micromodem](INFO): Starting
2019-05-27T00:35:16.458Z,1558917316.458 [Micromodem](INFO): Nmea in: $CACFG,SRC,7*35

2019-05-27T00:35:16.459Z,1558917316.459 [Micromodem](INFO): Nmea out: $CCCFG,BND,1*3B

2019-05-27T00:35:16.862Z,1558917316.862 [Micromodem](INFO): Starting
2019-05-27T00:35:17.266Z,1558917317.266 [Micromodem](INFO): Starting
2019-05-27T00:35:17.266Z,1558917317.266 [Micromodem](INFO): Nmea in: $CACFG,BND,1*39

2019-05-27T00:35:17.267Z,1558917317.267 [Micromodem](DEBUG): Nmea buf: $CCCLK,2019,9-,5-,7T,0:,5:*24

2019-05-27T00:35:17.267Z,1558917317.267 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,7T,0:,5:*24

2019-05-27T00:35:17.668Z,1558917317.668 [Micromodem](INFO): Starting
2019-05-27T00:35:18.083Z,1558917318.083 [Micromodem](INFO): Starting
2019-05-27T00:35:18.566Z,1558917318.566 [Micromodem](INFO): Starting
2019-05-27T00:35:18.970Z,1558917318.970 [Micromodem](INFO): Starting
2019-05-27T00:35:19.382Z,1558917319.382 [Micromodem](INFO): Starting
2019-05-27T00:35:19.774Z,1558917319.774 [Micromodem](INFO): Starting
2019-05-27T00:35:20.182Z,1558917320.182 [Micromodem](INFO): Starting
2019-05-27T00:35:20.587Z,1558917320.587 [Micromodem](INFO): Starting
2019-05-27T00:35:20.990Z,1558917320.990 [Micromodem](INFO): Starting
2019-05-27T00:35:21.394Z,1558917321.394 [Micromodem](INFO): Starting
2019-05-27T00:35:21.798Z,1558917321.798 [Micromodem](INFO): Starting
2019-05-27T00:35:22.202Z,1558917322.202 [Micromodem](INFO): Starting
2019-05-27T00:35:22.606Z,1558917322.606 [Micromodem](INFO): Starting
2019-05-27T00:35:23.010Z,1558917323.010 [Micromodem](INFO): Starting
2019-05-27T00:35:23.414Z,1558917323.414 [Micromodem](INFO): Starting
2019-05-27T00:35:23.818Z,1558917323.818 [Micromodem](INFO): Starting
2019-05-27T00:35:24.222Z,1558917324.222 [Micromodem](INFO): Starting
2019-05-27T00:35:24.626Z,1558917324.626 [Micromodem](INFO): Starting
2019-05-27T00:35:25.030Z,1558917325.030 [Micromodem](INFO): Starting
2019-05-27T00:35:25.434Z,1558917325.434 [Micromodem](INFO): Starting
2019-05-27T00:35:25.838Z,1558917325.838 [Micromodem](INFO): Starting
2019-05-27T00:35:26.242Z,1558917326.242 [Micromodem](INFO): Starting
2019-05-27T00:35:26.646Z,1558917326.646 [Micromodem](INFO): Starting
2019-05-27T00:35:27.050Z,1558917327.050 [Micromodem](INFO): Starting
2019-05-27T00:35:27.137Z,1558917327.137 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.001811
CHAN A1 (24V): 0.171724
CHAN A2 (12V): -0.007276
CHAN A3 (5V): -0.002539
CHAN B0 (3.3V): 0.000173
CHAN B1 (3.15aV): 0.000081
CHAN B2 (3.15bV): 0.000507
CHAN B3 (GND): 0.001824
OPEN: -0.000335
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-27T00:35:27.466Z,1558917327.466 [Micromodem](INFO): Starting
2019-05-27T00:35:27.858Z,1558917327.858 [Micromodem](INFO): Starting
2019-05-27T00:35:27.859Z,1558917327.859 [Micromodem](INFO): Nmea in: $CACLK,2019,09,05,07,00,05*42

2019-05-27T00:35:36.027Z,1558917336.027 [NAL9602](ERROR): NAL9602 initialization error.
2019-05-27T00:35:36.027Z,1558917336.027 [NAL9602] Communications Fault, FailCount= 1
2019-05-27T00:35:36.027Z,1558917336.027 [NAL9602](ERROR): Communications Fault
2019-05-27T00:35:36.166Z,1558917336.166 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-05-27T00:35:36.431Z,1558917336.431 [NAL9602](INFO): Powering down
2019-05-27T00:35:37.330Z,1558917337.330 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-27T00:35:37.330Z,1558917337.330 [NAL9602] No Fault, FailCount= 1
2019-05-27T00:35:45.413Z,1558917345.413 [CommandLine](IMPORTANT): got command show state
2019-05-27T00:35:45.413Z,1558917345.413 [CommandLine](IMPORTANT): Mission State:

2019-05-27T00:35:48.152Z,1558917348.152 [Micromodem](INFO): Nmea in: $CADQF,191,2*5A

2019-05-27T00:35:48.551Z,1558917348.551 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC,2*23

2019-05-27T00:35:52.188Z,1558917352.188 [Micromodem](INFO): Nmea in: $CACST,1,070034.0000,1,344,-4,0114,0112,250,03,03,05,05,-1,-1,-1,0,2,1,1,-1,-1,-1,-1,00,191,0.1,-1*4B

2019-05-27T00:35:59.977Z,1558917359.977 [CommandLine](IMPORTANT): got command show stack
2019-05-27T00:35:59.977Z,1558917359.977 [CommandLine](IMPORTANT): Behavior Stack:

2019-05-27T00:35:59.978Z,1558917359.978 [MissionManager](IMPORTANT): Mission loaded, but not running.
2019-05-27T00:36:06.811Z,1558917366.811 [NAL9602](INFO): Powering up NAL9602
2019-05-27T00:36:09.679Z,1558917369.679 [SBIT](IMPORTANT): SBIT PASSED
2019-05-27T00:36:09.697Z,1558917369.697 [CommandLine](IMPORTANT): got command configSet list
2019-05-27T00:36:09.697Z,1558917369.697 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-27T00:36:09.698Z,1558917369.698 [CommandLine](IMPORTANT): AHRS_M2.loadAtStartup=0 bool;

2019-05-27T00:36:09.699Z,1558917369.699 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=0 count;

2019-05-27T00:36:09.699Z,1558917369.699 [CommandLine](IMPORTANT): CBIT.vehicleOpen=1 bool;

2019-05-27T00:36:09.699Z,1558917369.699 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2019-05-27T00:36:09.699Z,1558917369.699 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-05-27T00:36:09.699Z,1558917369.699 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2019-05-27T00:36:09.699Z,1558917369.699 [CommandLine](IMPORTANT): VerticalControl.surfaceThreshold=1 meter;

2019-05-27T00:36:10.070Z,1558917370.070 [MissionManager](IMPORTANT): Started mission Startup
2019-05-27T00:36:10.070Z,1558917370.070 [Startup] Running Loop=1
2019-05-27T00:36:10.071Z,1558917370.071 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-27T00:36:10.071Z,1558917370.071 [Startup:A.GoToSurface] Running Loop=1
2019-05-27T00:36:10.071Z,1558917370.071 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-27T00:36:10.071Z,1558917370.071 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-27T00:36:10.072Z,1558917370.072 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-27T00:36:10.072Z,1558917370.072 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-27T00:36:10.072Z,1558917370.072 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-27T00:36:10.073Z,1558917370.073 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-27T00:36:10.074Z,1558917370.074 [Startup:StartupSatComms] Running Loop=1
2019-05-27T00:36:10.075Z,1558917370.075 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-27T00:36:10.075Z,1558917370.075 [Startup:StartupSatComms:A] Running Loop=1
2019-05-27T00:36:10.479Z,1558917370.479 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-27T00:36:16.104Z,1558917376.104 [Micromodem](INFO): Nmea in: $CADQF,192,2*59

2019-05-27T00:36:16.508Z,1558917376.508 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC,2*23

2019-05-27T00:36:19.740Z,1558917379.740 [Micromodem](INFO): Nmea in: $CACST,1,070102.0000,1,77,-5,0114,0112,250,03,03,04,05,-1,-1,-1,0,2,1,1,-1,-1,-1,-1,00,192,0.0,-1*7E

2019-05-27T00:36:27.415Z,1558917387.415 [NAL9602](ERROR): NAL9602 initialization error.
2019-05-27T00:36:27.415Z,1558917387.415 [NAL9602] Communications Fault, FailCount= 2
2019-05-27T00:36:27.415Z,1558917387.415 [NAL9602](ERROR): Communications Fault
2019-05-27T00:36:27.456Z,1558917387.456 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-05-27T00:36:27.815Z,1558917387.815 [NAL9602](INFO): Powering down
2019-05-27T00:36:28.659Z,1558917388.659 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-27T00:36:28.659Z,1558917388.659 [NAL9602] No Fault, FailCount= 2
2019-05-27T00:36:47.641Z,1558917407.641 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-27T00:36:47.641Z,1558917407.641 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-27T00:36:47.642Z,1558917407.642 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-27T00:36:47.652Z,1558917407.652 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-27T00:36:48.105Z,1558917408.105 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-27T00:36:48.105Z,1558917408.105 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-27T00:36:58.119Z,1558917418.119 [NAL9602](INFO): Powering up NAL9602
2019-05-27T00:37:10.266Z,1558917430.266 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-27T00:36:10.1Z
2019-05-27T00:37:10.266Z,1558917430.266 [Startup:StartupSatComms:A] Stopped
2019-05-27T00:37:10.266Z,1558917430.266 [Startup:StartupSatComms:B] Running Loop=1
2019-05-27T00:37:10.674Z,1558917430.674 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-27T00:37:13.194Z,1558917433.194 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190508T221548/Courier0235.lzma
2019-05-27T00:37:14.003Z,1558917434.003 [DataOverHttps](INFO): Moved sent file to Logs/20190508T221548/Courier0235.lzma.bak
2019-05-27T00:37:14.003Z,1558917434.003 [DataOverHttps](INFO): SBD MOMSN=11189443
2019-05-27T00:37:18.719Z,1558917438.719 [NAL9602](ERROR): NAL9602 initialization error.
2019-05-27T00:37:18.719Z,1558917438.719 [NAL9602] Communications Fault, FailCount= 3
2019-05-27T00:37:18.719Z,1558917438.719 [NAL9602](ERROR): Communications Fault
2019-05-27T00:37:18.794Z,1558917438.794 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-05-27T00:37:19.123Z,1558917439.123 [NAL9602](INFO): Powering down
2019-05-27T00:37:19.964Z,1558917439.964 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-27T00:37:19.964Z,1558917439.964 [NAL9602] No Fault, FailCount= 3
2019-05-27T00:37:20.853Z,1558917440.853 [CommandLine](IMPORTANT): got command show stack
2019-05-27T00:37:20.853Z,1558917440.853 [CommandLine](IMPORTANT): Behavior Stack:

2019-05-27T00:37:20.854Z,1558917440.854 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2019-05-27T00:37:20.854Z,1558917440.854 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B
2019-05-27T00:37:25.042Z,1558917445.042 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20190515T161931/Courier0000.lzma
2019-05-27T00:37:25.846Z,1558917445.846 [DataOverHttps](INFO): Moved sent file to Logs/20190515T161931/Courier0000.lzma.bak
2019-05-27T00:37:25.846Z,1558917445.846 [DataOverHttps](INFO): SBD MOMSN=11189445
2019-05-27T00:37:28.063Z,1558917448.063 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2019-05-27T00:37:28.063Z,1558917448.063 [WetLabsBB2FL] No Fault, FailCount= 5
2019-05-27T00:37:28.346Z,1558917448.346 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-05-27T00:37:28.346Z,1558917448.346 [WetLabsBB2FL](INFO): Powering up
2019-05-27T00:37:29.970Z,1558917449.970 [WetLabsBB2FL](ERROR): Uart error: serial buffer full
2019-05-27T00:37:29.970Z,1558917449.970 [WetLabsBB2FL] Communications Fault, FailCount= 1
2019-05-27T00:37:29.970Z,1558917449.970 [WetLabsBB2FL](ERROR): Communications Fault
2019-05-27T00:37:30.130Z,1558917450.130 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2019-05-27T00:37:30.469Z,1558917450.469 [WetLabsBB2FL](INFO): Powering down
2019-05-27T00:37:30.873Z,1558917450.873 [WetLabsBB2FL](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown. Software Overcurrent. Current Limiter Activated.
2019-05-27T00:37:30.874Z,1558917450.874 [WetLabsBB2FL] Hardware Fault, FailCount= 1
2019-05-27T00:37:30.874Z,1558917450.874 [WetLabsBB2FL](ERROR): Hardware Fault
2019-05-27T00:37:31.284Z,1558917451.284 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2019-05-27T00:37:31.284Z,1558917451.284 [WetLabsBB2FL] No Fault, FailCount= 1
2019-05-27T00:37:31.682Z,1558917451.682 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-05-27T00:37:31.682Z,1558917451.682 [WetLabsBB2FL](INFO): Powering up
2019-05-27T00:37:36.973Z,1558917456.973 [WetLabsBB2FL] Communications Fault, FailCount= 2
2019-05-27T00:37:36.973Z,1558917456.973 [WetLabsBB2FL](ERROR): Communications Fault
2019-05-27T00:37:37.106Z,1558917457.106 [DataOverHttps](INFO): Sending 247 bytes from file Logs/20190515T161931/Courier0004.lzma
2019-05-27T00:37:37.343Z,1558917457.343 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2019-05-27T00:37:37.473Z,1558917457.473 [WetLabsBB2FL](INFO): Powering down
2019-05-27T00:37:37.878Z,1558917457.878 [WetLabsBB2FL](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown. Software Overcurrent. Current Limiter Activated.
2019-05-27T00:37:37.878Z,1558917457.878 [WetLabsBB2FL] Hardware Fault, FailCount= 2
2019-05-27T00:37:37.878Z,1558917457.878 [WetLabsBB2FL](ERROR): Hardware Fault
2019-05-27T00:37:37.914Z,1558917457.914 [DataOverHttps](INFO): Moved sent file to Logs/20190515T161931/Courier0004.lzma.bak
2019-05-27T00:37:37.914Z,1558917457.914 [DataOverHttps](INFO): SBD MOMSN=11189452
2019-05-27T00:37:38.574Z,1558917458.574 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2019-05-27T00:37:38.574Z,1558917458.574 [WetLabsBB2FL] No Fault, FailCount= 2
2019-05-27T00:37:38.693Z,1558917458.693 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-05-27T00:37:38.693Z,1558917458.693 [WetLabsBB2FL](INFO): Powering up
2019-05-27T00:37:39.980Z,1558917459.980 [WetLabsBB2FL](ERROR): Uart error: serial buffer full
2019-05-27T00:37:39.980Z,1558917459.980 [WetLabsBB2FL] Communications Fault, FailCount= 3
2019-05-27T00:37:39.980Z,1558917459.980 [WetLabsBB2FL](ERROR): Communications Fault
2019-05-27T00:37:40.130Z,1558917460.130 [Micromodem](INFO): Nmea in: .34*0D

2019-05-27T00:37:40.130Z,1558917460.130 [Micromodem](ERROR): Response from modem failed NMEA checksum: .34*0D
 expected 0
2019-05-27T00:37:40.182Z,1558917460.182 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2019-05-27T00:37:40.477Z,1558917460.477 [WetLabsBB2FL](INFO): Powering down
2019-05-27T00:37:40.882Z,1558917460.882 [WetLabsBB2FL](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown. Software Overcurrent. Current Limiter Activated.
2019-05-27T00:37:40.882Z,1558917460.882 [WetLabsBB2FL] Hardware Fault, FailCount= 3
2019-05-27T00:37:40.882Z,1558917460.882 [WetLabsBB2FL](ERROR): Hardware Fault
2019-05-27T00:37:41.395Z,1558917461.395 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2019-05-27T00:37:41.395Z,1558917461.395 [WetLabsBB2FL] No Fault, FailCount= 3
2019-05-27T00:37:41.697Z,1558917461.697 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-05-27T00:37:41.697Z,1558917461.697 [WetLabsBB2FL](INFO): Powering up
2019-05-27T00:37:42.150Z,1558917462.150 [Micromodem](INFO): Nmea in: .34*0E

2019-05-27T00:37:42.151Z,1558917462.151 [Micromodem](ERROR): Response from modem failed NMEA checksum: .34*0E
 expected 0
2019-05-27T00:37:42.402Z,1558917462.402 [WetLabsBB2FL](ERROR): Uart error: serial buffer full
2019-05-27T00:37:42.402Z,1558917462.402 [WetLabsBB2FL] Communications Fault, FailCount= 4
2019-05-27T00:37:42.402Z,1558917462.402 [WetLabsBB2FL](ERROR): Communications Fault
2019-05-27T00:37:42.735Z,1558917462.735 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2019-05-27T00:37:42.909Z,1558917462.909 [WetLabsBB2FL](INFO): Powering down
2019-05-27T00:37:43.314Z,1558917463.314 [WetLabsBB2FL](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown. Software Overcurrent. Current Limiter Activated.
2019-05-27T00:37:43.314Z,1558917463.314 [WetLabsBB2FL] Hardware Fault, FailCount= 4
2019-05-27T00:37:43.314Z,1558917463.314 [WetLabsBB2FL](ERROR): Hardware Fault
2019-05-27T00:37:43.819Z,1558917463.819 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2019-05-27T00:37:43.819Z,1558917463.819 [WetLabsBB2FL] No Fault, FailCount= 4
2019-05-27T00:37:44.123Z,1558917464.123 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-05-27T00:37:44.123Z,1558917464.123 [WetLabsBB2FL](INFO): Powering up
2019-05-27T00:37:45.843Z,1558917465.843 [Micromodem](INFO): Nmea in: 71

2019-05-27T00:37:45.843Z,1558917465.843 [Micromodem](ERROR): Response from modem failed NMEA checksum: 71
 expected 0
2019-05-27T00:37:45.917Z,1558917465.917 [WetLabsBB2FL](ERROR): Uart error: serial buffer full
2019-05-27T00:37:45.917Z,1558917465.917 [WetLabsBB2FL] Communications Fault, FailCount= 5
2019-05-27T00:37:45.917Z,1558917465.917 [WetLabsBB2FL](ERROR): Communications Fault
2019-05-27T00:37:46.235Z,1558917466.235 [CBIT](ERROR): Communications Fault in component: WetLabsBB2FL
2019-05-27T00:37:46.236Z,1558917466.236 [CBIT](FAULT): Communications Fault in component: WetLabsBB2FL
2019-05-27T00:37:46.417Z,1558917466.417 [WetLabsBB2FL](INFO): Powering down
2019-05-27T00:37:46.821Z,1558917466.821 [WetLabsBB2FL](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown. Software Overcurrent. Current Limiter Activated.
2019-05-27T00:37:46.821Z,1558917466.821 [WetLabsBB2FL] Hardware Fault, FailCount= 5
2019-05-27T00:37:46.822Z,1558917466.822 [WetLabsBB2FL](ERROR): Hardware Fault
2019-05-27T00:37:49.088Z,1558917469.088 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190515T161931/Courier0007.lzma
2019-05-27T00:37:49.427Z,1558917469.427 [NAL9602](INFO): Powering up NAL9602
2019-05-27T00:37:49.890Z,1558917469.890 [DataOverHttps](INFO): Moved sent file to Logs/20190515T161931/Courier0007.lzma.bak
2019-05-27T00:37:49.891Z,1558917469.891 [DataOverHttps](INFO): SBD MOMSN=11189456
2019-05-27T00:37:55.898Z,1558917475.898 [Micromodem](INFO): Nmea in: .34*0B

2019-05-27T00:37:55.899Z,1558917475.899 [Micromodem](ERROR): Response from modem failed NMEA checksum: .34*0B
 expected 0
2019-05-27T00:38:03.498Z,1558917483.498 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20190515T164228/Courier0000.lzma
2019-05-27T00:38:04.302Z,1558917484.302 [DataOverHttps](INFO): Moved sent file to Logs/20190515T164228/Courier0000.lzma.bak
2019-05-27T00:38:04.303Z,1558917484.303 [DataOverHttps](INFO): SBD MOMSN=11189458
2019-05-27T00:38:07.616Z,1558917487.616 [Micromodem](INFO): Nmea in: $CADQF,193,2*58

2019-05-27T00:38:08.019Z,1558917488.019 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC,2*23

2019-05-27T00:38:10.039Z,1558917490.039 [NAL9602](ERROR): NAL9602 initialization error.
2019-05-27T00:38:10.039Z,1558917490.039 [NAL9602] Communications Fault, FailCount= 4
2019-05-27T00:38:10.039Z,1558917490.039 [NAL9602](ERROR): Communications Fault
2019-05-27T00:38:10.104Z,1558917490.104 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-05-27T00:38:10.447Z,1558917490.447 [NAL9602](INFO): Powering down
2019-05-27T00:38:10.487Z,1558917490.487 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-27T00:37:10.3Z
2019-05-27T00:38:10.487Z,1558917490.487 [Startup:StartupSatComms:B] Stopped
2019-05-27T00:38:10.487Z,1558917490.487 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-27T00:38:10.487Z,1558917490.487 [Startup:StartupSatComms] Stopped
2019-05-27T00:38:10.487Z,1558917490.487 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-27T00:38:10.488Z,1558917490.488 [Startup](INFO): Completed Startup
2019-05-27T00:38:10.488Z,1558917490.488 [MissionManager](INFO): Startup is completed.
2019-05-27T00:38:10.488Z,1558917490.488 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-27T00:38:10.488Z,1558917490.488 [Startup] Stopped
2019-05-27T00:38:10.488Z,1558917490.488 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-27T00:38:10.488Z,1558917490.488 [Startup:A.GoToSurface] Stopped
2019-05-27T00:38:10.498Z,1558917490.498 [CommandLine](IMPORTANT): got command show stack
2019-05-27T00:38:10.498Z,1558917490.498 [CommandLine](IMPORTANT): Behavior Stack:

2019-05-27T00:38:10.489Z,1558917490.489 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-27T00:38:10.506Z,1558917490.506 [MissionManager](IMPORTANT): Mission loaded, but not running.
2019-05-27T00:38:10.878Z,1558917490.878 [MissionManager](IMPORTANT): Started mission Default
2019-05-27T00:38:10.878Z,1558917490.878 [Default] Running Loop=1
2019-05-27T00:38:10.878Z,1558917490.878 [Default](DEBUG): Aggregate::initialize Default
2019-05-27T00:38:10.878Z,1558917490.878 [Default:B.GoToSurface] Running Loop=1
2019-05-27T00:38:10.878Z,1558917490.878 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-27T00:38:10.878Z,1558917490.878 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-27T00:38:10.879Z,1558917490.879 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-27T00:38:10.879Z,1558917490.879 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-27T00:38:10.879Z,1558917490.879 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-27T00:38:10.880Z,1558917490.880 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-27T00:38:10.880Z,1558917490.880 [Default:A.Wait] Running Loop=1
2019-05-27T00:38:10.880Z,1558917490.880 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-27T00:38:11.287Z,1558917491.287 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-27T00:38:11.287Z,1558917491.287 [NAL9602] No Fault, FailCount= 4
2019-05-27T00:38:11.676Z,1558917491.676 [Micromodem](INFO): Nmea in: $CACST,1,070254.0000,1,440,-3,0127,0112,250,03,03,05,03,-1,-1,-1,0,2,1,1,-1,-1,-1,-1,00,193,0.0,-1*4E

2019-05-27T00:38:15.542Z,1558917495.542 [DataOverHttps](INFO): Sending 247 bytes from file Logs/20190515T164228/Courier0004.lzma
2019-05-27T00:38:16.346Z,1558917496.346 [DataOverHttps](INFO): Moved sent file to Logs/20190515T164228/Courier0004.lzma.bak
2019-05-27T00:38:16.346Z,1558917496.346 [DataOverHttps](INFO): SBD MOMSN=11189466
2019-05-27T00:38:24.211Z,1558917504.211 [Default:A.Wait](INFO): Done Waiting.
2019-05-27T00:38:24.211Z,1558917504.211 [Default:A.Wait] Stopped
2019-05-27T00:38:24.211Z,1558917504.211 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-27T00:38:24.607Z,1558917504.607 [Default:CheckIn] Running Loop=1
2019-05-27T00:38:24.607Z,1558917504.607 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-27T00:38:24.607Z,1558917504.607 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-27T00:38:25.015Z,1558917505.015 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-27T00:38:40.747Z,1558917520.747 [NAL9602](INFO): Powering up NAL9602
2019-05-27T00:38:42.356Z,1558917522.356 [CommandLine](IMPORTANT): got command run ./Missions/Insert/MicromodemComms.xml
2019-05-27T00:38:42.357Z,1558917522.357 [MissionManager](INFO): Loading Mission: ./Missions/Insert/MicromodemComms.xml
2019-05-27T00:38:42.376Z,1558917522.376 [MissionManager](INFO): DefineArg MicromodemComms.Timeout = 10.000000 min
2019-05-27T00:38:42.397Z,1558917522.397 [MissionManager](INFO): DefineArg MicromodemComms.CommsInterval = 5.000000 min
2019-05-27T00:38:42.403Z,1558917522.403 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Aggregate 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="MicromodemComms">
       
    <Description>
        Triggers periodic uModem comms.
    </Description>

    <DefineArg Name="Timeout"><Units:minute/><Value>10</Value></DefineArg>
    
    <DefineArg Name="CommsInterval"><Description>
        The timing is based on the variable Universal:platform_communications
    </Description><Units:minute/><Value>5</Value></DefineArg>
    
    <When>
        <Called/>
        <Or>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt>
                <Arg Name="CommsInterval"/>
            </Gt>
        </Or>
    </When>

    <Aggregate Id="CheckIn">

        <Sequence/>

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

    </Aggregate>

</Aggregate>


2019-05-27T00:38:42.405Z,1558917522.405 [CommandLine](IMPORTANT): Running ./Missions/Insert/MicromodemComms.xml
2019-05-27T00:38:42.410Z,1558917522.410 [Default] Stopped
2019-05-27T00:38:42.411Z,1558917522.411 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-27T00:38:42.411Z,1558917522.411 [Default:B.GoToSurface] Stopped
2019-05-27T00:38:42.411Z,1558917522.411 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-27T00:38:42.411Z,1558917522.411 [Default:CheckIn] Stopped
2019-05-27T00:38:42.411Z,1558917522.411 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-27T00:38:42.411Z,1558917522.411 [Default:CheckIn:Read_GPS] Stopped
2019-05-27T00:38:42.411Z,1558917522.411 [MissionManager](IMPORTANT): Started mission MicromodemComms
2019-05-27T00:38:42.411Z,1558917522.411 [MicromodemComms] Running Loop=1
2019-05-27T00:38:42.412Z,1558917522.412 [MicromodemComms](DEBUG): Aggregate::initialize MicromodemComms
2019-05-27T00:38:42.412Z,1558917522.412 [MicromodemComms:CheckIn] Running Loop=1
2019-05-27T00:38:42.412Z,1558917522.412 [MicromodemComms:CheckIn](DEBUG): Aggregate::initialize MicromodemComms:CheckIn
2019-05-27T00:38:42.412Z,1558917522.412 [MicromodemComms:CheckIn:A] Running Loop=1
2019-05-27T00:38:42.413Z,1558917522.413 [MicromodemComms:CheckIn:A](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-27T00:38:48.851Z,1558917528.851 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-27T00:38:48.851Z,1558917528.851 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-05-27T00:38:48.851Z,1558917528.851 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-27T00:38:48.861Z,1558917528.861 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-27T00:38:49.318Z,1558917529.318 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-27T00:38:49.319Z,1558917529.319 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-05-27T00:38:52.910Z,1558917532.910 [DataOverHttps](INFO): Sending 78 bytes from file Logs/20190515T164228/Courier0007.lzma
2019-05-27T00:38:53.714Z,1558917533.714 [DataOverHttps](INFO): Moved sent file to Logs/20190515T164228/Courier0007.lzma.bak
2019-05-27T00:38:53.715Z,1558917533.715 [DataOverHttps](INFO): SBD MOMSN=11189500
2019-05-27T00:39:01.351Z,1558917541.351 [NAL9602](ERROR): NAL9602 initialization error.
2019-05-27T00:39:01.351Z,1558917541.351 [NAL9602] Communications Fault, FailCount= 5
2019-05-27T00:39:01.351Z,1558917541.351 [NAL9602](ERROR): Communications Fault
2019-05-27T00:39:01.402Z,1558917541.402 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-05-27T00:39:01.402Z,1558917541.402 [CBIT](CRITICAL): Communications Fault in component: NAL9602
2019-05-27T00:39:01.755Z,1558917541.755 [NAL9602](INFO): Powering down
2019-05-27T00:39:01.810Z,1558917541.810 [CommandLine](FAULT): Scheduling is paused
2019-05-27T00:39:01.811Z,1558917541.811 [CBIT](INFO): Critical error at 20190527T003901
2019-05-27T00:39:01.811Z,1558917541.811 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-05-27T00:39:02.209Z,1558917542.209 [MissionManager](INFO): MissionManager is completed.
2019-05-27T00:39:02.210Z,1558917542.210 [MissionManager](INFO): Uninitializing Mission MicromodemComms
2019-05-27T00:39:02.210Z,1558917542.210 [MicromodemComms] Stopped
2019-05-27T00:39:02.210Z,1558917542.210 [MicromodemComms](DEBUG): Aggregate::uninitialize MicromodemComms
2019-05-27T00:39:02.210Z,1558917542.210 [MicromodemComms:CheckIn] Stopped
2019-05-27T00:39:02.210Z,1558917542.210 [MicromodemComms:CheckIn](DEBUG): Aggregate::uninitialize MicromodemComms:CheckIn
2019-05-27T00:39:02.210Z,1558917542.210 [MicromodemComms:CheckIn:A] Stopped
2019-05-27T00:39:02.696Z,1558917542.696 [MissionManager](IMPORTANT): Started mission Default
2019-05-27T00:39:02.696Z,1558917542.696 [Default] Running Loop=1
2019-05-27T00:39:02.696Z,1558917542.696 [Default](DEBUG): Aggregate::initialize Default
2019-05-27T00:39:02.696Z,1558917542.696 [Default:B.GoToSurface] Running Loop=1
2019-05-27T00:39:02.696Z,1558917542.696 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-27T00:39:02.701Z,1558917542.701 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-27T00:39:02.701Z,1558917542.701 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-27T00:39:02.702Z,1558917542.702 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-27T00:39:02.702Z,1558917542.702 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-27T00:39:02.702Z,1558917542.702 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-27T00:39:02.703Z,1558917542.703 [Default:A.Wait] Running Loop=1
2019-05-27T00:39:02.703Z,1558917542.703 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-27T00:39:04.774Z,1558917544.774 [DataOverHttps](INFO): Sending 248 bytes from file Logs/20190515T165602/Courier0004.lzma
2019-05-27T00:39:05.578Z,1558917545.578 [DataOverHttps](INFO): Moved sent file to Logs/20190515T165602/Courier0004.lzma.bak
2019-05-27T00:39:05.578Z,1558917545.578 [DataOverHttps](INFO): SBD MOMSN=11189503
2019-05-27T00:39:12.517Z,1558917552.517 [CommandLine](IMPORTANT): got command run ./Missions/Insert/MicromodemComms.xml
2019-05-27T00:39:12.518Z,1558917552.518 [MissionManager](INFO): Loading Mission: ./Missions/Insert/MicromodemComms.xml
2019-05-27T00:39:12.532Z,1558917552.532 [MissionManager](INFO): DefineArg MicromodemComms.Timeout = 10.000000 min
2019-05-27T00:39:12.534Z,1558917552.534 [MissionManager](INFO): DefineArg MicromodemComms.CommsInterval = 5.000000 min
2019-05-27T00:39:12.539Z,1558917552.539 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Aggregate 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="MicromodemComms">
       
    <Description>
        Triggers periodic uModem comms.
    </Description>

    <DefineArg Name="Timeout"><Units:minute/><Value>10</Value></DefineArg>
    
    <DefineArg Name="CommsInterval"><Description>
        The timing is based on the variable Universal:platform_communications
    </Description><Units:minute/><Value>5</Value></DefineArg>
    
    <When>
        <Called/>
        <Or>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt>
                <Arg Name="CommsInterval"/>
            </Gt>
        </Or>
    </When>

    <Aggregate Id="CheckIn">

        <Sequence/>

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

    </Aggregate>

</Aggregate>


2019-05-27T00:39:12.541Z,1558917552.541 [CommandLine](IMPORTANT): Running ./Missions/Insert/MicromodemComms.xml
2019-05-27T00:39:12.695Z,1558917552.695 [Default] Stopped
2019-05-27T00:39:12.695Z,1558917552.695 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-27T00:39:12.695Z,1558917552.695 [Default:A.Wait] Stopped
2019-05-27T00:39:12.695Z,1558917552.695 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-27T00:39:12.695Z,1558917552.695 [Default:B.GoToSurface] Stopped
2019-05-27T00:39:12.695Z,1558917552.695 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-27T00:39:12.695Z,1558917552.695 [MissionManager](IMPORTANT): Started mission MicromodemComms
2019-05-27T00:39:12.696Z,1558917552.696 [MicromodemComms] Running Loop=1
2019-05-27T00:39:12.696Z,1558917552.696 [MicromodemComms](DEBUG): Aggregate::initialize MicromodemComms
2019-05-27T00:39:12.696Z,1558917552.696 [MicromodemComms:CheckIn] Running Loop=1
2019-05-27T00:39:12.696Z,1558917552.696 [MicromodemComms:CheckIn](DEBUG): Aggregate::initialize MicromodemComms:CheckIn
2019-05-27T00:39:12.696Z,1558917552.696 [MicromodemComms:CheckIn:A] Running Loop=1
2019-05-27T00:39:12.697Z,1558917552.697 [MicromodemComms:CheckIn:A](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-27T00:39:17.894Z,1558917557.894 [DataOverHttps](INFO): Sending 100 bytes from file Logs/20190515T165602/Courier0007.lzma
2019-05-27T00:39:18.698Z,1558917558.698 [DataOverHttps](INFO): Moved sent file to Logs/20190515T165602/Courier0007.lzma.bak
2019-05-27T00:39:18.698Z,1558917558.698 [DataOverHttps](INFO): SBD MOMSN=11189507
2019-05-27T00:39:22.101Z,1558917562.101 [CommandLine](IMPORTANT): got command get depth
2019-05-27T00:39:22.102Z,1558917562.102 [CommandLine](IMPORTANT): depth 0.773466 m
2019-05-27T00:39:30.286Z,1558917570.286 [DataOverHttps](INFO): Sending 248 bytes from file Logs/20190515T173258/Courier0004.lzma
2019-05-27T00:39:31.082Z,1558917571.082 [DataOverHttps](INFO): Moved sent file to Logs/20190515T173258/Courier0004.lzma.bak
2019-05-27T00:39:31.082Z,1558917571.082 [DataOverHttps](INFO): SBD MOMSN=11189514
2019-05-27T00:39:39.621Z,1558917579.621 [CommandLine](IMPORTANT): got command get Micromodem.surfaceThreshold
2019-05-27T00:39:39.622Z,1558917579.622 [CommandLine](IMPORTANT): Micromodem.surfaceThreshold 0.500000 m
2019-05-27T00:39:41.424Z,1558917581.424 [Micromodem](INFO): Nmea in: $CADQF,195,2*5E

2019-05-27T00:39:41.803Z,1558917581.803 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC,2*23

2019-05-27T00:39:42.182Z,1558917582.182 [DataOverHttps](INFO): Sending 295 bytes from file Logs/20190515T173258/Courier0007.lzma
2019-05-27T00:39:42.986Z,1558917582.986 [DataOverHttps](INFO): Moved sent file to Logs/20190515T173258/Courier0007.lzma.bak
2019-05-27T00:39:42.987Z,1558917582.987 [DataOverHttps](INFO): SBD MOMSN=11189518
2019-05-27T00:39:45.437Z,1558917585.437 [Micromodem](INFO): Nmea in: $CACST,1,070428.0000,1,311,-5,0109,0112,250,03,03,05,05,-1,-1,-1,0,2,1,1,-1,-1,-1,-1,00,195,0.0,-1*4A

2019-05-27T00:39:53.750Z,1558917593.750 [DataOverHttps](INFO): Sending 95 bytes from file Logs/20190515T173258/Courier0010.lzma
2019-05-27T00:39:54.554Z,1558917594.554 [DataOverHttps](INFO): Moved sent file to Logs/20190515T173258/Courier0010.lzma.bak
2019-05-27T00:39:54.554Z,1558917594.554 [DataOverHttps](INFO): SBD MOMSN=11189544
2019-05-27T00:40:05.394Z,1558917605.394 [DataOverHttps](INFO): Sending 360 bytes from file Logs/20190524T171938/Courier0000.lzma
2019-05-27T00:40:06.198Z,1558917606.198 [DataOverHttps](INFO): Moved sent file to Logs/20190524T171938/Courier0000.lzma.bak
2019-05-27T00:40:06.198Z,1558917606.198 [DataOverHttps](INFO): SBD MOMSN=11189547
2019-05-27T00:40:11.689Z,1558917611.689 [CommandLine](IMPORTANT): got command quit
2019-05-27T00:40:12.693Z,1558917612.693 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-05-27T00:40:12.693Z,1558917612.693 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-27T00:40:12.694Z,1558917612.694 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:12.857Z,1558917612.857 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-05-27T00:40:12.857Z,1558917612.857 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:12.858Z,1558917612.858 [CommandLine](INFO): Join timeout helper Thread ID is 429
2019-05-27T00:40:12.858Z,1558917612.858 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-27T00:40:12.858Z,1558917612.858 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:12.859Z,1558917612.859 [NavChartDb](INFO): Join timeout helper Thread ID is 430
2019-05-27T00:40:12.931Z,1558917612.931 [MissionManager](INFO): MissionManager is completed.
2019-05-27T00:40:12.931Z,1558917612.931 [MissionManager](INFO): Uninitializing Mission MicromodemComms
2019-05-27T00:40:12.931Z,1558917612.931 [MicromodemComms] Stopped
2019-05-27T00:40:12.932Z,1558917612.932 [MicromodemComms](DEBUG): Aggregate::uninitialize MicromodemComms
2019-05-27T00:40:12.932Z,1558917612.932 [MicromodemComms:CheckIn] Stopped
2019-05-27T00:40:12.932Z,1558917612.932 [MicromodemComms:CheckIn](DEBUG): Aggregate::uninitialize MicromodemComms:CheckIn
2019-05-27T00:40:12.932Z,1558917612.932 [MicromodemComms:CheckIn:A] Stopped
2019-05-27T00:40:13.057Z,1558917613.057 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-27T00:40:13.057Z,1558917613.057 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:13.077Z,1558917613.077 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-05-27T00:40:13.077Z,1558917613.077 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:13.077Z,1558917613.077 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 431
2019-05-27T00:40:13.117Z,1558917613.117 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-27T00:40:13.117Z,1558917613.117 [WetLabsBB2FL](INFO): Powering down
2019-05-27T00:40:13.118Z,1558917613.118 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:13.137Z,1558917613.137 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-27T00:40:13.137Z,1558917613.137 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:13.137Z,1558917613.137 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 432
2019-05-27T00:40:13.221Z,1558917613.221 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-27T00:40:13.221Z,1558917613.221 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:13.241Z,1558917613.241 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-27T00:40:13.241Z,1558917613.241 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:13.241Z,1558917613.241 [Radio_Surface](INFO): Join timeout helper Thread ID is 433
2019-05-27T00:40:13.334Z,1558917613.334 [MissionManager](IMPORTANT): Started mission Default
2019-05-27T00:40:13.334Z,1558917613.334 [Default] Running Loop=1
2019-05-27T00:40:13.334Z,1558917613.334 [Default](DEBUG): Aggregate::initialize Default
2019-05-27T00:40:13.334Z,1558917613.334 [Default:B.GoToSurface] Running Loop=1
2019-05-27T00:40:13.335Z,1558917613.335 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-27T00:40:13.335Z,1558917613.335 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-27T00:40:13.335Z,1558917613.335 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-27T00:40:13.335Z,1558917613.335 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-27T00:40:13.336Z,1558917613.336 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-27T00:40:13.336Z,1558917613.336 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-27T00:40:13.337Z,1558917613.337 [Default:A.Wait] Running Loop=1
2019-05-27T00:40:13.337Z,1558917613.337 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-27T00:40:13.609Z,1558917613.609 [Radio_Surface](INFO): Powering down
2019-05-27T00:40:13.610Z,1558917613.610 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-27T00:40:13.610Z,1558917613.610 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:13.614Z,1558917613.614 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-27T00:40:13.614Z,1558917613.614 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:13.614Z,1558917613.614 [DataOverHttps](INFO): Join timeout helper Thread ID is 434
2019-05-27T00:40:16.202Z,1558917616.202 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL
2019-05-27T00:40:16.202Z,1558917616.202 [WetLabsBB2FL] No Fault, FailCount= 5
2019-05-27T00:40:16.715Z,1558917616.715 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-27T00:40:16.719Z,1558917616.719 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:16.738Z,1558917616.738 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-27T00:40:16.738Z,1558917616.738 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:16.738Z,1558917616.738 [logger](INFO): Join timeout helper Thread ID is 435
2019-05-27T00:40:16.833Z,1558917616.833 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-27T00:40:16.833Z,1558917616.833 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:16.838Z,1558917616.838 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-27T00:40:16.838Z,1558917616.838 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:16.838Z,1558917616.838 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-27T00:40:16.838Z,1558917616.838 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:16.838Z,1558917616.838 [controlThread](INFO): Join timeout helper Thread ID is 436
2019-05-27T00:40:16.941Z,1558917616.941 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-27T00:40:16.941Z,1558917616.941 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-27T00:40:16.942Z,1558917616.942 [Micromodem](INFO): uninitialize
2019-05-27T00:40:16.942Z,1558917616.942 [Micromodem](INFO): Powering down
2019-05-27T00:40:17.037Z,1558917617.037 [NAL9602](INFO): Powering down
2019-05-27T00:40:17.039Z,1558917617.039 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-27T00:40:17.040Z,1558917617.040 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-27T00:40:17.041Z,1558917617.041 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-27T00:40:17.041Z,1558917617.041 [MissionManager](INFO): Uninitializing Mission Default
2019-05-27T00:40:17.042Z,1558917617.042 [Default] Stopped
2019-05-27T00:40:17.042Z,1558917617.042 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-27T00:40:17.042Z,1558917617.042 [Default:A.Wait] Stopped
2019-05-27T00:40:17.042Z,1558917617.042 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-27T00:40:17.042Z,1558917617.042 [Default:B.GoToSurface] Stopped
2019-05-27T00:40:17.042Z,1558917617.042 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-27T00:40:17.044Z,1558917617.044 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-27T00:40:17.044Z,1558917617.044 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-27T00:40:17.045Z,1558917617.045 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-27T00:40:17.045Z,1558917617.045 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-27T00:40:17.045Z,1558917617.045 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-27T00:40:17.046Z,1558917617.046 [BuoyancyServo](INFO): Powering down
2019-05-27T00:40:17.057Z,1558917617.057 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-27T00:40:17.057Z,1558917617.057 [ElevatorServo](INFO): Powering down
2019-05-27T00:40:17.058Z,1558917617.058 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-27T00:40:17.058Z,1558917617.058 [MassServo](INFO): Powering down
2019-05-27T00:40:17.059Z,1558917617.059 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-27T00:40:17.059Z,1558917617.059 [RudderServo](INFO): Powering down
2019-05-27T00:40:17.060Z,1558917617.060 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-27T00:40:17.060Z,1558917617.060 [ThrusterServo](INFO): Powering down
2019-05-27T00:40:17.060Z,1558917617.060 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-27T00:40:17.061Z,1558917617.061 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-27T00:40:17.061Z,1558917617.061 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-27T00:40:17.061Z,1558917617.061 [CBIT](DEBUG): Powering off loads.
2019-05-27T00:40:17.073Z,1558917617.073 [CBIT](DEBUG): Disabling WDT.
2019-05-27T00:40:17.085Z,1558917617.085 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-27T00:40:17.086Z,1558917617.086 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:17.166Z,1558917617.166 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:17.173Z,1558917617.173 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:17.223Z,1558917617.223 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:17.226Z,1558917617.226 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:17.235Z,1558917617.235 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-27T00:40:17.292Z,1558917617.292 [logger ThreadHandler](INFO): Thread cancelled.