2015-06-01T21:38:49.071Z,1433194729.071 [Supervisor](DEBUG): Initializing supervisor.
2015-06-01T21:38:49.075Z,1433194729.075 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-06-01T21:38:49.075Z,1433194729.075 [SyncHandler](INFO): Protected caller Thread ID is 766
2015-06-01T21:38:49.076Z,1433194729.076 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-06-01T21:38:49.079Z,1433194729.079 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-06-01T21:38:49.079Z,1433194729.079 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 767
2015-06-01T21:38:49.082Z,1433194729.082 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-06-01T21:38:49.094Z,1433194729.094 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-06-01T21:38:49.099Z,1433194729.099 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-06-01T21:38:49.099Z,1433194729.099 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 768
2015-06-01T21:38:49.100Z,1433194729.100 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-06-01T21:38:49.103Z,1433194729.103 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-06-01T21:38:49.103Z,1433194729.103 [logger ThreadHandler](INFO): Protected caller Thread ID is 769
2015-06-01T21:38:49.105Z,1433194729.105 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-06-01T21:38:49.106Z,1433194729.106 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-06-01T21:38:49.110Z,1433194729.110 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-06-01T21:38:49.513Z,1433194729.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-06-01T21:38:49.515Z,1433194729.515 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-06-01T21:38:49.709Z,1433194729.709 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-06-01T21:38:49.710Z,1433194729.710 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-06-01T21:38:49.833Z,1433194729.833 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-06-01T21:38:49.833Z,1433194729.833 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-06-01T21:38:49.976Z,1433194729.976 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-06-01T21:38:49.976Z,1433194729.976 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-06-01T21:38:50.072Z,1433194730.072 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-06-01T21:38:50.294Z,1433194730.294 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-06-01T21:38:50.294Z,1433194730.294 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-06-01T21:38:50.389Z,1433194730.389 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-06-01T21:38:50.390Z,1433194730.390 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-06-01T21:38:50.646Z,1433194730.646 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-06-01T21:38:50.647Z,1433194730.647 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-06-01T21:38:51.079Z,1433194731.079 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-06-01T21:38:51.080Z,1433194731.080 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-06-01T21:38:51.447Z,1433194731.447 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-06-01T21:38:51.448Z,1433194731.448 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-06-01T21:38:52.025Z,1433194732.025 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-06-01T21:38:52.026Z,1433194732.026 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-06-01T21:38:52.257Z,1433194732.257 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-06-01T21:38:52.258Z,1433194732.258 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-06-01T21:38:52.377Z,1433194732.377 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-06-01T21:38:52.377Z,1433194732.377 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-06-01T21:38:52.876Z,1433194732.876 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-06-01T21:38:52.877Z,1433194732.877 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-06-01T21:38:53.048Z,1433194733.048 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-06-01T21:38:53.050Z,1433194733.050 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-06-01T21:38:53.054Z,1433194733.054 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-06-01T21:38:53.322Z,1433194733.322 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-06-01T21:38:53.323Z,1433194733.323 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-06-01T21:38:53.459Z,1433194733.459 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-06-01T21:38:53.567Z,1433194733.567 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-06-01T21:38:53.676Z,1433194733.676 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-06-01T21:38:53.791Z,1433194733.791 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-06-01T21:38:53.964Z,1433194733.964 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-06-01T21:38:54.156Z,1433194734.156 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-06-01T21:38:54.268Z,1433194734.268 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-06-01T21:38:54.369Z,1433194734.369 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-06-01T21:38:54.463Z,1433194734.463 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-06-01T21:38:54.573Z,1433194734.573 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-06-01T21:38:54.785Z,1433194734.785 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2015-06-01T21:38:54.789Z,1433194734.789 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-06-01T21:38:54.863Z,1433194734.863 [VerticalControl](DEBUG): Construct VerticalControl.
2015-06-01T21:38:54.993Z,1433194734.993 [VerticalControl] Loaded
2015-06-01T21:38:54.993Z,1433194734.993 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-06-01T21:38:54.994Z,1433194734.994 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-06-01T21:38:55.078Z,1433194735.078 [HorizontalControl] Loaded
2015-06-01T21:38:55.078Z,1433194735.078 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-06-01T21:38:55.079Z,1433194735.079 [SpeedControl](DEBUG): Construct SpeedControl.
2015-06-01T21:38:55.085Z,1433194735.085 [SpeedControl] Loaded
2015-06-01T21:38:55.085Z,1433194735.085 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-06-01T21:38:55.086Z,1433194735.086 [LoopControl](DEBUG): Construct LoopControl.
2015-06-01T21:38:55.086Z,1433194735.086 [LoopControl] Loaded
2015-06-01T21:38:55.086Z,1433194735.086 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-06-01T21:38:55.087Z,1433194735.087 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-06-01T21:38:55.088Z,1433194735.088 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-06-01T21:38:55.246Z,1433194735.246 [SBIT](DEBUG): Construct Startup Built In Test.
2015-06-01T21:38:55.258Z,1433194735.258 [SBIT] Loaded
2015-06-01T21:38:55.258Z,1433194735.258 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-06-01T21:38:55.259Z,1433194735.259 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-06-01T21:38:55.292Z,1433194735.292 [IBIT] Loaded
2015-06-01T21:38:55.292Z,1433194735.292 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-06-01T21:38:55.295Z,1433194735.295 [CBIT](DEBUG): Construct Continuous Built In Test.
2015-06-01T21:38:55.450Z,1433194735.450 [CBIT] Loaded
2015-06-01T21:38:55.450Z,1433194735.450 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-06-01T21:38:55.451Z,1433194735.451 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-06-01T21:38:55.451Z,1433194735.451 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-06-01T21:38:55.487Z,1433194735.487 [DepthRateCalculator] Loaded
2015-06-01T21:38:55.487Z,1433194735.487 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-06-01T21:38:55.492Z,1433194735.492 [PitchRateCalculator] Loaded
2015-06-01T21:38:55.493Z,1433194735.493 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-06-01T21:38:55.504Z,1433194735.504 [SpeedCalculator] Loaded
2015-06-01T21:38:55.504Z,1433194735.504 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-06-01T21:38:55.520Z,1433194735.520 [TempGradientCalculator] Loaded
2015-06-01T21:38:55.520Z,1433194735.520 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-06-01T21:38:55.530Z,1433194735.530 [YawRateCalculator] Loaded
2015-06-01T21:38:55.530Z,1433194735.530 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-06-01T21:38:55.531Z,1433194735.531 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-06-01T21:38:55.531Z,1433194735.531 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-06-01T21:39:00.295Z,1433194740.295 [HFRadarCompactModelForecaster] Loaded
2015-06-01T21:39:00.296Z,1433194740.296 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2015-06-01T21:39:01.452Z,1433194741.452 [HFRCMSpaceInterpolator] Loaded
2015-06-01T21:39:01.452Z,1433194741.452 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2015-06-01T21:39:01.455Z,1433194741.455 [HFRCMTimeInterpolator] Loaded
2015-06-01T21:39:01.455Z,1433194741.455 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2015-06-01T21:39:02.633Z,1433194742.633 [HFRCMReconstructedInterpolator] Loaded
2015-06-01T21:39:02.633Z,1433194742.633 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread.
2015-06-01T21:39:02.645Z,1433194742.645 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2015-06-01T21:39:02.645Z,1433194742.645 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2015-06-01T21:39:02.677Z,1433194742.677 [HFRCMVirtualSurfaceDrifter] Loaded
2015-06-01T21:39:02.677Z,1433194742.677 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2015-06-01T21:39:02.677Z,1433194742.677 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-06-01T21:39:02.678Z,1433194742.678 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-06-01T21:39:02.969Z,1433194742.969 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-06-01T21:39:02.970Z,1433194742.970 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-06-01T21:39:03.143Z,1433194743.143 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-06-01T21:39:03.143Z,1433194743.143 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-06-01T21:39:03.202Z,1433194743.202 [DeadReckonUsingSpeedCalculator] Loaded
2015-06-01T21:39:03.202Z,1433194743.202 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2015-06-01T21:39:03.223Z,1433194743.223 [NavChart] Loaded
2015-06-01T21:39:03.224Z,1433194743.224 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-06-01T21:39:03.228Z,1433194743.228 [UniversalFixResidualReporter] Loaded
2015-06-01T21:39:03.228Z,1433194743.228 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-06-01T21:39:03.229Z,1433194743.229 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-06-01T21:39:03.229Z,1433194743.229 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-06-01T21:39:03.242Z,1433194743.242 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-06-01T21:39:03.243Z,1433194743.243 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-06-01T21:39:03.465Z,1433194743.465 [Aanderaa_O2] Loaded
2015-06-01T21:39:03.465Z,1433194743.465 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2015-06-01T21:39:03.476Z,1433194743.476 [CANONSampler] Loaded
2015-06-01T21:39:03.476Z,1433194743.476 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2015-06-01T21:39:03.560Z,1433194743.560 [CTD_NeilBrown] Loaded
2015-06-01T21:39:03.561Z,1433194743.561 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2015-06-01T21:39:03.565Z,1433194743.565 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 406EF4E0
2015-06-01T21:39:03.566Z,1433194743.566 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 852
2015-06-01T21:39:03.581Z,1433194743.581 [PAR_Licor] Loaded
2015-06-01T21:39:03.581Z,1433194743.581 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2015-06-01T21:39:03.637Z,1433194743.637 [WetLabsBB2FL] Loaded
2015-06-01T21:39:03.637Z,1433194743.637 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2015-06-01T21:39:03.641Z,1433194743.641 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4071F4E0
2015-06-01T21:39:03.642Z,1433194743.642 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 853
2015-06-01T21:39:03.642Z,1433194743.642 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-06-01T21:39:03.643Z,1433194743.643 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-06-01T21:39:04.176Z,1433194744.176 [AcousticModem_Benthos_ATM900] Loaded
2015-06-01T21:39:04.177Z,1433194744.177 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2015-06-01T21:39:04.360Z,1433194744.360 [DataOverHttps] Loaded
2015-06-01T21:39:04.361Z,1433194744.361 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-06-01T21:39:04.374Z,1433194744.374 [Depth_Keller] Loaded
2015-06-01T21:39:04.375Z,1433194744.375 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-06-01T21:39:04.380Z,1433194744.380 [DropWeight] Loaded
2015-06-01T21:39:04.380Z,1433194744.380 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2015-06-01T21:39:04.481Z,1433194744.481 [NAL9602] Loaded
2015-06-01T21:39:04.481Z,1433194744.481 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-06-01T21:39:04.527Z,1433194744.527 [Onboard] Loaded
2015-06-01T21:39:04.527Z,1433194744.527 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-06-01T21:39:04.538Z,1433194744.538 [Radio_Surface] Loaded
2015-06-01T21:39:04.539Z,1433194744.539 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-06-01T21:39:04.543Z,1433194744.543 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409634E0
2015-06-01T21:39:04.543Z,1433194744.543 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 854
2015-06-01T21:39:04.753Z,1433194744.753 [PNI_TCM] Loaded
2015-06-01T21:39:04.753Z,1433194744.753 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2015-06-01T21:39:06.818Z,1433194746.818 [BPC1] Loaded
2015-06-01T21:39:06.819Z,1433194746.819 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-06-01T21:39:06.819Z,1433194746.819 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-06-01T21:39:06.820Z,1433194746.820 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-06-01T21:39:06.950Z,1433194746.950 [BuoyancyServo] Loaded
2015-06-01T21:39:06.950Z,1433194746.950 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-06-01T21:39:06.967Z,1433194746.967 [ElevatorServo] Loaded
2015-06-01T21:39:06.967Z,1433194746.967 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-06-01T21:39:06.979Z,1433194746.979 [MassServo] Loaded
2015-06-01T21:39:06.979Z,1433194746.979 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2015-06-01T21:39:06.991Z,1433194746.991 [RudderServo] Loaded
2015-06-01T21:39:06.992Z,1433194746.992 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-06-01T21:39:07.008Z,1433194747.008 [ThrusterServo] Loaded
2015-06-01T21:39:07.008Z,1433194747.008 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-06-01T21:39:07.009Z,1433194747.009 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-06-01T21:39:07.009Z,1433194747.009 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-06-01T21:39:07.152Z,1433194747.152 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-06-01T21:39:07.152Z,1433194747.152 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-06-01T21:39:07.196Z,1433194747.196 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-06-01T21:39:07.200Z,1433194747.200 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-06-01T21:39:07.201Z,1433194747.201 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-06-01T21:39:07.207Z,1433194747.207 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-06-01T21:39:07.211Z,1433194747.211 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A114E0
2015-06-01T21:39:07.211Z,1433194747.211 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 855
2015-06-01T21:39:07.216Z,1433194747.216 [Supervisor](INFO): Main Thread ID is 765
2015-06-01T21:39:07.216Z,1433194747.216 [Supervisor](DEBUG): Running supervisor.
2015-06-01T21:39:07.217Z,1433194747.217 [CommandLine ThreadHandler](INFO): Handler Thread ID is 856
2015-06-01T21:39:07.224Z,1433194747.224 [controlThread ThreadHandler](INFO): Handler Thread ID is 857
2015-06-01T21:39:07.224Z,1433194747.224 [controlThread](DEBUG): Initializing ControlThread
2015-06-01T21:39:07.225Z,1433194747.225 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-06-01T21:39:07.227Z,1433194747.227 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-06-01T21:39:07.228Z,1433194747.228 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-06-01T21:39:07.228Z,1433194747.228 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-06-01T21:39:07.228Z,1433194747.228 [SBIT](INFO): Initialize SBIT Component.
2015-06-01T21:39:07.229Z,1433194747.229 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12274
2015-06-01T21:39:07.229Z,1433194747.229 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-06-01T21:39:07.229Z,1433194747.229 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-06-01T21:39:07.230Z,1433194747.230 [IBIT](INFO): Initialize IBIT Component.
2015-06-01T21:39:07.231Z,1433194747.231 [CBIT](DEBUG): Initialize CBIT Component.
2015-06-01T21:39:07.231Z,1433194747.231 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2015-06-01T21:39:07.231Z,1433194747.231 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-06-01T21:39:07.236Z,1433194747.236 [logger ThreadHandler](INFO): Handler Thread ID is 858
2015-06-01T21:39:07.255Z,1433194747.255 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-06-01T21:39:07.256Z,1433194747.256 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-06-01T21:39:07.256Z,1433194747.256 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-06-01T21:39:07.256Z,1433194747.256 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-06-01T21:39:07.257Z,1433194747.257 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-06-01T21:39:07.294Z,1433194747.294 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 859
2015-06-01T21:39:07.294Z,1433194747.294 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2015-06-01T21:39:07.296Z,1433194747.296 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2015-06-01T21:39:07.312Z,1433194747.312 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2015-06-01T21:39:07.312Z,1433194747.312 [HFRadarCompactModelForecaster](ERROR): Most recent ECs are more than six hours old.
2015-06-01T21:39:07.316Z,1433194747.316 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 861
2015-06-01T21:39:07.317Z,1433194747.317 [WetLabsBB2FL](INFO): Powering down
2015-06-01T21:39:07.343Z,1433194747.343 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 862
2015-06-01T21:39:07.349Z,1433194747.349 [Radio_Surface](INFO): Powering up
2015-06-01T21:39:07.359Z,1433194747.359 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 863
2015-06-01T21:39:07.380Z,1433194747.380 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-06-01T21:39:07.380Z,1433194747.380 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-06-01T21:39:07.381Z,1433194747.381 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-06-01T21:39:07.381Z,1433194747.381 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-06-01T21:39:07.381Z,1433194747.381 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-06-01T21:39:07.382Z,1433194747.382 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-06-01T21:39:07.382Z,1433194747.382 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-06-01T21:39:07.382Z,1433194747.382 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-06-01T21:39:07.382Z,1433194747.382 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-06-01T21:39:07.447Z,1433194747.447 [CTD_NeilBrown](DEBUG): CTD uart timeout: serial timeout
2015-06-01T21:39:07.448Z,1433194747.448 [CTD_NeilBrown](ERROR): Could not get real or simulated CTD data. startTime.elapsed() = 0.151437
2015-06-01T21:39:16.469Z,1433194756.469 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201505192300 published
2015-06-01T21:39:16.478Z,1433194756.478 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 0.
2015-06-01T21:39:16.479Z,1433194756.479 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2015-06-01T21:39:16.480Z,1433194756.480 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s.
2015-06-01T21:39:16.490Z,1433194756.490 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2015-06-01T21:39:16.490Z,1433194756.490 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2015-06-01T21:39:16.490Z,1433194756.490 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-06-01T21:39:16.491Z,1433194756.491 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after this many seconds: 120.000000
2015-06-01T21:39:16.491Z,1433194756.491 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after this many seconds: 20.000000
2015-06-01T21:39:16.492Z,1433194756.492 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-06-01T21:39:16.492Z,1433194756.492 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000
2015-06-01T21:39:16.492Z,1433194756.492 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000
2015-06-01T21:39:16.493Z,1433194756.493 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-06-01T21:39:16.493Z,1433194756.493 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-06-01T21:39:16.501Z,1433194756.501 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-06-01T21:39:16.559Z,1433194756.559 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-06-01T21:39:16.584Z,1433194756.584 [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://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.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>


2015-06-01T21:39:16.585Z,1433194756.585 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-06-01T21:39:16.669Z,1433194756.669 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2015-06-01T21:39:16.686Z,1433194756.686 [Default:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-06-01T21:39:16.706Z,1433194756.706 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-06-01T21:39:16.762Z,1433194756.762 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-06-01T21:39:16.765Z,1433194756.765 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-06-01T21:39:16.787Z,1433194756.787 [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://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

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

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

    <Aggregate Id="CheckIn">

        <When>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
            <And><Universal:platform_conversation/><Eq><True/></Eq></And>
            <Or><Elapsed><Universal:platform_communications/></Elapsed><Gt><Units:hour/><Value>1.0</Value></Gt></Or>
        </When>

<!-- Run application at high speed -->

        <Guidance:SetSpeed>
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
<!-- NOTE: Original Default.xml didn't have a timeout on the GPS read, so theoretically could have hung indefinitely there... -->
            <Universal:time_fix/>
        </ReadDatum>

<!-- Do data comms -->

        <Aggregate Id="ReportMinutesSinceMissionStarted">

            <When>
                <Elapsed><Universal:mission_started/></Elapsed>
                <Gt><Units:minute/><Value>10</Value></Gt>
                <And><Elapsed><Universal:time_fix/></Elapsed><Lt><Units:millisecond/><Value>500</Value></Lt></And>
            </When>

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

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

        <Guidance:SetSpeed Id="RunApplicationAtLowSpeed">
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:second/><Value>5</Value></Setting>
        </Guidance:SetSpeed>

    </Aggregate>

</Mission>


2015-06-01T21:39:16.793Z,1433194756.793 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,CANONSampler,PAR_Licor,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRadarCompactModelForecaster,HFRCMSpaceInterpolator,HFRCMTimeInterpolator,HFRCMReconstructedInterpolator,HFRCMSurfaceCurrentAtVehicleLocation,HFRCMVirtualSurfaceDrifter,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2015-06-01T21:39:16.836Z,1433194756.836 [CANONSampler](INFO): Powering down
2015-06-01T21:39:16.867Z,1433194756.867 [AcousticModem_Benthos_ATM900](INFO): Powering up
2015-06-01T21:39:16.867Z,1433194756.867 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2015-06-01T21:39:17.226Z,1433194757.226 [NAL9602](INFO): Powering up NAL9602
2015-06-01T21:39:27.078Z,1433194767.078 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:27.122Z,1433194767.122 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:27.244Z,1433194767.244 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-06-01T21:39:27.251Z,1433194767.251 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-06-01T21:39:27.268Z,1433194767.268 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-06-01T21:39:27.274Z,1433194767.274 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-06-01T21:39:27.280Z,1433194767.280 [MassServo](DEBUG): Initializing EZServoServo.
2015-06-01T21:39:27.291Z,1433194767.291 [MassServo](DEBUG): Initializing MassServo.
2015-06-01T21:39:27.301Z,1433194767.301 [RudderServo](DEBUG): Initializing EZServoServo.
2015-06-01T21:39:27.307Z,1433194767.307 [RudderServo](DEBUG): Initializing RudderServo.
2015-06-01T21:39:27.319Z,1433194767.319 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-06-01T21:39:27.327Z,1433194767.327 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-06-01T21:39:27.479Z,1433194767.479 [AcousticModem_Benthos_ATM900](DEBUG): 
2015-06-01T21:39:27.481Z,1433194767.481 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2015-06-01T21:39:27.481Z,1433194767.481 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2015-06-01T21:39:27.482Z,1433194767.482 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2015-06-01T21:39:27.482Z,1433194767.482 [AcousticModem_Benthos_ATM900](DEBUG): Jun  1 2015 21:43:09 
2015-06-01T21:39:27.583Z,1433194767.583 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:27.584Z,1433194767.584 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:27.605Z,1433194767.605 [SBIT](IMPORTANT): Beginning Startup BIT
2015-06-01T21:39:27.638Z,1433194767.638 [CBIT](IMPORTANT): Beginning GF scan
2015-06-01T21:39:27.903Z,1433194767.903 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:27.904Z,1433194767.904 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:28.252Z,1433194768.252 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2015-06-01T21:39:28.252Z,1433194768.252 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2015-06-01T21:39:28.252Z,1433194768.252 [BuoyancyServo] Communications Fault, FailCount= 1
2015-06-01T21:39:28.252Z,1433194768.252 [BuoyancyServo](ERROR): Communications Fault
2015-06-01T21:39:28.455Z,1433194768.455 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2015-06-01T21:39:28.576Z,1433194768.576 [Aanderaa_O2](INFO): Powering down
2015-06-01T21:39:28.662Z,1433194768.662 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2015-06-01T21:39:28.686Z,1433194768.686 [NAL9602](INFO): NAL9602 initialized
2015-06-01T21:39:28.764Z,1433194768.764 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:28.765Z,1433194768.765 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:28.771Z,1433194768.771 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-06-01T21:39:28.773Z,1433194768.773 [BuoyancyServo](INFO): Powering down
2015-06-01T21:39:28.900Z,1433194768.900 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2015-06-01T21:39:28.901Z,1433194768.901 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2015-06-01T21:39:28.901Z,1433194768.901 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2015-06-01T21:39:28.967Z,1433194768.967 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:28.968Z,1433194768.968 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:29.290Z,1433194769.290 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2015-06-01T21:39:29.390Z,1433194769.390 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:29.391Z,1433194769.391 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:29.707Z,1433194769.707 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2015-06-01T21:39:29.708Z,1433194769.708 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2015-06-01T21:39:29.824Z,1433194769.824 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:29.825Z,1433194769.825 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:30.092Z,1433194770.092 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2015-06-01T21:39:30.169Z,1433194770.169 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:30.170Z,1433194770.170 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-01T21:39:31.179Z,1433194771.179 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2015-06-01T21:39:31.179Z,1433194771.179 [BuoyancyServo] No Fault, FailCount= 1
2015-06-01T21:39:31.477Z,1433194771.477 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-06-01T21:39:31.605Z,1433194771.605 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-06-01T21:39:40.881Z,1433194780.881 [SBIT](ERROR): Could not read massPosReader_.
2015-06-01T21:39:42.783Z,1433194782.783 [BPC1](ERROR): Failed to receive battery data
2015-06-01T21:39:42.783Z,1433194782.783 [BPC1] Communications Fault, FailCount= 1
2015-06-01T21:39:42.783Z,1433194782.783 [BPC1](ERROR): Communications Fault
2015-06-01T21:39:42.970Z,1433194782.970 [CBIT](ERROR): Communications Fault in component: BPC1
2015-06-01T21:39:44.080Z,1433194784.080 [CBIT](INFO): Clearing failed state for component BPC1
2015-06-01T21:39:44.080Z,1433194784.080 [BPC1] No Fault, FailCount= 1
2015-06-01T21:39:54.112Z,1433194794.112 [CBIT](IMPORTANT): No ground fault detected
2015-06-01T21:39:59.938Z,1433194799.938 [BPC1](ERROR): Failed to receive battery data
2015-06-01T21:39:59.938Z,1433194799.938 [BPC1] Communications Fault, FailCount= 2
2015-06-01T21:39:59.938Z,1433194799.938 [BPC1](ERROR): Communications Fault
2015-06-01T21:40:00.065Z,1433194800.065 [CBIT](ERROR): Communications Fault in component: BPC1
2015-06-01T21:40:01.255Z,1433194801.255 [CBIT](INFO): Clearing failed state for component BPC1
2015-06-01T21:40:01.255Z,1433194801.255 [BPC1] No Fault, FailCount= 2
2015-06-01T21:40:17.659Z,1433194817.659 [BPC1](ERROR): Failed to receive battery data
2015-06-01T21:40:17.659Z,1433194817.659 [BPC1] Communications Fault, FailCount= 3
2015-06-01T21:40:17.659Z,1433194817.659 [BPC1](ERROR): Communications Fault
2015-06-01T21:40:17.764Z,1433194817.764 [CBIT](ERROR): Communications Fault in component: BPC1
2015-06-01T21:40:18.980Z,1433194818.980 [CBIT](INFO): Clearing failed state for component BPC1
2015-06-01T21:40:18.980Z,1433194818.980 [BPC1] No Fault, FailCount= 3
2015-06-01T21:40:21.767Z,1433194821.767 [SBIT](CRITICAL): SBIT FAILED
2015-06-01T21:40:21.770Z,1433194821.770 [CommandLine](FAULT): Scheduling is paused
2015-06-01T21:40:22.069Z,1433194822.069 [MissionManager](IMPORTANT): Started mission Startup
2015-06-01T21:40:22.070Z,1433194822.070 [Startup] Running Loop=1
2015-06-01T21:40:22.070Z,1433194822.070 [Startup](INFO): Aggregate::initialize Startup
2015-06-01T21:40:22.070Z,1433194822.070 [Startup:A.GoToSurface] Running Loop=1
2015-06-01T21:40:22.070Z,1433194822.070 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-06-01T21:40:22.071Z,1433194822.071 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-06-01T21:40:22.071Z,1433194822.071 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-06-01T21:40:22.088Z,1433194822.088 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-06-01T21:40:22.097Z,1433194822.097 [Startup:StartupSatComms] Running Loop=1
2015-06-01T21:40:22.097Z,1433194822.097 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-06-01T21:40:22.098Z,1433194822.098 [Startup:StartupSatComms:A] Running Loop=1
2015-06-01T21:40:22.472Z,1433194822.472 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-06-01T21:40:29.802Z,1433194829.802 [BPC1](ERROR): Failed to parse message.
2015-06-01T21:40:29.802Z,1433194829.802 [BPC1](ERROR): Failed to parse bank A battery data
2015-06-01T21:40:29.802Z,1433194829.802 [BPC1] Data Fault, FailCount= 4
2015-06-01T21:40:29.802Z,1433194829.802 [BPC1](ERROR): Data Fault
2015-06-01T21:40:29.931Z,1433194829.931 [CBIT](ERROR): Data Fault in component: BPC1
2015-06-01T21:40:31.140Z,1433194831.140 [CBIT](INFO): Clearing failed state for component BPC1
2015-06-01T21:40:31.140Z,1433194831.140 [BPC1] No Fault, FailCount= 4
2015-06-01T21:40:56.019Z,1433194856.019 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003906
2015-06-01T21:41:22.447Z,1433194882.447 [Startup:StartupSatComms:A](INFO): Timed out from 2015-06-01T21:40:22.1Z
2015-06-01T21:41:22.447Z,1433194882.447 [Startup:StartupSatComms:A] Stopped
2015-06-01T21:41:22.447Z,1433194882.447 [Startup:StartupSatComms:B] Running Loop=1
2015-06-01T21:41:22.851Z,1433194882.851 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-06-01T21:41:27.050Z,1433194887.050 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20150601T213849/Courier0000.lzma
2015-06-01T21:41:27.850Z,1433194887.850 [DataOverHttps](INFO): Moved sent file to Logs/20150601T213849/Courier0000.lzma.bak
2015-06-01T21:41:27.850Z,1433194887.850 [DataOverHttps](INFO): SBD MOMSN=3530352
2015-06-01T21:41:37.131Z,1433194897.131 [DataOverHttps](INFO): Sending 710 bytes from file Logs/20150601T213849/Express0001.lzma
2015-06-01T21:41:37.924Z,1433194897.924 [DataOverHttps](INFO): Moved sent file to Logs/20150601T213849/Express0001.lzma.bak
2015-06-01T21:41:37.924Z,1433194897.924 [DataOverHttps](INFO): SBD MOMSN=3530356
2015-06-01T21:41:38.393Z,1433194898.393 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2015-06-01T21:41:38.399Z,1433194898.399 [Startup:StartupSatComms:B] Stopped
2015-06-01T21:41:38.399Z,1433194898.399 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2015-06-01T21:41:38.399Z,1433194898.399 [Startup:StartupSatComms] Stopped
2015-06-01T21:41:38.400Z,1433194898.400 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2015-06-01T21:41:38.400Z,1433194898.400 [Startup](INFO): Completed Startup
2015-06-01T21:41:38.400Z,1433194898.400 [Startup] Stopped
2015-06-01T21:41:38.401Z,1433194898.401 [Startup](INFO): Aggregate::uninitialize Startup
2015-06-01T21:41:38.401Z,1433194898.401 [Startup:A.GoToSurface] Stopped
2015-06-01T21:41:38.401Z,1433194898.401 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-06-01T21:41:38.754Z,1433194898.754 [MissionManager](IMPORTANT): Started mission Default
2015-06-01T21:41:38.754Z,1433194898.754 [Default] Running Loop=1
2015-06-01T21:41:38.754Z,1433194898.754 [Default](INFO): Aggregate::initialize Default
2015-06-01T21:41:38.754Z,1433194898.754 [Default:A.GoToSurface] Running Loop=1
2015-06-01T21:41:38.754Z,1433194898.754 [Default:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-06-01T21:41:38.755Z,1433194898.755 [Default:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-06-01T21:41:38.755Z,1433194898.755 [Default:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-06-01T21:41:38.756Z,1433194898.756 [Default:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-06-01T21:41:38.761Z,1433194898.761 [Default:WaitAtTheSurface] Running Loop=1
2015-06-01T21:41:38.761Z,1433194898.761 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2015-06-01T21:41:38.761Z,1433194898.761 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-06-01T21:41:38.762Z,1433194898.762 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize.
2015-06-01T21:41:42.071Z,1433194902.071 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-06-01T21:41:49.191Z,1433194909.191 [BPC1](ERROR): Failed to receive battery data
2015-06-01T21:41:49.191Z,1433194909.191 [BPC1] Communications Fault, FailCount= 1
2015-06-01T21:41:49.191