2019-05-25T00:20:01.450Z,1558743601.450 [Supervisor](DEBUG): Initializing supervisor.
2019-05-25T00:20:01.452Z,1558743601.452 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-25T00:20:01.453Z,1558743601.453 [SyncHandler](INFO): Protected caller Thread ID is 432
2019-05-25T00:20:01.453Z,1558743601.453 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-25T00:20:01.454Z,1558743601.454 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-25T00:20:01.455Z,1558743601.455 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 433
2019-05-25T00:20:01.457Z,1558743601.457 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-25T00:20:01.662Z,1558743601.662 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-25T00:20:01.663Z,1558743601.663 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-25T00:20:01.664Z,1558743601.664 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 434
2019-05-25T00:20:01.665Z,1558743601.665 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-25T00:20:01.666Z,1558743601.666 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-25T00:20:01.666Z,1558743601.666 [logger ThreadHandler](INFO): Protected caller Thread ID is 435
2019-05-25T00:20:01.668Z,1558743601.668 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-25T00:20:01.668Z,1558743601.668 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-25T00:20:01.670Z,1558743601.670 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-25T00:20:01.766Z,1558743601.766 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-25T00:20:01.767Z,1558743601.767 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-25T00:20:02.315Z,1558743602.315 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-25T00:20:02.316Z,1558743602.316 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-25T00:20:02.416Z,1558743602.416 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-25T00:20:02.417Z,1558743602.417 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-25T00:20:02.520Z,1558743602.520 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-25T00:20:02.521Z,1558743602.521 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-25T00:20:02.602Z,1558743602.602 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-25T00:20:02.743Z,1558743602.743 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-25T00:20:02.743Z,1558743602.743 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-25T00:20:03.040Z,1558743603.040 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-25T00:20:03.041Z,1558743603.041 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-25T00:20:03.500Z,1558743603.500 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-25T00:20:03.501Z,1558743603.501 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-25T00:20:03.647Z,1558743603.647 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-25T00:20:03.648Z,1558743603.648 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-25T00:20:03.849Z,1558743603.849 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-25T00:20:03.849Z,1558743603.849 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-25T00:20:04.306Z,1558743604.306 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-25T00:20:04.306Z,1558743604.306 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-25T00:20:04.525Z,1558743604.525 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-25T00:20:04.525Z,1558743604.525 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-25T00:20:04.728Z,1558743604.728 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-25T00:20:04.729Z,1558743604.729 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-25T00:20:05.115Z,1558743605.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-25T00:20:05.116Z,1558743605.116 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-25T00:20:05.451Z,1558743605.451 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-25T00:20:05.453Z,1558743605.453 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2019-05-25T00:20:05.454Z,1558743605.454 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2019-05-25T00:20:05.539Z,1558743605.539 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2019-05-25T00:20:05.694Z,1558743605.694 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2019-05-25T00:20:05.804Z,1558743605.804 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2019-05-25T00:20:05.891Z,1558743605.891 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2019-05-25T00:20:05.987Z,1558743605.987 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2019-05-25T00:20:06.259Z,1558743606.259 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2019-05-25T00:20:06.813Z,1558743606.813 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-25T00:20:06.814Z,1558743606.814 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2019-05-25T00:20:06.934Z,1558743606.934 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2019-05-25T00:20:07.244Z,1558743607.244 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2019-05-25T00:20:07.428Z,1558743607.428 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2019-05-25T00:20:07.531Z,1558743607.531 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/LOGIN/
2019-05-25T00:20:07.531Z,1558743607.531 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-25T00:20:07.539Z,1558743607.539 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-25T00:20:07.606Z,1558743607.606 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-25T00:20:07.721Z,1558743607.721 [VerticalControl] Loaded
2019-05-25T00:20:07.721Z,1558743607.721 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-25T00:20:07.722Z,1558743607.722 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-25T00:20:07.790Z,1558743607.790 [HorizontalControl] Loaded
2019-05-25T00:20:07.790Z,1558743607.790 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-25T00:20:07.791Z,1558743607.791 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-25T00:20:07.796Z,1558743607.796 [SpeedControl] Loaded
2019-05-25T00:20:07.796Z,1558743607.796 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-25T00:20:07.797Z,1558743607.797 [LoopControl](DEBUG): Construct LoopControl.
2019-05-25T00:20:07.798Z,1558743607.798 [LoopControl] Loaded
2019-05-25T00:20:07.798Z,1558743607.798 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-25T00:20:07.798Z,1558743607.798 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-25T00:20:07.799Z,1558743607.799 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-25T00:20:07.840Z,1558743607.840 [DepthRateCalculator] Loaded
2019-05-25T00:20:07.840Z,1558743607.840 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-25T00:20:07.845Z,1558743607.845 [PitchRateCalculator] Loaded
2019-05-25T00:20:07.845Z,1558743607.845 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-25T00:20:07.861Z,1558743607.861 [SpeedCalculator] Loaded
2019-05-25T00:20:07.861Z,1558743607.861 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-25T00:20:07.882Z,1558743607.882 [TempGradientCalculator] Loaded
2019-05-25T00:20:07.882Z,1558743607.882 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-25T00:20:07.887Z,1558743607.887 [YawRateCalculator] Loaded
2019-05-25T00:20:07.887Z,1558743607.887 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-25T00:20:07.916Z,1558743607.916 [ElevatorOffsetCalculator] Loaded
2019-05-25T00:20:07.917Z,1558743607.917 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-25T00:20:07.917Z,1558743607.917 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-25T00:20:07.918Z,1558743607.918 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-25T00:20:07.944Z,1558743607.944 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-25T00:20:07.945Z,1558743607.945 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-25T00:20:08.012Z,1558743608.012 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-25T00:20:08.012Z,1558743608.012 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-25T00:20:08.305Z,1558743608.305 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-25T00:20:08.305Z,1558743608.305 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-25T00:20:08.402Z,1558743608.402 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-25T00:20:08.402Z,1558743608.402 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-25T00:20:08.758Z,1558743608.758 [DataOverHttps] Loaded
2019-05-25T00:20:08.758Z,1558743608.758 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-25T00:20:08.759Z,1558743608.759 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408D04E0
2019-05-25T00:20:08.760Z,1558743608.760 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 514
2019-05-25T00:20:08.773Z,1558743608.773 [Depth_Keller] Loaded
2019-05-25T00:20:08.774Z,1558743608.774 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-25T00:20:08.826Z,1558743608.826 [Micromodem] Loaded
2019-05-25T00:20:08.826Z,1558743608.826 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-05-25T00:20:08.924Z,1558743608.924 [NAL9602] Loaded
2019-05-25T00:20:08.924Z,1558743608.924 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-25T00:20:08.940Z,1558743608.940 [Onboard] Loaded
2019-05-25T00:20:08.940Z,1558743608.940 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-25T00:20:08.944Z,1558743608.944 [Radio_Surface] Loaded
2019-05-25T00:20:08.944Z,1558743608.944 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-25T00:20:08.945Z,1558743608.945 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409004E0
2019-05-25T00:20:08.945Z,1558743608.945 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 515
2019-05-25T00:20:10.447Z,1558743610.447 [BPC1] Loaded
2019-05-25T00:20:10.447Z,1558743610.447 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-25T00:20:10.447Z,1558743610.447 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-25T00:20:10.448Z,1558743610.448 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-25T00:20:10.552Z,1558743610.552 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-25T00:20:10.552Z,1558743610.552 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-25T00:20:10.573Z,1558743610.573 [NavChart] Loaded
2019-05-25T00:20:10.573Z,1558743610.573 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-25T00:20:10.577Z,1558743610.577 [UniversalFixResidualReporter] Loaded
2019-05-25T00:20:10.578Z,1558743610.578 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-25T00:20:10.578Z,1558743610.578 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-25T00:20:10.579Z,1558743610.579 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-25T00:20:10.713Z,1558743610.713 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-25T00:20:10.724Z,1558743610.724 [SBIT] Loaded
2019-05-25T00:20:10.725Z,1558743610.725 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-25T00:20:10.725Z,1558743610.725 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-25T00:20:10.737Z,1558743610.737 [IBIT] Loaded
2019-05-25T00:20:10.737Z,1558743610.737 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-25T00:20:10.740Z,1558743610.740 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-25T00:20:10.876Z,1558743610.876 [CBIT] Loaded
2019-05-25T00:20:10.877Z,1558743610.877 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-25T00:20:10.877Z,1558743610.877 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-25T00:20:10.878Z,1558743610.878 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-25T00:20:10.981Z,1558743610.981 [BuoyancyServo] Loaded
2019-05-25T00:20:10.981Z,1558743610.981 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-25T00:20:10.992Z,1558743610.992 [ElevatorServo] Loaded
2019-05-25T00:20:10.993Z,1558743610.993 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-25T00:20:11.004Z,1558743611.004 [MassServo] Loaded
2019-05-25T00:20:11.004Z,1558743611.004 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-25T00:20:11.015Z,1558743611.015 [RudderServo] Loaded
2019-05-25T00:20:11.015Z,1558743611.015 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-25T00:20:11.026Z,1558743611.026 [ThrusterServo] Loaded
2019-05-25T00:20:11.027Z,1558743611.027 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-25T00:20:11.027Z,1558743611.027 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-25T00:20:11.028Z,1558743611.028 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-25T00:20:11.041Z,1558743611.041 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-25T00:20:11.041Z,1558743611.041 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-25T00:20:11.287Z,1558743611.287 [CTD_NeilBrown] Loaded
2019-05-25T00:20:11.287Z,1558743611.287 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-25T00:20:11.288Z,1558743611.288 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 40A7C4E0
2019-05-25T00:20:11.289Z,1558743611.289 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 516
2019-05-25T00:20:11.303Z,1558743611.303 [PAR_Licor] Loaded
2019-05-25T00:20:11.304Z,1558743611.304 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-05-25T00:20:11.351Z,1558743611.351 [WetLabsBB2FL] Loaded
2019-05-25T00:20:11.352Z,1558743611.352 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-05-25T00:20:11.353Z,1558743611.353 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AAC4E0
2019-05-25T00:20:11.353Z,1558743611.353 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 517
2019-05-25T00:20:11.354Z,1558743611.354 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-25T00:20:11.395Z,1558743611.395 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-25T00:20:11.396Z,1558743611.396 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-25T00:20:11.406Z,1558743611.406 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-25T00:20:11.446Z,1558743611.446 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ADC4E0
2019-05-25T00:20:11.447Z,1558743611.447 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 518
2019-05-25T00:20:11.565Z,1558743611.565 [Supervisor](INFO): Main Thread ID is 431
2019-05-25T00:20:11.566Z,1558743611.566 [Supervisor](DEBUG): Running supervisor.
2019-05-25T00:20:11.566Z,1558743611.566 [CommandLine ThreadHandler](INFO): Handler Thread ID is 519
2019-05-25T00:20:11.568Z,1558743611.568 [controlThread ThreadHandler](INFO): Handler Thread ID is 520
2019-05-25T00:20:11.569Z,1558743611.569 [controlThread](DEBUG): Initializing ControlThread
2019-05-25T00:20:11.570Z,1558743611.570 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-25T00:20:11.571Z,1558743611.571 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-25T00:20:11.572Z,1558743611.572 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-25T00:20:11.572Z,1558743611.572 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-25T00:20:11.573Z,1558743611.573 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-25T00:20:11.573Z,1558743611.573 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-25T00:20:11.573Z,1558743611.573 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-25T00:20:11.574Z,1558743611.574 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-25T00:20:11.574Z,1558743611.574 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-25T00:20:11.574Z,1558743611.574 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-25T00:20:11.578Z,1558743611.578 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-25T00:20:11.579Z,1558743611.579 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-25T00:20:11.579Z,1558743611.579 [SBIT](INFO): Initialize SBIT Component.
2019-05-25T00:20:11.579Z,1558743611.579 [SBIT](IMPORTANT): git: 2019-05-01-19-g6ef4ecc
2019-05-25T00:20:11.580Z,1558743611.580 [SBIT](INFO): git hash: 6ef4ecc926d3cc84e5878e2d73d98fd38ff7dcf7
2019-05-25T00:20:11.580Z,1558743611.580 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-25T00:20:11.580Z,1558743611.580 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-05-25T00:20:11.582Z,1558743611.582 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-05-25T00:20:11.582Z,1558743611.582 [IBIT](INFO): Initialize IBIT Component.
2019-05-25T00:20:11.583Z,1558743611.583 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-25T00:20:11.584Z,1558743611.584 [logger ThreadHandler](INFO): Handler Thread ID is 521
2019-05-25T00:20:11.597Z,1558743611.597 [CBIT](DEBUG): Initialized mux pins.
2019-05-25T00:20:11.597Z,1558743611.597 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-25T00:20:11.605Z,1558743611.605 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 522
2019-05-25T00:20:11.606Z,1558743611.606 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-25T00:20:11.617Z,1558743611.617 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 523
2019-05-25T00:20:11.621Z,1558743611.621 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-25T00:20:11.621Z,1558743611.621 [CBIT](DEBUG): Initializing heartbeat.
2019-05-25T00:20:11.629Z,1558743611.629 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 524
2019-05-25T00:20:11.641Z,1558743611.641 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 525
2019-05-25T00:20:11.642Z,1558743611.642 [WetLabsBB2FL](INFO): Powering down
2019-05-25T00:20:11.669Z,1558743611.669 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 526
2019-05-25T00:20:11.672Z,1558743611.672 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-25T00:20:11.673Z,1558743611.673 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-25T00:20:11.673Z,1558743611.673 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-25T00:20:11.673Z,1558743611.673 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-25T00:20:11.673Z,1558743611.673 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-25T00:20:11.673Z,1558743611.673 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-25T00:20:11.674Z,1558743611.674 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-25T00:20:11.674Z,1558743611.674 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-25T00:20:11.674Z,1558743611.674 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-25T00:20:11.674Z,1558743611.674 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-25T00:20:11.674Z,1558743611.674 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-25T00:20:11.674Z,1558743611.674 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-25T00:20:11.675Z,1558743611.675 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-25T00:20:11.675Z,1558743611.675 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-25T00:20:11.675Z,1558743611.675 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-25T00:20:11.675Z,1558743611.675 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-25T00:20:11.693Z,1558743611.693 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-25T00:20:11.693Z,1558743611.693 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-25T00:20:11.729Z,1558743611.729 [CBIT](DEBUG): Backplane powered.
2019-05-25T00:20:11.734Z,1558743611.734 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-25T00:20:11.748Z,1558743611.748 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-25T00:20:11.783Z,1558743611.783 [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-25T00:20:11.783Z,1558743611.783 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-25T00:20:11.856Z,1558743611.856 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-25T00:20:11.873Z,1558743611.873 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-25T00:20:11.875Z,1558743611.875 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-25T00:20:11.896Z,1558743611.896 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-25T00:20:11.899Z,1558743611.899 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-25T00:20:11.925Z,1558743611.925 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-25T00:20:11.928Z,1558743611.928 [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-25T00:20:11.937Z,1558743611.937 [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-25T00:20:11.950Z,1558743611.950 [Depth_Keller](ERROR): Pressure reading out of range: 1925.893799 decibar
2019-05-25T00:20:11.951Z,1558743611.951 [Micromodem](INFO): Start
2019-05-25T00:20:12.021Z,1558743612.021 [Radio_Surface](INFO): Powering up
2019-05-25T00:20:12.145Z,1558743612.145 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-25T00:20:12.166Z,1558743612.166 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-25T00:20:12.173Z,1558743612.173 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-25T00:20:12.174Z,1558743612.174 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-25T00:20:12.181Z,1558743612.181 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-25T00:20:12.182Z,1558743612.182 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-25T00:20:12.189Z,1558743612.189 [MassServo](DEBUG): Initializing MassServo.
2019-05-25T00:20:12.190Z,1558743612.190 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-25T00:20:12.197Z,1558743612.197 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-25T00:20:12.198Z,1558743612.198 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-25T00:20:12.205Z,1558743612.205 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-25T00:20:12.467Z,1558743612.467 [Micromodem](INFO): Starting
2019-05-25T00:20:12.467Z,1558743612.467 [Micromodem](INFO): Powering up
2019-05-25T00:20:12.468Z,1558743612.468 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-25T00:20:12.754Z,1558743612.754 [Micromodem](INFO): Starting
2019-05-25T00:20:13.125Z,1558743613.125 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-05-25T00:20:13.125Z,1558743613.125 [RudderServo](FAULT): Rudder failed to initialize
2019-05-25T00:20:13.125Z,1558743613.125 [RudderServo] Communications Fault, FailCount= 1
2019-05-25T00:20:13.125Z,1558743613.125 [RudderServo](ERROR): Communications Fault
2019-05-25T00:20:13.236Z,1558743613.236 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-05-25T00:20:13.246Z,1558743613.246 [Micromodem](INFO): Starting
2019-05-25T00:20:13.450Z,1558743613.450 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-25T00:20:13.450Z,1558743613.450 [RudderServo](INFO): Powering down
2019-05-25T00:20:13.647Z,1558743613.647 [Micromodem](INFO): Starting
2019-05-25T00:20:14.051Z,1558743614.051 [Micromodem](INFO): Starting
2019-05-25T00:20:14.107Z,1558743614.107 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-25T00:20:14.226Z,1558743614.226 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-25T00:20:14.230Z,1558743614.230 [CBIT](INFO): Clearing failed state for component RudderServo
2019-05-25T00:20:14.230Z,1558743614.230 [RudderServo] No Fault, FailCount= 1
2019-05-25T00:20:14.455Z,1558743614.455 [Micromodem](INFO): Starting
2019-05-25T00:20:14.862Z,1558743614.862 [Micromodem](INFO): Starting
2019-05-25T00:20:15.263Z,1558743615.263 [Micromodem](INFO): Starting
2019-05-25T00:20:15.667Z,1558743615.667 [Micromodem](INFO): Starting
2019-05-25T00:20:16.078Z,1558743616.078 [Micromodem](INFO): Starting
2019-05-25T00:20:16.478Z,1558743616.478 [Micromodem](INFO): Starting
2019-05-25T00:20:16.886Z,1558743616.886 [Micromodem](INFO): Starting
2019-05-25T00:20:17.283Z,1558743617.283 [Micromodem](INFO): Starting
2019-05-25T00:20:17.283Z,1558743617.283 [Micromodem](INFO): Starting
2019-05-25T00:20:17.284Z,1558743617.284 [Micromodem](DEBUG): Nmea buf: $CCCFG,ALL,0*33

2019-05-25T00:20:17.284Z,1558743617.284 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-05-25T00:20:17.285Z,1558743617.285 [Micromodem](DEBUG): Nmea buf: $CCCFG,SRC,7*37

2019-05-25T00:20:17.287Z,1558743617.287 [Micromodem](DEBUG): Nmea buf: $CCCFG,BND,1*3B

2019-05-25T00:20:17.687Z,1558743617.687 [Micromodem](INFO): Starting
2019-05-25T00:20:18.135Z,1558743618.135 [Micromodem](INFO): Starting
2019-05-25T00:20:18.542Z,1558743618.542 [Micromodem](INFO): Starting
2019-05-25T00:20:18.950Z,1558743618.950 [Micromodem](INFO): Starting
2019-05-25T00:20:19.350Z,1558743619.350 [Micromodem](INFO): Starting
2019-05-25T00:20:19.351Z,1558743619.351 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2019-05-25T00:20:19.351Z,1558743619.351 [Micromodem](INFO): Nmea out: $CCCFG,SRC,7*37

2019-05-25T00:20:19.754Z,1558743619.754 [Micromodem](INFO): Starting
2019-05-25T00:20:20.162Z,1558743620.162 [Micromodem](INFO): Starting
2019-05-25T00:20:20.562Z,1558743620.562 [Micromodem](INFO): Starting
2019-05-25T00:20:20.966Z,1558743620.966 [Micromodem](INFO): Starting
2019-05-25T00:20:21.374Z,1558743621.374 [Micromodem](INFO): Starting
2019-05-25T00:20:21.778Z,1558743621.778 [Micromodem](INFO): Starting
2019-05-25T00:20:22.178Z,1558743622.178 [Micromodem](INFO): Starting
2019-05-25T00:20:22.582Z,1558743622.582 [Micromodem](INFO): Starting
2019-05-25T00:20:22.986Z,1558743622.986 [Micromodem](INFO): Starting
2019-05-25T00:20:23.390Z,1558743623.390 [Micromodem](INFO): Starting
2019-05-25T00:20:23.590Z,1558743623.590 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004468
2019-05-25T00:20:23.794Z,1558743623.794 [Micromodem](INFO): Starting
2019-05-25T00:20:24.198Z,1558743624.198 [Micromodem](INFO): Starting
2019-05-25T00:20:24.602Z,1558743624.602 [Micromodem](INFO): Starting
2019-05-25T00:20:25.006Z,1558743625.006 [Micromodem](INFO): Starting
2019-05-25T00:20:25.410Z,1558743625.410 [Micromodem](INFO): Starting
2019-05-25T00:20:25.814Z,1558743625.814 [Micromodem](INFO): Starting
2019-05-25T00:20:26.218Z,1558743626.218 [Micromodem](INFO): Starting
2019-05-25T00:20:26.622Z,1558743626.622 [Micromodem](INFO): Starting
2019-05-25T00:20:27.037Z,1558743627.037 [Micromodem](INFO): Starting
2019-05-25T00:20:27.430Z,1558743627.430 [Micromodem](INFO): Starting
2019-05-25T00:20:27.834Z,1558743627.834 [Micromodem](INFO): Starting
2019-05-25T00:20:28.238Z,1558743628.238 [Micromodem](INFO): Starting
2019-05-25T00:20:28.642Z,1558743628.642 [Micromodem](INFO): Starting
2019-05-25T00:20:29.046Z,1558743629.046 [Micromodem](INFO): Starting
2019-05-25T00:20:29.450Z,1558743629.450 [Micromodem](INFO): Starting
2019-05-25T00:20:29.450Z,1558743629.450 [Micromodem](INFO): Nmea in: $CACFG,SRC,7*35

2019-05-25T00:20:29.451Z,1558743629.451 [Micromodem](INFO): Nmea out: $CCCFG,BND,1*3B

2019-05-25T00:20:29.854Z,1558743629.854 [Micromodem](INFO): Starting
2019-05-25T00:20:30.258Z,1558743630.258 [Micromodem](INFO): Starting
2019-05-25T00:20:30.259Z,1558743630.259 [Micromodem](INFO): Nmea in: $CACFG,BND,1*39

2019-05-25T00:20:30.259Z,1558743630.259 [Micromodem](DEBUG): Nmea buf: $CCCLK,2019,9-,5-,5T,0:,0:*23

2019-05-25T00:20:30.259Z,1558743630.259 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,5T,0:,0:*23

2019-05-25T00:20:30.662Z,1558743630.662 [Micromodem](INFO): Starting
2019-05-25T00:20:31.066Z,1558743631.066 [Micromodem](INFO): Starting
2019-05-25T00:20:31.470Z,1558743631.470 [Micromodem](INFO): Starting
2019-05-25T00:20:31.874Z,1558743631.874 [Micromodem](INFO): Starting
2019-05-25T00:20:32.278Z,1558743632.278 [Micromodem](INFO): Starting
2019-05-25T00:20:32.682Z,1558743632.682 [Micromodem](INFO): Starting
2019-05-25T00:20:33.086Z,1558743633.086 [Micromodem](INFO): Starting
2019-05-25T00:20:33.490Z,1558743633.490 [Micromodem](INFO): Starting
2019-05-25T00:20:33.894Z,1558743633.894 [Micromodem](INFO): Starting
2019-05-25T00:20:34.308Z,1558743634.308 [Micromodem](INFO): Starting
2019-05-25T00:20:34.702Z,1558743634.702 [Micromodem](INFO): Starting
2019-05-25T00:20:35.106Z,1558743635.106 [Micromodem](INFO): Starting
2019-05-25T00:20:35.510Z,1558743635.510 [Micromodem](INFO): Starting
2019-05-25T00:20:35.914Z,1558743635.914 [Micromodem](INFO): Starting
2019-05-25T00:20:36.318Z,1558743636.318 [Micromodem](INFO): Starting
2019-05-25T00:20:36.722Z,1558743636.722 [Micromodem](INFO): Starting
2019-05-25T00:20:37.126Z,1558743637.126 [Micromodem](INFO): Starting
2019-05-25T00:20:37.530Z,1558743637.530 [Micromodem](INFO): Starting
2019-05-25T00:20:37.934Z,1558743637.934 [Micromodem](INFO): Starting
2019-05-25T00:20:38.338Z,1558743638.338 [Micromodem](INFO): Starting
2019-05-25T00:20:38.742Z,1558743638.742 [Micromodem](INFO): Starting
2019-05-25T00:20:39.146Z,1558743639.146 [Micromodem](INFO): Starting
2019-05-25T00:20:39.147Z,1558743639.147 [NAL9602](INFO): Powering up NAL9602
2019-05-25T00:20:39.550Z,1558743639.550 [Micromodem](INFO): Starting
2019-05-25T00:20:39.954Z,1558743639.954 [Micromodem](INFO): Starting
2019-05-25T00:20:40.022Z,1558743640.022 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-25T00:20:40.026Z,1558743640.026 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-25T00:20:40.358Z,1558743640.358 [Micromodem](INFO): Starting
2019-05-25T00:20:40.762Z,1558743640.762 [Micromodem](INFO): Starting
2019-05-25T00:20:40.763Z,1558743640.763 [Micromodem](INFO): Nmea in: $CACLK,2019,09,05,05,00,00*45

2019-05-25T00:20:51.067Z,1558743651.067 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.001553
CHAN A1 (24V): 0.171613
CHAN A2 (12V): -0.007503
CHAN A3 (5V): -0.002669
CHAN B0 (3.3V): 0.000734
CHAN B1 (3.15aV): 0.000381
CHAN B2 (3.15bV): 0.000187
CHAN B3 (GND): 0.002072
OPEN: -0.000786
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-25T00:20:59.931Z,1558743659.931 [NAL9602](ERROR): NAL9602 initialization error.
2019-05-25T00:20:59.931Z,1558743659.931 [NAL9602] Communications Fault, FailCount= 1
2019-05-25T00:20:59.931Z,1558743659.931 [NAL9602](ERROR): Communications Fault
2019-05-25T00:21:00.078Z,1558743660.078 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-05-25T00:21:00.335Z,1558743660.335 [NAL9602](INFO): Powering down
2019-05-25T00:21:01.229Z,1558743661.229 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-25T00:21:01.229Z,1558743661.229 [NAL9602] No Fault, FailCount= 1
2019-05-25T00:21:24.257Z,1558743684.257 [Micromodem](INFO): Nmea in: $CADQF,193,2*58

2019-05-25T00:21:24.659Z,1558743684.659 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC,2*23

2019-05-25T00:21:28.300Z,1558743688.300 [Micromodem](INFO): Nmea in: $CACST,1,050052.0000,1,101,-4,0112,0112,250,03,03,04,05,-1,-1,-1,0,2,1,1,-1,-1,-1,-1,00,193,-0.0,-1*63

2019-05-25T00:21:30.723Z,1558743690.723 [NAL9602](INFO): Powering up NAL9602
2019-05-25T00:21:33.591Z,1558743693.591 [SBIT](IMPORTANT): SBIT PASSED
2019-05-25T00:21:33.609Z,1558743693.609 [CommandLine](IMPORTANT): got command configSet list
2019-05-25T00:21:33.609Z,1558743693.609 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-25T00:21:33.610Z,1558743693.610 [CommandLine](IMPORTANT): AHRS_M2.loadAtStartup=0 bool;

2019-05-25T00:21:33.610Z,1558743693.610 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=0 count;

2019-05-25T00:21:33.610Z,1558743693.610 [CommandLine](IMPORTANT): CBIT.vehicleOpen=1 bool;

2019-05-25T00:21:33.611Z,1558743693.611 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2019-05-25T00:21:33.611Z,1558743693.611 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-05-25T00:21:33.611Z,1558743693.611 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2019-05-25T00:21:33.611Z,1558743693.611 [CommandLine](IMPORTANT): VerticalControl.surfaceThreshold=1 meter;

2019-05-25T00:21:33.978Z,1558743693.978 [MissionManager](IMPORTANT): Started mission Startup
2019-05-25T00:21:33.978Z,1558743693.978 [Startup] Running Loop=1
2019-05-25T00:21:33.978Z,1558743693.978 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-25T00:21:33.979Z,1558743693.979 [Startup:A.GoToSurface] Running Loop=1
2019-05-25T00:21:33.979Z,1558743693.979 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-25T00:21:33.979Z,1558743693.979 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-25T00:21:33.980Z,1558743693.980 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-25T00:21:33.980Z,1558743693.980 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-25T00:21:33.980Z,1558743693.980 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-25T00:21:33.981Z,1558743693.981 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-25T00:21:33.982Z,1558743693.982 [Startup:StartupSatComms] Running Loop=1
2019-05-25T00:21:33.982Z,1558743693.982 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-25T00:21:33.982Z,1558743693.982 [Startup:StartupSatComms:A] Running Loop=1
2019-05-25T00:21:34.383Z,1558743694.383 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-25T00:21:51.327Z,1558743711.327 [NAL9602](ERROR): NAL9602 initialization error.
2019-05-25T00:21:51.327Z,1558743711.327 [NAL9602] Communications Fault, FailCount= 2
2019-05-25T00:21:51.327Z,1558743711.327 [NAL9602](ERROR): Communications Fault
2019-05-25T00:21:51.363Z,1558743711.363 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-05-25T00:21:51.732Z,1558743711.732 [NAL9602](INFO): Powering down
2019-05-25T00:21:52.578Z,1558743712.578 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-25T00:21:52.578Z,1558743712.578 [NAL9602] No Fault, FailCount= 2
2019-05-25T00:22:11.603Z,1558743731.603 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-25T00:22:11.603Z,1558743731.603 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-25T00:22:11.603Z,1558743731.603 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-25T00:22:11.634Z,1558743731.634 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-25T00:22:11.975Z,1558743731.975 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-25T00:22:11.975Z,1558743731.975 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-25T00:22:22.031Z,1558743742.031 [NAL9602](INFO): Powering up NAL9602
2019-05-25T00:22:31.229Z,1558743751.229 [CommandLine](IMPORTANT): got command show stack
2019-05-25T00:22:31.229Z,1558743751.229 [CommandLine](IMPORTANT): Behavior Stack:

2019-05-25T00:22:31.230Z,1558743751.230 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2019-05-25T00:22:31.230Z,1558743751.230 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:A
2019-05-25T00:22:34.199Z,1558743754.199 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-25T00:21:33.0Z
2019-05-25T00:22:34.199Z,1558743754.199 [Startup:StartupSatComms:A] Stopped
2019-05-25T00:22:34.199Z,1558743754.199 [Startup:StartupSatComms:B] Running Loop=1
2019-05-25T00:22:34.582Z,1558743754.582 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-25T00:22:37.645Z,1558743757.645 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20190508T221548/Courier0202.lzma
2019-05-25T00:22:38.455Z,1558743758.455 [DataOverHttps](INFO): Moved sent file to Logs/20190508T221548/Courier0202.lzma.bak
2019-05-25T00:22:38.455Z,1558743758.455 [DataOverHttps](INFO): SBD MOMSN=11182285
2019-05-25T00:22:42.635Z,1558743762.635 [NAL9602](ERROR): NAL9602 initialization error.
2019-05-25T00:22:42.635Z,1558743762.635 [NAL9602] Communications Fault, FailCount= 3
2019-05-25T00:22:42.635Z,1558743762.635 [NAL9602](ERROR): Communications Fault
2019-05-25T00:22:42.694Z,1558743762.694 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-05-25T00:22:43.039Z,1558743763.039 [NAL9602](INFO): Powering down
2019-05-25T00:22:43.880Z,1558743763.880 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-25T00:22:43.880Z,1558743763.880 [NAL9602] No Fault, FailCount= 3
2019-05-25T00:22:48.189Z,1558743768.189 [CommandLine](IMPORTANT): got command show stack
2019-05-25T00:22:48.189Z,1558743768.189 [CommandLine](IMPORTANT): Behavior Stack:

2019-05-25T00:22:48.190Z,1558743768.190 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2019-05-25T00:22:48.190Z,1558743768.190 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B
2019-05-25T00:22:48.950Z,1558743768.950 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20190508T221548/Courier0205.lzma
2019-05-25T00:22:49.755Z,1558743769.755 [DataOverHttps](INFO): Moved sent file to Logs/20190508T221548/Courier0205.lzma.bak
2019-05-25T00:22:49.755Z,1558743769.755 [DataOverHttps](INFO): SBD MOMSN=11182397
2019-05-25T00:23:00.354Z,1558743780.354 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20190508T221548/Courier0208.lzma
2019-05-25T00:23:01.159Z,1558743781.159 [DataOverHttps](INFO): Moved sent file to Logs/20190508T221548/Courier0208.lzma.bak
2019-05-25T00:23:01.159Z,1558743781.159 [DataOverHttps](INFO): SBD MOMSN=11182422
2019-05-25T00:23:11.998Z,1558743791.998 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20190508T221548/Courier0211.lzma
2019-05-25T00:23:12.803Z,1558743792.803 [DataOverHttps](INFO): Moved sent file to Logs/20190508T221548/Courier0211.lzma.bak
2019-05-25T00:23:12.803Z,1558743792.803 [DataOverHttps](INFO): SBD MOMSN=11182448
2019-05-25T00:23:13.337Z,1558743793.337 [NAL9602](INFO): Powering up NAL9602
2019-05-25T00:23:23.602Z,1558743803.602 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20190508T221548/Courier0214.lzma
2019-05-25T00:23:24.407Z,1558743804.407 [DataOverHttps](INFO): Moved sent file to Logs/20190508T221548/Courier0214.lzma.bak
2019-05-25T00:23:24.407Z,1558743804.407 [DataOverHttps](INFO): SBD MOMSN=11182473
2019-05-25T00:23:33.943Z,1558743813.943 [NAL9602](ERROR): NAL9602 initialization error.
2019-05-25T00:23:33.943Z,1558743813.943 [NAL9602] Communications Fault, FailCount= 4
2019-05-25T00:23:33.943Z,1558743813.943 [NAL9602](ERROR): Communications Fault
2019-05-25T00:23:33.994Z,1558743813.994 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-05-25T00:23:34.348Z,1558743814.348 [NAL9602](INFO): Powering down
2019-05-25T00:23:34.390Z,1558743814.390 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-25T00:22:34.2Z
2019-05-25T00:23:34.390Z,1558743814.390 [Startup:StartupSatComms:B] Stopped
2019-05-25T00:23:34.390Z,1558743814.390 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-25T00:23:34.390Z,1558743814.390 [Startup:StartupSatComms] Stopped
2019-05-25T00:23:34.390Z,1558743814.390 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-25T00:23:34.391Z,1558743814.391 [Startup](INFO): Completed Startup
2019-05-25T00:23:34.391Z,1558743814.391 [MissionManager](INFO): Startup is completed.
2019-05-25T00:23:34.391Z,1558743814.391 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-25T00:23:34.391Z,1558743814.391 [Startup] Stopped
2019-05-25T00:23:34.391Z,1558743814.391 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-25T00:23:34.391Z,1558743814.391 [Startup:A.GoToSurface] Stopped
2019-05-25T00:23:34.392Z,1558743814.392 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-25T00:23:34.786Z,1558743814.786 [MissionManager](IMPORTANT): Started mission Default
2019-05-25T00:23:34.786Z,1558743814.786 [Default] Running Loop=1
2019-05-25T00:23:34.786Z,1558743814.786 [Default](DEBUG): Aggregate::initialize Default
2019-05-25T00:23:34.787Z,1558743814.787 [Default:B.GoToSurface] Running Loop=1
2019-05-25T00:23:34.787Z,1558743814.787 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-25T00:23:34.787Z,1558743814.787 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-25T00:23:34.787Z,1558743814.787 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-25T00:23:34.787Z,1558743814.787 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-25T00:23:34.788Z,1558743814.788 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-25T00:23:34.788Z,1558743814.788 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-25T00:23:34.788Z,1558743814.788 [Default:A.Wait] Running Loop=1
2019-05-25T00:23:34.789Z,1558743814.789 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-25T00:23:35.195Z,1558743815.195 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-25T00:23:35.196Z,1558743815.196 [NAL9602] No Fault, FailCount= 4
2019-05-25T00:23:35.478Z,1558743815.478 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20190508T221548/Courier0217.lzma
2019-05-25T00:23:36.283Z,1558743816.283 [DataOverHttps](INFO): Moved sent file to Logs/20190508T221548/Courier0217.lzma.bak
2019-05-25T00:23:36.283Z,1558743816.283 [DataOverHttps](INFO): SBD MOMSN=11182499
2019-05-25T00:23:48.108Z,1558743828.108 [Default:A.Wait](INFO): Done Waiting.
2019-05-25T00:23:48.108Z,1558743828.108 [Default:A.Wait] Stopped
2019-05-25T00:23:48.108Z,1558743828.108 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-25T00:23:48.518Z,1558743828.518 [Default:CheckIn] Running Loop=1
2019-05-25T00:23:48.519Z,1558743828.519 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-25T00:23:48.519Z,1558743828.519 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-25T00:23:48.916Z,1558743828.916 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-25T00:24:04.651Z,1558743844.651 [NAL9602](INFO): Powering up NAL9602
2019-05-25T00:24:08.437Z,1558743848.437 [CommandLine](IMPORTANT): got command run ./Missions/Insert/MicromodemComms.xml
2019-05-25T00:24:08.438Z,1558743848.438 [MissionManager](INFO): Loading Mission: ./Missions/Insert/MicromodemComms.xml
2019-05-25T00:24:08.454Z,1558743848.454 [MissionManager](INFO): DefineArg MicromodemComms.Timeout = 10.000000 min
2019-05-25T00:24:08.458Z,1558743848.458 [MissionManager](INFO): DefineArg MicromodemComms.CommsInterval = 5.000000 min
2019-05-25T00:24:08.463Z,1558743848.463 [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-25T00:24:08.465Z,1558743848.465 [CommandLine](IMPORTANT): Running ./Missions/Insert/MicromodemComms.xml
2019-05-25T00:24:08.718Z,1558743848.718 [Default] Stopped
2019-05-25T00:24:08.718Z,1558743848.718 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-25T00:24:08.718Z,1558743848.718 [Default:B.GoToSurface] Stopped
2019-05-25T00:24:08.718Z,1558743848.718 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-25T00:24:08.718Z,1558743848.718 [Default:CheckIn] Stopped
2019-05-25T00:24:08.718Z,1558743848.718 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-25T00:24:08.718Z,1558743848.718 [Default:CheckIn:Read_GPS] Stopped
2019-05-25T00:24:08.719Z,1558743848.719 [MissionManager](IMPORTANT): Started mission MicromodemComms
2019-05-25T00:24:08.719Z,1558743848.719 [MicromodemComms] Running Loop=1
2019-05-25T00:24:08.719Z,1558743848.719 [MicromodemComms](DEBUG): Aggregate::initialize MicromodemComms
2019-05-25T00:24:08.719Z,1558743848.719 [MicromodemComms:CheckIn] Running Loop=1
2019-05-25T00:24:08.719Z,1558743848.719 [MicromodemComms:CheckIn](DEBUG): Aggregate::initialize MicromodemComms:CheckIn
2019-05-25T00:24:08.719Z,1558743848.719 [MicromodemComms:CheckIn:A] Running Loop=1
2019-05-25T00:24:08.720Z,1558743848.720 [MicromodemComms:CheckIn:A](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-25T00:24:12.873Z,1558743852.873 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-05-25T00:24:12.873Z,1558743852.873 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-05-25T00:24:12.873Z,1558743852.873 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-25T00:24:12.907Z,1558743852.907 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-25T00:24:13.193Z,1558743853.193 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-25T00:24:13.194Z,1558743853.194 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-05-25T00:24:14.066Z,1558743854.066 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20190508T221548/Courier0220.lzma
2019-05-25T00:24:14.871Z,1558743854.871 [DataOverHttps](INFO): Moved sent file to Logs/20190508T221548/Courier0220.lzma.bak
2019-05-25T00:24:14.871Z,1558743854.871 [DataOverHttps](INFO): SBD MOMSN=11182543
2019-05-25T00:24:21.620Z,1558743861.620 [Micromodem](INFO): Nmea in: $CADQF,187,2*5D

2019-05-25T00:24:22.023Z,1558743862.023 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC,2*23

2019-05-25T00:24:25.253Z,1558743865.253 [Micromodem](INFO): Nmea in: $CACST,1,050350.0000,1,419,-3,0118,0112,250,03,03,05,05,-1,-1,-1,0,2,1,1,-1,-1,-1,-1,00,187,0.0,-1*4A

2019-05-25T00:24:25.254Z,1558743865.254 [NAL9602](ERROR): NAL9602 initialization error.
2019-05-25T00:24:25.254Z,1558743865.254 [NAL9602] Communications Fault, FailCount= 5
2019-05-25T00:24:25.254Z,1558743865.254 [NAL9602](ERROR): Communications Fault
2019-05-25T00:24:25.305Z,1558743865.305 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-05-25T00:24:25.306Z,1558743865.306 [CBIT](CRITICAL): Communications Fault in component: NAL9602
2019-05-25T00:24:25.586Z,1558743865.586 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20190508T221548/Courier0223.lzma
2019-05-25T00:24:25.655Z,1558743865.655 [NAL9602](INFO): Powering down
2019-05-25T00:24:25.752Z,1558743865.752 [CommandLine](FAULT): Scheduling is paused
2019-05-25T00:24:25.752Z,1558743865.752 [CBIT](INFO): Critical error at 20190525T002425
2019-05-25T00:24:25.752Z,1558743865.752 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-05-25T00:24:26.171Z,1558743866.171 [MissionManager](INFO): MissionManager is completed.
2019-05-25T00:24:26.171Z,1558743866.171 [MissionManager](INFO): Uninitializing Mission MicromodemComms
2019-05-25T00:24:26.171Z,1558743866.171 [MicromodemComms] Stopped
2019-05-25T00:24:26.171Z,1558743866.171 [MicromodemComms](DEBUG): Aggregate::uninitialize MicromodemComms
2019-05-25T00:24:26.171Z,1558743866.171 [MicromodemComms:CheckIn] Stopped
2019-05-25T00:24:26.171Z,1558743866.171 [MicromodemComms:CheckIn](DEBUG): Aggregate::uninitialize MicromodemComms:CheckIn
2019-05-25T00:24:26.171Z,1558743866.171 [MicromodemComms:CheckIn:A] Stopped
2019-05-25T00:24:26.391Z,1558743866.391 [DataOverHttps](INFO): Moved sent file to Logs/20190508T221548/Courier0223.lzma.bak
2019-05-25T00:24:26.391Z,1558743866.391 [DataOverHttps](INFO): SBD MOMSN=11182569
2019-05-25T00:24:26.510Z,1558743866.510 [MissionManager](IMPORTANT): Started mission Default
2019-05-25T00:24:26.510Z,1558743866.510 [Default] Running Loop=1
2019-05-25T00:24:26.510Z,1558743866.510 [Default](DEBUG): Aggregate::initialize Default
2019-05-25T00:24:26.510Z,1558743866.510 [Default:B.GoToSurface] Running Loop=1
2019-05-25T00:24:26.510Z,1558743866.510 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-25T00:24:26.511Z,1558743866.511 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-25T00:24:26.511Z,1558743866.511 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-25T00:24:26.511Z,1558743866.511 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-25T00:24:26.512Z,1558743866.512 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-25T00:24:26.512Z,1558743866.512 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-25T00:24:26.512Z,1558743866.512 [Default:A.Wait] Running Loop=1
2019-05-25T00:24:26.512Z,1558743866.512 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-25T00:24:39.855Z,1558743879.855 [Default:A.Wait](INFO): Done Waiting.
2019-05-25T00:24:39.855Z,1558743879.855 [Default:A.Wait] Stopped
2019-05-25T00:24:39.855Z,1558743879.855 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-25T00:24:40.255Z,1558743880.255 [Default:CheckIn] Running Loop=1
2019-05-25T00:24:40.255Z,1558743880.255 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-25T00:24:40.255Z,1558743880.255 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-25T00:25:09.893Z,1558743909.893 [CommandLine](IMPORTANT): got command run ./Missions/Engineering/transit_umodem_2k.xml
2019-05-25T00:25:09.894Z,1558743909.894 [MissionManager](INFO): Loading Mission: ./Missions/Engineering/transit_umodem_2k.xml
2019-05-25T00:25:09.919Z,1558743909.919 [MissionManager](INFO): DefineArg transit_umodem_2km.MicromodemCommsInterval = 2.000000 min
2019-05-25T00:25:09.919Z,1558743909.919 [MissionManager](INFO): Inserting Stack: Missions/Transport/transit.xml
2019-05-25T00:25:09.985Z,1558743909.985 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.MissionTimeout = 60.000000 min
2019-05-25T00:25:09.988Z,1558743909.988 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.NeedCommsTime = 30.000000 min
2019-05-25T00:25:09.991Z,1558743909.991 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.Latitude = nan arcdeg
2019-05-25T00:25:09.994Z,1558743909.994 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.Longitude = nan arcdeg
2019-05-25T00:25:10.013Z,1558743910.013 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.Northings = 0.000000 m
2019-05-25T00:25:10.016Z,1558743910.016 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.Eastings = 0.000000 m
2019-05-25T00:25:10.024Z,1558743910.024 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.Depth = 10.000000 m
2019-05-25T00:25:10.027Z,1558743910.027 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.Speed = 1.000000 m/s
2019-05-25T00:25:10.038Z,1558743910.038 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.MaxDepth = 20.000000 m
2019-05-25T00:25:10.045Z,1558743910.045 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.MinOffshore = 1.000000 km
2019-05-25T00:25:10.048Z,1558743910.048 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.MinAltitude = 7.000000 m
2019-05-25T00:25:10.063Z,1558743910.063 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.MassHold = 1 bool
2019-05-25T00:25:10.066Z,1558743910.066 [MissionManager](INFO): DefineArg transit_umodem_2km:transit.BuoyancyHold = 1 bool
2019-05-25T00:25:10.066Z,1558743910.066 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2019-05-25T00:25:10.191Z,1558743910.191 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.DiveInterval = 3.000000 h
2019-05-25T00:25:10.195Z,1558743910.195 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.WaitForPitchUp = 10.000000 min
2019-05-25T00:25:10.207Z,1558743910.207 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.SurfacePitch = 20.000000 arcdeg
2019-05-25T00:25:10.211Z,1558743910.211 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.SurfaceDepthRate = nan m/s
2019-05-25T00:25:10.222Z,1558743910.222 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.SurfaceSpeed = 1.000000 m/s
2019-05-25T00:25:10.230Z,1558743910.230 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.GPSTimeout = 7.000000 min
2019-05-25T00:25:10.237Z,1558743910.237 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:NeedComms.CommsTimeout = 30.000000 min
2019-05-25T00:25:10.247Z,1558743910.247 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-25T00:25:10.308Z,1558743910.308 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2019-05-25T00:25:10.338Z,1558743910.338 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:StandardEnvelopes.MinAltitude = 5.000000 m
2019-05-25T00:25:10.341Z,1558743910.341 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:StandardEnvelopes.MaxDepth = 200.000000 m
2019-05-25T00:25:10.344Z,1558743910.344 [MissionManager](INFO): DefineArg transit_umodem_2km:transit:StandardEnvelopes.MinOffshore = 2000.000000 m
2019-05-25T00:25:10.345Z,1558743910.345 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-05-25T00:25:10.354Z,1558743910.354 [transit_umodem_2km:transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-05-25T00:25:10.386Z,1558743910.386 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2019-05-25T00:25:10.411Z,1558743910.411 [transit_umodem_2km:transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2019-05-25T00:25:10.415Z,1558743910.415 [transit_umodem_2km:transit:MassHold.Pitch](DEBUG): Construct.
2019-05-25T00:25:10.429Z,1558743910.429 [transit_umodem_2km:transit:Transit:A.Pitch](DEBUG): Construct.
2019-05-25T00:25:10.435Z,1558743910.435 [transit_umodem_2km:transit:Transit:B.SetSpeed](DEBUG): Construct.
2019-05-25T00:25:10.450Z,1558743910.450 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2019-05-25T00:25:10.458Z,1558743910.458 [MissionManager](INFO): RedefineArg transit_umodem_2km:transit.MissionTimeout = value:90.000000 min
2019-05-25T00:25:10.461Z,1558743910.461 [MissionManager](INFO): RedefineArg transit_umodem_2km:transit.Latitude = value:36.804900 arcdeg
2019-05-25T00:25:10.475Z,1558743910.475 [MissionManager](INFO): RedefineArg transit_umodem_2km:transit.Longitude = value:-121.810800 arcdeg
2019-05-25T00:25:10.477Z,1558743910.477 [MissionManager](INFO): RedefineArg transit_umodem_2km:transit.MinOffshore = value:750.000000 m
2019-05-25T00:25:10.477Z,1558743910.477 [MissionManager](INFO): Inserting Stack: Missions/Insert/MicromodemComms.xml
2019-05-25T00:25:10.536Z,1558743910.536 [MissionManager](INFO): DefineArg transit_umodem_2km:MicromodemComms.Timeout = 10.000000 min
2019-05-25T00:25:10.551Z,1558743910.551 [MissionManager](INFO): DefineArg transit_umodem_2km:MicromodemComms.CommsInterval = 5.000000 min
2019-05-25T00:25:10.556Z,1558743910.556 [MissionManager](INFO): RedefineArg transit_umodem_2km:MicromodemComms.CommsInterval = reader:transit_umodem_2km.MicromodemCommsInterval
2019-05-25T00:25:10.598Z,1558743910.598 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="utf-8"?>
<Mission xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd"
         Id="transit_umodem_2km">

    <Description>
        Vehicle transits to waypoint 2km WNW of Moss Landing, using uModem for comms.
    </Description>

    <DefineArg Name="MicromodemCommsInterval"><Description>
        How often to trigger Umodem communications
    </Description><Units:minute/><Value>2</Value></DefineArg>

    <Insert Filename="Transport/transit.xml">
        <RedefineArg Name="MissionTimeout"><Units:minute/><Value>90</Value></RedefineArg>
        <RedefineArg Name="Latitude"><Units:degree/><Value>36.8049</Value></RedefineArg>
        <RedefineArg Name="Longitude"><Units:degree/><Value>-121.8108</Value></RedefineArg>
        <RedefineArg Name="MinOffshore"><Units:meter/><Value>750</Value></RedefineArg>
    </Insert>

    <Insert Filename="Insert/MicromodemComms.xml" Id="MicromodemComms">
        <RedefineArg Name="CommsInterval"><Arg Name="MicromodemCommsInterval"/></RedefineArg>
    </Insert>

</Mission>


2019-05-25T00:25:10.600Z,1558743910.600 [CommandLine](IMPORTANT): Running ./Missions/Engineering/transit_umodem_2k.xml
2019-05-25T00:25:10.930Z,1558743910.930 [Default] Stopped
2019-05-25T00:25:10.930Z,1558743910.930 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-25T00:25:10.930Z,1558743910.930 [Default:B.GoToSurface] Stopped
2019-05-25T00:25:10.930Z,1558743910.930 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-25T00:25:10.930Z,1558743910.930 [Default:CheckIn] Stopped
2019-05-25T00:25:10.930Z,1558743910.930 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-25T00:25:10.930Z,1558743910.930 [Default:CheckIn:Read_GPS] Stopped
2019-05-25T00:25:10.930Z,1558743910.931 [MissionManager](IMPORTANT): Started mission transit_umodem_2km
2019-05-25T00:25:10.931Z,1558743910.931 [transit_umodem_2km] Running Loop=1
2019-05-25T00:25:10.931Z,1558743910.931 [transit_umodem_2km](DEBUG): Aggregate::initialize transit_umodem_2km
2019-05-25T00:25:10.931Z,1558743910.931 [transit_umodem_2km:transit] Running Loop=1
2019-05-25T00:25:10.931Z,1558743910.931 [transit_umodem_2km:transit](DEBUG): Aggregate::initialize transit_umodem_2km:transit
2019-05-25T00:25:10.931Z,1558743910.931 [transit_umodem_2km:transit:StandardEnvelopes] Running Loop=1
2019-05-25T00:25:10.931Z,1558743910.931 [transit_umodem_2km:transit:StandardEnvelopes](DEBUG): Aggregate::initialize transit_umodem_2km:transit:StandardEnvelopes
2019-05-25T00:25:10.932Z,1558743910.932 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-05-25T00:25:10.932Z,1558743910.932 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-05-25T00:25:10.932Z,1558743910.932 [transit_umodem_2km:transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-05-25T00:25:10.932Z,1558743910.932 [transit_umodem_2km:transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-05-25T00:25:10.932Z,1558743910.932 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-05-25T00:25:10.932Z,1558743910.932 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2019-05-25T00:25:10.932Z,1558743910.932 [transit_umodem_2km:transit:BuoyancyHold.Buoyancy] Running Loop=1
2019-05-25T00:25:10.932Z,1558743910.932 [transit_umodem_2km:transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2019-05-25T00:25:10.932Z,1558743910.932 [transit_umodem_2km:transit:MassHold.Pitch] Running Loop=1
2019-05-25T00:25:10.933Z,1558743910.933 [transit_umodem_2km:transit:MassHold.Pitch](DEBUG): Initialize.
2019-05-25T00:25:10.933Z,1558743910.933 [transit_umodem_2km:transit:B] Running Loop=1
2019-05-25T00:25:10.933Z,1558743910.933 [transit_umodem_2km:MicromodemComms] Running Loop=1
2019-05-25T00:25:10.933Z,1558743910.933 [transit_umodem_2km:MicromodemComms](DEBUG): Aggregate::initialize transit_umodem_2km:MicromodemComms
2019-05-25T00:25:10.933Z,1558743910.933 [transit_umodem_2km:MicromodemComms:CheckIn] Running Loop=1
2019-05-25T00:25:10.934Z,1558743910.934 [transit_umodem_2km:MicromodemComms:CheckIn](DEBUG): Aggregate::initialize transit_umodem_2km:MicromodemComms:CheckIn
2019-05-25T00:25:10.934Z,1558743910.934 [transit_umodem_2km:MicromodemComms:CheckIn:A] Running Loop=1
2019-05-25T00:25:10.935Z,1558743910.935 [transit_umodem_2km:MicromodemComms:CheckIn:A](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-25T00:25:10.936Z,1558743910.936 [transit_umodem_2km:transit:MassHold.Pitch] Running Loop=1
2019-05-25T00:25:10.936Z,1558743910.936 [transit_umodem_2km:transit:BuoyancyHold.Buoyancy] Running Loop=1
2019-05-25T00:25:10.937Z,1558743910.937 [transit_umodem_2km:transit:StandardEnvelopes] Running Loop=1
2019-05-25T00:25:10.937Z,1558743910.937 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-05-25T00:25:10.938Z,1558743910.938 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:10.938Z,1558743910.938 [transit_umodem_2km:transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-05-25T00:25:10.939Z,1558743910.939 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-05-25T00:25:10.939Z,1558743910.939 [transit_umodem_2km:transit:B] Stopped
2019-05-25T00:25:10.939Z,1558743910.939 [transit_umodem_2km:transit:C] Running Loop=1
2019-05-25T00:25:10.939Z,1558743910.939 [transit_umodem_2km:transit:NeedComms] Running Loop=1
2019-05-25T00:25:10.940Z,1558743910.940 [transit_umodem_2km:transit:NeedComms](DEBUG): Aggregate::initialize transit_umodem_2km:transit:NeedComms
2019-05-25T00:25:10.940Z,1558743910.940 [transit_umodem_2km:transit:NeedComms:B.GoToSurface] Running Loop=1
2019-05-25T00:25:10.940Z,1558743910.940 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-25T00:25:10.940Z,1558743910.940 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2019-05-25T00:25:10.940Z,1558743910.940 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2019-05-25T00:25:10.941Z,1558743910.941 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2019-05-25T00:25:10.941Z,1558743910.941 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-25T00:25:10.942Z,1558743910.942 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-25T00:25:10.942Z,1558743910.942 [transit_umodem_2km:transit:NeedComms:A] Running Loop=1
2019-05-25T00:25:10.943Z,1558743910.943 [transit_umodem_2km:transit:NeedComms:A](ERROR): data element is not active.
2019-05-25T00:25:10.943Z,1558743910.943 [transit_umodem_2km:transit:NeedComms:A](INFO): last time_fix was: nan second since 1970/01/01T00:00:00Z 
2019-05-25T00:25:10.943Z,1558743910.943 [transit_umodem_2km:transit:NeedComms:A] Stopped
2019-05-25T00:25:11.464Z,1558743911.464 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:11.464Z,1558743911.464 [transit_umodem_2km:transit:C] Stopped
2019-05-25T00:25:11.484Z,1558743911.484 [transit_umodem_2km:transit:E] Running Loop=1
2019-05-25T00:25:11.489Z,1558743911.489 [transit_umodem_2km:transit:NeedComms:C] Running Loop=1
2019-05-25T00:25:11.835Z,1558743911.835 [transit_umodem_2km:transit:E] Stopped
2019-05-25T00:25:11.835Z,1558743911.835 [transit_umodem_2km:transit:F] Running Loop=1
2019-05-25T00:25:11.836Z,1558743911.836 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:11.837Z,1558743911.837 [transit_umodem_2km:transit:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-25T00:25:12.239Z,1558743912.239 [transit_umodem_2km:transit:F] Stopped
2019-05-25T00:25:12.239Z,1558743912.239 [transit_umodem_2km:transit:G] Running Loop=1
2019-05-25T00:25:12.240Z,1558743912.240 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:12.654Z,1558743912.654 [transit_umodem_2km:transit:G] Stopped
2019-05-25T00:25:12.655Z,1558743912.655 [transit_umodem_2km:transit:Transit] Running Loop=1
2019-05-25T00:25:12.655Z,1558743912.655 [transit_umodem_2km:transit:Transit](DEBUG): Aggregate::initialize transit_umodem_2km:transit:Transit
2019-05-25T00:25:12.655Z,1558743912.655 [transit_umodem_2km:transit:Transit:A.Pitch] Running Loop=1
2019-05-25T00:25:12.655Z,1558743912.655 [transit_umodem_2km:transit:Transit:A.Pitch](DEBUG): Initialize.
2019-05-25T00:25:12.655Z,1558743912.655 [transit_umodem_2km:transit:Transit:B.SetSpeed] Running Loop=1
2019-05-25T00:25:12.655Z,1558743912.655 [transit_umodem_2km:transit:Transit:B.SetSpeed](DEBUG): Initialize.
2019-05-25T00:25:12.655Z,1558743912.655 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint] Running Loop=1
2019-05-25T00:25:12.655Z,1558743912.655 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:12.656Z,1558743912.656 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:12.657Z,1558743912.657 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-05-25T00:25:13.069Z,1558743913.069 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:13.078Z,1558743913.078 [transit_umodem_2km:transit:Transit:B.SetSpeed] Running Loop=1
2019-05-25T00:25:13.078Z,1558743913.078 [transit_umodem_2km:transit:Transit:A.Pitch] Running Loop=1
2019-05-25T00:25:13.079Z,1558743913.079 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:13.486Z,1558743913.486 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:13.488Z,1558743913.488 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:13.866Z,1558743913.866 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:13.868Z,1558743913.868 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:14.296Z,1558743914.296 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:14.302Z,1558743914.302 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:14.681Z,1558743914.681 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:14.686Z,1558743914.686 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:15.086Z,1558743915.086 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:15.088Z,1558743915.088 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:15.486Z,1558743915.486 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:15.488Z,1558743915.488 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:15.882Z,1558743915.882 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:15.884Z,1558743915.884 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:16.235Z,1558743916.235 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20190508T221548/Courier0226.lzma
2019-05-25T00:25:16.316Z,1558743916.316 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:16.318Z,1558743916.318 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:16.691Z,1558743916.691 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:16.692Z,1558743916.692 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:17.039Z,1558743917.039 [DataOverHttps](INFO): Moved sent file to Logs/20190508T221548/Courier0226.lzma.bak
2019-05-25T00:25:17.039Z,1558743917.039 [DataOverHttps](INFO): SBD MOMSN=11182595
2019-05-25T00:25:17.109Z,1558743917.109 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:17.111Z,1558743917.111 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:17.520Z,1558743917.520 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:17.526Z,1558743917.526 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:17.935Z,1558743917.935 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:17.946Z,1558743917.946 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:18.307Z,1558743918.307 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:18.309Z,1558743918.309 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:18.711Z,1558743918.711 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:18.713Z,1558743918.713 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:19.138Z,1558743919.138 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:19.140Z,1558743919.140 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:19.748Z,1558743919.748 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:19.750Z,1558743919.750 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:19.947Z,1558743919.947 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:19.953Z,1558743919.953 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:20.358Z,1558743920.358 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:20.360Z,1558743920.360 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:20.762Z,1558743920.762 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:20.764Z,1558743920.764 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:21.138Z,1558743921.138 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:21.140Z,1558743921.140 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:21.557Z,1558743921.557 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:21.563Z,1558743921.563 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:21.970Z,1558743921.970 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:21.972Z,1558743921.972 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:22.347Z,1558743922.347 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:22.348Z,1558743922.348 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:22.746Z,1558743922.746 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:22.748Z,1558743922.748 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:23.152Z,1558743923.152 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:23.154Z,1558743923.154 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:23.558Z,1558743923.558 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:23.560Z,1558743923.560 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:23.962Z,1558743923.962 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:23.964Z,1558743923.964 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:24.363Z,1558743924.363 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:24.364Z,1558743924.364 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:24.774Z,1558743924.774 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:24.776Z,1558743924.776 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:25.199Z,1558743925.199 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:25.201Z,1558743925.201 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:25.578Z,1558743925.578 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:25.579Z,1558743925.579 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:25.990Z,1558743925.990 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:25.992Z,1558743925.992 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:26.398Z,1558743926.398 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:26.399Z,1558743926.399 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:26.809Z,1558743926.809 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:26.815Z,1558743926.815 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:27.207Z,1558743927.207 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:27.208Z,1558743927.208 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:27.626Z,1558743927.626 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:27.628Z,1558743927.628 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:28.034Z,1558743928.034 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:28.036Z,1558743928.036 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:28.330Z,1558743928.330 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20190508T221548/Courier0229.lzma
2019-05-25T00:25:28.407Z,1558743928.407 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:28.408Z,1558743928.408 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:28.810Z,1558743928.810 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:28.812Z,1558743928.812 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:29.135Z,1558743929.135 [DataOverHttps](INFO): Moved sent file to Logs/20190508T221548/Courier0229.lzma.bak
2019-05-25T00:25:29.135Z,1558743929.135 [DataOverHttps](INFO): SBD MOMSN=11182620
2019-05-25T00:25:29.207Z,1558743929.207 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:29.209Z,1558743929.209 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:29.630Z,1558743929.630 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:29.632Z,1558743929.632 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:30.034Z,1558743930.034 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:30.036Z,1558743930.036 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:30.436Z,1558743930.436 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:30.438Z,1558743930.438 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:30.831Z,1558743930.831 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:30.832Z,1558743930.832 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:31.246Z,1558743931.246 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:31.248Z,1558743931.248 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:31.666Z,1558743931.666 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:31.668Z,1558743931.668 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:32.050Z,1558743932.050 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:32.052Z,1558743932.052 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:32.345Z,1558743932.345 [CommandLine](IMPORTANT): got command stop
2019-05-25T00:25:32.345Z,1558743932.345 [CommandLine](IMPORTANT): Scheduling is paused
2019-05-25T00:25:32.345Z,1558743932.345 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-05-25T00:25:32.458Z,1558743932.458 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2019-05-25T00:25:32.459Z,1558743932.459 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2019-05-25T00:25:32.461Z,1558743932.461 [MissionManager](INFO): MissionManager is completed.
2019-05-25T00:25:32.461Z,1558743932.461 [MissionManager](INFO): Uninitializing Mission transit_umodem_2km
2019-05-25T00:25:32.461Z,1558743932.461 [transit_umodem_2km] Stopped
2019-05-25T00:25:32.461Z,1558743932.461 [transit_umodem_2km](DEBUG): Aggregate::uninitialize transit_umodem_2km
2019-05-25T00:25:32.461Z,1558743932.461 [transit_umodem_2km:transit] Stopped
2019-05-25T00:25:32.461Z,1558743932.461 [transit_umodem_2km:transit](DEBUG): Aggregate::uninitialize transit_umodem_2km:transit
2019-05-25T00:25:32.461Z,1558743932.461 [transit_umodem_2km:transit:NeedComms] Stopped
2019-05-25T00:25:32.461Z,1558743932.461 [transit_umodem_2km:transit:NeedComms](DEBUG): Aggregate::uninitialize transit_umodem_2km:transit:NeedComms
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:NeedComms:B.GoToSurface] Stopped
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:NeedComms:C] Stopped
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:StandardEnvelopes] Stopped
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:StandardEnvelopes](DEBUG): Aggregate::uninitialize transit_umodem_2km:transit:StandardEnvelopes
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:StandardEnvelopes:B.DepthEnvelope] Stopped
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:BuoyancyHold.Buoyancy] Stopped
2019-05-25T00:25:32.462Z,1558743932.462 [transit_umodem_2km:transit:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:transit:MassHold.Pitch] Stopped
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:transit:Transit] Stopped
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:transit:Transit](DEBUG): Aggregate::uninitialize transit_umodem_2km:transit:Transit
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:transit:Transit:A.Pitch] Stopped
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:transit:Transit:B.SetSpeed] Stopped
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:transit:Transit:B.SetSpeed](DEBUG): Uninitialize.
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint] Stopped
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:transit:Transit:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:MicromodemComms] Stopped
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:MicromodemComms](DEBUG): Aggregate::uninitialize transit_umodem_2km:MicromodemComms
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:MicromodemComms:CheckIn] Stopped
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:MicromodemComms:CheckIn](DEBUG): Aggregate::uninitialize transit_umodem_2km:MicromodemComms:CheckIn
2019-05-25T00:25:32.463Z,1558743932.463 [transit_umodem_2km:MicromodemComms:CheckIn:A] Stopped
2019-05-25T00:25:33.125Z,1558743933.125 [MissionManager](IMPORTANT): Started mission Default
2019-05-25T00:25:33.125Z,1558743933.125 [Default] Running Loop=1
2019-05-25T00:25:33.125Z,1558743933.125 [Default](DEBUG): Aggregate::initialize Default
2019-05-25T00:25:33.125Z,1558743933.125 [Default:B.GoToSurface] Running Loop=1
2019-05-25T00:25:33.125Z,1558743933.125 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-25T00:25:33.125Z,1558743933.125 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-25T00:25:33.126Z,1558743933.126 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-25T00:25:33.126Z,1558743933.126 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-25T00:25:33.126Z,1558743933.126 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-25T00:25:33.127Z,1558743933.127 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-25T00:25:33.128Z,1558743933.128 [Default:A.Wait] Running Loop=1
2019-05-25T00:25:33.128Z,1558743933.128 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-25T00:25:39.929Z,1558743939.929 [CommandLine](IMPORTANT): got command get depth
2019-05-25T00:25:39.930Z,1558743939.930 [CommandLine](IMPORTANT): depth 0.772099 m
2019-05-25T00:25:40.482Z,1558743940.482 [DataOverHttps](INFO): Sending 235 bytes from file Logs/20190508T221548/Courier0232.lzma
2019-05-25T00:25:41.287Z,1558743941.287 [DataOverHttps](INFO): Moved sent file to Logs/20190508T221548/Courier0232.lzma.bak
2019-05-25T00:25:41.287Z,1558743941.287 [DataOverHttps](INFO): SBD MOMSN=11182646
2019-05-25T00:25:46.238Z,1558743946.238 [Default:A.Wait](INFO): Done Waiting.
2019-05-25T00:25:46.238Z,1558743946.238 [Default:A.Wait] Stopped
2019-05-25T00:25:46.238Z,1558743946.238 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-25T00:25:46.649Z,1558743946.649 [Default:CheckIn] Running Loop=1
2019-05-25T00:25:46.650Z,1558743946.650 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-25T00:25:46.650Z,1558743946.650 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-25T00:25:48.765Z,1558743948.765 [CommandLine](IMPORTANT): got command exit
2019-05-25T00:25:49.769Z,1558743949.769 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-25T00:25:49.769Z,1558743949.769 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:49.937Z,1558743949.937 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-05-25T00:25:49.937Z,1558743949.937 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:49.938Z,1558743949.938 [CommandLine](INFO): Join timeout helper Thread ID is 547
2019-05-25T00:25:49.938Z,1558743949.938 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-25T00:25:49.938Z,1558743949.938 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:49.939Z,1558743949.939 [NavChartDb](INFO): Join timeout helper Thread ID is 548
2019-05-25T00:25:50.265Z,1558743950.265 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-25T00:25:50.265Z,1558743950.265 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:50.277Z,1558743950.277 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-05-25T00:25:50.277Z,1558743950.277 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:50.277Z,1558743950.277 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 549
2019-05-25T00:25:50.389Z,1558743950.389 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-25T00:25:50.390Z,1558743950.390 [WetLabsBB2FL](INFO): Powering down
2019-05-25T00:25:50.390Z,1558743950.390 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:50.397Z,1558743950.397 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-25T00:25:50.397Z,1558743950.397 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:50.397Z,1558743950.397 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 550
2019-05-25T00:25:50.605Z,1558743950.605 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-25T00:25:50.605Z,1558743950.605 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:50.620Z,1558743950.620 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-25T00:25:50.620Z,1558743950.620 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:50.620Z,1558743950.620 [Radio_Surface](INFO): Join timeout helper Thread ID is 551
2019-05-25T00:25:50.649Z,1558743950.649 [Radio_Surface](INFO): Powering down
2019-05-25T00:25:50.650Z,1558743950.650 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-25T00:25:50.650Z,1558743950.650 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:50.662Z,1558743950.662 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-25T00:25:50.662Z,1558743950.662 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:50.662Z,1558743950.662 [DataOverHttps](INFO): Join timeout helper Thread ID is 552
2019-05-25T00:25:50.981Z,1558743950.981 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-25T00:25:50.981Z,1558743950.981 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:50.994Z,1558743950.994 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-25T00:25:50.994Z,1558743950.994 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:50.994Z,1558743950.994 [logger](INFO): Join timeout helper Thread ID is 553
2019-05-25T00:25:51.029Z,1558743951.029 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-25T00:25:51.029Z,1558743951.029 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:51.042Z,1558743951.042 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-25T00:25:51.042Z,1558743951.042 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:51.042Z,1558743951.042 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-25T00:25:51.042Z,1558743951.042 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:51.042Z,1558743951.042 [controlThread](INFO): Join timeout helper Thread ID is 554
2019-05-25T00:25:51.397Z,1558743951.397 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-25T00:25:51.397Z,1558743951.397 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-25T00:25:51.398Z,1558743951.398 [Micromodem](INFO): uninitialize
2019-05-25T00:25:51.398Z,1558743951.398 [Micromodem](INFO): Powering down
2019-05-25T00:25:51.493Z,1558743951.493 [NAL9602](INFO): Powering down
2019-05-25T00:25:51.495Z,1558743951.495 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-25T00:25:51.496Z,1558743951.496 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-25T00:25:51.497Z,1558743951.497 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-25T00:25:51.497Z,1558743951.497 [MissionManager](INFO): Uninitializing Mission Default
2019-05-25T00:25:51.497Z,1558743951.497 [Default] Stopped
2019-05-25T00:25:51.498Z,1558743951.498 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-25T00:25:51.498Z,1558743951.498 [Default:B.GoToSurface] Stopped
2019-05-25T00:25:51.498Z,1558743951.498 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-25T00:25:51.498Z,1558743951.498 [Default:CheckIn] Stopped
2019-05-25T00:25:51.498Z,1558743951.498 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-25T00:25:51.498Z,1558743951.498 [Default:CheckIn:Read_GPS] Stopped
2019-05-25T00:25:51.500Z,1558743951.500 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-25T00:25:51.501Z,1558743951.501 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-25T00:25:51.501Z,1558743951.501 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-25T00:25:51.501Z,1558743951.501 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-25T00:25:51.502Z,1558743951.502 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-25T00:25:51.502Z,1558743951.502 [BuoyancyServo](INFO): Powering down
2019-05-25T00:25:51.513Z,1558743951.513 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-25T00:25:51.513Z,1558743951.513 [ElevatorServo](INFO): Powering down
2019-05-25T00:25:51.514Z,1558743951.514 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-25T00:25:51.514Z,1558743951.514 [MassServo](INFO): Powering down
2019-05-25T00:25:51.515Z,1558743951.515 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-25T00:25:51.515Z,1558743951.515 [RudderServo](INFO): Powering down
2019-05-25T00:25:51.516Z,1558743951.516 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-25T00:25:51.516Z,1558743951.516 [ThrusterServo](INFO): Powering down
2019-05-25T00:25:51.516Z,1558743951.516 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-25T00:25:51.517Z,1558743951.517 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-25T00:25:51.517Z,1558743951.517 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-25T00:25:51.517Z,1558743951.517 [CBIT](DEBUG): Powering off loads.
2019-05-25T00:25:51.529Z,1558743951.529 [CBIT](DEBUG): Disabling WDT.
2019-05-25T00:25:51.541Z,1558743951.541 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-25T00:25:51.542Z,1558743951.542 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:51.631Z,1558743951.631 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:51.638Z,1558743951.638 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:51.688Z,1558743951.688 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:51.691Z,1558743951.691 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:51.699Z,1558743951.699 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-25T00:25:51.755Z,1558743951.755 [logger ThreadHandler](INFO): Thread cancelled.