2018-08-28T17:36:17.291Z,1535477777.291 [Supervisor](DEBUG): Initializing supervisor.
2018-08-28T17:36:17.293Z,1535477777.293 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-08-28T17:36:17.294Z,1535477777.294 [SyncHandler](INFO): Protected caller Thread ID is 1101
2018-08-28T17:36:17.294Z,1535477777.294 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-08-28T17:36:17.295Z,1535477777.295 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-08-28T17:36:17.296Z,1535477777.296 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1102
2018-08-28T17:36:17.298Z,1535477777.298 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-08-28T17:36:17.310Z,1535477777.310 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-08-28T17:36:17.311Z,1535477777.311 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-08-28T17:36:17.311Z,1535477777.311 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1103
2018-08-28T17:36:17.312Z,1535477777.312 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-08-28T17:36:17.313Z,1535477777.313 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-08-28T17:36:17.313Z,1535477777.313 [logger ThreadHandler](INFO): Protected caller Thread ID is 1104
2018-08-28T17:36:17.315Z,1535477777.315 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-08-28T17:36:17.316Z,1535477777.316 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-08-28T17:36:17.317Z,1535477777.317 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-08-28T17:36:17.414Z,1535477777.414 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-08-28T17:36:17.414Z,1535477777.414 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-08-28T17:36:17.516Z,1535477777.516 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-08-28T17:36:17.516Z,1535477777.516 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-08-28T17:36:17.724Z,1535477777.724 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-08-28T17:36:17.725Z,1535477777.725 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-08-28T17:36:18.062Z,1535477778.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-08-28T17:36:18.063Z,1535477778.063 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-08-28T17:36:18.413Z,1535477778.413 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-08-28T17:36:18.413Z,1535477778.413 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-08-28T17:36:18.962Z,1535477778.962 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-08-28T17:36:18.962Z,1535477778.962 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-08-28T17:36:19.395Z,1535477779.395 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-08-28T17:36:19.395Z,1535477779.395 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-08-28T17:36:19.877Z,1535477779.877 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-08-28T17:36:19.878Z,1535477779.878 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-08-28T17:36:19.958Z,1535477779.958 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-08-28T17:36:20.275Z,1535477780.275 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-08-28T17:36:20.276Z,1535477780.276 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-08-28T17:36:20.424Z,1535477780.424 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-08-28T17:36:20.425Z,1535477780.425 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-08-28T17:36:20.637Z,1535477780.637 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-08-28T17:36:20.638Z,1535477780.638 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-08-28T17:36:20.855Z,1535477780.855 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-08-28T17:36:20.856Z,1535477780.856 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-08-28T17:36:20.954Z,1535477780.954 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-08-28T17:36:20.954Z,1535477780.954 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-08-28T17:36:21.098Z,1535477781.098 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-08-28T17:36:21.100Z,1535477781.100 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-08-28T17:36:21.101Z,1535477781.101 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-08-28T17:36:21.335Z,1535477781.335 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-08-28T17:36:21.336Z,1535477781.336 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-08-28T17:36:21.441Z,1535477781.441 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-08-28T17:36:21.586Z,1535477781.586 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-08-28T17:36:21.679Z,1535477781.679 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-08-28T17:36:21.764Z,1535477781.764 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-08-28T17:36:21.909Z,1535477781.909 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-08-28T17:36:22.094Z,1535477782.094 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-08-28T17:36:22.443Z,1535477782.443 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-08-28T17:36:22.551Z,1535477782.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-08-28T17:36:22.649Z,1535477782.649 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-08-28T17:36:22.732Z,1535477782.732 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2018-08-28T17:36:22.733Z,1535477782.733 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-08-28T17:36:22.746Z,1535477782.746 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-08-28T17:36:22.844Z,1535477782.844 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-08-28T17:36:22.844Z,1535477782.844 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-08-28T17:36:22.857Z,1535477782.857 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-08-28T17:36:22.858Z,1535477782.858 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-08-28T17:36:22.899Z,1535477782.899 [DepthRateCalculator] Loaded
2018-08-28T17:36:22.899Z,1535477782.899 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-08-28T17:36:22.905Z,1535477782.905 [PitchRateCalculator] Loaded
2018-08-28T17:36:22.905Z,1535477782.905 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-08-28T17:36:22.921Z,1535477782.921 [SpeedCalculator] Loaded
2018-08-28T17:36:22.922Z,1535477782.922 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-08-28T17:36:22.943Z,1535477782.943 [TempGradientCalculator] Loaded
2018-08-28T17:36:22.943Z,1535477782.943 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-08-28T17:36:22.959Z,1535477782.959 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-08-28T17:36:22.959Z,1535477782.959 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-08-28T17:36:22.965Z,1535477782.965 [YawRateCalculator] Loaded
2018-08-28T17:36:22.965Z,1535477782.965 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-08-28T17:36:23.005Z,1535477783.005 [ElevatorOffsetCalculator] Loaded
2018-08-28T17:36:23.005Z,1535477783.005 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-08-28T17:36:23.006Z,1535477783.006 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-08-28T17:36:23.006Z,1535477783.006 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-08-28T17:36:23.031Z,1535477783.031 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-08-28T17:36:23.031Z,1535477783.031 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-08-28T17:36:23.313Z,1535477783.313 [DataOverHttps] Loaded
2018-08-28T17:36:23.313Z,1535477783.313 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-08-28T17:36:23.339Z,1535477783.339 [Depth_Keller] Loaded
2018-08-28T17:36:23.340Z,1535477783.340 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-08-28T17:36:23.345Z,1535477783.345 [DropWeight] Loaded
2018-08-28T17:36:23.345Z,1535477783.345 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-08-28T17:36:23.444Z,1535477783.444 [NAL9602] Loaded
2018-08-28T17:36:23.444Z,1535477783.444 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-08-28T17:36:23.460Z,1535477783.460 [Onboard] Loaded
2018-08-28T17:36:23.460Z,1535477783.460 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-08-28T17:36:23.471Z,1535477783.471 [Radio_Surface] Loaded
2018-08-28T17:36:23.471Z,1535477783.471 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-08-28T17:36:23.472Z,1535477783.472 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407B84E0
2018-08-28T17:36:23.473Z,1535477783.473 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1184
2018-08-28T17:36:23.520Z,1535477783.520 [PNI_TCM] Loaded
2018-08-28T17:36:23.521Z,1535477783.521 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-08-28T17:36:25.288Z,1535477785.288 [BPC1] Loaded
2018-08-28T17:36:25.289Z,1535477785.289 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-08-28T17:36:25.289Z,1535477785.289 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-08-28T17:36:25.290Z,1535477785.290 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-08-28T17:36:25.419Z,1535477785.419 [SBIT](DEBUG): Construct Startup Built In Test.
2018-08-28T17:36:25.442Z,1535477785.442 [SBIT] Loaded
2018-08-28T17:36:25.442Z,1535477785.442 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-08-28T17:36:25.443Z,1535477785.443 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-08-28T17:36:25.455Z,1535477785.455 [IBIT] Loaded
2018-08-28T17:36:25.455Z,1535477785.455 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-08-28T17:36:25.458Z,1535477785.458 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-08-28T17:36:25.608Z,1535477785.608 [CBIT] Loaded
2018-08-28T17:36:25.608Z,1535477785.608 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-08-28T17:36:25.608Z,1535477785.608 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-08-28T17:36:25.609Z,1535477785.609 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-08-28T17:36:25.751Z,1535477785.751 [Aanderaa_O2] Loaded
2018-08-28T17:36:25.751Z,1535477785.751 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-08-28T17:36:25.804Z,1535477785.804 [CTD_Seabird] Loaded
2018-08-28T17:36:25.804Z,1535477785.804 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-08-28T17:36:25.805Z,1535477785.805 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4087C4E0
2018-08-28T17:36:25.806Z,1535477785.806 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1185
2018-08-28T17:36:25.823Z,1535477785.823 [ESPComponent] Loaded
2018-08-28T17:36:25.823Z,1535477785.823 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-08-28T17:36:25.838Z,1535477785.838 [PAR_Licor] Loaded
2018-08-28T17:36:25.838Z,1535477785.838 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-08-28T17:36:25.887Z,1535477785.887 [WetLabsBB2FL] Loaded
2018-08-28T17:36:25.887Z,1535477785.887 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-08-28T17:36:25.888Z,1535477785.888 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408AC4E0
2018-08-28T17:36:25.889Z,1535477785.889 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1186
2018-08-28T17:36:25.889Z,1535477785.889 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-08-28T17:36:25.890Z,1535477785.890 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-08-28T17:36:26.127Z,1535477786.127 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-08-28T17:36:26.127Z,1535477786.127 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-08-28T17:36:26.195Z,1535477786.195 [VerticalControl](DEBUG): Construct VerticalControl.
2018-08-28T17:36:26.291Z,1535477786.291 [VerticalControl] Loaded
2018-08-28T17:36:26.291Z,1535477786.291 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-08-28T17:36:26.292Z,1535477786.292 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-08-28T17:36:26.353Z,1535477786.353 [HorizontalControl] Loaded
2018-08-28T17:36:26.353Z,1535477786.353 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-08-28T17:36:26.354Z,1535477786.354 [SpeedControl](DEBUG): Construct SpeedControl.
2018-08-28T17:36:26.359Z,1535477786.359 [SpeedControl] Loaded
2018-08-28T17:36:26.359Z,1535477786.359 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-08-28T17:36:26.360Z,1535477786.360 [LoopControl](DEBUG): Construct LoopControl.
2018-08-28T17:36:26.361Z,1535477786.361 [LoopControl] Loaded
2018-08-28T17:36:26.361Z,1535477786.361 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-08-28T17:36:26.361Z,1535477786.361 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-08-28T17:36:26.362Z,1535477786.362 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-08-28T17:36:26.444Z,1535477786.444 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-08-28T17:36:26.445Z,1535477786.445 [StratificationFrontDetector](DEBUG): (re)initializing
2018-08-28T17:36:26.445Z,1535477786.445 [StratificationFrontDetector] Loaded
2018-08-28T17:36:26.445Z,1535477786.445 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-08-28T17:36:26.446Z,1535477786.446 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-08-28T17:36:26.446Z,1535477786.446 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-08-28T17:36:26.544Z,1535477786.544 [BuoyancyServo] Loaded
2018-08-28T17:36:26.544Z,1535477786.544 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-08-28T17:36:26.556Z,1535477786.556 [ElevatorServo] Loaded
2018-08-28T17:36:26.556Z,1535477786.556 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-08-28T17:36:26.567Z,1535477786.567 [MassServo] Loaded
2018-08-28T17:36:26.567Z,1535477786.567 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-08-28T17:36:26.579Z,1535477786.579 [RudderServo] Loaded
2018-08-28T17:36:26.579Z,1535477786.579 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-08-28T17:36:26.590Z,1535477786.590 [ThrusterServo] Loaded
2018-08-28T17:36:26.590Z,1535477786.590 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-08-28T17:36:26.590Z,1535477786.590 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-08-28T17:36:26.591Z,1535477786.591 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-08-28T17:36:26.682Z,1535477786.682 [DeadReckonUsingSpeedCalculator] Loaded
2018-08-28T17:36:26.683Z,1535477786.683 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-08-28T17:36:26.687Z,1535477786.687 [UniversalFixResidualReporter] Loaded
2018-08-28T17:36:26.688Z,1535477786.688 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-08-28T17:36:26.688Z,1535477786.688 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-08-28T17:36:26.692Z,1535477786.692 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-08-28T17:36:26.693Z,1535477786.693 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-08-28T17:36:26.699Z,1535477786.699 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-08-28T17:36:26.700Z,1535477786.700 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A054E0
2018-08-28T17:36:26.701Z,1535477786.701 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1187
2018-08-28T17:36:26.705Z,1535477786.705 [Supervisor](INFO): Main Thread ID is 1100
2018-08-28T17:36:26.706Z,1535477786.706 [Supervisor](DEBUG): Running supervisor.
2018-08-28T17:36:26.706Z,1535477786.706 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1188
2018-08-28T17:36:26.709Z,1535477786.709 [controlThread ThreadHandler](INFO): Handler Thread ID is 1189
2018-08-28T17:36:26.709Z,1535477786.709 [controlThread](DEBUG): Initializing ControlThread
2018-08-28T17:36:26.710Z,1535477786.710 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-08-28T17:36:26.710Z,1535477786.710 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-08-28T17:36:26.711Z,1535477786.711 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-08-28T17:36:26.711Z,1535477786.711 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-08-28T17:36:26.712Z,1535477786.712 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-08-28T17:36:26.713Z,1535477786.713 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-08-28T17:36:26.713Z,1535477786.713 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-08-28T17:36:26.718Z,1535477786.718 [SBIT](INFO): Initialize SBIT Component.
2018-08-28T17:36:26.719Z,1535477786.719 [SBIT](IMPORTANT): git: 2018-08-28
2018-08-28T17:36:26.719Z,1535477786.719 [SBIT](INFO): git hash: d6107db9677002c22763a174f01a68f0b5afcf19
2018-08-28T17:36:26.719Z,1535477786.719 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-08-28T17:36:26.721Z,1535477786.721 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-08-28T17:36:26.722Z,1535477786.722 [SBIT](INFO): Beginning SBIT in 68.000000 seconds.
2018-08-28T17:36:26.722Z,1535477786.722 [IBIT](INFO): Initialize IBIT Component.
2018-08-28T17:36:26.723Z,1535477786.723 [CBIT](DEBUG): Initialize CBIT Component.
2018-08-28T17:36:26.724Z,1535477786.724 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-08-28T17:36:26.725Z,1535477786.725 [logger ThreadHandler](INFO): Handler Thread ID is 1190
2018-08-28T17:36:26.744Z,1535477786.744 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1191
2018-08-28T17:36:26.750Z,1535477786.750 [Radio_Surface](INFO): Powering up
2018-08-28T17:36:26.756Z,1535477786.756 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1192
2018-08-28T17:36:26.757Z,1535477786.757 [CTD_Seabird](INFO): Initializing
2018-08-28T17:36:26.757Z,1535477786.757 [CTD_Seabird](INFO): Checking LCM
2018-08-28T17:36:26.766Z,1535477786.766 [CTD_Seabird](INFO): LCM OK
2018-08-28T17:36:26.766Z,1535477786.766 [CTD_Seabird](INFO): Powering up
2018-08-28T17:36:26.773Z,1535477786.773 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1193
2018-08-28T17:36:26.774Z,1535477786.774 [WetLabsBB2FL](INFO): Powering down
2018-08-28T17:36:26.801Z,1535477786.801 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1194
2018-08-28T17:36:26.803Z,1535477786.803 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI11M.000
2018-08-28T17:36:26.804Z,1535477786.804 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI11M.000
2018-08-28T17:36:26.804Z,1535477786.804 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5MI07M.000
2018-08-28T17:36:26.804Z,1535477786.804 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5MI07M.000
2018-08-28T17:36:26.805Z,1535477786.805 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH07M.000
2018-08-28T17:36:26.805Z,1535477786.805 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH07M.000
2018-08-28T17:36:26.805Z,1535477786.805 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH31M.000
2018-08-28T17:36:26.805Z,1535477786.805 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH31M.000
2018-08-28T17:36:26.840Z,1535477786.840 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-08-28T17:36:26.842Z,1535477786.842 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-08-28T17:36:26.843Z,1535477786.843 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-08-28T17:36:26.843Z,1535477786.843 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-08-28T17:36:26.845Z,1535477786.845 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T17:36:26.846Z,1535477786.846 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T17:36:26.846Z,1535477786.846 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T17:36:26.847Z,1535477786.847 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-08-28T17:36:26.848Z,1535477786.848 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-08-28T17:36:26.863Z,1535477786.863 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-28T17:36:26.908Z,1535477786.908 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

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

    </Aggregate>

</Mission>


2018-08-28T17:36:26.909Z,1535477786.909 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-08-28T17:36:26.989Z,1535477786.989 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-08-28T17:36:26.990Z,1535477786.990 [Default:A.Wait](DEBUG): Construct Wait.
2018-08-28T17:36:27.008Z,1535477787.008 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-28T17:36:27.035Z,1535477787.035 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-08-28T17:36:27.037Z,1535477787.037 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-08-28T17:36:27.059Z,1535477787.059 [Default:E.Execute](DEBUG): Construct Execute.
2018-08-28T17:36:27.108Z,1535477787.108 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

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

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2018-08-28T17:36:27.114Z,1535477787.114 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-08-28T17:36:27.147Z,1535477787.147 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-08-28T17:36:27.217Z,1535477787.217 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar
2018-08-28T17:36:27.559Z,1535477787.559 [ESPComponent](INFO): powering down ESP
2018-08-28T17:36:27.962Z,1535477787.962 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-08-28T17:36:28.072Z,1535477788.072 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:36:28.180Z,1535477788.180 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-28T17:36:28.188Z,1535477788.188 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-28T17:36:28.219Z,1535477788.219 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-08-28T17:36:28.224Z,1535477788.224 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-08-28T17:36:28.230Z,1535477788.230 [MassServo](DEBUG): Initializing EZServoServo.
2018-08-28T17:36:28.236Z,1535477788.236 [MassServo](DEBUG): Initializing MassServo.
2018-08-28T17:36:28.268Z,1535477788.268 [RudderServo](DEBUG): Initializing EZServoServo.
2018-08-28T17:36:28.276Z,1535477788.276 [RudderServo](DEBUG): Initializing RudderServo.
2018-08-28T17:36:28.286Z,1535477788.286 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-08-28T17:36:28.292Z,1535477788.292 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-08-28T17:36:28.661Z,1535477788.661 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:36:32.286Z,1535477792.286 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-28T17:36:32.427Z,1535477792.427 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null &
2018-08-28T17:36:32.481Z,1535477792.481 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-08-28T17:36:32.992Z,1535477792.992 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-28T17:36:32.992Z,1535477792.992 [CTD_Seabird](INFO): Powering down
2018-08-28T17:36:37.695Z,1535477797.695 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:36:38.067Z,1535477798.067 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:36:38.580Z,1535477798.580 [Aanderaa_O2](INFO): Powering down
2018-08-28T17:36:38.648Z,1535477798.648 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:36:38.826Z,1535477798.826 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004402
2018-08-28T17:36:38.900Z,1535477798.900 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:36:39.293Z,1535477799.293 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:36:39.665Z,1535477799.665 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:36:53.722Z,1535477813.722 [NAL9602](INFO): Powering up NAL9602
2018-08-28T17:37:14.926Z,1535477834.926 [NAL9602](ERROR): NAL9602 initialization error.
2018-08-28T17:37:14.926Z,1535477834.926 [NAL9602] Communications Fault, FailCount= 1
2018-08-28T17:37:14.926Z,1535477834.926 [NAL9602](ERROR): Communications Fault
2018-08-28T17:37:15.054Z,1535477835.054 [CBIT](ERROR): Communications Fault in component: NAL9602
2018-08-28T17:37:15.321Z,1535477835.321 [NAL9602](INFO): Powering down
2018-08-28T17:37:16.194Z,1535477836.194 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-28T17:37:16.194Z,1535477836.194 [NAL9602] No Fault, FailCount= 1
2018-08-28T17:37:35.389Z,1535477855.389 [SBIT](IMPORTANT): Beginning Startup BIT
2018-08-28T17:37:35.394Z,1535477855.394 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-28T17:37:45.430Z,1535477865.430 [NAL9602](INFO): Powering up NAL9602
2018-08-28T17:37:46.327Z,1535477866.327 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008649
CHAN A1 (24V): -0.012647
CHAN A2 (12V): -0.005154
CHAN A3 (5V): -0.003348
CHAN B0 (3.3V): -0.001699
CHAN B1 (3.15aV): -0.001512
CHAN B2 (3.15bV): -0.001464
CHAN B3 (GND): 0.000074
OPEN: 0.004512
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-28T17:37:56.437Z,1535477876.437 [NAL9602](INFO): NAL9602 initialized
2018-08-28T17:38:32.109Z,1535477912.109 [SBIT](IMPORTANT): SBIT PASSED
2018-08-28T17:38:32.188Z,1535477912.188 [CommandLine](IMPORTANT): got command configSet list
2018-08-28T17:38:32.189Z,1535477912.189 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-08-28T17:38:32.190Z,1535477912.190 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup=0 bool;

2018-08-28T17:38:32.190Z,1535477912.190 [CommandLine](IMPORTANT): CTD_Seabird.minSalinityBound=0.01 practical_salinity_unit;

2018-08-28T17:38:32.190Z,1535477912.190 [CommandLine](IMPORTANT): Depth_Keller.offset=-0.56 decibar;

2018-08-28T17:38:32.190Z,1535477912.190 [CommandLine](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.000500 practical_salinity_unit;

2018-08-28T17:38:32.193Z,1535477912.193 [CommandLine](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.005000 kelvin;

2018-08-28T17:38:32.193Z,1535477912.193 [CommandLine](IMPORTANT): Express linearApproximation WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 0.100000 microgram_per_liter;

2018-08-28T17:38:32.193Z,1535477912.193 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 2.000000 meter;

2018-08-28T17:38:32.193Z,1535477912.193 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 1.000000 microgram_per_liter;

2018-08-28T17:38:32.193Z,1535477912.193 [CommandLine](IMPORTANT): IBIT.batteryHibernationTimeout=1 minute;

2018-08-28T17:38:32.193Z,1535477912.193 [CommandLine](IMPORTANT): IBIT.batteryMissingStickThreshold=18 count;

2018-08-28T17:38:32.193Z,1535477912.193 [CommandLine](IMPORTANT): NavChart.loadAtStartup=0 bool;

2018-08-28T17:38:32.194Z,1535477912.194 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2018-08-28T17:38:32.194Z,1535477912.194 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=539 cubic_centimeter;

2018-08-28T17:38:32.194Z,1535477912.194 [CommandLine](IMPORTANT): VerticalControl.massDefault=-12 millimeter;

2018-08-28T17:38:32.286Z,1535477912.286 [MissionManager](IMPORTANT): Started mission Startup
2018-08-28T17:38:32.287Z,1535477912.287 [Startup] Running Loop=1
2018-08-28T17:38:32.287Z,1535477912.287 [Startup](DEBUG): Aggregate::initialize Startup
2018-08-28T17:38:32.287Z,1535477912.287 [Startup:A.GoToSurface] Running Loop=1
2018-08-28T17:38:32.287Z,1535477912.287 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-28T17:38:32.292Z,1535477912.292 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-28T17:38:32.293Z,1535477912.293 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-28T17:38:32.293Z,1535477912.293 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-28T17:38:32.294Z,1535477912.294 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-28T17:38:32.294Z,1535477912.294 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-28T17:38:32.321Z,1535477912.321 [Startup:StartupSatComms] Running Loop=1
2018-08-28T17:38:32.321Z,1535477912.321 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-08-28T17:38:32.321Z,1535477912.321 [Startup:StartupSatComms:A] Running Loop=1
2018-08-28T17:38:32.649Z,1535477912.649 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-08-28T17:39:08.987Z,1535477948.987 [NAL9602](INFO): SBD MO Status=2, MOMSN=24177, MT Status=2, MTMSN=0
2018-08-28T17:39:08.988Z,1535477948.988 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-28T17:39:17.387Z,1535477957.387 [NAL9602](INFO): SBD MO Status=0, MOMSN=24177, MT Status=0, MTMSN=0
2018-08-28T17:39:17.387Z,1535477957.387 [NAL9602](INFO): No messages in MT queue
2018-08-28T17:39:27.043Z,1535477967.043 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-28T17:39:27.044Z,1535477967.044 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-08-28T17:39:27.044Z,1535477967.044 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-28T17:39:27.057Z,1535477967.057 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-28T17:39:27.456Z,1535477967.456 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-28T17:39:27.456Z,1535477967.456 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-08-28T17:39:27.841Z,1535477967.841 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T17:39:27.842Z,1535477967.842 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T17:39:27.842Z,1535477967.842 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T17:39:32.653Z,1535477972.653 [Startup:StartupSatComms:A](INFO): Timed out from 2018-08-28T17:38:32.3Z
2018-08-28T17:39:32.653Z,1535477972.653 [Startup:StartupSatComms:A] Stopped
2018-08-28T17:39:32.653Z,1535477972.653 [Startup:StartupSatComms:B] Running Loop=1
2018-08-28T17:39:33.026Z,1535477973.026 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-28T17:39:34.059Z,1535477974.059 [DataOverHttps](IMPORTANT): SBD MTMSN=20180828T173932
2018-08-28T17:39:38.130Z,1535477978.130 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20180827T222551/Courier0144.lzma
2018-08-28T17:39:38.146Z,1535477978.146 [DataOverHttps](INFO): Received command:configSet VerticalControl.massDefault -0.5 cm persist
2018-08-28T17:39:38.476Z,1535477978.476 [CommandLine](IMPORTANT): got command configSet VerticalControl.massDefault -0.500000 centimeter persist
2018-08-28T17:39:38.983Z,1535477978.983 [DataOverHttps](INFO): Moved sent file to Logs/20180827T222551/Courier0144.lzma.bak
2018-08-28T17:39:38.983Z,1535477978.983 [DataOverHttps](INFO): SBD MOMSN=8449944
2018-08-28T17:39:51.671Z,1535477991.671 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20180828T171938/Courier0000.lzma
2018-08-28T17:39:52.466Z,1535477992.466 [DataOverHttps](INFO): Moved sent file to Logs/20180828T171938/Courier0000.lzma.bak
2018-08-28T17:39:52.466Z,1535477992.466 [DataOverHttps](INFO): SBD MOMSN=8449947
2018-08-28T17:40:04.968Z,1535478004.968 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20180828T171938/Courier0004.lzma
2018-08-28T17:40:05.766Z,1535478005.766 [DataOverHttps](INFO): Moved sent file to Logs/20180828T171938/Courier0004.lzma.bak
2018-08-28T17:40:05.766Z,1535478005.766 [DataOverHttps](INFO): SBD MOMSN=8449952
2018-08-28T17:40:16.113Z,1535478016.113 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180828T172414/Courier0004.lzma
2018-08-28T17:40:16.906Z,1535478016.906 [DataOverHttps](INFO): Moved sent file to Logs/20180828T172414/Courier0004.lzma.bak
2018-08-28T17:40:16.906Z,1535478016.906 [DataOverHttps](INFO): SBD MOMSN=8449954
2018-08-28T17:40:29.085Z,1535478029.085 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20180828T173111/Courier0004.lzma
2018-08-28T17:40:29.882Z,1535478029.882 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173111/Courier0004.lzma.bak
2018-08-28T17:40:29.883Z,1535478029.883 [DataOverHttps](INFO): SBD MOMSN=8449957
2018-08-28T17:40:32.721Z,1535478032.721 [Startup:StartupSatComms:B](INFO): Timed out from 2018-08-28T17:39:32.7Z
2018-08-28T17:40:32.721Z,1535478032.721 [Startup:StartupSatComms:B] Stopped
2018-08-28T17:40:32.721Z,1535478032.721 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-08-28T17:40:32.721Z,1535478032.721 [Startup:StartupSatComms] Stopped
2018-08-28T17:40:32.722Z,1535478032.722 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-08-28T17:40:32.723Z,1535478032.723 [Startup](INFO): Completed Startup
2018-08-28T17:40:32.723Z,1535478032.723 [MissionManager](INFO): Startup is completed.
2018-08-28T17:40:32.723Z,1535478032.723 [MissionManager](INFO): Uninitializing Mission Startup
2018-08-28T17:40:32.723Z,1535478032.723 [Startup] Stopped
2018-08-28T17:40:32.723Z,1535478032.723 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-08-28T17:40:32.723Z,1535478032.723 [Startup:A.GoToSurface] Stopped
2018-08-28T17:40:32.723Z,1535478032.723 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-28T17:40:33.128Z,1535478033.128 [MissionManager](IMPORTANT): Started mission Default
2018-08-28T17:40:33.129Z,1535478033.129 [Default] Running Loop=1
2018-08-28T17:40:33.129Z,1535478033.129 [Default](DEBUG): Aggregate::initialize Default
2018-08-28T17:40:33.129Z,1535478033.129 [Default:B.GoToSurface] Running Loop=1
2018-08-28T17:40:33.129Z,1535478033.129 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-28T17:40:33.129Z,1535478033.129 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-28T17:40:33.130Z,1535478033.130 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-28T17:40:33.130Z,1535478033.130 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-28T17:40:33.130Z,1535478033.130 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-28T17:40:33.131Z,1535478033.131 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-28T17:40:33.131Z,1535478033.131 [Default:A.Wait] Running Loop=1
2018-08-28T17:40:33.131Z,1535478033.131 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-08-28T17:40:41.908Z,1535478041.908 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180828T173617/Courier0004.lzma
2018-08-28T17:40:42.706Z,1535478042.706 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0004.lzma.bak
2018-08-28T17:40:42.706Z,1535478042.706 [DataOverHttps](INFO): SBD MOMSN=8449960
2018-08-28T17:40:46.404Z,1535478046.404 [Default:A.Wait](INFO): Done Waiting.
2018-08-28T17:40:46.420Z,1535478046.420 [Default:A.Wait] Stopped
2018-08-28T17:40:46.421Z,1535478046.421 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T17:40:46.846Z,1535478046.846 [Default:CheckIn] Running Loop=1
2018-08-28T17:40:46.846Z,1535478046.846 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T17:40:46.846Z,1535478046.846 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T17:40:47.200Z,1535478047.200 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-08-28T17:41:23.438Z,1535478083.438 [CommandLine](IMPORTANT): got command failComponent
2018-08-28T17:41:23.438Z,1535478083.438 [CommandLine](IMPORTANT): Failed components:
2018-08-28T17:41:23.439Z,1535478083.439 [CommandLine](IMPORTANT): No failed Components.
2018-08-28T17:41:36.662Z,1535478096.662 [CommandLine](IMPORTANT): got command configSet Rowe_600LCM.loadAtStartup 0.000000 bool
2018-08-28T17:41:36.662Z,1535478096.662 [CommandLine](FAULT): configSet Rowe_600LCM.loadAtStartup without persist will have no effect.
2018-08-28T17:41:44.486Z,1535478104.486 [CommandLine](IMPORTANT): got command failComponent
2018-08-28T17:41:44.486Z,1535478104.486 [CommandLine](IMPORTANT): Failed components:
2018-08-28T17:41:44.487Z,1535478104.487 [CommandLine](IMPORTANT): No failed Components.
2018-08-28T17:42:27.927Z,1535478147.927 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-28T17:42:27.927Z,1535478147.927 [BPC1] Communications Fault, FailCount= 1
2018-08-28T17:42:27.928Z,1535478147.928 [BPC1](ERROR): Communications Fault
2018-08-28T17:42:27.938Z,1535478147.938 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-28T17:42:27.939Z,1535478147.939 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-08-28T17:42:27.939Z,1535478147.939 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-28T17:42:27.983Z,1535478147.983 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-28T17:42:27.984Z,1535478147.984 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-28T17:42:28.350Z,1535478148.350 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-28T17:42:28.350Z,1535478148.350 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-08-28T17:42:28.743Z,1535478148.743 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T17:42:28.743Z,1535478148.743 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T17:42:28.744Z,1535478148.744 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T17:42:29.143Z,1535478149.143 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-28T17:42:29.143Z,1535478149.143 [BPC1] No Fault, FailCount= 1
2018-08-28T17:45:29.052Z,1535478329.052 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-28T17:45:29.052Z,1535478329.052 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2018-08-28T17:45:29.052Z,1535478329.052 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-28T17:45:29.109Z,1535478329.109 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-28T17:45:29.454Z,1535478329.454 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-28T17:45:29.454Z,1535478329.454 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2018-08-28T17:45:29.835Z,1535478329.835 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T17:45:29.836Z,1535478329.836 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T17:45:29.836Z,1535478329.836 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T17:45:47.019Z,1535478347.019 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-28T17:40:46.8Z
2018-08-28T17:45:47.019Z,1535478347.019 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T17:45:47.019Z,1535478347.019 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-28T17:45:47.423Z,1535478347.423 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-28T17:45:52.544Z,1535478352.544 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180828T173617/Courier0007.lzma
2018-08-28T17:45:53.338Z,1535478353.338 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0007.lzma.bak
2018-08-28T17:45:53.338Z,1535478353.338 [DataOverHttps](INFO): SBD MOMSN=8449966
2018-08-28T17:46:04.407Z,1535478364.407 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20180827T222551/Express0145.lzma
2018-08-28T17:46:05.204Z,1535478365.204 [DataOverHttps](INFO): Moved sent file to Logs/20180827T222551/Express0145.lzma.bak
2018-08-28T17:46:05.204Z,1535478365.204 [DataOverHttps](INFO): SBD MOMSN=8449968
2018-08-28T17:46:16.347Z,1535478376.347 [DataOverHttps](INFO): Sending 1393 bytes from file Logs/20180828T171938/Express0001.lzma
2018-08-28T17:46:17.138Z,1535478377.138 [DataOverHttps](INFO): Moved sent file to Logs/20180828T171938/Express0001.lzma.bak
2018-08-28T17:46:17.139Z,1535478377.139 [DataOverHttps](INFO): SBD MOMSN=8449970
2018-08-28T17:46:29.900Z,1535478389.900 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20180828T171938/Express0005.lzma
2018-08-28T17:46:30.698Z,1535478390.698 [DataOverHttps](INFO): Moved sent file to Logs/20180828T171938/Express0005.lzma.bak
2018-08-28T17:46:30.699Z,1535478390.699 [DataOverHttps](INFO): SBD MOMSN=8450014
2018-08-28T17:46:45.327Z,1535478405.327 [DataOverHttps](INFO): Sending 1213 bytes from file Logs/20180828T172414/Express0001.lzma
2018-08-28T17:46:46.111Z,1535478406.111 [DataOverHttps](INFO): Moved sent file to Logs/20180828T172414/Express0001.lzma.bak
2018-08-28T17:46:46.111Z,1535478406.111 [DataOverHttps](INFO): SBD MOMSN=8450016
2018-08-28T17:46:59.785Z,1535478419.785 [DataOverHttps](INFO): Sending 433 bytes from file Logs/20180828T172414/Express0005.lzma
2018-08-28T17:47:00.581Z,1535478420.581 [DataOverHttps](INFO): Moved sent file to Logs/20180828T172414/Express0005.lzma.bak
2018-08-28T17:47:00.581Z,1535478420.581 [DataOverHttps](INFO): SBD MOMSN=8450052
2018-08-28T17:47:13.272Z,1535478433.272 [DataOverHttps](INFO): Sending 1040 bytes from file Logs/20180828T173111/Express0001.lzma
2018-08-28T17:47:14.066Z,1535478434.066 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173111/Express0001.lzma.bak
2018-08-28T17:47:14.067Z,1535478434.067 [DataOverHttps](INFO): SBD MOMSN=8450064
2018-08-28T17:47:26.888Z,1535478446.888 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20180828T173111/Express0005.lzma
2018-08-28T17:47:27.686Z,1535478447.686 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173111/Express0005.lzma.bak
2018-08-28T17:47:27.686Z,1535478447.686 [DataOverHttps](INFO): SBD MOMSN=8450092
2018-08-28T17:47:38.716Z,1535478458.716 [DataOverHttps](INFO): Sending 985 bytes from file Logs/20180828T173617/Express0001.lzma
2018-08-28T17:47:39.521Z,1535478459.521 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0001.lzma.bak
2018-08-28T17:47:39.521Z,1535478459.521 [DataOverHttps](INFO): SBD MOMSN=8450094
2018-08-28T17:47:50.545Z,1535478470.545 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20180828T173617/Express0005.lzma
2018-08-28T17:47:51.342Z,1535478471.342 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0005.lzma.bak
2018-08-28T17:47:51.342Z,1535478471.342 [DataOverHttps](INFO): SBD MOMSN=8450120
2018-08-28T17:47:58.418Z,1535478478.418 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-28T17:47:58.418Z,1535478478.418 [NAL9602] Data Fault, FailCount= 1
2018-08-28T17:47:58.418Z,1535478478.418 [NAL9602](ERROR): Data Fault
2018-08-28T17:47:58.501Z,1535478478.501 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-28T17:47:58.826Z,1535478478.826 [NAL9602](INFO): Powering down
2018-08-28T17:48:03.736Z,1535478483.736 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-28T17:48:03.736Z,1535478483.736 [NAL9602] No Fault, FailCount= 1
2018-08-28T17:48:04.037Z,1535478484.037 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20180828T173617/Express0008.lzma
2018-08-28T17:48:04.834Z,1535478484.834 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0008.lzma.bak
2018-08-28T17:48:04.834Z,1535478484.834 [DataOverHttps](INFO): SBD MOMSN=8450124
2018-08-28T17:48:06.673Z,1535478486.673 [Default:CheckIn:Read_Iridium] Stopped
2018-08-28T17:48:06.673Z,1535478486.673 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-28T17:48:06.673Z,1535478486.673 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-28T17:48:29.061Z,1535478509.061 [NAL9602](INFO): Powering up NAL9602
2018-08-28T17:48:29.894Z,1535478509.894 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-28T17:48:29.895Z,1535478509.895 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2018-08-28T17:48:29.895Z,1535478509.895 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-28T17:48:29.907Z,1535478509.907 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-28T17:48:30.287Z,1535478510.287 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-28T17:48:30.287Z,1535478510.287 [BPC1] Communications Fault, FailCount= 2
2018-08-28T17:48:30.287Z,1535478510.287 [BPC1](ERROR): Communications Fault
2018-08-28T17:48:30.309Z,1535478510.309 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-28T17:48:30.310Z,1535478510.310 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-28T17:48:30.310Z,1535478510.310 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2018-08-28T17:48:30.695Z,1535478510.695 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T17:48:30.696Z,1535478510.696 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T17:48:30.696Z,1535478510.696 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T17:48:31.516Z,1535478511.516 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-28T17:48:31.516Z,1535478511.516 [BPC1] No Fault, FailCount= 2
2018-08-28T17:48:40.254Z,1535478520.254 [NAL9602](INFO): NAL9602 initialized
2018-08-28T17:51:31.007Z,1535478691.007 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-28T17:51:31.007Z,1535478691.007 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2018-08-28T17:51:31.008Z,1535478691.008 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-28T17:51:31.033Z,1535478691.033 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-28T17:51:31.435Z,1535478691.435 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-28T17:51:31.435Z,1535478691.435 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2018-08-28T17:51:31.811Z,1535478691.811 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T17:51:31.811Z,1535478691.811 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T17:51:31.812Z,1535478691.812 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T17:51:56.698Z,1535478716.698 [CommandLine](IMPORTANT): got command failComponent
2018-08-28T17:51:56.698Z,1535478716.698 [CommandLine](IMPORTANT): Failed components:
2018-08-28T17:51:56.698Z,1535478716.698 [CommandLine](IMPORTANT): No failed Components.
2018-08-28T17:53:06.973Z,1535478786.973 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-28T17:53:06.973Z,1535478786.973 [Default:CheckIn:C.Wait] Stopped
2018-08-28T17:53:06.973Z,1535478786.973 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T17:53:06.973Z,1535478786.973 [Default:CheckIn:D] Running Loop=1
2018-08-28T17:53:07.374Z,1535478787.374 [Default:CheckIn:D] Stopped
2018-08-28T17:53:07.375Z,1535478787.375 [Default:CheckIn:E] Running Loop=1
2018-08-28T17:53:07.777Z,1535478787.777 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.570733 min 
2018-08-28T17:53:07.779Z,1535478787.779 [Default:CheckIn:E] Stopped
2018-08-28T17:53:07.779Z,1535478787.779 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-28T17:53:07.779Z,1535478787.779 [Default:CheckIn] Stopped
2018-08-28T17:53:07.779Z,1535478787.779 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T17:53:07.779Z,1535478787.779 [Default:CheckIn](INFO): Running loop #2
2018-08-28T17:53:07.779Z,1535478787.779 [Default:CheckIn] Running Loop=2
2018-08-28T17:53:07.780Z,1535478787.780 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T17:53:07.780Z,1535478787.780 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T17:54:32.126Z,1535478872.126 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-28T17:54:32.126Z,1535478872.126 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2018-08-28T17:54:32.126Z,1535478872.126 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-28T17:54:32.139Z,1535478872.139 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-28T17:54:32.515Z,1535478872.515 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-28T17:54:32.515Z,1535478872.515 [BPC1] Communications Fault, FailCount= 3
2018-08-28T17:54:32.515Z,1535478872.515 [BPC1](ERROR): Communications Fault
2018-08-28T17:54:32.538Z,1535478872.538 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-28T17:54:32.538Z,1535478872.538 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-28T17:54:32.538Z,1535478872.538 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2018-08-28T17:54:32.936Z,1535478872.936 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T17:54:32.937Z,1535478872.937 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T17:54:32.937Z,1535478872.937 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T17:54:33.750Z,1535478873.750 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-28T17:54:33.750Z,1535478873.750 [BPC1] No Fault, FailCount= 3
2018-08-28T17:57:33.224Z,1535479053.224 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-28T17:57:33.224Z,1535479053.224 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2018-08-28T17:57:33.224Z,1535479053.224 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-28T17:57:33.236Z,1535479053.236 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-28T17:57:33.671Z,1535479053.671 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-28T17:57:33.671Z,1535479053.671 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2018-08-28T17:57:34.043Z,1535479054.043 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T17:57:34.043Z,1535479054.043 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T17:57:34.044Z,1535479054.044 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T17:58:08.025Z,1535479088.025 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-28T17:53:07.8Z
2018-08-28T17:58:08.025Z,1535479088.025 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T17:58:08.025Z,1535479088.025 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-28T17:58:13.541Z,1535479093.541 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180828T173617/Courier0010.lzma
2018-08-28T17:58:14.338Z,1535479094.338 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0010.lzma.bak
2018-08-28T17:58:14.338Z,1535479094.338 [DataOverHttps](INFO): SBD MOMSN=8450135
2018-08-28T17:58:28.550Z,1535479108.550 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20180828T173617/Express0011.lzma
2018-08-28T17:58:29.346Z,1535479109.346 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0011.lzma.bak
2018-08-28T17:58:29.347Z,1535479109.347 [DataOverHttps](INFO): SBD MOMSN=8450137
2018-08-28T17:58:31.164Z,1535479111.164 [Default:CheckIn:Read_Iridium] Stopped
2018-08-28T17:58:31.164Z,1535479111.164 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-28T17:58:31.165Z,1535479111.165 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-28T17:58:42.478Z,1535479122.478 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-28T17:58:42.478Z,1535479122.478 [NAL9602] Data Fault, FailCount= 2
2018-08-28T17:58:42.478Z,1535479122.478 [NAL9602](ERROR): Data Fault
2018-08-28T17:58:42.562Z,1535479122.562 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-28T17:58:42.878Z,1535479122.878 [NAL9602](INFO): Powering down
2018-08-28T17:58:43.733Z,1535479123.733 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-28T17:58:43.733Z,1535479123.733 [NAL9602] No Fault, FailCount= 2
2018-08-28T17:59:13.278Z,1535479153.278 [NAL9602](INFO): Powering up NAL9602
2018-08-28T17:59:24.478Z,1535479164.478 [NAL9602](INFO): NAL9602 initialized
2018-08-28T18:00:35.967Z,1535479235.967 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-28T18:00:35.967Z,1535479235.967 [BPC1] Communications Fault, FailCount= 4
2018-08-28T18:00:35.967Z,1535479235.967 [BPC1](ERROR): Communications Fault
2018-08-28T18:00:35.978Z,1535479235.978 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-28T18:00:35.978Z,1535479235.978 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8
2018-08-28T18:00:35.978Z,1535479235.978 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-28T18:00:35.991Z,1535479235.991 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-28T18:00:35.992Z,1535479235.992 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-28T18:00:36.163Z,1535479236.163 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-28T18:00:36.163Z,1535479236.163 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8
2018-08-28T18:00:36.471Z,1535479236.471 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T18:00:36.471Z,1535479236.471 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T18:00:36.472Z,1535479236.472 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T18:00:36.862Z,1535479236.862 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-28T18:00:36.862Z,1535479236.862 [BPC1] No Fault, FailCount= 4
2018-08-28T18:02:37.162Z,1535479357.162 [DataOverHttps](IMPORTANT): SBD MTMSN=20180828T180234
2018-08-28T18:02:42.765Z,1535479362.765 [DataOverHttps](INFO): Received command:ibit
2018-08-28T18:02:42.841Z,1535479362.841 [CommandLine](IMPORTANT): got command ibit
2018-08-28T18:02:42.846Z,1535479362.846 [IBIT](IMPORTANT): Beginning Initiated BIT
2018-08-28T18:02:42.846Z,1535479362.846 [IBIT](IMPORTANT): Beginning control surface checks.
2018-08-28T18:02:42.854Z,1535479362.854 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-28T18:02:53.647Z,1535479373.647 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008017
CHAN A1 (24V): -0.012092
CHAN A2 (12V): -0.005613
CHAN A3 (5V): -0.002495
CHAN B0 (3.3V): -0.000945
CHAN B1 (3.15aV): -0.001209
CHAN B2 (3.15bV): -0.001344
CHAN B3 (GND): 0.000544
OPEN: 0.004612
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-28T18:03:36.817Z,1535479416.817 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-28T18:03:36.817Z,1535479416.817 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 9
2018-08-28T18:03:36.817Z,1535479416.817 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-28T18:03:36.828Z,1535479416.828 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-28T18:03:37.225Z,1535479417.225 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-28T18:03:37.225Z,1535479417.225 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 9
2018-08-28T18:03:37.617Z,1535479417.617 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T18:03:37.617Z,1535479417.617 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T18:03:37.618Z,1535479417.618 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T18:03:43.154Z,1535479423.154 [NAL9602](INFO): GPS fix at 20180828T180338: (41.827893, -83.411670)
2018-08-28T18:03:43.237Z,1535479423.237 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 41.827892 Longitude: -83.411667
2018-08-28T18:03:43.624Z,1535479423.624 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2018-08-28T18:03:43.993Z,1535479423.993 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2018-08-28T18:03:43.993Z,1535479423.993 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2018-08-28T18:03:43.994Z,1535479423.994 [IBIT](IMPORTANT): Pressure:12.027907 PSI
2018-08-28T18:03:43.994Z,1535479423.994 [IBIT](IMPORTANT): Humidity:20.992554 %
2018-08-28T18:03:44.397Z,1535479424.397 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2018-08-28T18:03:44.398Z,1535479424.398 [IBIT](IMPORTANT): buoyancyNeutral: 539.000000 cc
2018-08-28T18:03:44.398Z,1535479424.398 [IBIT](IMPORTANT): massDefault: -0.500000 cm
2018-08-28T18:03:44.398Z,1535479424.398 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2018-08-28T18:03:44.399Z,1535479424.399 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2018-08-28T18:03:44.399Z,1535479424.399 [IBIT](IMPORTANT): IBIT PASSED
2018-08-28T18:03:44.796Z,1535479424.796 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-28T18:03:44.796Z,1535479424.796 [Default:CheckIn:C.Wait] Stopped
2018-08-28T18:03:44.796Z,1535479424.796 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T18:03:44.796Z,1535479424.796 [Default:CheckIn:D] Running Loop=1
2018-08-28T18:03:45.191Z,1535479425.191 [Default:CheckIn:D] Stopped
2018-08-28T18:03:45.191Z,1535479425.191 [Default:CheckIn:E] Running Loop=1
2018-08-28T18:03:45.595Z,1535479425.595 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.201036 min 
2018-08-28T18:03:45.595Z,1535479425.595 [Default:CheckIn:E] Stopped
2018-08-28T18:03:45.595Z,1535479425.595 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-28T18:03:45.595Z,1535479425.595 [Default:CheckIn] Stopped
2018-08-28T18:03:45.596Z,1535479425.596 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T18:03:45.597Z,1535479425.597 [Default:CheckIn](INFO): Running loop #3
2018-08-28T18:03:45.597Z,1535479425.597 [Default:CheckIn] Running Loop=3
2018-08-28T18:03:45.597Z,1535479425.597 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T18:03:45.598Z,1535479425.598 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T18:03:47.548Z,1535479427.548 [NAL9602](INFO): GPS fix at 20180828T180343: (41.827898, -83.411845)
2018-08-28T18:03:47.586Z,1535479427.586 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T18:03:47.586Z,1535479427.586 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-28T18:03:53.309Z,1535479433.309 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20180828T173617/Courier0013.lzma
2018-08-28T18:03:54.106Z,1535479434.106 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0013.lzma.bak
2018-08-28T18:03:54.106Z,1535479434.106 [DataOverHttps](INFO): SBD MOMSN=8450146
2018-08-28T18:04:07.631Z,1535479447.631 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180828T173617/Courier0016.lzma
2018-08-28T18:04:08.426Z,1535479448.426 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0016.lzma.bak
2018-08-28T18:04:08.426Z,1535479448.426 [DataOverHttps](INFO): SBD MOMSN=8450149
2018-08-28T18:04:19.418Z,1535479459.418 [DataOverHttps](INFO): Sending 871 bytes from file Logs/20180828T173617/Express0014.lzma
2018-08-28T18:04:19.424Z,1535479459.424 [NAL9602](INFO): Powering down
2018-08-28T18:04:20.206Z,1535479460.206 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0014.lzma.bak
2018-08-28T18:04:20.206Z,1535479460.206 [DataOverHttps](INFO): SBD MOMSN=8450151
2018-08-28T18:04:31.172Z,1535479471.172 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180828T173617/Express0017.lzma
2018-08-28T18:04:31.971Z,1535479471.971 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0017.lzma.bak
2018-08-28T18:04:31.971Z,1535479471.971 [DataOverHttps](INFO): SBD MOMSN=8450173
2018-08-28T18:04:33.811Z,1535479473.811 [Default:CheckIn:Read_Iridium] Stopped
2018-08-28T18:04:33.811Z,1535479473.811 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-28T18:04:33.811Z,1535479473.811 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-28T18:06:37.669Z,1535479597.669 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-28T18:06:37.669Z,1535479597.669 [BPC1] Communications Fault, FailCount= 5
2018-08-28T18:06:37.669Z,1535479597.669 [BPC1](ERROR): Communications Fault
2018-08-28T18:06:37.694Z,1535479597.694 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-28T18:06:38.563Z,1535479598.563 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-28T18:06:38.563Z,1535479598.563 [BPC1] No Fault, FailCount= 5
2018-08-28T18:09:34.074Z,1535479774.074 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-28T18:09:34.074Z,1535479774.074 [Default:CheckIn:C.Wait] Stopped
2018-08-28T18:09:34.074Z,1535479774.074 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T18:09:34.074Z,1535479774.074 [Default:CheckIn:D] Running Loop=1
2018-08-28T18:09:34.471Z,1535479774.471 [Default:CheckIn:D] Stopped
2018-08-28T18:09:34.471Z,1535479774.471 [Default:CheckIn:E] Running Loop=1
2018-08-28T18:09:34.876Z,1535479774.876 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.022378 min 
2018-08-28T18:09:34.877Z,1535479774.877 [Default:CheckIn:E] Stopped
2018-08-28T18:09:34.877Z,1535479774.877 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-28T18:09:34.877Z,1535479774.877 [Default:CheckIn] Stopped
2018-08-28T18:09:34.877Z,1535479774.877 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T18:09:34.877Z,1535479774.877 [Default:CheckIn](INFO): Running loop #4
2018-08-28T18:09:34.877Z,1535479774.877 [Default:CheckIn] Running Loop=4
2018-08-28T18:09:34.877Z,1535479774.877 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T18:09:34.877Z,1535479774.877 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T18:09:35.630Z,1535479775.630 [NAL9602](INFO): Powering up
2018-08-28T18:09:46.813Z,1535479786.813 [NAL9602](INFO): NAL9602 initialized
2018-08-28T18:10:17.215Z,1535479817.215 [NAL9602](INFO): SBD MO Status=2, MOMSN=24178, MT Status=2, MTMSN=0
2018-08-28T18:10:17.215Z,1535479817.215 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-28T18:10:33.615Z,1535479833.615 [NAL9602](INFO): SBD MO Status=0, MOMSN=24178, MT Status=0, MTMSN=0
2018-08-28T18:10:33.615Z,1535479833.615 [NAL9602](INFO): No messages in MT queue
2018-08-28T18:10:34.821Z,1535479834.821 [NAL9602](INFO): GPS fix at 20180828T181030: (41.827906, -83.411549)
2018-08-28T18:10:34.899Z,1535479834.899 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T18:10:34.899Z,1535479834.899 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-28T18:10:40.377Z,1535479840.377 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180828T173617/Courier0019.lzma
2018-08-28T18:10:41.174Z,1535479841.174 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0019.lzma.bak
2018-08-28T18:10:41.174Z,1535479841.174 [DataOverHttps](INFO): SBD MOMSN=8450175
2018-08-28T18:10:54.487Z,1535479854.487 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20180828T173617/Express0020.lzma
2018-08-28T18:10:55.282Z,1535479855.282 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0020.lzma.bak
2018-08-28T18:10:55.282Z,1535479855.282 [DataOverHttps](INFO): SBD MOMSN=8450178
2018-08-28T18:10:57.065Z,1535479857.065 [Default:CheckIn:Read_Iridium] Stopped
2018-08-28T18:10:57.065Z,1535479857.065 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-28T18:10:57.065Z,1535479857.065 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-28T18:11:09.985Z,1535479869.985 [NAL9602](INFO): Powering down
2018-08-28T18:12:39.577Z,1535479959.577 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-28T18:12:39.577Z,1535479959.577 [BPC1] Communications Fault, FailCount= 6
2018-08-28T18:12:39.577Z,1535479959.577 [BPC1](ERROR): Communications Fault
2018-08-28T18:12:39.601Z,1535479959.601 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-28T18:12:40.801Z,1535479960.801 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-28T18:12:40.801Z,1535479960.801 [BPC1] No Fault, FailCount= 6
2018-08-28T18:15:57.482Z,1535480157.482 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-28T18:15:57.482Z,1535480157.482 [Default:CheckIn:C.Wait] Stopped
2018-08-28T18:15:57.482Z,1535480157.482 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T18:15:57.482Z,1535480157.482 [Default:CheckIn:D] Running Loop=1
2018-08-28T18:15:57.875Z,1535480157.875 [Default:CheckIn:D] Stopped
2018-08-28T18:15:57.875Z,1535480157.875 [Default:CheckIn:E] Running Loop=1
2018-08-28T18:15:58.282Z,1535480158.282 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.412443 min 
2018-08-28T18:15:58.283Z,1535480158.283 [Default:CheckIn:E] Stopped
2018-08-28T18:15:58.283Z,1535480158.283 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-28T18:15:58.283Z,1535480158.283 [Default:CheckIn] Stopped
2018-08-28T18:15:58.283Z,1535480158.283 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T18:15:58.283Z,1535480158.283 [Default:CheckIn](INFO): Running loop #5
2018-08-28T18:15:58.283Z,1535480158.283 [Default:CheckIn] Running Loop=5
2018-08-28T18:15:58.283Z,1535480158.283 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T18:15:58.284Z,1535480158.284 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T18:15:59.037Z,1535480159.037 [NAL9602](INFO): Powering up
2018-08-28T18:16:10.206Z,1535480170.206 [NAL9602](INFO): NAL9602 initialized
2018-08-28T18:17:41.391Z,1535480261.391 [NAL9602](INFO): SBD MO Status=2, MOMSN=24179, MT Status=2, MTMSN=0
2018-08-28T18:17:41.391Z,1535480261.391 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-28T18:17:58.591Z,1535480278.591 [NAL9602](INFO): SBD MO Status=2, MOMSN=24179, MT Status=2, MTMSN=0
2018-08-28T18:17:58.591Z,1535480278.591 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-28T18:18:19.374Z,1535480299.374 [NAL9602](INFO): SBD MO Status=0, MOMSN=24179, MT Status=0, MTMSN=0
2018-08-28T18:18:19.374Z,1535480299.374 [NAL9602](INFO): No messages in MT queue
2018-08-28T18:18:20.569Z,1535480300.569 [NAL9602](INFO): GPS fix at 20180828T181815: (41.827948, -83.411719)
2018-08-28T18:18:20.635Z,1535480300.635 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T18:18:20.635Z,1535480300.635 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-28T18:18:26.139Z,1535480306.139 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180828T173617/Courier0022.lzma
2018-08-28T18:18:26.934Z,1535480306.934 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0022.lzma.bak
2018-08-28T18:18:26.934Z,1535480306.934 [DataOverHttps](INFO): SBD MOMSN=8450209
2018-08-28T18:18:41.874Z,1535480321.874 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-28T18:18:41.874Z,1535480321.874 [BPC1] Communications Fault, FailCount= 7
2018-08-28T18:18:41.874Z,1535480321.874 [BPC1](ERROR): Communications Fault
2018-08-28T18:18:41.899Z,1535480321.899 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-28T18:18:42.313Z,1535480322.313 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20180828T173617/Express0023.lzma
2018-08-28T18:18:42.794Z,1535480322.794 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-28T18:18:42.794Z,1535480322.794 [BPC1] No Fault, FailCount= 7
2018-08-28T18:18:43.110Z,1535480323.110 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0023.lzma.bak
2018-08-28T18:18:43.110Z,1535480323.110 [DataOverHttps](INFO): SBD MOMSN=8450212
2018-08-28T18:18:44.947Z,1535480324.947 [Default:CheckIn:Read_Iridium] Stopped
2018-08-28T18:18:44.947Z,1535480324.947 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-28T18:18:44.947Z,1535480324.947 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-28T18:18:55.877Z,1535480335.877 [NAL9602](INFO): Powering down
2018-08-28T18:23:45.422Z,1535480625.422 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-28T18:23:45.422Z,1535480625.422 [Default:CheckIn:C.Wait] Stopped
2018-08-28T18:23:45.422Z,1535480625.422 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T18:23:45.422Z,1535480625.422 [Default:CheckIn:D] Running Loop=1
2018-08-28T18:23:45.817Z,1535480625.817 [Default:CheckIn:D] Stopped
2018-08-28T18:23:45.818Z,1535480625.818 [Default:CheckIn:E] Running Loop=1
2018-08-28T18:23:46.219Z,1535480626.219 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.211479 min 
2018-08-28T18:23:46.219Z,1535480626.219 [Default:CheckIn:E] Stopped
2018-08-28T18:23:46.219Z,1535480626.219 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-28T18:23:46.219Z,1535480626.219 [Default:CheckIn] Stopped
2018-08-28T18:23:46.219Z,1535480626.219 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T18:23:46.219Z,1535480626.219 [Default:CheckIn](INFO): Running loop #6
2018-08-28T18:23:46.220Z,1535480626.220 [Default:CheckIn] Running Loop=6
2018-08-28T18:23:46.220Z,1535480626.220 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T18:23:46.220Z,1535480626.220 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T18:23:46.977Z,1535480626.977 [NAL9602](INFO): Powering up
2018-08-28T18:23:58.141Z,1535480638.141 [NAL9602](INFO): NAL9602 initialized
2018-08-28T18:24:16.143Z,1535480656.143 [NAL9602](INFO): SBD MO Status=0, MOMSN=24180, MT Status=0, MTMSN=0
2018-08-28T18:24:16.143Z,1535480656.143 [NAL9602](INFO): No messages in MT queue
2018-08-28T18:24:36.541Z,1535480676.541 [NAL9602](INFO): GPS fix at 20180828T182430: (41.827947, -83.411456)
2018-08-28T18:24:36.603Z,1535480676.603 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T18:24:36.603Z,1535480676.603 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-28T18:24:42.113Z,1535480682.113 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180828T173617/Courier0025.lzma
2018-08-28T18:24:42.910Z,1535480682.910 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0025.lzma.bak
2018-08-28T18:24:42.910Z,1535480682.910 [DataOverHttps](INFO): SBD MOMSN=8450252
2018-08-28T18:24:44.715Z,1535480684.715 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-28T18:24:44.715Z,1535480684.715 [BPC1] Communications Fault, FailCount= 8
2018-08-28T18:24:44.715Z,1535480684.715 [BPC1](ERROR): Communications Fault
2018-08-28T18:24:44.776Z,1535480684.776 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-28T18:24:49.676Z,1535480689.676 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-28T18:24:49.676Z,1535480689.676 [BPC1] No Fault, FailCount= 8
2018-08-28T18:24:56.221Z,1535480696.221 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20180828T173617/Express0026.lzma
2018-08-28T18:24:57.018Z,1535480697.018 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0026.lzma.bak
2018-08-28T18:24:57.018Z,1535480697.018 [DataOverHttps](INFO): SBD MOMSN=8450255
2018-08-28T18:24:58.926Z,1535480698.926 [Default:CheckIn:Read_Iridium] Stopped
2018-08-28T18:24:58.926Z,1535480698.926 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-28T18:24:58.926Z,1535480698.926 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-28T18:25:08.533Z,1535480708.533 [NAL9602](INFO): Powering down
2018-08-28T18:29:59.234Z,1535480999.234 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-28T18:29:59.234Z,1535480999.234 [Default:CheckIn:C.Wait] Stopped
2018-08-28T18:29:59.234Z,1535480999.234 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T18:29:59.234Z,1535480999.234 [Default:CheckIn:D] Running Loop=1
2018-08-28T18:29:59.632Z,1535480999.632 [Default:CheckIn:D] Stopped
2018-08-28T18:29:59.632Z,1535480999.632 [Default:CheckIn:E] Running Loop=1
2018-08-28T18:30:00.029Z,1535481000.029 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.441724 min 
2018-08-28T18:30:00.029Z,1535481000.029 [Default:CheckIn:E] Stopped
2018-08-28T18:30:00.029Z,1535481000.029 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-28T18:30:00.029Z,1535481000.029 [Default:CheckIn] Stopped
2018-08-28T18:30:00.029Z,1535481000.029 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T18:30:00.030Z,1535481000.030 [Default:CheckIn](INFO): Running loop #7
2018-08-28T18:30:00.030Z,1535481000.030 [Default:CheckIn] Running Loop=7
2018-08-28T18:30:00.030Z,1535481000.030 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T18:30:00.030Z,1535481000.030 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T18:30:00.790Z,1535481000.790 [NAL9602](INFO): Powering up
2018-08-28T18:30:11.953Z,1535481011.953 [NAL9602](INFO): NAL9602 initialized
2018-08-28T18:30:50.375Z,1535481050.375 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-28T18:30:50.375Z,1535481050.375 [BPC1] Communications Fault, FailCount= 9
2018-08-28T18:30:50.375Z,1535481050.375 [BPC1](ERROR): Communications Fault
2018-08-28T18:30:50.446Z,1535481050.446 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-28T18:30:51.640Z,1535481051.640 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-28T18:30:51.640Z,1535481051.640 [BPC1] No Fault, FailCount= 9
2018-08-28T18:30:53.155Z,1535481053.155 [NAL9602](INFO): SBD MO Status=2, MOMSN=24181, MT Status=2, MTMSN=0
2018-08-28T18:30:53.155Z,1535481053.155 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-28T18:31:00.760Z,1535481060.760 [NAL9602](INFO): SBD MO Status=0, MOMSN=24181, MT Status=0, MTMSN=0
2018-08-28T18:31:00.760Z,1535481060.760 [NAL9602](INFO): No messages in MT queue
2018-08-28T18:32:08.730Z,1535481128.730 [NAL9602](INFO): GPS fix at 20180828T183201: (41.827333, -83.411781)
2018-08-28T18:32:08.800Z,1535481128.800 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T18:32:08.800Z,1535481128.800 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-28T18:32:14.295Z,1535481134.295 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180828T173617/Courier0028.lzma
2018-08-28T18:32:15.090Z,1535481135.090 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0028.lzma.bak
2018-08-28T18:32:15.091Z,1535481135.091 [DataOverHttps](INFO): SBD MOMSN=8450259
2018-08-28T18:32:27.765Z,1535481147.765 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20180828T173617/Express0029.lzma
2018-08-28T18:32:28.554Z,1535481148.554 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0029.lzma.bak
2018-08-28T18:32:28.555Z,1535481148.555 [DataOverHttps](INFO): SBD MOMSN=8450263
2018-08-28T18:32:30.387Z,1535481150.387 [Default:CheckIn:Read_Iridium] Stopped
2018-08-28T18:32:30.387Z,1535481150.387 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-28T18:32:30.387Z,1535481150.387 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-28T18:32:44.017Z,1535481164.017 [NAL9602](INFO): Powering down
2018-08-28T18:37:30.878Z,1535481450.878 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-28T18:37:30.878Z,1535481450.878 [Default:CheckIn:C.Wait] Stopped
2018-08-28T18:37:30.878Z,1535481450.878 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T18:37:30.878Z,1535481450.878 [Default:CheckIn:D] Running Loop=1
2018-08-28T18:37:31.278Z,1535481451.278 [Default:CheckIn:D] Stopped
2018-08-28T18:37:31.278Z,1535481451.278 [Default:CheckIn:E] Running Loop=1
2018-08-28T18:37:31.682Z,1535481451.682 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.969149 min 
2018-08-28T18:37:31.682Z,1535481451.682 [Default:CheckIn:E] Stopped
2018-08-28T18:37:31.683Z,1535481451.683 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-28T18:37:31.683Z,1535481451.683 [Default:CheckIn] Stopped
2018-08-28T18:37:31.683Z,1535481451.683 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T18:37:31.683Z,1535481451.683 [Default:CheckIn](INFO): Running loop #8
2018-08-28T18:37:31.683Z,1535481451.683 [Default:CheckIn] Running Loop=8
2018-08-28T18:37:31.683Z,1535481451.683 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T18:37:31.683Z,1535481451.683 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T18:37:32.433Z,1535481452.433 [NAL9602](INFO): Powering up
2018-08-28T18:37:43.597Z,1535481463.597 [NAL9602](INFO): NAL9602 initialized
2018-08-28T18:37:59.999Z,1535481479.999 [NAL9602](INFO): SBD MO Status=0, MOMSN=24182, MT Status=0, MTMSN=0
2018-08-28T18:37:59.999Z,1535481479.999 [NAL9602](INFO): No messages in MT queue
2018-08-28T18:38:09.606Z,1535481489.606 [NAL9602](INFO): GPS fix at 20180828T183802: (41.827211, -83.413112)
2018-08-28T18:38:09.662Z,1535481489.662 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T18:38:09.662Z,1535481489.662 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-28T18:38:15.220Z,1535481495.220 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180828T173617/Courier0031.lzma
2018-08-28T18:38:16.018Z,1535481496.018 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0031.lzma.bak
2018-08-28T18:38:16.019Z,1535481496.019 [DataOverHttps](INFO): SBD MOMSN=8450307
2018-08-28T18:38:28.243Z,1535481508.243 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20180828T173617/Express0032.lzma
2018-08-28T18:38:29.039Z,1535481509.039 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0032.lzma.bak
2018-08-28T18:38:29.040Z,1535481509.040 [DataOverHttps](INFO): SBD MOMSN=8450310
2018-08-28T18:38:30.865Z,1535481510.865 [Default:CheckIn:Read_Iridium] Stopped
2018-08-28T18:38:30.865Z,1535481510.865 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-28T18:38:30.865Z,1535481510.865 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-28T18:38:41.249Z,1535481521.249 [NAL9602](INFO): Powering down
2018-08-28T18:41:43.968Z,1535481703.968 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-28T18:41:43.969Z,1535481703.969 [BPC1] Communications Fault, FailCount= 10
2018-08-28T18:41:43.969Z,1535481703.969 [BPC1](ERROR): Communications Fault
2018-08-28T18:41:44.025Z,1535481704.025 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-28T18:41:44.025Z,1535481704.025 [CBIT](CRITICAL): Communications Fault in component: BPC1
2018-08-28T18:41:44.426Z,1535481704.426 [CommandLine](FAULT): Scheduling is paused
2018-08-28T18:41:44.427Z,1535481704.427 [CBIT](INFO): Critical error at 20180828T184144
2018-08-28T18:41:44.427Z,1535481704.427 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-08-28T18:43:31.272Z,1535481811.272 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-28T18:43:31.272Z,1535481811.272 [Default:CheckIn:C.Wait] Stopped
2018-08-28T18:43:31.272Z,1535481811.272 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T18:43:31.273Z,1535481811.273 [Default:CheckIn:D] Running Loop=1
2018-08-28T18:43:31.622Z,1535481811.622 [Default:CheckIn:D] Stopped
2018-08-28T18:43:31.622Z,1535481811.622 [Default:CheckIn:E] Running Loop=1
2018-08-28T18:43:31.934Z,1535481811.934 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.974890 min 
2018-08-28T18:43:31.935Z,1535481811.935 [Default:CheckIn:E] Stopped
2018-08-28T18:43:31.935Z,1535481811.935 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-28T18:43:31.935Z,1535481811.935 [Default:CheckIn] Stopped
2018-08-28T18:43:31.935Z,1535481811.935 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T18:43:31.935Z,1535481811.935 [Default:CheckIn](INFO): Running loop #9
2018-08-28T18:43:31.935Z,1535481811.935 [Default:CheckIn] Running Loop=9
2018-08-28T18:43:31.935Z,1535481811.935 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T18:43:31.936Z,1535481811.936 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T18:43:32.697Z,1535481812.697 [NAL9602](INFO): Powering up
2018-08-28T18:43:43.517Z,1535481823.517 [NAL9602](INFO): NAL9602 initialized
2018-08-28T18:44:14.719Z,1535481854.719 [NAL9602](INFO): SBD MO Status=0, MOMSN=24183, MT Status=0, MTMSN=0
2018-08-28T18:44:14.719Z,1535481854.719 [NAL9602](INFO): No messages in MT queue
2018-08-28T18:44:15.921Z,1535481855.921 [NAL9602](INFO): GPS fix at 20180828T184408: (41.827488, -83.413593)
2018-08-28T18:44:15.989Z,1535481855.989 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T18:44:15.989Z,1535481855.989 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-28T18:44:22.656Z,1535481862.656 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20180828T173617/Courier0034.lzma
2018-08-28T18:44:23.438Z,1535481863.438 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0034.lzma.bak
2018-08-28T18:44:23.439Z,1535481863.439 [DataOverHttps](INFO): SBD MOMSN=8450332
2018-08-28T18:44:36.020Z,1535481876.020 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20180828T173617/Express0035.lzma
2018-08-28T18:44:36.815Z,1535481876.815 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0035.lzma.bak
2018-08-28T18:44:36.815Z,1535481876.815 [DataOverHttps](INFO): SBD MOMSN=8450336
2018-08-28T18:44:38.613Z,1535481878.613 [Default:CheckIn:Read_Iridium] Stopped
2018-08-28T18:44:38.613Z,1535481878.613 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-28T18:44:38.613Z,1535481878.613 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-28T18:44:48.633Z,1535481888.633 [NAL9602](INFO): Powering down
2018-08-28T18:46:44.204Z,1535482004.204 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-28T18:46:44.205Z,1535482004.205 [BPC1] No Fault, FailCount= 10
2018-08-28T18:48:03.782Z,1535482083.782 [BPC1](INFO): Failure count cleared after critical for BPC1
2018-08-28T18:49:38.958Z,1535482178.958 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-28T18:49:38.958Z,1535482178.958 [Default:CheckIn:C.Wait] Stopped
2018-08-28T18:49:38.958Z,1535482178.958 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T18:49:38.958Z,1535482178.958 [Default:CheckIn:D] Running Loop=1
2018-08-28T18:49:39.358Z,1535482179.358 [Default:CheckIn:D] Stopped
2018-08-28T18:49:39.358Z,1535482179.358 [Default:CheckIn:E] Running Loop=1
2018-08-28T18:49:39.752Z,1535482179.752 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.103817 min 
2018-08-28T18:49:39.752Z,1535482179.752 [Default:CheckIn:E] Stopped
2018-08-28T18:49:39.752Z,1535482179.752 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-28T18:49:39.752Z,1535482179.752 [Default:CheckIn] Stopped
2018-08-28T18:49:39.752Z,1535482179.752 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T18:49:39.753Z,1535482179.753 [Default:CheckIn](INFO): Running loop #10
2018-08-28T18:49:39.753Z,1535482179.753 [Default:CheckIn] Running Loop=10
2018-08-28T18:49:39.753Z,1535482179.753 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T18:49:39.753Z,1535482179.753 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T18:49:40.509Z,1535482180.509 [NAL9602](INFO): Powering up
2018-08-28T18:49:51.678Z,1535482191.678 [NAL9602](INFO): NAL9602 initialized
2018-08-28T18:50:04.079Z,1535482204.079 [NAL9602](INFO): SBD MO Status=0, MOMSN=24184, MT Status=0, MTMSN=0
2018-08-28T18:50:04.079Z,1535482204.079 [NAL9602](INFO): No messages in MT queue
2018-08-28T18:50:25.686Z,1535482225.686 [NAL9602](INFO): GPS fix at 20180828T185017: (41.827468, -83.413618)
2018-08-28T18:50:25.758Z,1535482225.758 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T18:50:25.758Z,1535482225.758 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-28T18:50:31.247Z,1535482231.247 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20180828T173617/Courier0037.lzma
2018-08-28T18:50:32.042Z,1535482232.042 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0037.lzma.bak
2018-08-28T18:50:32.043Z,1535482232.043 [DataOverHttps](INFO): SBD MOMSN=8450341
2018-08-28T18:50:45.223Z,1535482245.223 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20180828T173617/Express0038.lzma
2018-08-28T18:50:46.014Z,1535482246.014 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0038.lzma.bak
2018-08-28T18:50:46.015Z,1535482246.015 [DataOverHttps](INFO): SBD MOMSN=8450344
2018-08-28T18:50:47.842Z,1535482247.842 [Default:CheckIn:Read_Iridium] Stopped
2018-08-28T18:50:47.842Z,1535482247.842 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-28T18:50:47.842Z,1535482247.842 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-28T18:50:57.825Z,1535482257.825 [NAL9602](INFO): Powering down
2018-08-28T18:55:48.124Z,1535482548.124 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-28T18:55:48.125Z,1535482548.125 [Default:CheckIn:C.Wait] Stopped
2018-08-28T18:55:48.125Z,1535482548.125 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T18:55:48.125Z,1535482548.125 [Default:CheckIn:D] Running Loop=1
2018-08-28T18:55:48.525Z,1535482548.525 [Default:CheckIn:D] Stopped
2018-08-28T18:55:48.525Z,1535482548.525 [Default:CheckIn:E] Running Loop=1
2018-08-28T18:55:48.920Z,1535482548.920 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.256600 min 
2018-08-28T18:55:48.922Z,1535482548.922 [Default:CheckIn:E] Stopped
2018-08-28T18:55:48.922Z,1535482548.922 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-28T18:55:48.924Z,1535482548.924 [Default:CheckIn] Stopped
2018-08-28T18:55:48.924Z,1535482548.924 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T18:55:48.924Z,1535482548.924 [Default:CheckIn](INFO): Running loop #11
2018-08-28T18:55:48.924Z,1535482548.924 [Default:CheckIn] Running Loop=11
2018-08-28T18:55:48.924Z,1535482548.924 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T18:55:48.924Z,1535482548.924 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T18:55:49.677Z,1535482549.677 [NAL9602](INFO): Powering up
2018-08-28T18:56:00.849Z,1535482560.849 [NAL9602](INFO): NAL9602 initialized
2018-08-28T18:56:25.651Z,1535482585.651 [NAL9602](INFO): SBD MO Status=0, MOMSN=24185, MT Status=0, MTMSN=0
2018-08-28T18:56:25.651Z,1535482585.651 [NAL9602](INFO): No messages in MT queue
2018-08-28T18:56:56.033Z,1535482616.033 [NAL9602](INFO): GPS fix at 20180828T185646: (41.827552, -83.413066)
2018-08-28T18:56:56.117Z,1535482616.117 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T18:56:56.117Z,1535482616.117 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-28T18:57:01.876Z,1535482621.876 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20180828T173617/Courier0040.lzma
2018-08-28T18:57:02.674Z,1535482622.674 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0040.lzma.bak
2018-08-28T18:57:02.675Z,1535482622.675 [DataOverHttps](INFO): SBD MOMSN=8450368
2018-08-28T18:57:15.321Z,1535482635.321 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20180828T173617/Express0041.lzma
2018-08-28T18:57:16.110Z,1535482636.110 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0041.lzma.bak
2018-08-28T18:57:16.111Z,1535482636.111 [DataOverHttps](INFO): SBD MOMSN=8450371
2018-08-28T18:57:17.941Z,1535482637.941 [Default:CheckIn:Read_Iridium] Stopped
2018-08-28T18:57:17.941Z,1535482637.941 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-28T18:57:17.941Z,1535482637.941 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-28T18:57:27.929Z,1535482647.929 [NAL9602](INFO): Powering down
2018-08-28T19:02:18.298Z,1535482938.298 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-28T19:02:18.298Z,1535482938.298 [Default:CheckIn:C.Wait] Stopped
2018-08-28T19:02:18.299Z,1535482938.299 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T19:02:18.299Z,1535482938.299 [Default:CheckIn:D] Running Loop=1
2018-08-28T19:02:18.688Z,1535482938.688 [Default:CheckIn:D] Stopped
2018-08-28T19:02:18.688Z,1535482938.688 [Default:CheckIn:E] Running Loop=1
2018-08-28T19:02:19.088Z,1535482939.088 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.759326 min 
2018-08-28T19:02:19.089Z,1535482939.089 [Default:CheckIn:E] Stopped
2018-08-28T19:02:19.089Z,1535482939.089 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-28T19:02:19.089Z,1535482939.089 [Default:CheckIn] Stopped
2018-08-28T19:02:19.089Z,1535482939.089 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T19:02:19.089Z,1535482939.089 [Default:CheckIn](INFO): Running loop #12
2018-08-28T19:02:19.089Z,1535482939.089 [Default:CheckIn] Running Loop=12
2018-08-28T19:02:19.090Z,1535482939.090 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T19:02:19.090Z,1535482939.090 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T19:02:19.845Z,1535482939.845 [NAL9602](INFO): Powering up
2018-08-28T19:02:31.025Z,1535482951.025 [NAL9602](INFO): NAL9602 initialized
2018-08-28T19:03:00.235Z,1535482980.235 [NAL9602](INFO): SBD MO Status=2, MOMSN=24186, MT Status=2, MTMSN=0
2018-08-28T19:03:00.235Z,1535482980.235 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-28T19:03:11.827Z,1535482991.827 [NAL9602](INFO): SBD MO Status=0, MOMSN=24186, MT Status=0, MTMSN=0
2018-08-28T19:03:11.827Z,1535482991.827 [NAL9602](INFO): No messages in MT queue
2018-08-28T19:07:19.253Z,1535483239.253 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-28T19:02:19.1Z
2018-08-28T19:07:19.254Z,1535483239.254 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T19:07:19.254Z,1535483239.254 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-28T19:07:24.796Z,1535483244.796 [DataOverHttps](INFO): Sending 46 bytes from file Logs/20180828T173617/Courier0043.lzma
2018-08-28T19:07:25.590Z,1535483245.590 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Courier0043.lzma.bak
2018-08-28T19:07:25.591Z,1535483245.591 [DataOverHttps](INFO): SBD MOMSN=8450412
2018-08-28T19:07:37.763Z,1535483257.763 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20180828T173617/Express0044.lzma
2018-08-28T19:07:38.558Z,1535483258.558 [DataOverHttps](INFO): Moved sent file to Logs/20180828T173617/Express0044.lzma.bak
2018-08-28T19:07:38.559Z,1535483258.559 [DataOverHttps](INFO): SBD MOMSN=8450414
2018-08-28T19:07:40.391Z,1535483260.391 [Default:CheckIn:Read_Iridium] Stopped
2018-08-28T19:07:40.391Z,1535483260.391 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-28T19:07:40.391Z,1535483260.391 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-28T19:07:54.433Z,1535483274.433 [NAL9602](INFO): Powering down
2018-08-28T19:12:40.801Z,1535483560.801 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-28T19:12:40.801Z,1535483560.801 [Default:CheckIn:C.Wait] Stopped
2018-08-28T19:12:40.801Z,1535483560.801 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T19:12:40.801Z,1535483560.801 [Default:CheckIn:D] Running Loop=1
2018-08-28T19:12:41.203Z,1535483561.203 [Default:CheckIn:D] Stopped
2018-08-28T19:12:41.203Z,1535483561.203 [Default:CheckIn:E] Running Loop=1
2018-08-28T19:12:41.619Z,1535483561.619 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.134562 min 
2018-08-28T19:12:41.620Z,1535483561.620 [Default:CheckIn:E] Stopped
2018-08-28T19:12:41.620Z,1535483561.620 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-28T19:12:41.620Z,1535483561.620 [Default:CheckIn] Stopped
2018-08-28T19:12:41.620Z,1535483561.620 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T19:12:41.620Z,1535483561.620 [Default:CheckIn](INFO): Running loop #13
2018-08-28T19:12:41.621Z,1535483561.621 [Default:CheckIn] Running Loop=13
2018-08-28T19:12:41.621Z,1535483561.621 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T19:12:41.621Z,1535483561.621 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T19:12:45.049Z,1535483565.049 [NAL9602](INFO): Powering up
2018-08-28T19:12:55.945Z,1535483575.945 [NAL9602](INFO): NAL9602 initialized
2018-08-28T19:12:56.746Z,1535483576.746 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-28T19:12:56.746Z,1535483576.746 [NAL9602] Data Fault, FailCount= 1
2018-08-28T19:12:56.746Z,1535483576.746 [NAL9602](ERROR): Data Fault
2018-08-28T19:12:56.834Z,1535483576.834 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-28T19:12:57.145Z,1535483577.145 [NAL9602](INFO): Powering down
2018-08-28T19:12:58.006Z,1535483578.006 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-28T19:12:58.006Z,1535483578.006 [NAL9602] No Fault, FailCount= 1
2018-08-28T19:13:27.152Z,1535483607.152 [NAL9602](INFO): Powering up NAL9602
2018-08-28T19:13:38.348Z,1535483618.348 [NAL9602](INFO): NAL9602 initialized
2018-08-28T19:13:54.711Z,1535483634.711 [NAL9602](INFO): SBD MO Status=0, MOMSN=24187, MT Status=0, MTMSN=0
2018-08-28T19:13:54.711Z,1535483634.711 [NAL9602](INFO): No messages in MT queue
2018-08-28T19:15:48.658Z,1535483748.658 [DataOverHttps](IMPORTANT): SBD MTMSN=20180828T191538
2018-08-28T19:15:53.077Z,1535483753.077 [DataOverHttps](INFO): Received command:restart logs