2019-05-30T16:07:53.033Z,1559232473.033 [Supervisor](DEBUG): Initializing supervisor.
2019-05-30T16:07:53.035Z,1559232473.035 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-30T16:07:53.036Z,1559232473.036 [SyncHandler](INFO): Protected caller Thread ID is 2982
2019-05-30T16:07:53.036Z,1559232473.036 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-30T16:07:53.037Z,1559232473.037 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-30T16:07:53.038Z,1559232473.038 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2983
2019-05-30T16:07:53.040Z,1559232473.040 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-30T16:07:53.172Z,1559232473.172 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-30T16:07:53.173Z,1559232473.173 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-30T16:07:53.173Z,1559232473.173 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2984
2019-05-30T16:07:53.174Z,1559232473.174 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-30T16:07:53.175Z,1559232473.175 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-30T16:07:53.176Z,1559232473.176 [logger ThreadHandler](INFO): Protected caller Thread ID is 2985
2019-05-30T16:07:53.178Z,1559232473.178 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-30T16:07:53.178Z,1559232473.178 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-30T16:07:53.180Z,1559232473.180 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-30T16:07:53.604Z,1559232473.604 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-30T16:07:53.604Z,1559232473.604 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-30T16:07:53.703Z,1559232473.703 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-30T16:07:53.704Z,1559232473.704 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-30T16:07:54.030Z,1559232474.030 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-30T16:07:54.031Z,1559232474.031 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-30T16:07:54.174Z,1559232474.174 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-30T16:07:54.175Z,1559232474.175 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-30T16:07:54.369Z,1559232474.369 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-30T16:07:54.369Z,1559232474.369 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-30T16:07:54.827Z,1559232474.827 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-30T16:07:54.827Z,1559232474.827 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-30T16:07:55.039Z,1559232475.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-30T16:07:55.040Z,1559232475.040 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-30T16:07:55.187Z,1559232475.187 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-30T16:07:55.188Z,1559232475.188 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-30T16:07:55.383Z,1559232475.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-30T16:07:55.384Z,1559232475.384 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-30T16:07:55.481Z,1559232475.481 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-30T16:07:55.482Z,1559232475.482 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-30T16:07:55.804Z,1559232475.804 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-30T16:07:55.805Z,1559232475.805 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-30T16:07:55.887Z,1559232475.887 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-30T16:07:55.992Z,1559232475.992 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-30T16:07:55.993Z,1559232475.993 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-30T16:07:56.596Z,1559232476.596 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-30T16:07:56.596Z,1559232476.596 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-30T16:07:56.987Z,1559232476.987 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-30T16:07:56.989Z,1559232476.989 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-05-30T16:07:56.990Z,1559232476.990 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-05-30T16:07:57.205Z,1559232477.205 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-05-30T16:07:57.308Z,1559232477.308 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-05-30T16:07:57.409Z,1559232477.409 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-05-30T16:07:57.639Z,1559232477.639 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-30T16:07:57.639Z,1559232477.639 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-05-30T16:07:57.725Z,1559232477.725 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-05-30T16:07:57.821Z,1559232477.821 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-05-30T16:07:57.919Z,1559232477.919 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-05-30T16:07:58.003Z,1559232478.003 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-05-30T16:07:58.147Z,1559232478.147 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-05-30T16:07:58.649Z,1559232478.649 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-05-30T16:07:58.938Z,1559232478.938 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/LOGIN/
2019-05-30T16:07:58.939Z,1559232478.939 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-30T16:07:58.953Z,1559232478.953 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-30T16:07:59.485Z,1559232479.485 [AHRS_M2] Loaded
2019-05-30T16:07:59.485Z,1559232479.485 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-30T16:07:59.561Z,1559232479.561 [DataOverHttps] Loaded
2019-05-30T16:07:59.561Z,1559232479.561 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-30T16:07:59.562Z,1559232479.562 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407644E0
2019-05-30T16:07:59.563Z,1559232479.563 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3064
2019-05-30T16:07:59.576Z,1559232479.576 [Depth_Keller] Loaded
2019-05-30T16:07:59.576Z,1559232479.576 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-30T16:07:59.581Z,1559232479.581 [DropWeight] Loaded
2019-05-30T16:07:59.581Z,1559232479.581 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-05-30T16:07:59.637Z,1559232479.637 [DUSBL_Hydroid] Loaded
2019-05-30T16:07:59.637Z,1559232479.637 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-05-30T16:07:59.684Z,1559232479.684 [Micromodem] Loaded
2019-05-30T16:07:59.684Z,1559232479.684 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-05-30T16:07:59.781Z,1559232479.781 [NAL9602] Loaded
2019-05-30T16:07:59.781Z,1559232479.781 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-30T16:07:59.797Z,1559232479.797 [Onboard] Loaded
2019-05-30T16:07:59.797Z,1559232479.797 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-30T16:07:59.803Z,1559232479.803 [PowerOnly] Loaded
2019-05-30T16:07:59.803Z,1559232479.803 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-05-30T16:07:59.810Z,1559232479.810 [Radio_Surface] Loaded
2019-05-30T16:07:59.810Z,1559232479.810 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-30T16:07:59.811Z,1559232479.811 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407944E0
2019-05-30T16:07:59.811Z,1559232479.811 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3065
2019-05-30T16:07:59.855Z,1559232479.855 [RDI_Pathfinder] Loaded
2019-05-30T16:07:59.855Z,1559232479.855 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-05-30T16:08:01.327Z,1559232481.327 [BPC1] Loaded
2019-05-30T16:08:01.328Z,1559232481.328 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-30T16:08:01.328Z,1559232481.328 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-30T16:08:01.329Z,1559232481.329 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-30T16:08:01.341Z,1559232481.341 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-30T16:08:01.342Z,1559232481.342 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-30T16:08:01.446Z,1559232481.446 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-30T16:08:01.447Z,1559232481.447 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-30T16:08:01.467Z,1559232481.467 [NavChart] Loaded
2019-05-30T16:08:01.467Z,1559232481.467 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-30T16:08:01.471Z,1559232481.471 [UniversalFixResidualReporter] Loaded
2019-05-30T16:08:01.472Z,1559232481.472 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-30T16:08:01.472Z,1559232481.472 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-30T16:08:01.473Z,1559232481.473 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-30T16:08:01.578Z,1559232481.578 [BuoyancyServo] Loaded
2019-05-30T16:08:01.578Z,1559232481.578 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-30T16:08:01.593Z,1559232481.593 [ElevatorServo] Loaded
2019-05-30T16:08:01.594Z,1559232481.594 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-30T16:08:01.608Z,1559232481.608 [MassServo] Loaded
2019-05-30T16:08:01.608Z,1559232481.608 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-30T16:08:01.623Z,1559232481.623 [RudderServo] Loaded
2019-05-30T16:08:01.624Z,1559232481.624 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-30T16:08:01.638Z,1559232481.638 [ThrusterServo] Loaded
2019-05-30T16:08:01.638Z,1559232481.638 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-30T16:08:01.639Z,1559232481.639 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-30T16:08:01.639Z,1559232481.639 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-30T16:08:01.885Z,1559232481.885 [CTD_NeilBrown] Loaded
2019-05-30T16:08:01.885Z,1559232481.885 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-30T16:08:01.886Z,1559232481.886 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408D64E0
2019-05-30T16:08:01.887Z,1559232481.887 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 3066
2019-05-30T16:08:01.930Z,1559232481.930 [WetLabsSeaOWL_UV_A] Loaded
2019-05-30T16:08:01.931Z,1559232481.931 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-05-30T16:08:01.932Z,1559232481.932 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409064E0
2019-05-30T16:08:01.932Z,1559232481.932 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 3067
2019-05-30T16:08:01.933Z,1559232481.933 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-30T16:08:01.933Z,1559232481.933 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-30T16:08:02.218Z,1559232482.218 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-30T16:08:02.219Z,1559232482.219 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-30T16:08:02.259Z,1559232482.259 [DepthRateCalculator] Loaded
2019-05-30T16:08:02.259Z,1559232482.259 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-30T16:08:02.265Z,1559232482.265 [PitchRateCalculator] Loaded
2019-05-30T16:08:02.265Z,1559232482.265 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-30T16:08:02.277Z,1559232482.277 [SpeedCalculator] Loaded
2019-05-30T16:08:02.277Z,1559232482.277 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-30T16:08:02.298Z,1559232482.298 [TempGradientCalculator] Loaded
2019-05-30T16:08:02.298Z,1559232482.298 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-30T16:08:02.304Z,1559232482.304 [YawRateCalculator] Loaded
2019-05-30T16:08:02.304Z,1559232482.304 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-30T16:08:02.345Z,1559232482.345 [ElevatorOffsetCalculator] Loaded
2019-05-30T16:08:02.345Z,1559232482.345 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-30T16:08:02.345Z,1559232482.345 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-30T16:08:02.346Z,1559232482.346 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-30T16:08:02.478Z,1559232482.478 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-30T16:08:02.499Z,1559232482.499 [SBIT] Loaded
2019-05-30T16:08:02.499Z,1559232482.499 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-30T16:08:02.500Z,1559232482.500 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-30T16:08:02.512Z,1559232482.512 [IBIT] Loaded
2019-05-30T16:08:02.512Z,1559232482.512 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-30T16:08:02.515Z,1559232482.515 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-30T16:08:02.652Z,1559232482.652 [CBIT] Loaded
2019-05-30T16:08:02.653Z,1559232482.653 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-30T16:08:02.653Z,1559232482.653 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-30T16:08:02.653Z,1559232482.653 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-30T16:08:02.721Z,1559232482.721 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-30T16:08:02.721Z,1559232482.721 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-30T16:08:02.818Z,1559232482.818 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-30T16:08:02.819Z,1559232482.819 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-30T16:08:02.884Z,1559232482.884 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-30T16:08:02.967Z,1559232482.967 [VerticalControl] Loaded
2019-05-30T16:08:02.968Z,1559232482.968 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-30T16:08:02.968Z,1559232482.968 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-30T16:08:03.025Z,1559232483.025 [HorizontalControl] Loaded
2019-05-30T16:08:03.025Z,1559232483.025 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-30T16:08:03.026Z,1559232483.026 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-30T16:08:03.028Z,1559232483.028 [SpeedControl] Loaded
2019-05-30T16:08:03.028Z,1559232483.028 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-30T16:08:03.029Z,1559232483.029 [LoopControl](DEBUG): Construct LoopControl.
2019-05-30T16:08:03.029Z,1559232483.029 [LoopControl] Loaded
2019-05-30T16:08:03.029Z,1559232483.029 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-30T16:08:03.030Z,1559232483.030 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-30T16:08:03.030Z,1559232483.030 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-30T16:08:03.056Z,1559232483.056 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-30T16:08:03.060Z,1559232483.060 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-30T16:08:03.061Z,1559232483.061 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-30T16:08:03.068Z,1559232483.068 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-30T16:08:03.069Z,1559232483.069 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ADD4E0
2019-05-30T16:08:03.069Z,1559232483.069 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3068
2019-05-30T16:08:03.074Z,1559232483.074 [Supervisor](INFO): Main Thread ID is 2981
2019-05-30T16:08:03.074Z,1559232483.074 [Supervisor](DEBUG): Running supervisor.
2019-05-30T16:08:03.074Z,1559232483.074 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3069
2019-05-30T16:08:03.076Z,1559232483.076 [controlThread ThreadHandler](INFO): Handler Thread ID is 3070
2019-05-30T16:08:03.077Z,1559232483.077 [controlThread](DEBUG): Initializing ControlThread
2019-05-30T16:08:03.082Z,1559232483.082 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-30T16:08:03.083Z,1559232483.083 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-30T16:08:03.084Z,1559232483.084 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-30T16:08:03.084Z,1559232483.084 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-30T16:08:03.084Z,1559232483.084 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-30T16:08:03.085Z,1559232483.085 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-30T16:08:03.085Z,1559232483.085 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-30T16:08:03.085Z,1559232483.085 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-30T16:08:03.086Z,1559232483.086 [SBIT](INFO): Initialize SBIT Component.
2019-05-30T16:08:03.086Z,1559232483.086 [SBIT](IMPORTANT): git: 2019-05-01-19-g6ef4ecc
2019-05-30T16:08:03.087Z,1559232483.087 [SBIT](INFO): git hash: 6ef4ecc926d3cc84e5878e2d73d98fd38ff7dcf7
2019-05-30T16:08:03.087Z,1559232483.087 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-30T16:08:03.088Z,1559232483.088 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-05-30T16:08:03.089Z,1559232483.089 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2019-05-30T16:08:03.090Z,1559232483.090 [IBIT](INFO): Initialize IBIT Component.
2019-05-30T16:08:03.090Z,1559232483.090 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-30T16:08:03.092Z,1559232483.092 [logger ThreadHandler](INFO): Handler Thread ID is 3071
2019-05-30T16:08:03.103Z,1559232483.103 [CBIT](DEBUG): Initialized mux pins.
2019-05-30T16:08:03.103Z,1559232483.103 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-30T16:08:03.111Z,1559232483.111 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3072
2019-05-30T16:08:03.113Z,1559232483.113 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-30T16:08:03.123Z,1559232483.123 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3073
2019-05-30T16:08:03.127Z,1559232483.127 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-30T16:08:03.127Z,1559232483.127 [CBIT](DEBUG): Initializing heartbeat.
2019-05-30T16:08:03.136Z,1559232483.136 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 3074
2019-05-30T16:08:03.137Z,1559232483.137 [CTD_NeilBrown](INFO): Powering down
2019-05-30T16:08:03.176Z,1559232483.176 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 3075
2019-05-30T16:08:03.176Z,1559232483.176 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-30T16:08:03.195Z,1559232483.195 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3076
2019-05-30T16:08:03.199Z,1559232483.199 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-30T16:08:03.199Z,1559232483.199 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-30T16:08:03.202Z,1559232483.202 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-30T16:08:03.202Z,1559232483.202 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-30T16:08:03.203Z,1559232483.203 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-30T16:08:03.203Z,1559232483.203 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-30T16:08:03.204Z,1559232483.204 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-30T16:08:03.204Z,1559232483.204 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-30T16:08:03.210Z,1559232483.210 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-30T16:08:03.211Z,1559232483.211 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-30T16:08:03.223Z,1559232483.223 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-30T16:08:03.223Z,1559232483.223 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-30T16:08:03.223Z,1559232483.223 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-30T16:08:03.224Z,1559232483.224 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-30T16:08:03.224Z,1559232483.224 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-30T16:08:03.224Z,1559232483.224 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-30T16:08:03.224Z,1559232483.224 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-30T16:08:03.224Z,1559232483.224 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-30T16:08:03.235Z,1559232483.235 [CBIT](DEBUG): Backplane powered.
2019-05-30T16:08:03.235Z,1559232483.235 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-30T16:08:03.237Z,1559232483.237 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-30T16:08:03.238Z,1559232483.238 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-30T16:08:03.238Z,1559232483.238 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-30T16:08:03.239Z,1559232483.239 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-30T16:08:03.249Z,1559232483.249 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T16:08:03.277Z,1559232483.277 [MissionManager](DEBUG):
2019-05-30T16:08:03.277Z,1559232483.277 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-30T16:08:03.354Z,1559232483.354 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-30T16:08:03.355Z,1559232483.355 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-30T16:08:03.372Z,1559232483.372 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T16:08:03.399Z,1559232483.399 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-30T16:08:03.402Z,1559232483.402 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-30T16:08:03.424Z,1559232483.424 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-30T16:08:03.427Z,1559232483.427 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2019-05-30T16:08:03.443Z,1559232483.443 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-30T16:08:03.455Z,1559232483.455 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-30T16:08:03.488Z,1559232483.488 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-05-30T16:08:03.489Z,1559232483.489 [DUSBL_Hydroid](INFO): Powering up
2019-05-30T16:08:03.489Z,1559232483.489 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-05-30T16:08:03.527Z,1559232483.527 [Radio_Surface](INFO): Powering up
2019-05-30T16:08:03.575Z,1559232483.575 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-30T16:08:03.593Z,1559232483.593 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-30T16:08:03.599Z,1559232483.599 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-30T16:08:03.600Z,1559232483.600 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-30T16:08:03.607Z,1559232483.607 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-30T16:08:03.608Z,1559232483.608 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-30T16:08:03.615Z,1559232483.615 [MassServo](DEBUG): Initializing MassServo.
2019-05-30T16:08:03.616Z,1559232483.616 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-30T16:08:03.623Z,1559232483.623 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-30T16:08:03.624Z,1559232483.624 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-30T16:08:03.631Z,1559232483.631 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-30T16:08:03.874Z,1559232483.874 [Micromodem](INFO): Powering up
2019-05-30T16:08:03.875Z,1559232483.875 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-30T16:08:08.757Z,1559232488.757 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33
2019-05-30T16:08:14.725Z,1559232494.725 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004579
2019-05-30T16:08:16.827Z,1559232496.827 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-05-30T16:08:19.226Z,1559232499.226 [Micromodem](INFO): Nmea in: $CATMG,2019-05-30T16:08:04Z,RTC,RTC*79
2019-05-30T16:08:19.226Z,1559232499.226 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2019-05-30T16:08:04Z,RTC,RTC*79
2019-05-30T16:08:20.033Z,1559232500.033 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33
2019-05-30T16:08:21.649Z,1559232501.649 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-05-30T16:08:28.922Z,1559232508.922 [Micromodem](INFO): Nmea in: $CAERR,160815,NI ,12,Unknown command*47
2019-05-30T16:08:28.922Z,1559232508.922 [Micromodem](ERROR): CFG response from modem unexpected: $CAERR,160815,NI ,12,Unknown command*47
2019-05-30T16:08:30.133Z,1559232510.133 [NAL9602](INFO): Powering up NAL9602
2019-05-30T16:08:31.345Z,1559232511.345 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33
2019-05-30T16:08:39.021Z,1559232519.021 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31
2019-05-30T16:08:39.021Z,1559232519.021 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31
2019-05-30T16:08:41.045Z,1559232521.045 [NAL9602](INFO): NAL9602 initialized
2019-05-30T16:08:41.863Z,1559232521.863 [NAL9602](DEBUG): Fix Requested
2019-05-30T16:08:42.742Z,1559232522.742 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-30T16:08:42.746Z,1559232522.746 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-30T16:08:44.738Z,1559232524.738 [RDI_Pathfinder](ERROR): Failed to parse:
:BE, -3, -22, -12,A
2019-05-30T16:08:48.869Z,1559232528.869 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33
2019-05-30T16:08:48.869Z,1559232528.869 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64
2019-05-30T16:08:53.844Z,1559232533.844 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.012994
CHAN A1 (24V): -0.025785
CHAN A2 (12V): -0.006193
CHAN A3 (5V): -0.002145
CHAN B0 (3.3V): 0.000532
CHAN B1 (3.15aV): 0.000169
CHAN B2 (3.15bV): -0.000325
CHAN B3 (GND): 0.001656
OPEN: 0.006842
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-30T16:08:59.037Z,1559232539.037 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66
2019-05-30T16:08:59.038Z,1559232539.038 [Micromodem](INFO): Nmea out: $CCCFG,nav.nst,1*4D
2019-05-30T16:09:09.141Z,1559232549.141 [Micromodem](INFO): Nmea in: $CACFG,nav.nst,1*4F
2019-05-30T16:09:09.142Z,1559232549.142 [Micromodem](INFO): Nmea out: $CCCFG,DTO,20*1F
2019-05-30T16:09:19.237Z,1559232559.237 [Micromodem](INFO): Nmea in: $CACFG,DTO,20*1D
2019-05-30T16:09:19.238Z,1559232559.238 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46
2019-05-30T16:09:29.009Z,1559232569.009 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44
2019-05-30T16:09:29.009Z,1559232569.009 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63
2019-05-30T16:09:35.948Z,1559232575.948 [SBIT](IMPORTANT): SBIT PASSED
2019-05-30T16:09:36.027Z,1559232576.027 [CommandLine](IMPORTANT): got command configSet list
2019-05-30T16:09:36.028Z,1559232576.028 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-30T16:09:36.028Z,1559232576.028 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour;
2019-05-30T16:09:36.029Z,1559232576.029 [CommandLine](IMPORTANT): BPC1.loadAtStartup=1 bool;
2019-05-30T16:09:36.029Z,1559232576.029 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=40 count;
2019-05-30T16:09:36.029Z,1559232576.029 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.range 2.000000 meter;
2019-05-30T16:09:36.029Z,1559232576.029 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 angular_degree;
2019-05-30T16:09:36.029Z,1559232576.029 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.BottomVelocityFlag 0.000000 count;
2019-05-30T16:09:36.029Z,1559232576.029 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;
2019-05-30T16:09:36.029Z,1559232576.029 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_latitude;
2019-05-30T16:09:36.029Z,1559232576.029 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_longitude;
2019-05-30T16:09:36.029Z,1559232576.029 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 1.000000 meter;
2019-05-30T16:09:36.030Z,1559232576.030 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 5.000000 microgram_per_liter;
2019-05-30T16:09:36.030Z,1559232576.030 [CommandLine](IMPORTANT): Express none mass_concentration_of_oxygen_in_sea_water;
2019-05-30T16:09:36.030Z,1559232576.030 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;
2019-05-30T16:09:36.030Z,1559232576.030 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=190 cubic_centimeter;
2019-05-30T16:09:36.030Z,1559232576.030 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter;
2019-05-30T16:09:36.308Z,1559232576.308 [MissionManager](IMPORTANT): Started mission Startup
2019-05-30T16:09:36.309Z,1559232576.309 [Startup] Running Loop=1
2019-05-30T16:09:36.309Z,1559232576.309 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-30T16:09:36.309Z,1559232576.309 [Startup:A.GoToSurface] Running Loop=1
2019-05-30T16:09:36.309Z,1559232576.309 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T16:09:36.309Z,1559232576.309 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T16:09:36.310Z,1559232576.310 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T16:09:36.310Z,1559232576.310 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T16:09:36.311Z,1559232576.311 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T16:09:36.311Z,1559232576.311 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T16:09:36.313Z,1559232576.313 [Startup:StartupSatComms] Running Loop=1
2019-05-30T16:09:36.313Z,1559232576.313 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-30T16:09:36.313Z,1559232576.313 [Startup:StartupSatComms:A] Running Loop=1
2019-05-30T16:09:36.761Z,1559232576.761 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-30T16:09:39.113Z,1559232579.113 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61
2019-05-30T16:09:39.113Z,1559232579.113 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A
2019-05-30T16:09:49.209Z,1559232589.209 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38
2019-05-30T16:09:49.210Z,1559232589.210 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:09:58.906Z,1559232598.906 [Micromodem](INFO): Nmea in: $CAERR,60944,NI ,17,Argument value out of range*08
2019-05-30T16:09:58.906Z,1559232598.906 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAERR,60944,NI ,17,Argument value out of range*08
expected 39
2019-05-30T16:09:58.907Z,1559232598.907 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:10:03.753Z,1559232603.753 [Micromodem](FAULT): failed to initialize; deviceResponse_ loaded: $CAREV,160954,COPROC,0.10.0.46*4F
, available: $CARR,60954,NI ,17,Argument value out of range*09
ȋ!
2019-05-30T16:10:03.753Z,1559232603.753 [Micromodem] Communications Fault, FailCount= 1
2019-05-30T16:10:03.753Z,1559232603.753 [Micromodem](ERROR): Communications Fault
2019-05-30T16:10:03.803Z,1559232603.803 [CBIT](ERROR): Communications Fault in component: Micromodem
2019-05-30T16:10:04.156Z,1559232604.156 [Micromodem](INFO): Powering down
2019-05-30T16:10:04.561Z,1559232604.561 [Micromodem](FAULT): LCB 2 fault: Software Overcurrent.
2019-05-30T16:10:04.561Z,1559232604.561 [Micromodem] Hardware Fault, FailCount= 1
2019-05-30T16:10:04.561Z,1559232604.561 [Micromodem](ERROR): Hardware Fault
2019-05-30T16:10:05.018Z,1559232605.018 [CBIT](INFO): Clearing failed state for component Micromodem
2019-05-30T16:10:05.019Z,1559232605.019 [Micromodem] No Fault, FailCount= 1
2019-05-30T16:10:07.793Z,1559232607.793 [Micromodem](INFO): Powering up
2019-05-30T16:10:07.793Z,1559232607.793 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-30T16:10:10.217Z,1559232610.217 [Micromodem](ERROR): Nmea resend: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:10:21.529Z,1559232621.529 [Micromodem](ERROR): Nmea resend: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:10:21.938Z,1559232621.938 [Micromodem](INFO): Nmea in: $CATMG,2019-05-30T16:10:08Z,RTC,RTC*7C
2019-05-30T16:10:21.938Z,1559232621.938 [Micromodem](ERROR): Response from modem unexpected: $CATMG,2019-05-30T16:10:08Z,RTC,RTC*7C
2019-05-30T16:10:22.751Z,1559232622.751 [Micromodem](INFO): Nmea in: $CAER16016,NI ,17,Argument value out of range*07
2019-05-30T16:10:22.752Z,1559232622.752 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAER16016,NI ,17,Argument value out of range*07
expected 48
2019-05-30T16:10:22.752Z,1559232622.752 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:10:32.842Z,1559232632.842 [Micromodem](INFO): Nmea in: $AERR,161018,NI ,17,Argument value out of range*09
2019-05-30T16:10:32.842Z,1559232632.842 [Micromodem](ERROR): Response from modem failed NMEA checksum: $AERR,161018,NI ,17,Argument value out of range*09
expected 4A
2019-05-30T16:10:32.843Z,1559232632.843 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:10:36.548Z,1559232636.548 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-30T16:09:36.3Z
2019-05-30T16:10:36.548Z,1559232636.548 [Startup:StartupSatComms:A] Stopped
2019-05-30T16:10:36.548Z,1559232636.548 [Startup:StartupSatComms:B] Running Loop=1
2019-05-30T16:10:36.926Z,1559232636.926 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-30T16:10:42.120Z,1559232642.120 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190529T231116/Courier0457.lzma
2019-05-30T16:10:42.925Z,1559232642.925 [DataOverHttps](INFO): Moved sent file to Logs/20190529T231116/Courier0457.lzma.bak
2019-05-30T16:10:42.925Z,1559232642.925 [DataOverHttps](INFO): SBD MOMSN=11222920
2019-05-30T16:10:42.942Z,1559232642.942 [Micromodem](INFO): Nmea in: $CAERR,161028,NI ,17,Argument value out of range*0A
2019-05-30T16:10:42.942Z,1559232642.942 [Micromodem](ERROR): Response from modem unexpected: $CAERR,161028,NI ,17,Argument value out of range*0A
2019-05-30T16:10:44.197Z,1559232644.197 [Micromodem](ERROR): Nmea resend: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:10:53.042Z,1559232653.042 [Micromodem](INFO): Nmea in: $CAERR,161039,NI ,17,Argument value out of range*0A
2019-05-30T16:10:53.042Z,1559232653.042 [Micromodem](ERROR): Response from modem unexpected: $CAERR,161039,NI ,17,Argument value out of range*0A
2019-05-30T16:10:55.476Z,1559232655.476 [Micromodem](ERROR): Nmea resend: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:11:02.747Z,1559232662.747 [Micromodem](INFO): Nmea in: $CER,1100,NI ,17,Argument value out of range*05
2019-05-30T16:11:02.747Z,1559232662.747 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CER,1100,NI ,17,Argument value out of range*05
expected 15
2019-05-30T16:11:02.748Z,1559232662.748 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:11:03.167Z,1559232663.167 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-30T16:11:03.167Z,1559232663.167 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-30T16:11:03.213Z,1559232663.213 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-30T16:11:03.546Z,1559232663.546 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAREV,16105,COPROC,0.10.0.46*44
expected 73
2019-05-30T16:11:03.546Z,1559232663.546 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:11:03.629Z,1559232663.629 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-30T16:11:03.629Z,1559232663.629 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-30T16:11:03.950Z,1559232663.950 [Micromodem](INFO): Nmea in: $CAERR,161058,NI ,17,Argument value out of range*0D
2019-05-30T16:11:03.950Z,1559232663.950 [Micromodem](ERROR): Response from modem unexpected: $CAERR,161058,NI ,17,Argument value out of range*0D
2019-05-30T16:11:12.842Z,1559232672.842 [Micromodem](INFO): Nmea in: $AER,1108,NI ,17,Argument value out of range*0D
2019-05-30T16:11:12.843Z,1559232672.843 [Micromodem](ERROR): Response from modem failed NMEA checksum: $AER,1108,NI ,17,Argument value out of range*0D
expected 1F
2019-05-30T16:11:12.843Z,1559232672.843 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:11:22.938Z,1559232682.938 [Micromodem](INFO): Nmea in: $CAR1608NI ,17,Argument value out of range*09
2019-05-30T16:11:22.938Z,1559232682.938 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAR1608NI ,17,Argument value out of range*09
expected 1E
2019-05-30T16:11:22.938Z,1559232682.938 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:11:33.042Z,1559232693.042 [Micromodem](INFO): Nmea in: $CAERR,161118,NI ,17,Argument value out of range*08
2019-05-30T16:11:33.042Z,1559232693.042 [Micromodem](ERROR): Response from modem unexpected: $CAERR,161118,NI ,17,Argument value out of range*08
2019-05-30T16:11:34.253Z,1559232694.253 [Micromodem](ERROR): Nmea resend: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:11:36.734Z,1559232696.734 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-30T16:10:36.5Z
2019-05-30T16:11:36.734Z,1559232696.734 [Startup:StartupSatComms:B] Stopped
2019-05-30T16:11:36.734Z,1559232696.734 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-30T16:11:36.734Z,1559232696.734 [Startup:StartupSatComms] Stopped
2019-05-30T16:11:36.734Z,1559232696.734 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-30T16:11:36.739Z,1559232696.739 [Startup](INFO): Completed Startup
2019-05-30T16:11:36.740Z,1559232696.740 [MissionManager](INFO): Startup is completed.
2019-05-30T16:11:36.740Z,1559232696.740 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-30T16:11:36.740Z,1559232696.740 [Startup] Stopped
2019-05-30T16:11:36.740Z,1559232696.740 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-30T16:11:36.740Z,1559232696.740 [Startup:A.GoToSurface] Stopped
2019-05-30T16:11:36.740Z,1559232696.740 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T16:11:37.124Z,1559232697.124 [MissionManager](IMPORTANT): Started mission Default
2019-05-30T16:11:37.124Z,1559232697.124 [Default] Running Loop=1
2019-05-30T16:11:37.124Z,1559232697.124 [Default](DEBUG): Aggregate::initialize Default
2019-05-30T16:11:37.124Z,1559232697.124 [Default:B.GoToSurface] Running Loop=1
2019-05-30T16:11:37.124Z,1559232697.124 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T16:11:37.125Z,1559232697.125 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T16:11:37.125Z,1559232697.125 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T16:11:37.125Z,1559232697.125 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T16:11:37.126Z,1559232697.126 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T16:11:37.126Z,1559232697.126 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T16:11:37.126Z,1559232697.126 [Default:A.Wait] Running Loop=1
2019-05-30T16:11:37.126Z,1559232697.126 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-30T16:11:39.422Z,1559232699.422 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190529T231116/Courier0460.lzma
2019-05-30T16:11:40.229Z,1559232700.229 [DataOverHttps](INFO): Moved sent file to Logs/20190529T231116/Courier0460.lzma.bak
2019-05-30T16:11:40.229Z,1559232700.229 [DataOverHttps](INFO): SBD MOMSN=11222924
2019-05-30T16:11:42.743Z,1559232702.743 [Micromodem](INFO): Nmea in: $CAERR,16129,NI ,17,Argument value out of range*0A
2019-05-30T16:11:42.744Z,1559232702.744 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAERR,16129,NI ,17,Argument value out of range*0A
expected 3B
2019-05-30T16:11:42.744Z,1559232702.744 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:11:43.142Z,1559232703.142 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAREV,161137,AUV,2.0.7690*16
expected 24
2019-05-30T16:11:43.142Z,1559232703.142 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:11:43.546Z,1559232703.546 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAREV,161138,CPROC0.10.0.46*4C
expected 2F
2019-05-30T16:11:43.546Z,1559232703.546 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:11:43.962Z,1559232703.962 [Micromodem](INFO): Nmea in: $CAERR,161138,NI ,17,Argument value out of range*0A
2019-05-30T16:11:43.962Z,1559232703.962 [Micromodem](ERROR): Response from modem unexpected: $CAERR,161138,NI ,17,Argument value out of range*0A
2019-05-30T16:11:44.354Z,1559232704.354 [Micromodem](INFO): Nmea in: $CAERR,1138,NI ,17,Argument value out of range*0A
2019-05-30T16:11:44.354Z,1559232704.354 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAERR,1138,NI ,17,Argument value out of range*0A
expected D
2019-05-30T16:11:44.354Z,1559232704.354 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:11:44.758Z,1559232704.758 [Micromodem](INFO): Nmea in: $CAERR,161138NI ,17,Argument value out of range*0A
2019-05-30T16:11:44.758Z,1559232704.758 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAERR,161138NI ,17,Argument value out of range*0A
expected 26
2019-05-30T16:11:44.758Z,1559232704.758 [Micromodem](INFO): Nmea out: $CCCLK,2019,9-,5-,0T,6:,9:*29
2019-05-30T16:11:45.162Z,1559232705.162 [Micromodem](INFO): Nmea in: $CAERR,161139,NI ,17,Argument value out of range*0B
2019-05-30T16:11:45.162Z,1559232705.162 [Micromodem](ERROR): Response from modem unexpected: $CAERR,161139,NI ,17,Argument value out of range*0B
2019-05-30T16:11:49.115Z,1559232709.115 [CommandLine](IMPORTANT): got command quit
2019-05-30T16:11:50.119Z,1559232710.119 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-05-30T16:11:50.119Z,1559232710.119 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:11:50.120Z,1559232710.120 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:50.195Z,1559232710.195 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2019-05-30T16:11:50.195Z,1559232710.195 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:50.196Z,1559232710.196 [CommandLine](INFO): Join timeout helper Thread ID is 3100
2019-05-30T16:11:50.199Z,1559232710.199 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-30T16:11:50.200Z,1559232710.200 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:50.200Z,1559232710.200 [NavChartDb](INFO): Join timeout helper Thread ID is 3101
2019-05-30T16:11:50.440Z,1559232710.440 [Default:A.Wait](INFO): Done Waiting.
2019-05-30T16:11:50.440Z,1559232710.440 [Default:A.Wait] Stopped
2019-05-30T16:11:50.440Z,1559232710.440 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T16:11:50.567Z,1559232710.567 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:11:50.567Z,1559232710.567 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:50.587Z,1559232710.587 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-05-30T16:11:50.587Z,1559232710.587 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:50.587Z,1559232710.587 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 3102
2019-05-30T16:11:50.663Z,1559232710.663 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:11:50.663Z,1559232710.663 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-30T16:11:50.664Z,1559232710.664 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:50.667Z,1559232710.667 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-30T16:11:50.667Z,1559232710.667 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:50.667Z,1559232710.667 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 3103
2019-05-30T16:11:50.811Z,1559232710.811 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:11:50.811Z,1559232710.811 [CTD_NeilBrown](INFO): Powering down
2019-05-30T16:11:50.823Z,1559232710.823 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:50.829Z,1559232710.829 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-30T16:11:50.829Z,1559232710.829 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:50.833Z,1559232710.833 [Radio_Surface](INFO): Join timeout helper Thread ID is 3104
2019-05-30T16:11:50.867Z,1559232710.867 [Default:CheckIn] Running Loop=1
2019-05-30T16:11:50.868Z,1559232710.868 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T16:11:50.868Z,1559232710.868 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T16:11:50.995Z,1559232710.995 [Radio_Surface](INFO): Powering down
2019-05-30T16:11:50.996Z,1559232710.996 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:11:50.997Z,1559232710.997 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.016Z,1559232711.016 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-30T16:11:51.016Z,1559232711.016 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.016Z,1559232711.016 [DataOverHttps](INFO): Join timeout helper Thread ID is 3105
2019-05-30T16:11:51.167Z,1559232711.167 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:11:51.167Z,1559232711.167 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.180Z,1559232711.180 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-30T16:11:51.180Z,1559232711.180 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.180Z,1559232711.180 [logger](INFO): Join timeout helper Thread ID is 3106
2019-05-30T16:11:51.240Z,1559232711.240 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:11:51.240Z,1559232711.240 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.248Z,1559232711.248 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-30T16:11:51.248Z,1559232711.248 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.248Z,1559232711.248 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-30T16:11:51.248Z,1559232711.248 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.249Z,1559232711.249 [controlThread](INFO): Join timeout helper Thread ID is 3107
2019-05-30T16:11:51.259Z,1559232711.259 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-30T16:11:51.270Z,1559232711.270 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T16:11:51.270Z,1559232711.270 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-30T16:11:51.270Z,1559232711.270 [AHRS_M2](INFO): Powering down
2019-05-30T16:11:51.336Z,1559232711.336 [DUSBL_Hydroid](INFO): Powering down
2019-05-30T16:11:51.428Z,1559232711.428 [Micromodem](INFO): Powering down
2019-05-30T16:11:51.523Z,1559232711.523 [NAL9602](INFO): Powering down
2019-05-30T16:11:51.595Z,1559232711.595 [RDI_Pathfinder](INFO): Powering down
2019-05-30T16:11:51.597Z,1559232711.597 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-30T16:11:51.598Z,1559232711.598 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-30T16:11:51.598Z,1559232711.598 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-30T16:11:51.599Z,1559232711.599 [MissionManager](INFO): Uninitializing Mission Default
2019-05-30T16:11:51.599Z,1559232711.599 [Default] Stopped
2019-05-30T16:11:51.599Z,1559232711.599 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-30T16:11:51.599Z,1559232711.599 [Default:B.GoToSurface] Stopped
2019-05-30T16:11:51.599Z,1559232711.599 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T16:11:51.599Z,1559232711.599 [Default:CheckIn] Stopped
2019-05-30T16:11:51.599Z,1559232711.599 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T16:11:51.599Z,1559232711.599 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T16:11:51.602Z,1559232711.602 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-30T16:11:51.602Z,1559232711.602 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-30T16:11:51.602Z,1559232711.602 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-30T16:11:51.602Z,1559232711.602 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-30T16:11:51.603Z,1559232711.603 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-30T16:11:51.603Z,1559232711.603 [BuoyancyServo](INFO): Powering down
2019-05-30T16:11:51.615Z,1559232711.615 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-30T16:11:51.615Z,1559232711.615 [ElevatorServo](INFO): Powering down
2019-05-30T16:11:51.616Z,1559232711.616 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-30T16:11:51.616Z,1559232711.616 [MassServo](INFO): Powering down
2019-05-30T16:11:51.617Z,1559232711.617 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-30T16:11:51.617Z,1559232711.617 [RudderServo](INFO): Powering down
2019-05-30T16:11:51.618Z,1559232711.618 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-30T16:11:51.618Z,1559232711.618 [ThrusterServo](INFO): Powering down
2019-05-30T16:11:51.619Z,1559232711.619 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-30T16:11:51.619Z,1559232711.619 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-30T16:11:51.619Z,1559232711.619 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-30T16:11:51.620Z,1559232711.620 [CBIT](DEBUG): Powering off loads.
2019-05-30T16:11:51.631Z,1559232711.631 [CBIT](DEBUG): Disabling WDT.
2019-05-30T16:11:51.643Z,1559232711.643 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-30T16:11:51.644Z,1559232711.644 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.700Z,1559232711.700 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.709Z,1559232711.709 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.749Z,1559232711.749 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.751Z,1559232711.751 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.806Z,1559232711.806 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-30T16:11:51.861Z,1559232711.861 [logger ThreadHandler](INFO): Thread cancelled.