2015-07-20T18:30:57.656Z,1437417057.656 [Supervisor](DEBUG): Initializing supervisor. 2015-07-20T18:30:57.659Z,1437417057.659 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0 2015-07-20T18:30:57.660Z,1437417057.660 [SyncHandler](INFO): Protected caller Thread ID is 1273 2015-07-20T18:30:57.660Z,1437417057.660 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2015-07-20T18:30:57.661Z,1437417057.661 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0 2015-07-20T18:30:57.662Z,1437417057.662 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1274 2015-07-20T18:30:57.664Z,1437417057.664 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2015-07-20T18:30:57.677Z,1437417057.677 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2015-07-20T18:30:57.678Z,1437417057.678 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0 2015-07-20T18:30:57.679Z,1437417057.679 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1275 2015-07-20T18:30:57.679Z,1437417057.679 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2015-07-20T18:30:57.680Z,1437417057.680 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0 2015-07-20T18:30:57.681Z,1437417057.681 [logger ThreadHandler](INFO): Protected caller Thread ID is 1276 2015-07-20T18:30:57.683Z,1437417057.683 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2015-07-20T18:30:57.683Z,1437417057.683 [Supervisor](INFO): Looking for Config files in directory: Config/ 2015-07-20T18:30:57.685Z,1437417057.685 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2015-07-20T18:30:58.217Z,1437417058.217 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2015-07-20T18:30:58.217Z,1437417058.217 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2015-07-20T18:30:58.397Z,1437417058.397 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2015-07-20T18:30:58.397Z,1437417058.397 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2015-07-20T18:30:58.509Z,1437417058.509 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2015-07-20T18:30:58.509Z,1437417058.509 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2015-07-20T18:30:58.637Z,1437417058.637 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2015-07-20T18:30:58.637Z,1437417058.637 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2015-07-20T18:30:58.725Z,1437417058.725 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2015-07-20T18:30:58.927Z,1437417058.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2015-07-20T18:30:58.928Z,1437417058.928 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2015-07-20T18:30:59.016Z,1437417059.016 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2015-07-20T18:30:59.017Z,1437417059.017 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2015-07-20T18:30:59.295Z,1437417059.295 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2015-07-20T18:30:59.295Z,1437417059.295 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2015-07-20T18:30:59.655Z,1437417059.655 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2015-07-20T18:30:59.655Z,1437417059.655 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2015-07-20T18:30:59.988Z,1437417059.988 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2015-07-20T18:30:59.989Z,1437417059.989 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2015-07-20T18:31:00.536Z,1437417060.536 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2015-07-20T18:31:00.537Z,1437417060.537 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2015-07-20T18:31:00.766Z,1437417060.766 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2015-07-20T18:31:00.767Z,1437417060.767 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2015-07-20T18:31:00.874Z,1437417060.874 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2015-07-20T18:31:00.874Z,1437417060.874 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2015-07-20T18:31:01.344Z,1437417061.344 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2015-07-20T18:31:01.344Z,1437417061.344 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2015-07-20T18:31:01.550Z,1437417061.550 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2015-07-20T18:31:01.552Z,1437417061.552 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2015-07-20T18:31:01.553Z,1437417061.553 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2015-07-20T18:31:01.800Z,1437417061.800 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2015-07-20T18:31:01.801Z,1437417061.801 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2015-07-20T18:31:01.927Z,1437417061.927 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2015-07-20T18:31:02.028Z,1437417062.028 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2015-07-20T18:31:02.131Z,1437417062.131 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2015-07-20T18:31:02.292Z,1437417062.292 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2015-07-20T18:31:02.441Z,1437417062.441 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2015-07-20T18:31:02.551Z,1437417062.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2015-07-20T18:31:02.645Z,1437417062.645 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2015-07-20T18:31:02.729Z,1437417062.729 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2015-07-20T18:31:02.830Z,1437417062.830 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2015-07-20T18:31:03.025Z,1437417063.025 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2015-07-20T18:31:03.027Z,1437417063.027 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2015-07-20T18:31:03.086Z,1437417063.086 [VerticalControl](DEBUG): Construct VerticalControl. 2015-07-20T18:31:03.206Z,1437417063.206 [VerticalControl] Loaded 2015-07-20T18:31:03.206Z,1437417063.206 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2015-07-20T18:31:03.207Z,1437417063.207 [HorizontalControl](DEBUG): Construct HorizontalControl. 2015-07-20T18:31:03.278Z,1437417063.278 [HorizontalControl] Loaded 2015-07-20T18:31:03.278Z,1437417063.278 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2015-07-20T18:31:03.279Z,1437417063.279 [SpeedControl](DEBUG): Construct SpeedControl. 2015-07-20T18:31:03.285Z,1437417063.285 [SpeedControl] Loaded 2015-07-20T18:31:03.285Z,1437417063.285 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2015-07-20T18:31:03.286Z,1437417063.286 [LoopControl](DEBUG): Construct LoopControl. 2015-07-20T18:31:03.286Z,1437417063.286 [LoopControl] Loaded 2015-07-20T18:31:03.287Z,1437417063.287 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2015-07-20T18:31:03.287Z,1437417063.287 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2015-07-20T18:31:03.288Z,1437417063.288 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2015-07-20T18:31:03.425Z,1437417063.425 [SBIT](DEBUG): Construct Startup Built In Test. 2015-07-20T18:31:03.436Z,1437417063.436 [SBIT] Loaded 2015-07-20T18:31:03.437Z,1437417063.437 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2015-07-20T18:31:03.437Z,1437417063.437 [IBIT](DEBUG): Construct Initiated Built In Test. 2015-07-20T18:31:03.467Z,1437417063.467 [IBIT] Loaded 2015-07-20T18:31:03.468Z,1437417063.468 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2015-07-20T18:31:03.470Z,1437417063.470 [CBIT](DEBUG): Construct Continuous Built In Test. 2015-07-20T18:31:03.610Z,1437417063.610 [CBIT] Loaded 2015-07-20T18:31:03.611Z,1437417063.611 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2015-07-20T18:31:03.611Z,1437417063.611 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2015-07-20T18:31:03.612Z,1437417063.612 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2015-07-20T18:31:03.637Z,1437417063.637 [DepthRateCalculator] Loaded 2015-07-20T18:31:03.638Z,1437417063.638 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2015-07-20T18:31:03.643Z,1437417063.643 [PitchRateCalculator] Loaded 2015-07-20T18:31:03.643Z,1437417063.643 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2015-07-20T18:31:03.655Z,1437417063.655 [SpeedCalculator] Loaded 2015-07-20T18:31:03.655Z,1437417063.655 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2015-07-20T18:31:03.672Z,1437417063.672 [TempGradientCalculator] Loaded 2015-07-20T18:31:03.672Z,1437417063.672 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2015-07-20T18:31:03.678Z,1437417063.678 [YawRateCalculator] Loaded 2015-07-20T18:31:03.678Z,1437417063.678 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2015-07-20T18:31:03.678Z,1437417063.678 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2015-07-20T18:31:03.679Z,1437417063.679 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2015-07-20T18:31:03.757Z,1437417063.757 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2015-07-20T18:31:03.758Z,1437417063.758 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2015-07-20T18:31:04.003Z,1437417064.003 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2015-07-20T18:31:04.004Z,1437417064.004 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2015-07-20T18:31:04.111Z,1437417064.111 [DeadReckonUsingMultipleVelocitySources] Loaded 2015-07-20T18:31:04.112Z,1437417064.112 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2015-07-20T18:31:04.168Z,1437417064.168 [DeadReckonUsingSpeedCalculator] Loaded 2015-07-20T18:31:04.169Z,1437417064.169 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2015-07-20T18:31:04.186Z,1437417064.186 [NavChart] Loaded 2015-07-20T18:31:04.186Z,1437417064.186 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2015-07-20T18:31:04.190Z,1437417064.190 [UniversalFixResidualReporter] Loaded 2015-07-20T18:31:04.191Z,1437417064.191 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2015-07-20T18:31:04.191Z,1437417064.191 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2015-07-20T18:31:04.192Z,1437417064.192 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2015-07-20T18:31:04.204Z,1437417064.204 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2015-07-20T18:31:04.205Z,1437417064.205 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2015-07-20T18:31:04.452Z,1437417064.452 [CTD_NeilBrown] Loaded 2015-07-20T18:31:04.452Z,1437417064.452 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2015-07-20T18:31:04.453Z,1437417064.453 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 405904E0 2015-07-20T18:31:04.454Z,1437417064.454 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1355 2015-07-20T18:31:04.470Z,1437417064.470 [ESPComponent] Loaded 2015-07-20T18:31:04.470Z,1437417064.470 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2015-07-20T18:31:04.486Z,1437417064.486 [PAR_Licor] Loaded 2015-07-20T18:31:04.486Z,1437417064.486 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2015-07-20T18:31:04.487Z,1437417064.487 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2015-07-20T18:31:04.487Z,1437417064.487 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2015-07-20T18:31:04.820Z,1437417064.820 [AcousticModem_Benthos_ATM900] Loaded 2015-07-20T18:31:04.821Z,1437417064.821 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread. 2015-07-20T18:31:04.898Z,1437417064.898 [DataOverHttps] Loaded 2015-07-20T18:31:04.899Z,1437417064.899 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2015-07-20T18:31:04.912Z,1437417064.912 [Depth_Keller] Loaded 2015-07-20T18:31:04.913Z,1437417064.913 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2015-07-20T18:31:04.918Z,1437417064.918 [DropWeight] Loaded 2015-07-20T18:31:04.918Z,1437417064.918 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2015-07-20T18:31:05.013Z,1437417065.013 [NAL9602] Loaded 2015-07-20T18:31:05.013Z,1437417065.013 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2015-07-20T18:31:05.055Z,1437417065.055 [Onboard] Loaded 2015-07-20T18:31:05.055Z,1437417065.055 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2015-07-20T18:31:05.062Z,1437417065.062 [Radio_Surface] Loaded 2015-07-20T18:31:05.062Z,1437417065.062 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2015-07-20T18:31:05.063Z,1437417065.063 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407D44E0 2015-07-20T18:31:05.064Z,1437417065.064 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1356 2015-07-20T18:31:05.112Z,1437417065.112 [PNI_TCM] Loaded 2015-07-20T18:31:05.112Z,1437417065.112 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2015-07-20T18:31:05.298Z,1437417065.298 [Rowe_600] Loaded 2015-07-20T18:31:05.298Z,1437417065.298 [ComponentRegistry](DEBUG): Component "Rowe_600" handled in its own thread. 2015-07-20T18:31:05.299Z,1437417065.299 [Rowe_600 ThreadHandler](DEBUG): Created PCaller Thread at 408044E0 2015-07-20T18:31:05.300Z,1437417065.300 [Rowe_600 ThreadHandler](INFO): Protected caller Thread ID is 1357 2015-07-20T18:31:07.174Z,1437417067.174 [BPC1] Loaded 2015-07-20T18:31:07.174Z,1437417067.174 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2015-07-20T18:31:07.174Z,1437417067.174 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2015-07-20T18:31:07.175Z,1437417067.175 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2015-07-20T18:31:07.288Z,1437417067.288 [BuoyancyServo] Loaded 2015-07-20T18:31:07.289Z,1437417067.289 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2015-07-20T18:31:07.301Z,1437417067.301 [ElevatorServo] Loaded 2015-07-20T18:31:07.302Z,1437417067.302 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2015-07-20T18:31:07.313Z,1437417067.313 [MassServo] Loaded 2015-07-20T18:31:07.314Z,1437417067.314 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2015-07-20T18:31:07.326Z,1437417067.326 [RudderServo] Loaded 2015-07-20T18:31:07.326Z,1437417067.326 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2015-07-20T18:31:07.338Z,1437417067.338 [ThrusterServo] Loaded 2015-07-20T18:31:07.338Z,1437417067.338 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2015-07-20T18:31:07.339Z,1437417067.339 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2015-07-20T18:31:07.339Z,1437417067.339 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2015-07-20T18:31:07.461Z,1437417067.461 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2015-07-20T18:31:07.461Z,1437417067.461 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2015-07-20T18:31:07.497Z,1437417067.497 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2015-07-20T18:31:07.501Z,1437417067.501 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2015-07-20T18:31:07.502Z,1437417067.502 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2015-07-20T18:31:07.509Z,1437417067.509 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2015-07-20T18:31:07.510Z,1437417067.510 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408B24E0 2015-07-20T18:31:07.511Z,1437417067.511 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1358 2015-07-20T18:31:07.516Z,1437417067.516 [Supervisor](INFO): Main Thread ID is 942 2015-07-20T18:31:07.516Z,1437417067.516 [Supervisor](DEBUG): Running supervisor. 2015-07-20T18:31:07.517Z,1437417067.517 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1359 2015-07-20T18:31:07.519Z,1437417067.519 [controlThread ThreadHandler](INFO): Handler Thread ID is 1360 2015-07-20T18:31:07.520Z,1437417067.520 [controlThread](DEBUG): Initializing ControlThread 2015-07-20T18:31:07.521Z,1437417067.521 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2015-07-20T18:31:07.523Z,1437417067.523 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2015-07-20T18:31:07.523Z,1437417067.523 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2015-07-20T18:31:07.524Z,1437417067.524 [LoopControl](DEBUG): Initialize LoopControlComponent. 2015-07-20T18:31:07.524Z,1437417067.524 [SBIT](INFO): Initialize SBIT Component. 2015-07-20T18:31:07.525Z,1437417067.525 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12461 2015-07-20T18:31:07.525Z,1437417067.525 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2015-07-20T18:31:07.525Z,1437417067.525 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2015-07-20T18:31:07.527Z,1437417067.527 [SBIT](INFO): Beginning SBIT in 63.000000 seconds. 2015-07-20T18:31:07.527Z,1437417067.527 [IBIT](INFO): Initialize IBIT Component. 2015-07-20T18:31:07.528Z,1437417067.528 [CBIT](DEBUG): Initialize CBIT Component. 2015-07-20T18:31:07.528Z,1437417067.528 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2015-07-20T18:31:07.529Z,1437417067.529 [logger ThreadHandler](INFO): Handler Thread ID is 1361 2015-07-20T18:31:07.550Z,1437417067.550 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1362 2015-07-20T18:31:07.550Z,1437417067.550 [CTD_NeilBrown](INFO): Powering down 2015-07-20T18:31:07.553Z,1437417067.553 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2015-07-20T18:31:07.554Z,1437417067.554 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2015-07-20T18:31:07.554Z,1437417067.554 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2015-07-20T18:31:07.554Z,1437417067.554 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2015-07-20T18:31:07.555Z,1437417067.555 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2015-07-20T18:31:07.555Z,1437417067.555 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-07-20T18:31:07.556Z,1437417067.556 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-07-20T18:31:07.556Z,1437417067.556 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-07-20T18:31:07.557Z,1437417067.557 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-07-20T18:31:07.557Z,1437417067.557 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-07-20T18:31:07.557Z,1437417067.557 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-07-20T18:31:07.558Z,1437417067.558 [NavChart](DEBUG): Initialize NavChart Navigation. 2015-07-20T18:31:07.558Z,1437417067.558 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2015-07-20T18:31:07.573Z,1437417067.573 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2015-07-20T18:31:07.586Z,1437417067.586 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-07-20T18:31:07.610Z,1437417067.610 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1363 2015-07-20T18:31:07.621Z,1437417067.621 [Radio_Surface](INFO): Powering up 2015-07-20T18:31:07.625Z,1437417067.625 [MissionManager](DEBUG): 2015-07-20T18:31:07.626Z,1437417067.626 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2015-07-20T18:31:07.629Z,1437417067.629 [Rowe_600 ThreadHandler](INFO): Handler Thread ID is 1364 2015-07-20T18:31:07.650Z,1437417067.650 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1365 2015-07-20T18:31:07.656Z,1437417067.656 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2015-07-20T18:31:07.657Z,1437417067.657 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2015-07-20T18:31:07.658Z,1437417067.658 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2015-07-20T18:31:07.658Z,1437417067.658 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2015-07-20T18:31:07.658Z,1437417067.658 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2015-07-20T18:31:07.658Z,1437417067.658 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2015-07-20T18:31:07.658Z,1437417067.658 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2015-07-20T18:31:07.659Z,1437417067.659 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2015-07-20T18:31:07.659Z,1437417067.659 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2015-07-20T18:31:07.722Z,1437417067.722 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2015-07-20T18:31:07.723Z,1437417067.723 [Default:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-07-20T18:31:07.759Z,1437417067.759 [Default:SplitLargeDefaultLogs:A.Execute](DEBUG): Construct Execute. 2015-07-20T18:31:07.783Z,1437417067.783 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2015-07-20T18:31:07.796Z,1437417067.796 [Default:CheckIn:WaitAnHour:A.Wait](DEBUG): Construct Wait. 2015-07-20T18:31:07.806Z,1437417067.806 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2015-07-20T18:31:07.818Z,1437417067.818 [MissionManager](DEBUG): 0 10 500 Default mission has been running for 1 restart logs Burn 300 Dropped weight due to communications timeout. 1 5 2015-07-20T18:31:07.824Z,1437417067.824 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2015-07-20T18:31:07.847Z,1437417067.847 [ESPComponent](DEBUG): start simulateHardware()=0 2015-07-20T18:31:07.872Z,1437417067.872 [AcousticModem_Benthos_ATM900](INFO): Powering up 2015-07-20T18:31:07.873Z,1437417067.873 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2015-07-20T18:31:07.900Z,1437417067.900 [Rowe_600](INFO): Powering down 2015-07-20T18:31:08.159Z,1437417068.159 [Rowe_600](INFO): Initializing 2015-07-20T18:31:08.174Z,1437417068.174 [Rowe_600](INFO): Powering up 2015-07-20T18:31:08.353Z,1437417068.353 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:08.377Z,1437417068.377 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:08.491Z,1437417068.491 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2015-07-20T18:31:08.499Z,1437417068.499 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2015-07-20T18:31:08.521Z,1437417068.521 [ElevatorServo](DEBUG): Initializing EZServoServo. 2015-07-20T18:31:08.527Z,1437417068.527 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2015-07-20T18:31:08.541Z,1437417068.541 [MassServo](DEBUG): Initializing EZServoServo. 2015-07-20T18:31:08.543Z,1437417068.543 [MassServo](DEBUG): Initializing MassServo. 2015-07-20T18:31:08.564Z,1437417068.564 [RudderServo](DEBUG): Initializing EZServoServo. 2015-07-20T18:31:08.571Z,1437417068.571 [RudderServo](DEBUG): Initializing RudderServo. 2015-07-20T18:31:08.588Z,1437417068.588 [ThrusterServo](DEBUG): Initializing EZServoServo. 2015-07-20T18:31:08.595Z,1437417068.595 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2015-07-20T18:31:08.711Z,1437417068.711 [ESPComponent](DEBUG): ESPComponent::stop 2015-07-20T18:31:08.711Z,1437417068.711 [ESPComponent](INFO): Powering down 2015-07-20T18:31:09.160Z,1437417069.160 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:09.162Z,1437417069.162 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:09.564Z,1437417069.564 [ESPComponent](DEBUG): ESPComponent::stopping 2015-07-20T18:31:09.715Z,1437417069.715 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:09.717Z,1437417069.717 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:10.011Z,1437417070.011 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:10.012Z,1437417070.012 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:10.375Z,1437417070.375 [NAL9602](INFO): Powering up NAL9602 2015-07-20T18:31:10.424Z,1437417070.424 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:10.426Z,1437417070.426 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:10.829Z,1437417070.829 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:10.830Z,1437417070.830 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:11.186Z,1437417071.186 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:11.187Z,1437417071.187 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:11.799Z,1437417071.799 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:11.828Z,1437417071.828 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-20T18:31:15.378Z,1437417075.378 [AcousticModem_Benthos_ATM900](DEBUG): 2015-07-20T18:31:16.877Z,1437417076.877 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire 2015-07-20T18:31:16.877Z,1437417076.877 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band 2015-07-20T18:31:16.878Z,1437417076.878 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3 2015-07-20T18:31:16.879Z,1437417076.879 [AcousticModem_Benthos_ATM900](DEBUG): Jul 20 2015 18:34:33 2015-07-20T18:31:18.567Z,1437417078.567 [AcousticModem_Benthos_ATM900](INFO): entering command mode 2015-07-20T18:31:19.096Z,1437417079.096 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment 2015-07-20T18:31:19.097Z,1437417079.097 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1> 2015-07-20T18:31:19.097Z,1437417079.097 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged 2015-07-20T18:31:19.608Z,1437417079.608 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3 2015-07-20T18:31:21.609Z,1437417081.609 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment 2015-07-20T18:31:21.689Z,1437417081.689 [AcousticModem_Benthos_ATM900](INFO): set local address to 3 2015-07-20T18:31:22.017Z,1437417082.017 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2> 2015-07-20T18:31:22.720Z,1437417082.720 [NAL9602](INFO): NAL9602 initialized 2015-07-20T18:31:26.412Z,1437417086.412 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:31:26.716Z,1437417086.716 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:31:26.727Z,1437417086.727 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:31:27.038Z,1437417087.038 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:32:06.863Z,1437417126.863 [BPC1](ERROR): Failed to parse bank B battery data 2015-07-20T18:32:06.863Z,1437417126.863 [BPC1] Data Fault, FailCount= 1 2015-07-20T18:32:06.864Z,1437417126.864 [BPC1](ERROR): Data Fault 2015-07-20T18:32:06.912Z,1437417126.912 [CBIT](ERROR): Data Fault in component: BPC1 2015-07-20T18:32:08.065Z,1437417128.065 [CBIT](INFO): Clearing failed state for component BPC1 2015-07-20T18:32:08.065Z,1437417128.065 [BPC1] No Fault, FailCount= 1 2015-07-20T18:32:10.995Z,1437417130.995 [SBIT](IMPORTANT): Beginning Startup BIT 2015-07-20T18:32:11.141Z,1437417131.141 [CBIT](IMPORTANT): Beginning GF scan 2015-07-20T18:32:11.299Z,1437417131.299 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:32:11.606Z,1437417131.606 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:32:11.617Z,1437417131.617 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:32:11.926Z,1437417131.926 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:32:40.230Z,1437417160.230 [CBIT](IMPORTANT): No ground fault detected 2015-07-20T18:32:41.683Z,1437417161.683 [NAL9602](INFO): SBD MO Status=0, MOMSN=13404, MT Status=0, MTMSN=0 2015-07-20T18:32:41.683Z,1437417161.683 [NAL9602](INFO): No messages in MT queue 2015-07-20T18:32:53.480Z,1437417173.480 [Rowe_600](ERROR): Only MATLAB type 10 (float32) matrices are supported, got MATLAB type 0 2015-07-20T18:33:06.463Z,1437417186.463 [SBIT](IMPORTANT): SBIT PASSED 2015-07-20T18:33:06.699Z,1437417186.699 [MissionManager](IMPORTANT): Started mission Startup 2015-07-20T18:33:06.699Z,1437417186.699 [Startup] Running Loop=1 2015-07-20T18:33:06.700Z,1437417186.700 [Startup](DEBUG): Aggregate::initialize Startup 2015-07-20T18:33:06.700Z,1437417186.700 [Startup:A.GoToSurface] Running Loop=1 2015-07-20T18:33:06.700Z,1437417186.700 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2015-07-20T18:33:06.700Z,1437417186.700 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2015-07-20T18:33:06.701Z,1437417186.701 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2015-07-20T18:33:06.701Z,1437417186.701 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s. 2015-07-20T18:33:06.731Z,1437417186.731 [Startup:StartupSatComms] Running Loop=1 2015-07-20T18:33:06.731Z,1437417186.731 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2015-07-20T18:33:06.731Z,1437417186.731 [Startup:StartupSatComms:A] Running Loop=1 2015-07-20T18:33:07.500Z,1437417187.500 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2015-07-20T18:33:40.282Z,1437417220.282 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2015-07-20T18:33:41.682Z,1437417221.682 [Rowe_600](ERROR): unknown matrix type0 2015-07-20T18:34:07.381Z,1437417247.381 [Startup:StartupSatComms:A](INFO): Timed out from 2015-07-20T18:33:06.7Z 2015-07-20T18:34:07.381Z,1437417247.381 [Startup:StartupSatComms:A] Stopped 2015-07-20T18:34:07.381Z,1437417247.381 [Startup:StartupSatComms:B] Running Loop=1 2015-07-20T18:34:07.532Z,1437417247.532 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2015-07-20T18:34:10.239Z,1437417250.239 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-07-20T18:34:10.239Z,1437417250.239 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2015-07-20T18:34:10.239Z,1437417250.239 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-07-20T18:34:10.253Z,1437417250.253 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-07-20T18:34:10.254Z,1437417250.254 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2015-07-20T18:34:10.254Z,1437417250.254 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2015-07-20T18:34:10.289Z,1437417250.289 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-07-20T18:34:10.290Z,1437417250.290 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2015-07-20T18:34:10.481Z,1437417250.481 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-07-20T18:34:10.481Z,1437417250.481 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2015-07-20T18:34:10.491Z,1437417250.491 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2015-07-20T18:34:10.491Z,1437417250.491 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2015-07-20T18:34:35.961Z,1437417275.961 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-07-20T18:34:35.961Z,1437417275.961 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-07-20T18:34:35.962Z,1437417275.962 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-07-20T18:34:36.010Z,1437417276.010 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-07-20T18:34:36.013Z,1437417276.013 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-07-20T18:34:36.015Z,1437417276.015 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-07-20T18:34:37.296Z,1437417277.296 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.010619 2015-07-20T18:35:03.510Z,1437417303.510 [BPC1](ERROR): Failed to receive battery data 2015-07-20T18:35:03.511Z,1437417303.511 [BPC1] Communications Fault, FailCount= 1 2015-07-20T18:35:03.511Z,1437417303.511 [BPC1](ERROR): Communications Fault 2015-07-20T18:35:03.570Z,1437417303.570 [CBIT](ERROR): Communications Fault in component: BPC1 2015-07-20T18:35:03.610Z,1437417303.610 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20150720T161757/Courier0076.lzma 2015-07-20T18:35:05.595Z,1437417305.595 [DataOverHttps](INFO): Moved sent file to Logs/20150720T161757/Courier0076.lzma.bak 2015-07-20T18:35:05.603Z,1437417305.603 [DataOverHttps](INFO): SBD MOMSN=3615651 2015-07-20T18:35:06.037Z,1437417306.037 [CBIT](INFO): Clearing failed state for component BPC1 2015-07-20T18:35:06.037Z,1437417306.037 [BPC1] No Fault, FailCount= 1 2015-07-20T18:35:32.937Z,1437417332.937 [BPC1](ERROR): Failed to receive battery data 2015-07-20T18:35:32.952Z,1437417332.952 [BPC1] Communications Fault, FailCount= 2 2015-07-20T18:35:32.952Z,1437417332.952 [BPC1](ERROR): Communications Fault 2015-07-20T18:35:33.076Z,1437417333.076 [Startup:StartupSatComms:B](INFO): Timed out from 2015-07-20T18:34:07.4Z 2015-07-20T18:35:33.076Z,1437417333.076 [Startup:StartupSatComms:B] Stopped 2015-07-20T18:35:33.076Z,1437417333.076 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2015-07-20T18:35:33.076Z,1437417333.076 [Startup:StartupSatComms] Stopped 2015-07-20T18:35:33.076Z,1437417333.076 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2015-07-20T18:35:33.077Z,1437417333.077 [Startup](INFO): Completed Startup 2015-07-20T18:35:33.077Z,1437417333.077 [Startup] Stopped 2015-07-20T18:35:33.077Z,1437417333.077 [Startup](DEBUG): Aggregate::uninitialize Startup 2015-07-20T18:35:33.077Z,1437417333.077 [Startup:A.GoToSurface] Stopped 2015-07-20T18:35:33.077Z,1437417333.077 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2015-07-20T18:35:33.125Z,1437417333.125 [CBIT](ERROR): Communications Fault in component: BPC1 2015-07-20T18:35:33.243Z,1437417333.243 [MissionManager](IMPORTANT): Started mission Default 2015-07-20T18:35:33.243Z,1437417333.243 [Default] Running Loop=1 2015-07-20T18:35:33.243Z,1437417333.243 [Default](DEBUG): Aggregate::initialize Default 2015-07-20T18:35:33.244Z,1437417333.244 [Default:A.GoToSurface] Running Loop=1 2015-07-20T18:35:33.244Z,1437417333.244 [Default:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2015-07-20T18:35:33.244Z,1437417333.244 [Default:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2015-07-20T18:35:33.244Z,1437417333.244 [Default:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2015-07-20T18:35:33.245Z,1437417333.245 [Default:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s. 2015-07-20T18:35:33.266Z,1437417333.266 [Default:Read_GPS] Running Loop=1 2015-07-20T18:35:33.929Z,1437417333.929 [Default:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2015-07-20T18:35:35.086Z,1437417335.086 [CBIT](INFO): Clearing failed state for component BPC1 2015-07-20T18:35:35.086Z,1437417335.086 [BPC1] No Fault, FailCount= 2 2015-07-20T18:35:47.570Z,1437417347.570 [BPC1](ERROR): Failed to parse bank B battery data 2015-07-20T18:35:47.570Z,1437417347.570 [BPC1] Data Fault, FailCount= 3 2015-07-20T18:35:47.570Z,1437417347.570 [BPC1](ERROR): Data Fault 2015-07-20T18:35:47.589Z,1437417347.589 [CBIT](ERROR): Data Fault in component: BPC1 2015-07-20T18:35:47.868Z,1437417347.868 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20150720T161757/Courier0080.lzma 2015-07-20T18:35:48.494Z,1437417348.494 [DataOverHttps](INFO): Moved sent file to Logs/20150720T161757/Courier0080.lzma.bak 2015-07-20T18:35:48.494Z,1437417348.494 [DataOverHttps](INFO): SBD MOMSN=3615653 2015-07-20T18:35:49.251Z,1437417349.251 [CBIT](INFO): Clearing failed state for component BPC1 2015-07-20T18:35:49.251Z,1437417349.251 [BPC1] No Fault, FailCount= 3 2015-07-20T18:36:03.877Z,1437417363.877 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:04.313Z,1437417364.313 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:04.644Z,1437417364.644 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:14.964Z,1437417374.964 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:15.275Z,1437417375.275 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:15.481Z,1437417375.481 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:21.675Z,1437417381.675 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:21.685Z,1437417381.685 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:21.987Z,1437417381.987 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:44.118Z,1437417404.118 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:44.129Z,1437417404.129 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:44.434Z,1437417404.434 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:48.616Z,1437417408.616 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:48.940Z,1437417408.940 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:36:49.122Z,1437417409.122 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:13.119Z,1437417433.119 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:13.130Z,1437417433.130 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:13.442Z,1437417433.442 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:13.754Z,1437417433.754 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:14.060Z,1437417434.060 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:14.072Z,1437417434.072 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:14.383Z,1437417434.383 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:29.462Z,1437417449.462 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:29.783Z,1437417449.783 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:29.984Z,1437417449.984 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:30.090Z,1437417450.090 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:35.510Z,1437417455.510 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:35.815Z,1437417455.815 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:36.131Z,1437417456.131 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:36.219Z,1437417456.219 [NAL9602](INFO): GPS fix at 20150720T183634: (36.802123, -121.787255) 2015-07-20T18:37:36.263Z,1437417456.263 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:36.324Z,1437417456.324 [Default:Read_GPS] Stopped 2015-07-20T18:37:36.324Z,1437417456.324 [Default:CheckIn] Running Loop=1 2015-07-20T18:37:36.324Z,1437417456.324 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2015-07-20T18:37:36.324Z,1437417456.324 [Default:CheckIn:Read_Iridium] Running Loop=1 2015-07-20T18:37:40.759Z,1437417460.759 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:41.075Z,1437417461.075 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:37:41.219Z,1437417461.219 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:38:09.045Z,1437417489.045 [BPC1](ERROR): Failed to receive battery data 2015-07-20T18:38:09.046Z,1437417489.046 [BPC1] Communications Fault, FailCount= 1 2015-07-20T18:38:09.046Z,1437417489.046 [BPC1](ERROR): Communications Fault 2015-07-20T18:38:09.079Z,1437417489.079 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2015-07-20T18:38:09.130Z,1437417489.130 [CBIT](ERROR): Communications Fault in component: BPC1 2015-07-20T18:38:38.762Z,1437417518.762 [CBIT](INFO): Clearing failed state for component BPC1 2015-07-20T18:38:38.762Z,1437417518.762 [BPC1] No Fault, FailCount= 1 2015-07-20T18:38:38.879Z,1437417518.879 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20150720T183057/Courier0004.lzma 2015-07-20T18:38:38.896Z,1437417518.896 [NAL9602](INFO): Powering down 2015-07-20T18:38:39.817Z,1437417519.817 [DataOverHttps](INFO): Moved sent file to Logs/20150720T183057/Courier0004.lzma.bak 2015-07-20T18:38:39.817Z,1437417519.817 [DataOverHttps](INFO): SBD MOMSN=3615655 2015-07-20T18:38:51.707Z,1437417531.707 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:38:52.033Z,1437417532.033 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:38:52.171Z,1437417532.171 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:38:55.891Z,1437417535.891 [CommandLine](IMPORTANT): got command show variable pni 2015-07-20T18:38:57.687Z,1437417537.687 [CommandLine](IMPORTANT): PNI_TCM.loadAtStartup (bool) 2015-07-20T18:38:57.687Z,1437417537.687 [CommandLine](IMPORTANT): PNI_TCM.simulateHardware (bool) 2015-07-20T18:38:57.688Z,1437417537.688 [CommandLine](IMPORTANT): PNI_TCM.verbosity (count) 2015-07-20T18:38:57.688Z,1437417537.688 [CommandLine](IMPORTANT): PNI_TCM.power (watt) 2015-07-20T18:38:57.701Z,1437417537.701 [CommandLine](IMPORTANT): PNI_TCM.readMagnetics (bool) 2015-07-20T18:38:57.701Z,1437417537.701 [CommandLine](IMPORTANT): PNI_TCM.magDeviation (degree) 2015-07-20T18:38:57.701Z,1437417537.701 [CommandLine](IMPORTANT): PNI_TCM.pitchOffset (degree) 2015-07-20T18:38:57.702Z,1437417537.702 [CommandLine](IMPORTANT): PNI_TCM.rollOffset (degree) 2015-07-20T18:38:57.754Z,1437417537.754 [CommandLine](IMPORTANT): PNI_TCM.loadControl (none) 2015-07-20T18:38:57.754Z,1437417537.754 [CommandLine](IMPORTANT): PNI_TCM.uart (none) 2015-07-20T18:38:57.755Z,1437417537.755 [CommandLine](IMPORTANT): PNI_TCM.baud (bit_per_second) 2015-07-20T18:38:57.766Z,1437417537.766 [CommandLine](IMPORTANT): PNI_TCM.readAccelerations (bool) 2015-07-20T18:38:57.798Z,1437417537.798 [CommandLine](IMPORTANT): PNI_TCM.CompassOrientation (degree) 2015-07-20T18:38:57.798Z,1437417537.798 [CommandLine](IMPORTANT): PNI_TCM.CompassTemperature (celsius) 2015-07-20T18:38:57.798Z,1437417537.798 [CommandLine](IMPORTANT): PNI_TCM.Mx (microtesla) 2015-07-20T18:38:57.799Z,1437417537.799 [CommandLine](IMPORTANT): PNI_TCM.My (microtesla) 2015-07-20T18:38:57.799Z,1437417537.799 [CommandLine](IMPORTANT): PNI_TCM.Mz (microtesla) 2015-07-20T18:38:57.799Z,1437417537.799 [CommandLine](IMPORTANT): PNI_TCM.platform_magnetic_orientation (radian) 2015-07-20T18:38:57.800Z,1437417537.800 [CommandLine](IMPORTANT): PNI_TCM.platform_orientation (radian) 2015-07-20T18:38:57.800Z,1437417537.800 [CommandLine](IMPORTANT): PNI_TCM.platform_pitch_angle (radian) 2015-07-20T18:38:57.817Z,1437417537.817 [CommandLine](IMPORTANT): PNI_TCM.platform_roll_angle (radian) 2015-07-20T18:38:57.825Z,1437417537.825 [CommandLine](IMPORTANT): PNI_TCM.platform_orientation_matrix (none) 2015-07-20T18:38:57.945Z,1437417537.945 [CommandLine](IMPORTANT): PNI_TCM.durationOfLastRun (second) 2015-07-20T18:38:57.947Z,1437417537.947 [CommandLine](IMPORTANT): PNI_TCM.component_voltage (volt) 2015-07-20T18:38:57.947Z,1437417537.947 [CommandLine](IMPORTANT): PNI_TCM.component_avgVoltage (volt) 2015-07-20T18:38:57.948Z,1437417537.948 [CommandLine](IMPORTANT): PNI_TCM.component_current (milliampere) 2015-07-20T18:38:57.948Z,1437417537.948 [CommandLine](IMPORTANT): PNI_TCM.component_avgCurrent (milliampere) 2015-07-20T18:38:58.289Z,1437417538.289 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:38:58.595Z,1437417538.595 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:38:58.606Z,1437417538.606 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:38:58.917Z,1437417538.917 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:39:10.764Z,1437417550.764 [BPC1](ERROR): Failed to receive battery data 2015-07-20T18:39:10.790Z,1437417550.790 [BPC1] Communications Fault, FailCount= 2 2015-07-20T18:39:10.791Z,1437417550.791 [BPC1](ERROR): Communications Fault 2015-07-20T18:39:11.732Z,1437417551.732 [CBIT](ERROR): Communications Fault in component: BPC1 2015-07-20T18:39:12.354Z,1437417552.354 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2015-07-20T18:39:13.157Z,1437417553.157 [CBIT](INFO): Clearing failed state for component BPC1 2015-07-20T18:39:13.157Z,1437417553.157 [BPC1] No Fault, FailCount= 2 2015-07-20T18:39:13.206Z,1437417553.206 [CommandLine](IMPORTANT): got command report touch PNI_TCM.platform_magnetic_orientation 2015-07-20T18:39:13.399Z,1437417553.399 [Reporter](INFO): PNI_TCM.platform_magnetic_orientation 0.511536 rad 2015-07-20T18:39:28.752Z,1437417568.752 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:39:29.063Z,1437417569.063 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:39:29.231Z,1437417569.231 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:39:29.516Z,1437417569.516 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:39:35.861Z,1437417575.861 [Reporter](INFO): PNI_TCM.platform_magnetic_orientation 0.538334 rad 2015-07-20T18:39:36.940Z,1437417576.940 [Reporter](INFO): PNI_TCM.platform_magnetic_orientation 0.528286 rad 2015-07-20T18:39:37.929Z,1437417577.929 [Reporter](INFO): PNI_TCM.platform_magnetic_orientation 0.511060 rad 2015-07-20T18:39:38.411Z,1437417578.411 [Reporter](INFO): PNI_TCM.platform_magnetic_orientation 0.547232 rad 2015-07-20T18:39:38.597Z,1437417578.597 [Reporter](INFO): PNI_TCM.platform_magnetic_orientation 0.547232 rad 2015-07-20T18:39:39.350Z,1437417579.350 [Reporter](INFO): PNI_TCM.platform_magnetic_orientation 0.516622 rad 2015-07-20T18:39:39.771Z,1437417579.771 [CommandLine](IMPORTANT): got command report clear 2015-07-20T18:39:40.123Z,1437417580.123 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:39:40.454Z,1437417580.454 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:39:40.848Z,1437417580.848 [Rowe_600](DEBUG): LCB error: Software Overcurrent. 2015-07-20T18:39:49.447Z,1437417589.447 [CommandLine](IMPORTANT): got command restart system 2015-07-20T18:39:52.713Z,1437417592.713 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2015-07-20T18:39:52.715Z,1437417592.715 [CommandLine ThreadHandler](INFO): Thread cancelled. 2015-07-20T18:39:52.811Z,1437417592.811 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2015-07-20T18:39:52.811Z,1437417592.811 [CommandLine ThreadHandler](INFO): Thread cancelled. 2015-07-20T18:39:52.815Z,1437417592.815 [CommandLine](INFO): Join timeout helper Thread ID is 1409 2015-07-20T18:39:52.870Z,1437417592.870 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2015-07-20T18:39:52.870Z,1437417592.870 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2015-07-20T18:39:52.871Z,1437417592.871 [NavChartDb](INFO): Join timeout helper Thread ID is 1410 2015-07-20T18:39:52.881Z,1437417592.881 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2015-07-20T18:39:52.882Z,1437417592.882 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2015-07-20T18:39:52.894Z,1437417592.894 [ComponentRegistry](INFO): Shutting down Rowe_600 ThreadHandler 2015-07-20T18:39:52.894Z,1437417592.894 [Rowe_600 ThreadHandler](INFO): Thread cancelled. 2015-07-20T18:39:52.895Z,1437417592.895 [Rowe_600](INFO): Join timeout helper Thread ID is 1411 2015-07-20T18:39:53.173Z,1437417593.173 [Rowe_600 ThreadHandler](INFO): Uninitializing protected caller thread. 2015-07-20T18:39:53.174Z,1437417593.174 [Rowe_600](INFO): Powering down 2015-07-20T18:39:53.247Z,1437417593.247 [Rowe_600 ThreadHandler](INFO): Thread cancelled. 2015-07-20T18:39:53.251Z,1437417593.251 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2015-07-20T18:39:53.251Z,1437417593.251 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2015-07-20T18:39:53.252Z,1437417593.252 [Radio_Surface](INFO): Join timeout helper Thread ID is 1412 2015-07-20T18:39:53.600Z,1437417593.600 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2015-07-20T18:39:53.600Z,1437417593.600 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2015-07-20T18:39:53.611Z,1437417593.611 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2015-07-20T18:39:53.612Z,1437417593.612 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2015-07-20T18:39:53.612Z,1437417593.612 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1413 2015-07-20T18:39:53.616Z,1437417593.616 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2015-07-20T18:39:53.616Z,1437417593.616 [CTD_NeilBrown](INFO): Powering down 2015-07-20T18:39:53.617Z,1437417593.617 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2015-07-20T18:39:53.640Z,1437417593.640 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2015-07-20T18:39:53.641Z,1437417593.641 [logger ThreadHandler](INFO): Thread cancelled. 2015-07-20T18:39:53.641Z,1437417593.641 [logger](INFO): Join timeout helper Thread ID is 1414 2015-07-20T18:3